← index #916Issue #785
Related · high · value 2.628
QUERY · ISSUE

urequests: Extra response headers at the end of res.text with Pico W

openby canuckdevopened 2023-11-11updated 2024-09-25
bug

Using latest urequests with Pico W and finding that extra response headers are being appended to the res.text attribute which results in the data not being able to be parsed as JSON.

import urequests as requests
import config
import putils

postHeaders = { 'Content-Type': 'application/json', 'Accept': 'application/json' }
alsaHost = 'pi9'
method = 'POST'
url = 'http://' + alsaHost + ':1780/jsonrpc'
postData = '{"id":0,"jsonrpc":"2.0","method":"Server.GetStatus"}'

try:
    wlan = putils.wlan_connect(config.ssid, config.password)
    res = requests.request(method, url, data=postData, headers=postHeaders)
    if res.status_code != 200:
        print('{} {} {}'.format(res.status_code, method, url))
    else:
        print(res.text)
except OSError as e:
    print('OSError in reqUrl {} {}'.format(method, url))

The result:

{"id":0,"jsonrpc":"2.0","result":{"server":{"groups":[{"clients":[{"config":{"instance":1,"latency":0,"name":"","volume":{"muted":false,"percent":33}},"connected":true,"host":{"arch":"aarch64","ip":"192.168.1.126","mac":"b8:27:eb:99:b6:1e","name":"pi4","os":"Debian GNU/Linux 12 (bookworm)"},"id":"b8:27:eb:99:b6:1e","lastSeen":{"sec":1699725481,"usec":49965},"snapclient":{"name":"Snapclient","protocolVersion":2,"version":"0.26.0"}},{"config":{"instance":1,"latency":0,"name":"","volume":{"muted":false,"percent":33}},"connected":true,"host":{"arch":"aarch64","ip":"192.168.1.144","mac":"e4:5f:01:f5:48:88","name":"pi8","os":"Debian GNU/Linux 12 (bookworm)"},"id":"e4:5f:01:f5:48:88","lastSeen":{"sec":1699725480,"usec":546206},"snapclient":{"name":"Snapclient","protocolVersion":2,"version":"0.26.0"}}],"id":"77eaeda3-1297-437d-e8cf-d492a07bf103","muted":false,"name":"","stream_id":"default"}],"server":{"host":{"arch":"aarch64","ip":"","mac":"","name":"pi9","os":"Debian GNU/Linux 12 (bookworm)"},"snapserver":{"controlProtocolVersion":1,"name":"Snapserver","protocolVersion":1,"version":"0.26.0"}},"streams":[{"id":"default","properties":{"canControl":false,"canGoNext":false,"canGoPrevious":false,"canPause":false,"canPlay":false,"canSeek":false},"status":"playing","uri":{"fragment":"","host":"","path":"/tmp/snapfifo","query":{"chunk_ms":"20","codec":"flac","name":"default","sampleformat":"48000:16:2"},"raw":"pipe:////tmp/snapfifo?chunk_ms=20&codec=flac&name=default&sampleformat=48000:16:2","scheme":"pipe"}}]}}}HTTP/1.0 200 OK
Server: Snapcast
Content-Type: application/json
Content-Length: 0

Looking at the output there are 4 response headers appended to the JSON response:

HTTP/1.0 200 OK
Server: Snapcast
Content-Type: application/json
Content-Length: 0

Running the equivalent code in python3 gives the expected response of only the JSON output in the res.text attribute.

canuckdev

3 comments
projectgus · 2024-08-27

@canuckdev Thanks for being patient while someone got back to you about this.

It looks like you're talking to a SnapCast JSON HTTP endpoint, is that right? It seems either its embedded webserver is not sending a valid HTTP/1.0 response or MicroPython requests isn't parsing the response properly. However it's hard to tell which without a SnapCast server to query for a sample response.

If you're able to, could you please build up your POST request via a curl command and send it with the -v --http1.0 options appended? The verbose output might show enough to figure out what part of the response is confusing MicroPython requests module.

canuckdev · 2024-09-18

Thanks for getting back to me. Here is zip which includes a script for the POST request with stdout in test.out and stderr in test.err

canuckdev
test.zip

projectgus · 2024-09-25

Thanks for that, @canuckdev. I am unfortunately none the wiser, as this HTTP response looks OK:

