immediate uncalled reset at ussl.wrap_socket

[domi-a]

i worked though it for quite some hours, and have no clue why it happens.
but i can for sure say that in line 207 where code is like "s = ussl.wrap_socket(s, server_hostname=host)". hostname is of course "api.github.com" at runtime.
on my 8266 devboard an immediate reset is happening.
no exception is catched in exept OSError.
i erased and flashed new 1.12 micopython firmware. sill happening.
my code is pretty small, just doing a POC.
what could i be ding wrong?

[rdehuyss]

To be honest, my only guess is #1. I have never tried it on an ESP8266.

[suysh]

My esp8266 is also stopping downloading on s = ussl.wrap_socket(s, server_hostname=host) in the class HttpClient()

Checking version...
        Current version:  0.0
        Latest version:  0.5.3
Updating to version 0.5.3...
Downloading version 0.5.3
        Downloading:  /rdehuyss/micropython-ota-updater/0.5.3/app/__init__.py to next/__init__.py
https://raw.githubusercontent.com/rdehuyss/micropython-ota-updater/0.5.3/app/__init__.py
Traceback (most recent call last):
  File "main.py", line 25, in <module>
  File "main.py", line 14, in connectToWifiAndUpdate
  File "app/ota_updater.py", line 43, in install_update_if_available
  File "app/ota_updater.py", line 93, in _download_new_version
  File "app/ota_updater.py", line 104, in _download_all_files
  File "app/ota_updater.py", line 115, in _download_file
  File "app/ota_updater2.py", line 141, in get
  File "app/ota_updater2.py", line 80, in request
OSError: -40
MicroPython v1.13 on 2020-09-11; ESP module with ESP8266
Type "help()" for more information.

I needed to split the ota_updater.py in 2 files because of memory problems importing all at once.

[suysh]

Looks like memory is indeed the problem for esp8266 devices.
Another post about this : https://forum.micropython.org/viewtopic.php?f=16&t=9241

[suysh]

I tried with the older firmware version MicroPython v1.11-8-g48dcbbe60 on 2019-05-29; ESP module with ESP8266 without good results.

[rdehuyss]

Caused by upstream issue: micropython/micropython#6737

[suysh]

The workaround version is also running into memory problems. But not the OSError -40

Memory free 34256
network config: ('10.0.0.75', '255.255.255.0', '10.0.0.1', '10.0.0.1')
(2, 1, 0, '', ('140.82.121.6', 443))
Checking version...
        Current version:  0.0
        Latest version:  0.5.4
Updating to version 0.5.4...
Downloading version 0.5.4
https://api.github.com/repos/rdehuyss/micropython-ota-updater/contents/app
(2, 1, 0, '', ('140.82.121.6', 443))
Traceback (most recent call last):
  File "main.py", line 29, in <module>
  File "main.py", line 18, in connectToWifiAndUpdate
  File "app/ota_updater.py", line 81, in install_update_if_available
  File "app/ota_updater.py", line 132, in _download_new_version
  File "app/ota_updater.py", line 140, in _download_all_files
  File "app/httpclient.py", line 43, in json
  File "app/httpclient.py", line 32, in content
MemoryError: memory allocation failed, allocating 3328 bytes

MicroPython v1.13 on 2020-09-11; ESP module with ESP8266
Type "help()" for more information.
>>>

[suysh]

When moving the ota_updater file (which is big and not needed to update) to another dir. Probably this file to big to load into memory. When I change the github reference to only small files I'm getting the following coding error:

Memory free 34272
network config: ('10.0.0.75', '255.255.255.0', '10.0.0.1', '10.0.0.1')
(2, 1, 0, '', ('140.82.121.6', 443))
Checking version...
        Current version:  0.0
        Latest version:  v1.2
Updating to version v1.2...
Downloading version v1.2
https://api.github.com/repos/suysh/ESP_OTA_Test/contents/app
(2, 1, 0, '', ('140.82.121.6', 443))
Traceback (most recent call last):
  File "main.py", line 29, in <module>
  File "main.py", line 18, in connectToWifiAndUpdate
  File "app/ota_updater.py", line 81, in install_update_if_available
  File "app/ota_updater.py", line 132, in _download_new_version
  File "app/ota_updater.py", line 144, in _download_all_files
TypeError: function takes 4 positional arguments but 3 were given
MicroPython v1.13 on 2020-09-11; ESP module with ESP8266
Type "help()" for more information.
>>>

[rdehuyss]

There are much more problems with it... To be honest, I'm having doubts about the stability of micropython on ESP8266. - SSL errors - Random resets - ... Did the previous version work on Esp8266? I almost can't believe it...

