Flashing Tasmota is not working

[RamiHaikal]

• Operating System: Mac OS High Sierra
• Python Version: 3.7
• Sonoff model: Sonoff Basic

I have tried everything but it is not working, can anyone help? Below is what I am getting.

./sonota.py --legacy
Current IPs: ['192.168.1.20']
Select IP address of the WiFi interface:
0: 192.168.1.20
Select IP address [0]: 0
WiFi SSID: R&R
WiFi Password: ********

Using the following configuration:
Server IP Address: 192.168.1.20
WiFi SSID: R&R
WiFi Password: ************
Platform: darwin
** Now connect via WiFi to your Sonoff device.
** Please change into the ITEAD WiFi network (ITEAD-100001XXXX). The default password is 12345678.
To reset the Sonoff to defaults, press the button for 7 seconds and the light will start flashing rapidly.
** This application should be kept running and will wait until connected to the Sonoff...
...Current IPs: []
..Current IPs: ['10.10.7.2']
~~ Connection attempt

HTTP GET /10.10.7.1/device
<< {
"deviceid": "1000439fa8",
"apikey": "c7d3afc6-4ddb-4d77-922c-c410502dbfa6",
"accept": "post"
}
HTTP POST /10.10.7.1/ap
{
"version": 4,
"ssid": "R&R",
"password": "************",
"serverName": "192.168.1.20",
"port": 443
}
<< {
"error": 0
}
~~ Provisioning completed
Starting stage2...
** The IP address of <serve_host> (192.168.1.20) is not assigned to any interface on this machine.
** Please change WiFi network to R&R and make sure 192.168.1.20 is being assigned to your WiFi interface.
** This application should be kept running and will wait until connected to the WiFi...
......Current IPs: []
.....Current IPs: ['192.168.1.20']
~~ Starting web server (HTTP port: 8080, HTTPS port 443)
Using selector: KqueueSelector
Traceback (most recent call last):
File "./sonota.py", line 734, in
main()
File "./sonota.py", line 730, in main
stage2()
File "./sonota.py", line 660, in stage2
app_ssl.listen(DEFAULT_PORT_HTTPS)
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/tcpserver.py", line 143, in listen
sockets = bind_sockets(port, address=address)
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/netutil.py", line 168, in bind_sockets
sock.bind(sockaddr)
PermissionError: [Errno 13] Permission denied

[sillyfrog]

Have you tried running without --legacy - it'll be an extremely old unit if you need that.
If you do need legacy, run it as root (ie: sudo ./sonota...)

[RamiHaikal]

When I ran without --legacy it didn't work and I read somewhere that it might help, I tried sudo but also didn't work.

I ran without --legacy and here is what I am getting:

./sonota.py
Current IPs: ['192.168.1.20']
Select IP address of the WiFi interface:
0: 192.168.1.20
Select IP address [0]: 0
WiFi SSID: R&R
WiFi Password: *********

Using the following configuration:
Server IP Address: 192.168.1.20
WiFi SSID: R&R
WiFi Password: ************
Platform: darwin
** Now connect via WiFi to your Sonoff device.
** Please change into the ITEAD WiFi network (ITEAD-100001XXXX). The default password is 12345678.
To reset the Sonoff to defaults, press the button for 7 seconds and the light will start flashing rapidly.
** This application should be kept running and will wait until connected to the Sonoff...
...........................Current IPs: ['10.10.7.2']
~~ Connection attempt

HTTP GET /10.10.7.1/device
<< {
"deviceid": "1000439fa8",
"apikey": "c7d3afc6-4ddb-4d77-922c-c410502dbfa6",
"accept": "post"
}
HTTP POST /10.10.7.1/ap
{
"version": 4,
"ssid": "R&R",
"password": "************",
"serverName": "192.168.1.20",
"port": 8443
}
<< {
"error": 0
}
~~ Provisioning completed
Starting stage2...
** The IP address of <serve_host> (192.168.1.20) is not assigned to any interface on this machine.
** Please change WiFi network to R&R and make sure 192.168.1.20 is being assigned to your WiFi interface.
** This application should be kept running and will wait until connected to the WiFi...
......Current IPs: []
..Current IPs: ['192.168.1.20']
~~ Starting web server (HTTP port: 8080, HTTPS port 8443)
Traceback (most recent call last):
File "./sonota.py", line 734, in
main()
File "./sonota.py", line 730, in main
stage2()
File "./sonota.py", line 653, in stage2
app.listen(DEFAULT_PORT_HTTP)
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/web.py", line 2042, in listen
server.listen(port, address)
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/tcpserver.py", line 143, in listen
sockets = bind_sockets(port, address=address)
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/netutil.py", line 168, in bind_sockets
sock.bind(sockaddr)
OSError: [Errno 48] Address already in use

[sillyfrog]

You will see the error is "Address already in use" - that means something is already running on one of the ports (eg: port 8080). Be sure to shut down all services that are listening on your Mac to be safe.