*   Trying 192.168.1.37:1780...
* Connected to pi9 (192.168.1.37) port 1780 (#0)
> POST /jsonrpc HTTP/1.0
> Host: pi9:1780
> User-Agent: curl/7.81.0
> Content-Type: application/json
> Accept: application/json
> Content-Length: 52
> 
} [52 bytes data]
* Mark bundle as not supporting multiuse
* HTTP 1.0, assume close after body
< HTTP/1.0 200 OK
< Server: Snapcast
< Content-Type: application/json
< Content-Length: 1525
< 
{ [1525 bytes data]
* Closing connection 0

The first thing the requests module does after sending the request is parse out the status line (HTTP/1.0 200 OK), and then it's discarded so I don't see how it can be printed after the body:
https://github.com/micropython/micropython-lib/blob/master/python-ecosys/requests/requests/init.py#L146

Of course, maybe requests is sending a malformed POST compared to the curl. I don't suppose you're in a position to capture the network packets from a faulty request/response? (Can do this on the Pi end with something like sudo tcpdump -i any -w requests.pcap tcp port 1780, then perform the request and Ctrl-C to exit.)

Also, just to double check, did you install urequests by mpremote mip install urequests or via some other method?

(In recent versions urequests is a minimal wrapper around requests.)

CANDIDATE · ISSUE

urequests.get in Micropython randomly results in OSError 103 and 104 as well as ValueError

openby nanowizopened 2024-01-05updated 2025-01-15

I am using urequest.get in Micropython running on a Raspberry Pi PICO W in a loop containing the following to access Ecobee's server for my furnace status:

url = "https://api.ecobee.com/1/thermostatSummary?format=json&body={\"selection\":{\"selectionType\":\"registered\",\"selectionMatch\":\"\",\"includeEquipmentStatus\":true}}"
headers = {
        'Content-Type': 'text/json',
        'Authorization': f'Bearer {accessToken}'
}
response = urequests.get(url, headers=headers)
rstatus = response.status_code
data = response.json()
response.close()

This works most of the time, but the code will randomly crash with either OSError 104 or OSError 103 or ValueError. The following are REPL outputs of these errors.

Traceback (most recent call last):
File "<stdin>", line 157, in <module>
File "<stdin>", line 52, in furnaceStatus
File "requests/init.py", line 180, in get
File "requests/init.py", line 125, in request
OSError: -104

Traceback (most recent call last):
File "<stdin>", line 166, in <module>
File "<stdin>", line 52, in furnaceStatus
File "requests/init.py", line 180, in get
File "requests/init.py", line 130, in request
ValueError: HTTP error: BadStatusLine:
[]

I understand that the OSError 104 and 103 are network response issues. It would be much better if they can be handled with a returned status code rather than causing an OSError. According to the githib code at line 130 of request in requests/init.py, it is complaining about an invalid response presumabily from the internet response. Again, it would be more desirable to be handled with a status code response rather than causing a program crash.

7 comments
ned-pcs · 2024-01-18

OSError 104 is ECONNRESET. Which can be caused by one end or the other closing a socket too soon.
But one should usually enclose network functions in try/except blocks anyway:

url = "https://api.ecobee.com/1/thermostatSummary?format=json&body={\"selection\":{\"selectionType\":\"registered\",\"selectionMatch\":\"\",\"includeEquipmentStatus\":true}}"
headers = {
        'Content-Type': 'text/json',
        'Authorization': f'Bearer {accessToken}'
}
try:
    response = urequests.get(url, headers=headers)
    rstatus = response.status_code
    data = response.json()
    response.close()
except OSError, ValueError:
    data = None
    rstatus = 500
nanowiz · 2024-01-20

Hi Ned,

Thanks for the reply. I am already doing that and catching the OSError so I
can restart. OCError 104 is not too bad, but sometimes I get OSError 103
which occasionally can become sticky, where every following
urequest.get call will get the OSError 103. I increased the calls to
gc.collect() to free up memory in my loop. It reduced the frequency of
these errors, but they still pop up once every few hours and within a day,
it will turn sticky. Only way out was to do a machine.reset() and restart
the program after a soft boot.

It would be much easier to handle if urequest.get just returned with a
status code indicating the error instead of crashing with an exception 103
or 104.

Sammy

On Thu, Jan 18, 2024 at 3:14 PM Ned Konz @.***> wrote:

OSError 104 is ECONNRESET. Which can be caused by one end or the other
closing a socket too soon.
But one should usually enclose network functions in try/except blocks
anyway:

url = "https://api.ecobee.com/1/thermostatSummary?format=json&body={"selection":{"selectionType":"registered","selectionMatch":"","includeEquipmentStatus":true}}"headers = {
'Content-Type': 'text/json',
'Authorization': f'Bearer {accessToken}'
}try:
response = urequests.get(url, headers=headers)
rstatus = response.status_code
data = response.json()
response.close()except OSError, ValueError:
data = None
rstatus = 500


Reply to this email directly, view it on GitHub
https://github.com/micropython/micropython-lib/issues/785#issuecomment-1899366761,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/AOBUR45SMZETAHI3OAVQYI3YPGUGRAVCNFSM6AAAAABBOA546CVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTQOJZGM3DMNZWGE
.
You are receiving this because you authored the thread.Message ID:
@.***>

joshunagy · 2025-01-14

Hi Sammy,

I'm also seeing a very similar problem and I can't figure it out. I'm new to MicroPython so I'm still leaning the ropes, so please forgive me.
I'm also using urequest but a post(), not a get() and see very similar occasional OSError 103 errors. I also see the same "stickiness", where it sometimes starts to always respond like this and doesn't stop. When the OSError occurs there's a long delay after the request.post(). I have the post happening in an asyncio function. When the post works, it's super fast, but when it doesn't, it take anywhere from 5-20 seconds to respond with the error. I've only seen the OSError 104 once in my days of testing, but that could have just been a momentary wifi/internet connection issue. My internet and Wifi are pretty solid. Using Postman the API always responds instantly. I'm posting to a very simple self hosted PHP script right now. I can see the apache logs and there's nothing obviously wrong with the requests (that I can see).

I'm pretty sure it was working reliably at one point, though I could have been wrong. I'm going to strip my program back to just the absolute essentials and see if I can get the posts to be reliable again.

Have you discovered anything since your last post?

nanowiz · 2025-01-14

Hi Josh,

Sorry, it has been a long time since I had that problem, and I have
forgotten exactly what I did. But I know I did get over that problem so I
no longer get those errors. Just cannot remember exactly what I did. Sorry.

Sammy

On Mon, Jan 13, 2025 at 6:25 PM joshunagy @.***> wrote:

Hi Sammy,

I'm also seeing a very similar problem and I can't figure it out. I'm new
to MicroPython so I'm still leaning the ropes, so please forgive me.
I'm also using urequest but a post(), not a get() and see very similar
occasional OSError 103 errors. I also see the same "stickiness", where it
sometimes starts to always respond like this and doesn't stop. When the
OSError occurs there's a long delay after the request.post(). I have the
post happening in an asyncio function. When the post works, it's super
fast, but when it doesn't, it take anywhere from 5-20 seconds to respond
with the error. I've only seen the OSError 104 once in my days of testing,
but that could have just been a momentary wifi/internet connection issue.
My internet and Wifi are pretty solid. Using Postman the API always
responds instantly. I'm posting to a very simple self hosted PHP script
right now. I can see the apache logs and there's nothing obviously wrong
with the requests (that I can see).

I'm pretty sure it was working reliably at one point, though I could have
been wrong. I'm going to strip my program back to just the absolute
essentials and see if I can get the posts to be reliable again.

Have you discovered anything since your last post, forgive the pun :)