…

On Sun, Dec 27, 2020, 14:32 Hans ***@***.***> wrote: The workaround version is also running into memory problems. But not the OSError -40 Memory free 34256 network config: ('10.0.0.75', '255.255.255.0', '10.0.0.1', '10.0.0.1') (2, 1, 0, '', ('140.82.121.6', 443)) Checking version... Current version: 0.0 Latest version: 0.5.4 Updating to version 0.5.4... Downloading version 0.5.4https://api.github.com/repos/rdehuyss/micropython-ota-updater/contents/app (2, 1, 0, '', ('140.82.121.6', 443)) Traceback (most recent call last): File "main.py", line 29, in <module> File "main.py", line 18, in connectToWifiAndUpdate File "app/ota_updater.py", line 81, in install_update_if_available File "app/ota_updater.py", line 132, in _download_new_version File "app/ota_updater.py", line 140, in _download_all_files File "app/httpclient.py", line 43, in json File "app/httpclient.py", line 32, in content MemoryError: memory allocation failed, allocating 3328 bytes MicroPython v1.13 on 2020-09-11; ESP module with ESP8266 Type "help()" for more information. >>> — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#6 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAEKUITZVP3QTDICXFXOCN3SW4ZQVANCNFSM4NLHBOYQ> .

[suysh]

It just have updated... I will test it with my own repo.
For sure : line 144 is missing the first argument 'version'
self._download_file(version,download_url.replace('refs/tags/', ''), path)

[suysh]

I think we are close. The code is downloading, creating the next folder, copy the secrets...

But my downloaded file (app/start.py) is overwritten with an error message instead of the downloaded code:
Couldn't find the requested file /https://raw.githubusercontent.com/suysh/ESP_OTA_Test/v0.1/app/start.py in suysh/ESP_OTA_Test.

[rdehuyss]

FYI - I may have a breakthrough. Need to do some family-related stuff though.

I'll continue later on!

[rdehuyss]

I pushed my WIP

[suysh]

Sure, no problem, family-related stuff is very important.

Now all files are overwritten with html code:

<html>
<head><title>403 Forbidden</title></head>
<body>
<center><h1>403 Forbidden</h1></center>
<hr><center>cloudflare</center>
</body>
</html>

[suysh]

My full log including your debug printouts.

MPY: soft reboot
Memory free 34320
network config: ('10.0.0.75', '255.255.255.0', '10.0.0.1', '10.0.0.1')
Req https://api.github.com/repos/suysh/ESP_OTA_Test/releases/latest
Getting addr info
Opening socket (2, 1, 0, '', ('140.82.121.5', 443))
Socket open
Connecting to socket
Connected to socket
Wrapping socket with ssl
Wrapped socket with ssl
b'HTTP/1.1 200 OK\r\n'
b'date: Sun, 27 Dec 2020 15:09:44 GMT\r\n'
b'content-type: application/json; charset=utf-8\r\n'
b'server: GitHub.com\r\n'
b'status: 200 OK\r\n'
b'cache-control: public, max-age=60, s-maxage=60\r\n'
b'vary: Accept, Accept-Encoding, Accept, X-Requested-With, Accept-Encoding\r\n'
b'etag: W/"ab2fa273797edb3dbca9a62f8af6e3efc7039e524d3ef849cfb888ea0cf78548"\r\n'
b'last-modified: Thu, 01 Jan 1970 00:00:00 GMT\r\n'
b'x-github-media-type: github.v3; format=json\r\n'
b'access-control-expose-headers: ETag, Link, Location, Retry-After, X-GitHub-OTP, X-RateLimit-Limit, X-RateLimit-Remaining, X-RateLimit-Used, X-RateLimit-Reset, X-OAuth-Scopes, X-Accepted-OAuth-Scopes, X-Poll-Interval, X-GitHub-Media-Type, Deprecation, Sunset\r\n'
b'access-control-allow-origin: *\r\n'
b'strict-transport-security: max-age=31536000; includeSubdomains; preload\r\n'
b'x-frame-options: deny\r\n'
b'x-content-type-options: nosniff\r\n'
b'x-xss-protection: 1; mode=block\r\n'
b'referrer-policy: origin-when-cross-origin, strict-origin-when-cross-origin\r\n'
b"content-security-policy: default-src 'none'\r\n"
b'X-Ratelimit-Limit: 60\r\n'
b'X-Ratelimit-Remaining: 45\r\n'
b'X-Ratelimit-Reset: 1609082834\r\n'
b'X-Ratelimit-Used: 15\r\n'
b'Accept-Ranges: bytes\r\n'
b'Content-Length: 1619\r\n'
b'Connection: close\r\n'
b'X-GitHub-Request-Id: 06BA:4599:E1A8F4B:101B6092:5FE8A3B5\r\n'
Checking version...
        Current version:  v0.1
        Latest version:  v0.1