[RamiHaikal]

Now I am getting this error:

Starting stage2...
** The IP address of <serve_host> (192.168.1.20) is not assigned to any interface on this machine.
** Please change WiFi network to R&R and make sure 192.168.1.20 is being assigned to your WiFi interface.
** This application should be kept running and will wait until connected to the WiFi...
......Current IPs: ['192.168.1.20']
~~ Starting web server (HTTP port: 8080, HTTPS port 8443)
Using selector: KqueueSelector
~~ Waiting for device to connect

*** IMPORTANT! ***
** AFTER the first download is COMPLETE, with in a minute or so you should connect to the new SSID "FinalStage" to finish the process.
** ONLY disconnect when the new "FinalStage" SSID is visible as an available WiFi network.
This server should automatically be allocated the IP address: 192.168.4.2.
If you have successfully connected to "FinalStage" and this is not the IP Address you were allocated, please ensure no other device has connected, and reboot your Sonoff.
.Uncaught exception, closing connection.
Traceback (most recent call last):
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 709, in _handle_events
self._handle_read()
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 1581, in _handle_read
self._do_ssl_handshake()
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 1501, in _do_ssl_handshake
self.socket.do_handshake()
File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/ssl.py", line 1108, in do_handshake
self._sslobj.do_handshake()
OSError: [Errno 0] Error
Exception in callback None()
handle:
Traceback (most recent call last):
File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/events.py", line 88, in _run
self._context.run(self._callback, *self._args)
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/platform/asyncio.py", line 122, in _handle_events
handler_func(fileobj, events)
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/stack_context.py", line 300, in null_wrapper
return fn(*args, **kwargs)
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 709, in _handle_events
self._handle_read()
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 1581, in _handle_read
self._do_ssl_handshake()
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 1501, in _do_ssl_handshake
self.socket.do_handshake()
File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/ssl.py", line 1108, in do_handshake
self._sslobj.do_handshake()
OSError: [Errno 0] Error
..............Uncaught exception, closing connection.
Traceback (most recent call last):
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 709, in _handle_events
self._handle_read()
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 1581, in _handle_read
self._do_ssl_handshake()
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 1501, in _do_ssl_handshake
self.socket.do_handshake()
File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/ssl.py", line 1108, in do_handshake
self._sslobj.do_handshake()
OSError: [Errno 0] Error
Exception in callback None()
handle:
Traceback (most recent call last):
File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/events.py", line 88, in _run
self._context.run(self._callback, *self._args)
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/platform/asyncio.py", line 122, in _handle_events
handler_func(fileobj, events)
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/stack_context.py", line 300, in null_wrapper
return fn(*args, **kwargs)
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 709, in _handle_events
self._handle_read()
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 1581, in _handle_read
self._do_ssl_handshake()
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 1501, in _do_ssl_handshake
self.socket.do_handshake()
File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/ssl.py", line 1108, in do_handshake
self._sslobj.do_handshake()
OSError: [Errno 0] Error
...........Uncaught exception, closing connection.
Traceback (most recent call last):
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 709, in _handle_events
self._handle_read()
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 1581, in _handle_read
self._do_ssl_handshake()
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 1501, in _do_ssl_handshake
self.socket.do_handshake()
File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/ssl.py", line 1108, in do_handshake
self._sslobj.do_handshake()
OSError: [Errno 0] Error
Exception in callback None()
handle:
Traceback (most recent call last):
File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/events.py", line 88, in _run
self._context.run(self._callback, *self._args)
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/platform/asyncio.py", line 122, in _handle_events
handler_func(fileobj, events)
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/stack_context.py", line 300, in null_wrapper
return fn(*args, **kwargs)
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 709, in _handle_events
self._handle_read()
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 1581, in _handle_read
self._do_ssl_handshake()
File "/Users/ramihaikal/Library/Python/3.7/lib/python/site-packages/tornado/iostream.py", line 1501, in _do_ssl_handshake
self.socket.do_handshake()
File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/ssl.py", line 1108, in do_handshake
self._sslobj.do_handshake()
OSError: [Errno 0] Error

[sillyfrog]

That's.... weird... I would suggest trying Python 3.6 as it's not been tested with 3.7 on a Mac as it has only been released recently.

[RamiHaikal]

I installed 3.6 and I am not getting the handshake exception anymore. But Sonoff is not changing to the Finalstage SSID, I have waited for 20 minutes but still it is not switching to that SSID.

The firewall on my MAC is turned off

[giovannigenna]

@RamiHaikal have you resolved the issue ?

[robdejonge]

I get the exact same messages as @RamiHaikal as listed in the Aug 18 comment.
Sonoff Basic running 2.6.0, SonOTA downloaded today.

[Salsalove]

Same issue...Maybe SonOTA method doesn’t work on 2.6.0 firmware...

[Tom1803]

Raspian: The same issue as @RamiHaikal as listed in the Aug 18 comment.
Windows: No Error Messages, but won't start downloading firmware in "Stage2"
Looks like Sonoff connects brave to local update Server - but serversite crashes.