Reply to this email directly, view it on GitHub
https://github.com/micropython/micropython-lib/issues/785#issuecomment-2588720534,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/AOBUR47SB472ZP6Q2I3UJGL2KRYTLAVCNFSM6AAAAABVD4XNRKVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDKOBYG4ZDANJTGQ
.
You are receiving this because you authored the thread.Message ID:
@.***>

joshunagy · 2025-01-14

No problem, I get it. But thanks for the quick response!
I "feel" like it's resource issue, almost like my urequest.close() isn't isn't actually closing the sockets and they're building up, or some resource leak like that, or the async function is trying to grab a resource at the same time as another async function. Anyways, I'll keep stripping down my app until I find it and I'll post it if I figure it out.

joshunagy · 2025-01-14

So I've stripped by script down to the basics and I'm still having the issue.

`import urequests
import network
import time

ssid="MySSID"
password="MyKey"

url = "http://mydomain.com/api.php"
data = {"mac_addr": "aabbccddee"}
headers = {"Content-Type": "application/json"}

fail_count = 0
success_count = 0

wlan = network.WLAN(network.STA_IF)
wlan.active(True)

print("Starting")

while True:

while wlan.isconnected() == False:
    print("Connecting to Wifi...")
    wlan.connect(ssid, password)
    
    
    time.sleep(3)
    if wlan.isconnected() == True:
        print("WiFi Manager: Connected")


if wlan.isconnected() == True:

    try:
        print("Sending POST Request")
        response = urequests.post(url, json=data, headers=headers)
        print(response.text)
        response.close()
        success_count += 1
    
    except OSError as error:
        print ("Error with REST API call. " + str(error.errno) + " Error: " + str(error) )
        fail_count += 1
        
print("Update attempts. Success: " + str(success_count) + " Failed: " + str(fail_count))       
time.sleep(10)

`

The URL in the snippet is obviously not what I'm actually using but you can see from the REPL what it returns.

'Sending POST Request
{"mac_addr":"aabbccddee","temp_scale":"C","temp_low_value":"19","timestamp":"Tue, 14 Jan 2025 11:42:12 +0000"}
Update attempts. Success: 38 Failed: 0
Sending POST Request
{"mac_addr":"aabbccddee","temp_scale":"C","temp_low_value":"19","timestamp":"Tue, 14 Jan 2025 11:42:23 +0000"}
Update attempts. Success: 39 Failed: 0
Sending POST Request
{"mac_addr":"aabbccddee","temp_scale":"C","temp_low_value":"19","timestamp":"Tue, 14 Jan 2025 11:42:33 +0000"}
Update attempts. Success: 40 Failed: 0
Sending POST Request