Traceback (most recent call last):
  File "main.py", line 29, in <module>
  File "main.py", line 25, in startApp
  File "app/start.py", line 1
SyntaxError: invalid syntax
MicroPython v1.13 on 2020-09-11; ESP module with ESP8266
Type "help()" for more information.
>>> import os
>>> os.remove('app/.version')
>>>
MPY: soft reboot
Memory free 34320
network config: ('10.0.0.75', '255.255.255.0', '10.0.0.1', '10.0.0.1')
Req https://api.github.com/repos/suysh/ESP_OTA_Test/releases/latest
Getting addr info
Opening socket (2, 1, 0, '', ('140.82.121.6', 443))
Socket open
Connecting to socket
Connected to socket
Wrapping socket with ssl
Wrapped socket with ssl
b'HTTP/1.1 200 OK\r\n'
b'date: Sun, 27 Dec 2020 15:10:30 GMT\r\n'
b'content-type: application/json; charset=utf-8\r\n'
b'server: GitHub.com\r\n'
b'status: 200 OK\r\n'
b'cache-control: public, max-age=60, s-maxage=60\r\n'
b'vary: Accept, Accept-Encoding, Accept, X-Requested-With, Accept-Encoding\r\n'
b'etag: W/"ab2fa273797edb3dbca9a62f8af6e3efc7039e524d3ef849cfb888ea0cf78548"\r\n'
b'last-modified: Thu, 01 Jan 1970 00:00:00 GMT\r\n'
b'x-github-media-type: github.v3; format=json\r\n'
b'access-control-expose-headers: ETag, Link, Location, Retry-After, X-GitHub-OTP, X-RateLimit-Limit, X-RateLimit-Remaining, X-RateLimit-Used, X-RateLimit-Reset, X-OAuth-Scopes, X-Accepted-OAuth-Scopes, X-Poll-Interval, X-GitHub-Media-Type, Deprecation, Sunset\r\n'
b'access-control-allow-origin: *\r\n'
b'strict-transport-security: max-age=31536000; includeSubdomains; preload\r\n'
b'x-frame-options: deny\r\n'
b'x-content-type-options: nosniff\r\n'
b'x-xss-protection: 1; mode=block\r\n'
b'referrer-policy: origin-when-cross-origin, strict-origin-when-cross-origin\r\n'
b"content-security-policy: default-src 'none'\r\n"
b'X-Ratelimit-Limit: 60\r\n'
b'X-Ratelimit-Remaining: 44\r\n'
b'X-Ratelimit-Reset: 1609082835\r\n'
b'X-Ratelimit-Used: 16\r\n'
b'Accept-Ranges: bytes\r\n'
b'Content-Length: 1619\r\n'
b'Connection: close\r\n'
b'X-GitHub-Request-Id: 5D9C:A2C6:1A18F112:1DF0C87F:5FE8A3E3\r\n'
Checking version...
        Current version:  0.0
        Latest version:  v0.1
Updating to version v0.1...
Downloading version v0.1
https://api.github.com/repos/suysh/ESP_OTA_Test/contents/app
Req https://api.github.com/repos/suysh/ESP_OTA_Test/contents/app?ref=refs/tags/v0.1
Getting addr info
Opening socket (2, 1, 0, '', ('140.82.121.6', 443))
Socket open
Connecting to socket
Connected to socket
Wrapping socket with ssl
Wrapped socket with ssl
b'HTTP/1.1 200 OK\r\n'
b'date: Sun, 27 Dec 2020 15:10:39 GMT\r\n'
b'content-type: application/json; charset=utf-8\r\n'
b'server: GitHub.com\r\n'
b'status: 200 OK\r\n'
b'cache-control: public, max-age=60, s-maxage=60\r\n'
b'vary: Accept, Accept-Encoding, Accept, X-Requested-With, Accept-Encoding\r\n'
b'etag: W/"926be1790af02cc861f2ee24c9cdfbc56d3e7774"\r\n'
b'last-modified: Sun, 27 Dec 2020 13:58:12 GMT\r\n'
b'x-github-media-type: github.v3; format=json\r\n'
b'access-control-expose-headers: ETag, Link, Location, Retry-After, X-GitHub-OTP, X-RateLimit-Limit, X-RateLimit-Remaining, X-RateLimit-Used, X-RateLimit-Reset, X-OAuth-Scopes, X-Accepted-OAuth-Scopes, X-Poll-Interval, X-GitHub-Media-Type, Deprecation, Sunset\r\n'
b'access-control-allow-origin: *\r\n'
b'strict-transport-security: max-age=31536000; includeSubdomains; preload\r\n'
b'x-frame-options: deny\r\n'
b'x-content-type-options: nosniff\r\n'
b'x-xss-protection: 1; mode=block\r\n'
b'referrer-policy: origin-when-cross-origin, strict-origin-when-cross-origin\r\n'
b"content-security-policy: default-src 'none'\r\n"
b'X-Ratelimit-Limit: 60\r\n'
b'X-Ratelimit-Remaining: 43\r\n'
b'X-Ratelimit-Reset: 1609082834\r\n'
b'X-Ratelimit-Used: 17\r\n'
b'Accept-Ranges: bytes\r\n'
b'Content-Length: 802\r\n'
b'Connection: close\r\n'
b'X-GitHub-Request-Id: 101B:9059:CE9B9A5:ECFC4B0:5FE8A3EB\r\n'
        Downloading:  app/start.py to next/start.py