[mjhartley]

Python version 2.7.10
Mac O/S Majove
Sonoff PoW v 2.0.2
Firewall has been disabled.

Hi. I've attempted to up date 2 PoWs and they are both in the same state now. The LED is permanently on and the relay clicks every X minutes.

When I ran through the upgrade process, stage 4 did not appear to execute

Attached is the log.
"Once the firmware has been downloaded, there will be a new FinalStage SSID that you can connect to. Do this, and the device will then download the final stages of the firmware, including the Arduino image, replacing the default boot loader."

2018-12-02 20:31:35,118: DEBUG: Current IPs: ['192.168.1.15', '10.6.6.152']
2018-12-02 20:32:31,232: INFO: Using the following configuration:
2018-12-02 20:32:31,232: INFO: Server IP Address: 192.168.1.15
2018-12-02 20:32:31,232: INFO: WiFi SSID: belkin.7fd_front
2018-12-02 20:32:31,232: INFO: WiFi Password: **********************
2018-12-02 20:32:31,232: INFO: Platform: darwin
2018-12-02 20:32:31,243: INFO: ** Now connect via WiFi to your Sonoff device.
2018-12-02 20:32:31,243: INFO: ** Please change into the ITEAD WiFi network (ITEAD-100001XXXX). The default password is 12345678.
2018-12-02 20:32:31,243: INFO: To reset the Sonoff to defaults, press the button for 7 seconds and the light will start flashing rapidly.
2018-12-02 20:32:31,243: INFO: ** This application should be kept running and will wait until connected to the Sonoff...
2018-12-02 20:32:59,382: DEBUG: Current IPs: []
2018-12-02 20:33:03,397: DEBUG: Current IPs: ['10.10.7.3']
2018-12-02 20:33:03,404: DEBUG: ~~ Connection attempt
2018-12-02 20:33:03,404: DEBUG: >> HTTP GET /10.10.7.1/device
2018-12-02 20:33:03,432: DEBUG: << {
2018-12-02 20:33:03,432: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:33:03,432: DEBUG: "apikey": "747c979d-a2ed-4952-a34b-fc622b64d572",
2018-12-02 20:33:03,432: DEBUG: "accept": "post"
2018-12-02 20:33:03,432: DEBUG: }
2018-12-02 20:33:03,432: DEBUG: >> HTTP POST /10.10.7.1/ap
2018-12-02 20:33:03,433: DEBUG: >> {
2018-12-02 20:33:03,433: DEBUG: "version": 4,
2018-12-02 20:33:03,433: DEBUG: "ssid": "belkin.7fd_front",
2018-12-02 20:33:03,434: DEBUG: "password": "**********************",
2018-12-02 20:33:03,434: DEBUG: "serverName": "192.168.1.15",
2018-12-02 20:33:03,434: DEBUG: "port": 443
2018-12-02 20:33:03,434: DEBUG: }
2018-12-02 20:33:03,542: DEBUG: << {
2018-12-02 20:33:03,543: DEBUG: "error": 0
2018-12-02 20:33:03,543: DEBUG: }
2018-12-02 20:33:03,543: INFO: ~~ Provisioning completed
2018-12-02 20:33:03,543: INFO: Starting stage2...
2018-12-02 20:33:03,549: INFO: ** The IP address of <serve_host> (192.168.1.15) is not assigned to any interface on this machine.
2018-12-02 20:33:03,549: INFO: ** Please change WiFi network to belkin.7fd_front and make sure 192.168.1.15 is being assigned to your WiFi interface.
2018-12-02 20:33:03,549: INFO: ** This application should be kept running and will wait until connected to the WiFi...
2018-12-02 20:33:41,635: DEBUG: Current IPs: []
2018-12-02 20:33:43,638: DEBUG: Current IPs: ['192.168.1.15']
2018-12-02 20:33:43,639: INFO: ~~ Starting web server (HTTP port: 8080, HTTPS port 443)
2018-12-02 20:33:43,641: DEBUG: Using selector: KqueueSelector
2018-12-02 20:33:43,643: INFO: ~~ Waiting for device to connect
2018-12-02 20:33:43,647: INFO: *** IMPORTANT! ***
2018-12-02 20:33:43,647: INFO: ** AFTER the first download is COMPLETE, with in a minute or so you should connect to the new SSID "FinalStage" to finish the process.
2018-12-02 20:33:43,648: INFO: ** ONLY disconnect when the new "FinalStage" SSID is visible as an available WiFi network.
2018-12-02 20:33:43,648: INFO: This server should automatically be allocated the IP address: 192.168.4.2.
2018-12-02 20:33:43,648: INFO: If you have successfully connected to "FinalStage" and this is not the IP Address you were allocated, please ensure no other device has connected, and reboot your Sonoff.
2018-12-02 20:33:45,652: DEBUG: Current IPs: ['192.168.1.15', '10.6.6.152']
2018-12-02 20:33:53,395: DEBUG: << HTTP POST /dispatch/device
2018-12-02 20:33:53,396: DEBUG: >> /dispatch/device
2018-12-02 20:33:53,396: DEBUG: >> {
2018-12-02 20:33:53,396: DEBUG: "error": 0,
2018-12-02 20:33:53,396: DEBUG: "reason": "ok",
2018-12-02 20:33:53,396: DEBUG: "IP": "192.168.1.15",
2018-12-02 20:33:53,396: DEBUG: "port": 443
2018-12-02 20:33:53,396: DEBUG: }
2018-12-02 20:33:53,397: INFO: 200 POST /dispatch/device (192.168.1.48) 4.14ms
2018-12-02 20:33:53,409: INFO: 101 GET /api/ws (192.168.1.48) 0.97ms
2018-12-02 20:33:53,409: DEBUG: << WEBSOCKET OPEN
2018-12-02 20:33:53,413: DEBUG: << WEBSOCKET INPUT
2018-12-02 20:33:53,413: DEBUG: << {
2018-12-02 20:33:53,413: DEBUG: "userAgent": "device",
2018-12-02 20:33:53,414: DEBUG: "apikey": "747c979d-a2ed-4952-a34b-fc622b64d572",
2018-12-02 20:33:53,414: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:33:53,414: DEBUG: "action": "register",
2018-12-02 20:33:53,414: DEBUG: "version": 2,
2018-12-02 20:33:53,414: DEBUG: "romVersion": "2.0.2",
2018-12-02 20:33:53,414: DEBUG: "model": "PSC-B01-GL",
2018-12-02 20:33:53,414: DEBUG: "ts": 374
2018-12-02 20:33:53,414: DEBUG: }
2018-12-02 20:33:53,414: DEBUG: ~~~ device sent action request, acknowledging / answering...
2018-12-02 20:33:53,415: INFO: We are dealing with a PSC-B01-GL model.
2018-12-02 20:33:53,415: DEBUG: ~~~~ register
2018-12-02 20:33:53,415: DEBUG: >> {
2018-12-02 20:33:53,415: DEBUG: "error": 0,
2018-12-02 20:33:53,415: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:33:53,415: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668",
2018-12-02 20:33:53,415: DEBUG: "config": {
2018-12-02 20:33:53,415: DEBUG: "hb": 1,
2018-12-02 20:33:53,415: DEBUG: "hbInterval": 145
2018-12-02 20:33:53,416: DEBUG: }
2018-12-02 20:33:53,416: DEBUG: }
2018-12-02 20:33:53,420: DEBUG: << WEBSOCKET INPUT
2018-12-02 20:33:53,421: DEBUG: << {
2018-12-02 20:33:53,421: DEBUG: "userAgent": "device",
2018-12-02 20:33:53,421: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668",
2018-12-02 20:33:53,421: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:33:53,421: DEBUG: "action": "date"
2018-12-02 20:33:53,421: DEBUG: }
2018-12-02 20:33:53,422: DEBUG: ~~~ device sent action request, acknowledging / answering...
2018-12-02 20:33:53,422: DEBUG: ~~~~ date
2018-12-02 20:33:53,422: DEBUG: >> {
2018-12-02 20:33:53,422: DEBUG: "error": 0,
2018-12-02 20:33:53,422: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:33:53,422: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668",
2018-12-02 20:33:53,422: DEBUG: "date": "2018-12-02T20:33:53.422Z"
2018-12-02 20:33:53,422: DEBUG: }
2018-12-02 20:33:53,426: DEBUG: << WEBSOCKET INPUT
2018-12-02 20:33:53,426: DEBUG: << {
2018-12-02 20:33:53,427: DEBUG: "userAgent": "device",
2018-12-02 20:33:53,427: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668",
2018-12-02 20:33:53,427: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:33:53,427: DEBUG: "action": "update",
2018-12-02 20:33:53,427: DEBUG: "params": {
2018-12-02 20:33:53,427: DEBUG: "switch": "off",
2018-12-02 20:33:53,427: DEBUG: "power": "0",
2018-12-02 20:33:53,427: DEBUG: "fwVersion": "2.0.2",
2018-12-02 20:33:53,428: DEBUG: "rssi": -54,
2018-12-02 20:33:53,428: DEBUG: "staMac": "D0:27:00:07:56:7C"
2018-12-02 20:33:53,428: DEBUG: }
2018-12-02 20:33:53,428: DEBUG: }
2018-12-02 20:33:53,428: DEBUG: ~~~ device sent action request, acknowledging / answering...
2018-12-02 20:33:53,428: DEBUG: ~~~~ update
2018-12-02 20:33:53,428: DEBUG: >> {
2018-12-02 20:33:53,428: DEBUG: "error": 0,
2018-12-02 20:33:53,428: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:33:53,429: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668"
2018-12-02 20:33:53,429: DEBUG: }
2018-12-02 20:33:53,429: DEBUG: >> {
2018-12-02 20:33:53,429: DEBUG: "action": "update",
2018-12-02 20:33:53,430: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:33:53,430: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668",
2018-12-02 20:33:53,430: DEBUG: "userAgent": "app",
2018-12-02 20:33:53,430: DEBUG: "sequence": "1543782833429",
2018-12-02 20:33:53,430: DEBUG: "ts": 0,
2018-12-02 20:33:53,430: DEBUG: "params": {
2018-12-02 20:33:53,430: DEBUG: "switch": "off"
2018-12-02 20:33:53,430: DEBUG: },
2018-12-02 20:33:53,430: DEBUG: "from": "hackepeter"
2018-12-02 20:33:53,431: DEBUG: }
2018-12-02 20:33:53,431: DEBUG: >> {
2018-12-02 20:33:53,431: DEBUG: "action": "update",
2018-12-02 20:33:53,431: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:33:53,431: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668",
2018-12-02 20:33:53,432: DEBUG: "userAgent": "app",
2018-12-02 20:33:53,432: DEBUG: "sequence": "1543782833431",
2018-12-02 20:33:53,432: DEBUG: "ts": 0,
2018-12-02 20:33:53,432: DEBUG: "params": {
2018-12-02 20:33:53,432: DEBUG: "switch": "on"
2018-12-02 20:33:53,432: DEBUG: },
2018-12-02 20:33:53,432: DEBUG: "from": "hackepeter"
2018-12-02 20:33:53,432: DEBUG: }
2018-12-02 20:33:53,433: DEBUG: >> {
2018-12-02 20:33:53,433: DEBUG: "action": "update",
2018-12-02 20:33:53,433: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:33:53,433: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668",
2018-12-02 20:33:53,433: DEBUG: "userAgent": "app",
2018-12-02 20:33:53,433: DEBUG: "sequence": "1543782833433",
2018-12-02 20:33:53,433: DEBUG: "ts": 0,
2018-12-02 20:33:53,433: DEBUG: "params": {
2018-12-02 20:33:53,433: DEBUG: "switch": "off"
2018-12-02 20:33:53,434: DEBUG: },
2018-12-02 20:33:53,434: DEBUG: "from": "hackepeter"
2018-12-02 20:33:53,434: DEBUG: }
2018-12-02 20:33:53,434: DEBUG: >> {
2018-12-02 20:33:53,434: DEBUG: "action": "update",
2018-12-02 20:33:53,434: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:33:53,435: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668",
2018-12-02 20:33:53,435: DEBUG: "userAgent": "app",
2018-12-02 20:33:53,435: DEBUG: "sequence": "1543782833434",
2018-12-02 20:33:53,435: DEBUG: "ts": 0,
2018-12-02 20:33:53,435: DEBUG: "params": {
2018-12-02 20:33:53,435: DEBUG: "switch": "on"
2018-12-02 20:33:53,435: DEBUG: },
2018-12-02 20:33:53,435: DEBUG: "from": "hackepeter"
2018-12-02 20:33:53,435: DEBUG: }
2018-12-02 20:33:53,436: DEBUG: >> {
2018-12-02 20:33:53,436: DEBUG: "action": "update",
2018-12-02 20:33:53,436: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:33:53,436: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668",
2018-12-02 20:33:53,436: DEBUG: "userAgent": "app",
2018-12-02 20:33:53,436: DEBUG: "sequence": "1543782833436",
2018-12-02 20:33:53,436: DEBUG: "ts": 0,
2018-12-02 20:33:53,437: DEBUG: "params": {
2018-12-02 20:33:53,437: DEBUG: "switch": "off"
2018-12-02 20:33:53,437: DEBUG: },
2018-12-02 20:33:53,437: DEBUG: "from": "hackepeter"
2018-12-02 20:33:53,437: DEBUG: }
2018-12-02 20:33:53,441: DEBUG: >> {
2018-12-02 20:33:53,442: DEBUG: "action": "upgrade",
2018-12-02 20:33:53,442: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:33:53,442: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668",
2018-12-02 20:33:53,442: DEBUG: "userAgent": "app",
2018-12-02 20:33:53,442: DEBUG: "sequence": "1543782833441",
2018-12-02 20:33:53,442: DEBUG: "ts": 0,
2018-12-02 20:33:53,443: DEBUG: "params": {
2018-12-02 20:33:53,443: DEBUG: "binList": [
2018-12-02 20:33:53,443: DEBUG: {
2018-12-02 20:33:53,443: DEBUG: "downloadUrl": "http://192.168.1.15:8080/slowota/image_user1-0x01000.bin",
2018-12-02 20:33:53,443: DEBUG: "digest": "e9b6b18c9905834ec39f88d2ee64362dcc676d13be308460e4a9877f6ddefb0e",
2018-12-02 20:33:53,444: DEBUG: "name": "user1.bin"
2018-12-02 20:33:53,444: DEBUG: },
2018-12-02 20:33:53,444: DEBUG: {
2018-12-02 20:33:53,444: DEBUG: "downloadUrl": "http://192.168.1.15:8080/slowota/image_user2-0x81000.bin",
2018-12-02 20:33:53,444: DEBUG: "digest": "fb4753bea76a37d8ce83204593d5d91ade05250e70c34b92f82136ad2e946c31",
2018-12-02 20:33:53,444: DEBUG: "name": "user2.bin"
2018-12-02 20:33:53,444: DEBUG: }
2018-12-02 20:33:53,445: DEBUG: ],
2018-12-02 20:33:53,445: DEBUG: "model": "PSC-B01-GL",
2018-12-02 20:33:53,445: DEBUG: "version": "23.42.5"
2018-12-02 20:33:53,445: DEBUG: }
2018-12-02 20:33:53,445: DEBUG: }
2018-12-02 20:33:53,446: DEBUG: << WEBSOCKET INPUT
2018-12-02 20:33:53,446: DEBUG: << {
2018-12-02 20:33:53,446: DEBUG: "userAgent": "device",
2018-12-02 20:33:53,446: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668",
2018-12-02 20:33:53,447: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:33:53,447: DEBUG: "action": "query",
2018-12-02 20:33:53,447: DEBUG: "params": [
2018-12-02 20:33:53,447: DEBUG: "timers",
2018-12-02 20:33:53,447: DEBUG: "timeZone"
2018-12-02 20:33:53,447: DEBUG: ]
2018-12-02 20:33:53,447: DEBUG: }
2018-12-02 20:33:53,447: DEBUG: ~~~ device sent action request, acknowledging / answering...
2018-12-02 20:33:53,448: DEBUG: ~~~~ query
2018-12-02 20:33:53,448: DEBUG: >> {
2018-12-02 20:33:53,448: DEBUG: "error": 0,
2018-12-02 20:33:53,448: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:33:53,448: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668",
2018-12-02 20:33:53,448: DEBUG: "params": 0
2018-12-02 20:33:53,448: DEBUG: }
2018-12-02 20:33:53,449: DEBUG: << WEBSOCKET INPUT
2018-12-02 20:33:53,449: DEBUG: << {
2018-12-02 20:33:53,449: DEBUG: "error": 0,
2018-12-02 20:33:53,449: DEBUG: "userAgent": "device",
2018-12-02 20:33:53,449: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668",
2018-12-02 20:33:53,450: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:33:53,450: DEBUG: "sequence": "1543782833433"
2018-12-02 20:33:53,450: DEBUG: }
2018-12-02 20:33:53,450: DEBUG: ~~~ device acknowledged our action request (seq 1543782833433) with error code 0
2018-12-02 20:33:53,459: DEBUG: Slow Sending file: /slowota/image_user2-0x81000.bin (This may take several minutes)
2018-12-02 20:34:43,810: INFO: *** IMPORTANT! ***
2018-12-02 20:34:43,811: INFO: ** AFTER the first download is COMPLETE, with in a minute or so you should connect to the new SSID "FinalStage" to finish the process.
2018-12-02 20:34:43,811: INFO: ** ONLY disconnect when the new "FinalStage" SSID is visible as an available WiFi network.
2018-12-02 20:34:43,811: INFO: This server should automatically be allocated the IP address: 192.168.4.2.
2018-12-02 20:34:43,811: INFO: If you have successfully connected to "FinalStage" and this is not the IP Address you were allocated, please ensure no other device has connected, and reboot your Sonoff.
2018-12-02 20:34:45,845: INFO: 200 GET /slowota/image_user2-0x81000.bin?deviceid=100003ac96&ts=1979932169&sign=8c98389e6eb29be00fc9f31447bc1c6da9fc7d661f8b39403ba433339dd41d8b (192.168.1.48) 52387.10ms
2018-12-02 20:34:45,876: DEBUG: << WEBSOCKET INPUT
2018-12-02 20:34:45,877: DEBUG: << {
2018-12-02 20:34:45,877: DEBUG: "error": 0,
2018-12-02 20:34:45,877: DEBUG: "userAgent": "device",
2018-12-02 20:34:45,877: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668",
2018-12-02 20:34:45,877: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:34:45,877: DEBUG: "sequence": "1543782833441"
2018-12-02 20:34:45,877: DEBUG: }
2018-12-02 20:34:45,878: DEBUG: ~~~ device acknowledged our action request (seq 1543782833441) with error code 0
2018-12-02 20:34:50,637: DEBUG: << WEBSOCKET INPUT
2018-12-02 20:34:50,637: DEBUG: << {
2018-12-02 20:34:50,638: DEBUG: "userAgent": "device",
2018-12-02 20:34:50,638: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668",
2018-12-02 20:34:50,638: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:34:50,638: DEBUG: "action": "update",
2018-12-02 20:34:50,638: DEBUG: "params": {
2018-12-02 20:34:50,638: DEBUG: "switch": "off",
2018-12-02 20:34:50,638: DEBUG: "power": "0",
2018-12-02 20:34:50,639: DEBUG: "rssi": -54
2018-12-02 20:34:50,639: DEBUG: }
2018-12-02 20:34:50,639: DEBUG: }
2018-12-02 20:34:50,639: DEBUG: ~~~ device sent action request, acknowledging / answering...
2018-12-02 20:34:50,639: DEBUG: ~~~~ update
2018-12-02 20:34:50,640: DEBUG: >> {
2018-12-02 20:34:50,640: DEBUG: "error": 0,
2018-12-02 20:34:50,640: DEBUG: "deviceid": "100003ac96",
2018-12-02 20:34:50,640: DEBUG: "apikey": "49f0a4d8-625c-46fd-b696-8991bc298668"
2018-12-02 20:34:50,640: DEBUG: }
2018-12-02 20:35:43,972: INFO: *** IMPORTANT! ***
2018-12-02 20:35:43,973: INFO: ** AFTER the first download is COMPLETE, with in a minute or so you should connect to the new SSID "FinalStage" to finish the process.
2018-12-02 20:35:43,973: INFO: ** ONLY disconnect when the new "FinalStage" SSID is visible as an available WiFi network.
2018-12-02 20:35:43,973: INFO: This server should automatically be allocated the IP address: 192.168.4.2.
2018-12-02 20:35:43,973: INFO: If you have successfully connected to "FinalStage" and this is not the IP Address you were allocated, please ensure no other device has connected, and reboot your Sonoff.
2018-12-02 20:36:44,125: INFO: *** IMPORTANT! ***
2018-12-02 20:36:44,127: INFO: ** AFTER the first download is COMPLETE, with in a minute or so you should connect to the new SSID "FinalStage" to finish the process.
2018-12-02 20:36:44,127: INFO: ** ONLY disconnect when the new "FinalStage" SSID is visible as an available WiFi network.
2018-12-02 20:36:44,127: INFO: This server should automatically be allocated the IP address: 192.168.4.2.
2018-12-02 20:36:44,127: INFO: If you have successfully connected to "FinalStage" and this is not the IP Address you were allocated, please ensure no other device has connected, and reboot your Sonoff.
2018-12-02 20:37:44,325: INFO: *** IMPORTANT! ***
2018-12-02 20:37:44,326: INFO: ** AFTER the first download is COMPLETE, with in a minute or so you should connect to the new SSID "FinalStage" to finish the process.
2018-12-02 20:37:44,326: INFO: ** ONLY disconnect when the new "FinalStage" SSID is visible as an available WiFi network.
2018-12-02 20:37:44,327: INFO: This server should automatically be allocated the IP address: 192.168.4.2.
2018-12-02 20:37:44,327: INFO: If you have successfully connected to "FinalStage" and this is not the IP Address you were allocated, please ensure no other device has connected, and reboot your Sonoff.
2018-12-02 20:38:44,649: INFO: *** IMPORTANT! ***
2018-12-02 20:38:44,649: INFO: ** AFTER the first download is COMPLETE, with in a minute or so you should connect to the new SSID "FinalStage" to finish the process.
2018-12-02 20:38:44,650: INFO: ** ONLY disconnect when the new "FinalStage" SSID is visible as an available WiFi network.
2018-12-02 20:38:44,650: INFO: This server should automatically be allocated the IP address: 192.168.4.2.
2018-12-02 20:38:44,650: INFO: If you have successfully connected to "FinalStage" and this is not the IP Address you were allocated, please ensure no other device has connected, and reboot your Sonoff.
2018-12-02 20:39:44,976: INFO: *** IMPORTANT! ***
2018-12-02 20:39:44,978: INFO: ** AFTER the first download is COMPLETE, with in a minute or so you should connect to the new SSID "FinalStage" to finish the process.
2018-12-02 20:39:44,978: INFO: ** ONLY disconnect when the new "FinalStage" SSID is visible as an available WiFi network.
2018-12-02 20:39:44,979: INFO: This server should automatically be allocated the IP address: 192.168.4.2.
2018-12-02 20:39:44,979: INFO: If you have successfully connected to "FinalStage" and this is not the IP Address you were allocated, please ensure no other device has connected, and reboot your Sonoff.
2018-12-02 20:40:45,292: INFO: *** IMPORTANT! ***
2018-12-02 20:40:45,293: INFO: ** AFTER the first download is COMPLETE, with in a minute or so you should connect to the new SSID "FinalStage" to finish the process.
2018-12-02 20:40:45,294: INFO: ** ONLY disconnect when the new "FinalStage" SSID is visible as an available WiFi network.
2018-12-02 20:40:45,294: INFO: This server should automatically be allocated the IP address: 192.168.4.2.
2018-12-02 20:40:45,294: INFO: If you have successfully connected to "FinalStage" and this is not the IP Address you were allocated, please ensure no other device has connected, and reboot your Sonoff.
2018-12-02 20:41:03,382: DEBUG: Current IPs: ['192.168.4.2']
2018-12-02 20:41:03,388: INFO: The "FinalStage" SSID will disappear when the device has been fully flashed and image_arduino.bin has been installed.
2018-12-02 20:41:03,389: INFO: If there is no "Sending file: /ota/image_arduino.bin" log entry, ensure all firewalls have been COMPLETELY disabled on your system.
2018-12-02 20:42:03,625: INFO: The "FinalStage" SSID will disappear when the device has been fully flashed and image_arduino.bin has been installed.
2018-12-02 20:42:03,627: INFO: If there is no "Sending file: /ota/image_arduino.bin" log entry, ensure all firewalls have been COMPLETELY disabled on your system.
2018-12-02 20:43:03,926: INFO: The "FinalStage" SSID will disappear when the device has been fully flashed and image_arduino.bin has been installed.
2018-12-02 20:43:03,928: INFO: If there is no "Sending file: /ota/image_arduino.bin" log entry, ensure all firewalls have been COMPLETELY disabled on your system.
2018-12-02 20:44:04,171: INFO: The "FinalStage" SSID will disappear when the device has been fully flashed and image_arduino.bin has been installed.
2018-12-02 20:44:04,173: INFO: If there is no "Sending file: /ota/image_arduino.bin" log entry, ensure all firewalls have been COMPLETELY disabled on your system.
2018-12-02 20:45:04,398: INFO: The "FinalStage" SSID will disappear when the device has been fully flashed and image_arduino.bin has been installed.
2018-12-02 20:45:04,400: INFO: If there is no "Sending file: /ota/image_arduino.bin" log entry, ensure all firewalls have been COMPLETELY disabled on your system.
2018-12-02 20:45:52,542: DEBUG: Current IPs: []
2018-12-02 20:45:52,542: INFO: It appears we have been disconnected from the "FinalStage" SSID, however the final image has not been downloaded. Reconnect to "FinalStage" when it returns to continue the process (this may require a power cycle of your Sonoff device)...
2018-12-02 20:46:18,600: DEBUG: Current IPs: ['192.168.4.2']
2018-12-02 20:46:24,622: DEBUG: Current IPs: []
2018-12-02 20:46:24,623: INFO: It appears we have been disconnected from the "FinalStage" SSID, however the final image has not been downloaded. Reconnect to "FinalStage" when it returns to continue the process (this may require a power cycle of your Sonoff device)...
2018-12-02 20:46:48,687: DEBUG: Current IPs: ['192.168.4.2']
2018-12-02 20:46:54,716: INFO: The "FinalStage" SSID will disappear when the device has been fully flashed and image_arduino.bin has been installed.
2018-12-02 20:46:54,717: INFO: If there is no "Sending file: /ota/image_arduino.bin" log entry, ensure all firewalls have been COMPLETELY disabled on your system.
2018-12-02 20:47:54,931: INFO: The "FinalStage" SSID will disappear when the device has been fully flashed and image_arduino.bin has been installed.
2018-12-02 20:47:54,931: INFO: If there is no "Sending file: /ota/image_arduino.bin" log entry, ensure all firewalls have been COMPLETELY disabled on your system.
2018-12-02 20:48:55,161: INFO: The "FinalStage" SSID will disappear when the device has been fully flashed and image_arduino.bin has been installed.
2018-12-02 20:48:55,162: INFO: If there is no "Sending file: /ota/image_arduino.bin" log entry, ensure all firewalls have been COMPLETELY disabled on your system.
2018-12-02 20:49:09,210: DEBUG: Current IPs: []
2018-12-02 20:49:09,211: INFO: It appears we have been disconnected from the "FinalStage" SSID, however the final image has not been downloaded. Reconnect to "FinalStage" when it returns to continue the process (this may require a power cycle of your Sonoff device)...
2018-12-02 20:49:13,236: DEBUG: Current IPs: ['192.168.1.15']
2018-12-02 20:49:15,244: DEBUG: Current IPs: ['192.168.1.15', '10.6.6.173']
2018-12-02 21:28:00,956: DEBUG: Current IPs: []
2018-12-02 21:28:11,015: DEBUG: Current IPs: ['192.168.1.15']
2018-12-02 21:28:17,086: DEBUG: Current IPs: ['192.168.1.15', '10.6.6.197']
2018-12-02 21:58:19,579: INFO: Quitting.

Please advise. Thanks

[pererikl]

Since fw 2.6 on sonoff ota is no longer working.
Seems to work 2> <2.6
Make shure you disabled all firewalls including windows defender for public networks.

[sushenmathur]

debug_1548842483.log
Getting the issue with Sonoff fw : 2.6.1 and Python 3.7
is any body else facing this issue

[visstro]

@sushenmathur
Looks exactly the same for me.

[heiderich]

The issue reported by by @RamiHaikal in #141 (comment) might be due to the following issue: tornadoweb/tornado#2504

See also #67.