<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>408 Request Timeout</title>
</head><body>
<h1>Request Timeout</h1>
<p>Server timeout waiting for the HTTP request from the client.</p>
</body></html>

Update attempts. Success: 41 Failed: 0
Sending POST Request
Error with REST API call. 103 Error: [Errno 103] ECONNABORTED
Update attempts. Success: 41 Failed: 1
Sending POST Request
Error with REST API call. 103 Error: [Errno 103] ECONNABORTED
Update attempts. Success: 41 Failed: 2
Sending POST Request
{"mac_addr":"aabbccddee","temp_scale":"C","temp_low_value":"19","timestamp":"Tue, 14 Jan 2025 11:44:16 +0000"}
Update attempts. Success: 42 Failed: 2
Sending POST Request
Error with REST API call. 103 Error: [Errno 103] ECONNABORTED
Update attempts. Success: 42 Failed: 3
Sending POST Request
Error with REST API call. 103 Error: [Errno 103] ECONNABORTED
Update attempts. Success: 42 Failed: 4
Sending POST Request
{"mac_addr":"aabbccddee","temp_scale":"C","temp_low_value":"19","timestamp":"Tue, 14 Jan 2025 11:45:24 +0000"}
Update attempts. Success: 43 Failed: 4
'

At one point the API response timed out, which I've never seen before, so maybe that's a hint as to what's happening. But as you can see once the 103 errors start, they keep going. It's almost as if the sockets aren't getting closed and once it runs out, that's it. I'm wondering if there's something in my API response that's causing the issue. I'm going to try changing the POST to a GET and see what happens, and will also try changing the response from the API and see what I get. Two separates tests...

joshunagy · 2025-01-15

Just to follow up... I figured it out, for the most part. After striping down the app to the absolute bare minimum, trying GET's instead of POSTs, modifying the API responses to an absolute minimum, I continued to have the Error: [Errno 103] ECONNABORTED errors in the order of around 20% of the time. Even worse, it would occasionally get sticky and always return an Error: [Errno 103] ECONNABORTED error with the urequest.post() and urequest.get(). Not only that, but it would sometimes take 10-40 seconds to even respond with the error and would hang everything in the meantime. I would need to reboot the PICO to clear it.

I deduced down that the wifi.isconnected() would return True, but I really don't think it was actually fully / properly connected. Also, sometimes the wlan.connect(ssid, key) would take many, many tries to connect. At this point, I suspected the physical Wifi layer being the problem. I know the PICO W only supports 2.4Ghz. I have a Unifi network setup with both 2.4Ghz and 5Ghz on the same SSID. It's been a VERY solid WiFi setup. I rarely have any Wifi issues except, I know some of my other devices in my house that only use 2.4GHz don't like the dual band SSIDs. So I decided to switch the PICO to a 2.4Ghz SSID only as a test. In the process of adding this new SSID with 2.4Ghz only, it must have "restarted" the WiFi across all configured SSIDs because I lost WIfi for a moment on my laptop. After that, everything started to work!! No more multiple attempts to connect to WiFi. No more Error: [Errno 103] ECONNABORTED. The problem was just gone. I assumed it couldn't be a problem with the access points because everything else in my house using Wifi worked great.

Now I've been building this app on the PICO W on and off for weeks now. When I first started, I had no issues. Over time this issues got worse and worse, which is why I just couldn't figure out what I changed with the app to cause the issue. It wasn't the app. I suspect the constant connect/reconnect of the PICO to the access point(s) caused an issue on the access points and the restart cleared the issue. I put my original version of the app back on the PICO, with the first dual band SSID and it worked great! 1000 urequests.post() and 0 errors. What an ordeal.

However, that said, it would be really handy to get more details on networking related errors when they occur. I spent hours trying to figure out what the [Errno 103] ECONNABORTED meant, and because I can't see open sockets, or file handles or any network details on the PICO I found it super hard to diagnose. Most posts I found related to [Errno 103] ECONNABORTED where due to not issuing urequests.close() which we result in running out of available sockets, which makes sense. When/if the issue happens again I set up a constant ping to the PICO IP and see how it responds, or use wireshark to monitor the traffic.

I hope this bit of information helps anybody else in the future.

Keyboard

j / / n
next pair
k / / p
previous pair
1 / / h
show query pane
2 / / l
show candidate pane
c
copy suggested comment
r
toggle reasoning
g i
go to index
?
show this help
esc
close overlays

press ? or esc to close

copied