Stuck in FinalStage - Sonoff TH16, MacOS

[hutchwilco]

Stuck in FinalStage AP mode currently.
By my reading there are no glaring errors - see output below. Any advice? Cycling power returns to FInalStage, button appears to do nothing, I don't seem to have an OTA recovery option - serial it is then? Or can I step through the script to pickup at FinalStage again?
How long should I expect the flashing to take place during FinalStage? I think I gave it a good 5 minutes, but it never connected to the SSID again.
@mirko ?

Select IP address of the WiFi interface:
    0: 10.0.1.10
Select IP address [0]: 0
WiFi SSID: SSID_WHAT_I_OWN
WiFi Password: PASSWORD_WHAT_GETS_ME_IN

Using the following configuration:
	Server IP Address: 10.0.1.10
	WiFi SSID: SSID_WHAT_I_OWN
	WiFi Password: PASSWORD_WHAT_GETS_ME_IN
** 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...
......................................^[[C.......~~ Connection attempt
>> HTTP GET /10.10.7.1/device
<< {
    "deviceid": "100006b46f",
    "apikey": "0f01e839-97a1-4abd-9c5d-ff4deb5050fe",
    "accept": "post"
}
>> HTTP POST /10.10.7.1/ap
>> %s {
    "version": 4,
    "ssid": "SSID_WHAT_I_OWN",
    "password": "PASSWORD_WHAT_GETS_ME_IN",
    "serverName": "10.0.1.10",
    "port": 8443
}
<< {
    "error": 0
}
~~ Provisioning completed
Starting stage2...
** The IP address of <serve_host> (10.0.1.10) is not  assigned to any interface on this machine.
** Please change WiFi network to applepomis and make sure 10.0.1.10 is being assigned to your WiFi interface.
** This application should be kept running and will wait until connected to the WiFi...
...............~~ Starting web server (HTTP port: 8080, HTTPS port 8443)
~~ 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.
.<< HTTP POST /dispatch/device
>> /dispatch/device
>> {
    "error": 0,
    "reason": "ok",
    "IP": "10.0.1.10",
    "port": 8443
}
2017-09-27 21:42:33,485 (INFO) 200 POST /dispatch/device (10.0.1.52) 2.13ms
2017-09-27 21:42:33,669 (INFO) 101 GET /api/ws (10.0.1.52) 0.84ms
2017-09-27 21:42:33,669 (DEBUG) << WEBSOCKET OPEN
2017-09-27 21:42:33,678 (DEBUG) << WEBSOCKET INPUT
2017-09-27 21:42:33,678 (DEBUG) << {
    "userAgent": "device",
    "apikey": "0f01e839-97a1-4abd-9c5d-ff4deb5050fe",
    "deviceid": "100006b46f",
    "action": "register",
    "version": 2,
    "romVersion": "2.0.4",
    "model": "PSA-BHA-GL",
    "ts": 466
}
~~~ device sent action request,  acknowledging / answering...
2017-09-27 21:42:33,678 (INFO) We are dealing with a PSA-BHA-GL model.
~~~~ register
>> {
    "error": 0,
    "deviceid": "100006b46f",
    "apikey": "c06ca5ba-2113-4820-9c3f-f22058d90ab7",
    "config": {
        "hb": 1,
        "hbInterval": 145
    }
}
2017-09-27 21:42:33,687 (DEBUG) << WEBSOCKET INPUT
2017-09-27 21:42:33,687 (DEBUG) << {
    "userAgent": "device",
    "apikey": "c06ca5ba-2113-4820-9c3f-f22058d90ab7",
    "deviceid": "100006b46f",
    "action": "date"
}
~~~ device sent action request,  acknowledging / answering...
~~~~ date
>> {
    "error": 0,
    "deviceid": "100006b46f",
    "apikey": "c06ca5ba-2113-4820-9c3f-f22058d90ab7",
    "date": "2017-09-27T21:42:33.687Z"
}
2017-09-27 21:42:33,694 (DEBUG) << WEBSOCKET INPUT
2017-09-27 21:42:33,694 (DEBUG) << {
    "userAgent": "device",
    "apikey": "c06ca5ba-2113-4820-9c3f-f22058d90ab7",
    "deviceid": "100006b46f",
    "action": "update",
    "params": {
        "switch": "off",
        "fwVersion": "2.0.4",
        "rssi": -63,
        "staMac": "5C:CF:7F:9F:22:F5",
        "startup": "off"
    }
}
~~~ device sent action request,  acknowledging / answering...
~~~~ update
>> {
    "error": 0,
    "deviceid": "100006b46f",
    "apikey": "c06ca5ba-2113-4820-9c3f-f22058d90ab7"
}
>> {
    "action": "update",
    "deviceid": "100006b46f",
    "apikey": "c06ca5ba-2113-4820-9c3f-f22058d90ab7",
    "userAgent": "app",
    "sequence": "1506501753695",
    "ts": 0,
    "params": {
        "switch": "off"
    },
    "from": "hackepeter"
}
>> {
    "action": "update",
    "deviceid": "100006b46f",
    "apikey": "c06ca5ba-2113-4820-9c3f-f22058d90ab7",
    "userAgent": "app",
    "sequence": "1506501753695",
    "ts": 0,
    "params": {
        "switch": "on"
    },
    "from": "hackepeter"
}
>> {
    "action": "update",
    "deviceid": "100006b46f",
    "apikey": "c06ca5ba-2113-4820-9c3f-f22058d90ab7",
    "userAgent": "app",
    "sequence": "1506501753695",
    "ts": 0,
    "params": {
        "switch": "off"
    },
    "from": "hackepeter"
}
>> {
    "action": "update",
    "deviceid": "100006b46f",
    "apikey": "c06ca5ba-2113-4820-9c3f-f22058d90ab7",
    "userAgent": "app",
    "sequence": "1506501753695",
    "ts": 0,
    "params": {
        "switch": "on"
    },
    "from": "hackepeter"
}
>> {
    "action": "update",
    "deviceid": "100006b46f",
    "apikey": "c06ca5ba-2113-4820-9c3f-f22058d90ab7",
    "userAgent": "app",
    "sequence": "1506501753695",
    "ts": 0,
    "params": {
        "switch": "off"
    },
    "from": "hackepeter"
}
>> {
    "action": "upgrade",
    "deviceid": "100006b46f",
    "apikey": "c06ca5ba-2113-4820-9c3f-f22058d90ab7",
    "userAgent": "app",
    "sequence": "1506501753698",
    "ts": 0,
    "params": {
        "binList": [
            {
                "downloadUrl": "http://10.0.1.10:8080/ota/image_user1-0x01000.bin",
                "digest": "97fe70d737390bbde7b8d208c79d590e29fc76962623c7bd198ee210210ea616",
                "name": "user1.bin"
            },
            {
                "downloadUrl": "http://10.0.1.10:8080/ota/image_user2-0x81000.bin",
                "digest": "e6d0cbb641542bd0a27e6c4628fc9331f1f5d3ac3afa42c9307569cf4d70fcdc",
                "name": "user2.bin"
            }
        ],
        "model": "PSA-BHA-GL",
        "version": "23.42.5"
    }
}
2017-09-27 21:42:34,167 (DEBUG) << WEBSOCKET INPUT
2017-09-27 21:42:34,168 (DEBUG) << {
    "error": 0,
    "userAgent": "device",
    "apikey": "c06ca5ba-2113-4820-9c3f-f22058d90ab7",
    "deviceid": "100006b46f",
    "sequence": "1506501753695"
}
2017-09-27 21:42:34,168 (DEBUG) ~~~ device acknowledged our action request (seq 1506501753695) with error code 0
2017-09-27 21:42:34,583 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=196150922&sign=7bbc897f00354ab8f9552f4a894dff18f828ccc6f8d39c8200d435fafd6bb82e (10.0.1.52) 13.98ms
2017-09-27 21:42:34,769 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=2138392511&sign=080156b920b6db8fe9cdbc03c506db9bd7fc6d60568aabb33fa92dfb6b14d24c (10.0.1.52) 0.95ms
2017-09-27 21:42:34,860 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=862720893&sign=5146b498ad168f4794fe8972c667f9544e7e773307bbe5cc76a89d9f7e7c8364 (10.0.1.52) 1.06ms
2017-09-27 21:42:34,957 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=354043648&sign=22d57ebb6cbde5a5a94436c51809b0d07965b4eb3cac9b6d4d87af0fb6b8e89e (10.0.1.52) 1.72ms
2017-09-27 21:42:35,047 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1546965957&sign=5293af37e0b8f379afaf6223f2ff69d23eaf73d40523c373db85e917190c171e (10.0.1.52) 2.25ms
2017-09-27 21:42:35,140 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1466668831&sign=ad6974b3e50a61c06df0164df1b89080f2015c046258fb236b0628a5dea1c725 (10.0.1.52) 1.68ms
2017-09-27 21:42:35,306 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=916382919&sign=ba9b753b98d0204d6b8ce4325f4605eece12c9002de8daf53562a02f5fda9ef7 (10.0.1.52) 2.15ms
2017-09-27 21:42:35,388 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1322111512&sign=43da2e6ac5e847c019204edda1b616eac0f4bf9a4024c6761fe35ef97efe60f0 (10.0.1.52) 0.96ms
.2017-09-27 21:42:35,476 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=164897092&sign=660f4767f313d00d6caccac1241c77d51b0cb596a9c712c820aff5daa14d2c0f (10.0.1.52) 1.96ms
2017-09-27 21:42:35,575 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1258046232&sign=ac398e88d4f73b9663ccfa9a5767ebc5b311816f0c34c88818a7aa0ff6e339c1 (10.0.1.52) 2.17ms
2017-09-27 21:42:35,664 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=478762220&sign=bff5d3d5f00c0467cd7da863e066c25d8b289b373bd2af9df155c9c3643db205 (10.0.1.52) 1.74ms
2017-09-27 21:42:35,748 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=254320223&sign=7770fd0d5c76840c5897f672e015915f4f7f9c5a7caf4b9de1d96a88fbad44af (10.0.1.52) 1.90ms
2017-09-27 21:42:35,850 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1715848038&sign=47a28d1a416d3869e611aee26ad50a91c458942552fea9d399ffd01d96e5d0fb (10.0.1.52) 1.58ms
2017-09-27 21:42:35,937 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1696058609&sign=022eb61ded33e90e6c7a3ca1762b238efa8b12b7d9ed73e89ea3f30141b89f66 (10.0.1.52) 1.95ms
2017-09-27 21:42:36,024 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=2006807452&sign=9d043e3120cb1947b8bb127088fd5e2b6714eb479f4cb5518a2fc17f93d017b5 (10.0.1.52) 1.89ms
2017-09-27 21:42:36,111 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1341788522&sign=5e669b00f9a249e7e9d9f3461514ac8494a39bd89dc19fbd00348bed5948ed47 (10.0.1.52) 1.30ms
2017-09-27 21:42:36,205 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1604321728&sign=32f75efb268ea6b5698312b739c13ef8543c3c0a1aa6f106b83db3bb910804ae (10.0.1.52) 2.52ms
2017-09-27 21:42:36,290 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1382741976&sign=78511801c3b34f8f2bfab58fcbd7506a8bb732e10772b3e2141afd21ff750ee2 (10.0.1.52) 1.83ms
2017-09-27 21:42:36,384 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=584975152&sign=168ac5ae46c23a1a44ae9d3953986bf198c8736addb2ca1cf15df800ffdcd7ee (10.0.1.52) 1.91ms
2017-09-27 21:42:36,475 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1537501517&sign=8aab40c5109ae81b5a384a1cc022301a5bec7e0e5172c03124d8c9dd62506a55 (10.0.1.52) 2.32ms
2017-09-27 21:42:36,566 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1471641423&sign=004801e7c3fce9fe1cc5f3df88650b879885f2c0b9b6f1960876381cb6abbe4c (10.0.1.52) 2.03ms
2017-09-27 21:42:36,652 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=180281402&sign=9706e4cda970a76276711c7f8827da686ca0cc26af15d0d3593ac48b4baa9df7 (10.0.1.52) 1.56ms
2017-09-27 21:42:36,742 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=943538704&sign=df73564b2603e96b3f9ea60f1d616213ab0944914187ad7d82c914e6464ecead (10.0.1.52) 1.56ms
2017-09-27 21:42:36,831 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=390271936&sign=a2bc2cf21d0f99a13f549ec3a77ff2d818315730194466d00ba9ebd2064515d8 (10.0.1.52) 2.00ms
2017-09-27 21:42:36,918 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1860379350&sign=472bf657a5610d9b673f70259471aa92fda23cadc7f208346f65732353c33f0f (10.0.1.52) 2.10ms
2017-09-27 21:42:37,004 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1895591035&sign=59a5bfaed69f95aaf3e0e3bbf847e475fac2d5502682bc94322b2e95d2e4bf25 (10.0.1.52) 2.07ms
2017-09-27 21:42:37,095 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1631817825&sign=4cfad5cf92e00bf60b71b504f085938f5aef14a895f0ec303f4808b3390f4629 (10.0.1.52) 2.09ms
2017-09-27 21:42:37,185 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=952331128&sign=d88267667c891d2b7d350ca0a97ee059a0ddbcfd8e92ee68d2631f66c9c20b1d (10.0.1.52) 1.21ms
2017-09-27 21:42:37,271 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=832433964&sign=c26806db6574e17b406f687b8fbb45433bcc586b1de6aa3722c2b89ad419915a (10.0.1.52) 2.08ms
2017-09-27 21:42:37,359 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=2102803426&sign=58ba068e5ab429801f672f6428d185e4946a9ee6e0c148e6167a7c2b0b194829 (10.0.1.52) 1.99ms
.2017-09-27 21:42:37,448 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=2110844165&sign=b7f1556cce779c33ff8b4bfb824190d6d554fc0ecaf4c140cc5c35693ccb464d (10.0.1.52) 1.83ms
2017-09-27 21:42:37,536 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1339394775&sign=66da3b368f31336c7db3a4055b03ed906a0b578ba512225f769eb3170e9e2dae (10.0.1.52) 2.09ms
2017-09-27 21:42:37,625 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1588783404&sign=c85ebb210789c0308b2dd23c043aed8a63ab9d8b3af6e85d7c622bd89d67c9f4 (10.0.1.52) 1.33ms
2017-09-27 21:42:37,713 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1455244164&sign=74255557136a72c0572fc8851933ccb59ed44dd4704b05d3905789c442311c90 (10.0.1.52) 1.83ms
2017-09-27 21:42:37,803 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=308476873&sign=35d61e06c409ea1a7fb42883f587786fd7a49f21fb9418d269a090d09fd216a1 (10.0.1.52) 1.67ms
2017-09-27 21:42:37,890 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=38297258&sign=a3328d40658533fa33d91b660a8d1af65233fb04c014a1a7e05ce55b0ea83ebe (10.0.1.52) 1.63ms
2017-09-27 21:42:37,979 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=938993624&sign=077db0ff3d2f6bfa963ebcb878383dbab08570b4bdb4dfeb75cb67f3de4b9899 (10.0.1.52) 2.10ms
2017-09-27 21:42:38,064 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1048555821&sign=bd086c24c72858780d07785c34a1d7abfe02f8fe1314ad0ac0bf0f9efde10c27 (10.0.1.52) 1.60ms
2017-09-27 21:42:38,152 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1930358829&sign=0149f6f0975f81707b58b565da064ada5e969a2b802c6da3f92d7bd7d1c64504 (10.0.1.52) 1.59ms
2017-09-27 21:42:38,239 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=2139193777&sign=57eb8c278945c9ed81d89ac59f207535fcf173fedfe64293cbed4f40811547cb (10.0.1.52) 2.01ms
2017-09-27 21:42:38,328 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=447992224&sign=f494b768d9004fa29307b332f5f81e7d513d84e88a7a242ff20127b55cb2fca9 (10.0.1.52) 1.69ms
2017-09-27 21:42:38,411 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=117920226&sign=489103c4e8300379aefc4cc738a306f7179b7435ded8d49452c64e7bce3c0625 (10.0.1.52) 1.26ms
2017-09-27 21:42:38,500 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1682827604&sign=f40187f169dfcca35b9980ef570691558c75b06f978d671b294b6b893a0cc232 (10.0.1.52) 1.64ms
2017-09-27 21:42:38,588 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=669388451&sign=1f2d1a0528464c6a759341171e6ed549e4ab4643ea0c91c4bd2a825f7ae91b9c (10.0.1.52) 1.98ms
2017-09-27 21:42:38,678 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=562105037&sign=8248ba7baad371dc80b8ccd673999139efd2e931aec74d6be35a29a85b1c72bd (10.0.1.52) 1.99ms
2017-09-27 21:42:38,763 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=2028664838&sign=c81b22fceba8b7289a1878f251665ce4ecab244a621fcb16cc8787902204a665 (10.0.1.52) 1.84ms
2017-09-27 21:42:38,851 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=2019386625&sign=a16cb331f35a0490eab62fa2aae3355898ca69df3ad6e91c11988a3a37d29a7b (10.0.1.52) 1.63ms
2017-09-27 21:42:38,941 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1464321379&sign=2eaaef086a8384282aa5a090d080f48749dc8cfe3c86e7f700584c3200d89430 (10.0.1.52) 2.10ms
2017-09-27 21:42:39,029 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1297990419&sign=d4e73a223bbf910579b4c2bb2901224b896f79ed6f72bf78e9b74476a333863d (10.0.1.52) 1.85ms
2017-09-27 21:42:39,122 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1144638575&sign=7f8f733d5b5b8b13e8a323b18a3fbfe9cfc751db617ba8df349ab5ec5dd05dbd (10.0.1.52) 1.95ms
2017-09-27 21:42:39,211 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=852188688&sign=8c052c99d9550d1bf75fd596d849c9a1e0402242c8770b89e168660c129786bf (10.0.1.52) 1.65ms
2017-09-27 21:42:39,301 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1430549897&sign=da565ed3816f4d897fd2a2ef84e7e3a5d8bb4ab92b2ba2e7d853d2d13932cd99 (10.0.1.52) 1.29ms
2017-09-27 21:42:39,390 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1114506820&sign=15065cb48c5c5681e8e86b2dc3f592a7cd742259b218d408f91e0dbaac8e47c0 (10.0.1.52) 2.05ms
.2017-09-27 21:42:39,493 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1413917078&sign=45e8f1e5d6f9c55194e3c20ba3ab02cde3710790336b0c773cd910681767159a (10.0.1.52) 2.09ms
2017-09-27 21:42:39,576 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=947037966&sign=702634541f3fa1c976254a3d513b4daa142e1ca2d14c5341a63929339937140d (10.0.1.52) 2.02ms
2017-09-27 21:42:39,663 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=885118797&sign=43380648a0c30c3a9c73846dba6660be7cae8d0a32123604768c79b9b55df3e9 (10.0.1.52) 1.61ms
2017-09-27 21:42:39,751 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1841827055&sign=7937d23f0ffcd5b686e4eeb32aa09cd2d23b117e1ebd36082628cc8ae16d3e85 (10.0.1.52) 2.04ms
2017-09-27 21:42:39,842 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=537716674&sign=f638fd36326efefcf23ad16b0056d72901805d38afe8acaefc015a77f7f4846b (10.0.1.52) 2.00ms
2017-09-27 21:42:39,930 (INFO) 206 GET /ota/image_user1-0x01000.bin?deviceid=100006b46f&ts=1060528228&sign=b20f39d269e4f570f731845a8966b84b36de7c72ef21b01879a2cdd196e459ea (10.0.1.52) 1.59ms
2017-09-27 21:42:40,246 (DEBUG) << WEBSOCKET INPUT
2017-09-27 21:42:40,246 (DEBUG) << {
    "error": 0,
    "userAgent": "device",
    "apikey": "c06ca5ba-2113-4820-9c3f-f22058d90ab7",
    "deviceid": "100006b46f",
    "sequence": "1506501753698"
}
2017-09-27 21:42:40,246 (DEBUG) ~~~ device acknowledged our action request (seq 1506501753698) with error code 0
......

*** 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.
..........

*** 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.
.........


The "FinalStage" SSID will disappear when the device has been fully flashed and image_arduino.bin has been installed
Once "FinalStage" has gone away, you can stop this program
2017-09-27 21:43:35,666 (INFO) 200 GET /ota/image_user2-0x81000.bin (192.168.4.1) 7100.75ms
No longer on "FinalStage" SSID, all done!
2017-09-27 21:43:59,653 (INFO) Quitting.

EDIT:
Watching the serial output (no surprises) shows the "FinalStage" boot and "Connecting..." output.
Clearly waiting to contact the OTA server that isn't there anymore.

Initalizing.......................................................................................................Done
Current rom: 2
Rom 1 magic byte: 0xE9
Reflashing rom: 0
Configuring Wifi...Connecting...
.Connecting...
.Connecting...
.Connecting...
.Connecting...

[apathyuk]

I got further with my T1 but now it's stuck in Final Stage. Is there a way to tell the script to pick off at that point?

Having played a bit further, it is possible to skip ahead in the script but alternating between HOMENET and Final Stage.

Running netstat shows that my PC never receives a connection from 192.168.4.1 when connected to FInal Stage.

Is there something that can be done or do I need to wiring up a data connection?

(Would be useful for the script to show whether a connection has been made and how much data has been sent or better still a percentage)

[sillyfrog]

@apathyuk When I get a chance I'll make it easier to select which stage to start at. At the moment you can use --no-prov and that'll get you to stage 2, and (in theory) when you connect to "FinalStage", it should move to stage 3 (the FinalStage). Especially if running on Windows, it's important to ensure that your Firwall is turned off during this process as inbound connections will be blocked otherwise.

@hutchwilco This line suggests the download completed:
2017-09-27 21:43:35,666 (INFO) 200 GET /ota/image_user2-0x81000.bin (192.168.4.1) 7100.75ms

I'm not sure what happened after that as it should just work - I would try a full power cycle of the Sonoff and see what you get after the reboot.

[hutchwilco]

@sillyfrog thanks yes, I figured the download was fine. A full power cycle just left the sonoff creating the FinalStage SSID. Of course the server script had completed and there was no way (that I knew) to start the server at the FinalStage part of the script again.
In the end I flashed it via serial, will try again for the next hardware.

[sillyfrog]

@hutchwilco Let me know how you go - I think what happened (and this appears to be very rare!), the active image has in the "user2" space (ie: the second half of the flash). The idea is it should have downloaded user1 (which it did), then it would be in FinalStage mode, and and get user2 (which it also did).

The issue then is the script saw that FinalStage had gone away, so it exited (and there is no easy way to get back to stage 3). I'll have a think as to the best way to address that (with out having to start at stage 3 again - which I'm looking to do anyway).

The most common case in the Sonoff gets user2 straight up, so there is no need to hang around for 2 instances of FinalStage - hence not something I have seen before. (And working on this is tricky as once the Sonoff firmware is replaced, I have not found a way to restore it, so each full run requires a new Sonoff).

Thanks for getting back to me, and if you do see thing again, let me know and hopefully I'll be able to come up with a solution.

[sillyfrog]

Confirming that I have made some changes to fix this now in the DOUT-mode branch. This will likely become master shortly, should you come across this again.