Req https://cdn.jsdelivr.net/gh/suysh/[email protected]/app/start.py
Getting addr info
Opening socket (2, 1, 0, '', ('104.16.86.20', 443))
Socket open
Connecting to socket
Connected to socket
Wrapping socket with ssl
Wrapped socket with ssl
b'HTTP/1.1 403 Forbidden\r\n'
b'Server: cloudflare\r\n'
b'Date: Sun, 27 Dec 2020 15:10:47 GMT\r\n'
b'Content-Type: text/html\r\n'
b'Content-Length: 151\r\n'
b'Connection: close\r\n'
b'CF-RAY: 6083f869bbf5c785-AMS\r\n'
Saving to file next/start.py
Opened file next/start.py
Data written to file next/start.py
Version v0.1 downloaded to next
Copying secrets file from app/secrets.py to next/secrets.py
Copied secrets file from app/secrets.py to next/secrets.py
Deleting old version at app ...
Deleted old version at app ...
Installing new version at app ...
Update installed, please reboot now
Traceback (most recent call last):
  File "main.py", line 29, in <module>
  File "main.py", line 25, in startApp
  File "app/start.py", line 1
SyntaxError: invalid syntax
MicroPython v1.13 on 2020-09-11; ESP module with ESP8266
Type "help()" for more information.
>>>

[rdehuyss]

After 8 hours of debugging, sniffing SSL traffick (which was not easy), ... I found out that the reason we're getting a 403 (the cloudflare error), is also related due to SSL handshakes not working out.

I added a note on the README.md specifying that the ESP8266 is currently not supported 😞 . I created an issue in the MicroPython core (see micropython/micropython#6737) - let's see if they are able to solve it and if so, I can pick this up again.

[c-p-b]

I found some more info here:

https://forum.micropython.org/viewtopic.php?t=10437&p=57759

The issue seems to be that certain certificate types are not supported in axtls. So to test it I applied the patch linked there (see it below) and compiled it into the ESP8266 firmware:

https://github.com/micropython/micropython/pull/6433/files

Here is same changes in patch file format: https://gist.github.com/cpdeethree/6c293ed7b78f8e5aeba27cfcfeb14877

And it worked. So it does seem to be problem with axtls library and switching to mbedtls fixes the issue. However, as noted in the link and the issue, the above patch is a hack. My ESP8266 hangs for about 7-8 seconds trying to call that library for every HTTP request, and I have to call gc.mem_free() in between calls. So it's not ideal and probably shouldn't be considered anything other than a way to demonstrate that axtls is the issue.

[rdehuyss]

Wauw, thanks for this indepth analysis.

[grafalex82]

Any updates on this? Was the issue solved, or there will be no OTA updates for ESP8266 devices forever?

[c-p-b]

@grafalex82 you could do the hack I mentioned - though it's not really something that I would trust in production - or if your SSL site happens to not be of the wrong format (it seems to be only specific cert types) that causes this issue it seems to be OK as well. The issue really isn't with micropython-ota-updater (or really even micropython, though they could switch to a different library) but rather that the ESP8266 hardware seems like it can't really compute the cipher for these cert types in a reasonable amount of time with the available libraries in their current form. Perhaps some other library other than the two mentioned would be able to do it but I'm not really aware of what's available in that area. You'll probably get a better answer if you search for/open issues upstream of this project in either micropython or axtls

[grafalex82]

ok, thank you.