rboot Rom 1 is bad

[icodk]

Try to run Basic_rBoot. All compiles and flashed and even downloaded with the ota command. However when try to switch get the following:

swapping from rom 0 to rom 1.
Restarting...

state: 5 -> 0 (0)
rm 0
del if0
usl

 ets Jan  8 2013,rst cause:2, boot mode:(3,6)

load 0x40100000, len 1588, room 16 
tail 4
chksum 0xb6
load 0x3ffe8000, len 700, room 4 
tail 8
chksum 0xfe
csum 0xfe

rBoot v1.2.1 - richardaburton@gmail.com
Flash Size:   32 Mbit
Flash Mode:   QIO
Flash Speed:  40 MHz
rBoot Option: Big flash

Rom 1 is bad.
Booting rom 0.
don't use rtc mem data
sdS

etc. Still running on slot 0

Sming 2.1.0 sdk 1.5.2(7eee54f4) nodemcu (esp-12) USB powered. Downloaded file with a browser matches the original rom0.bin Help appreciated

[raburton]

Flash writing is broken in SDK v1.5.1/v1.5.2. Intermittent failures occur when performing sustained writes while using wifi at the same time (and possibly other untested scenarios too). See http://richard.burtons.org/2016/03/03/flash-write-bug-in-espressif-sdk-v1-5-1/ and http://bbs.espressif.com/viewtopic.php?f=7&t=1664 (espressif supplied a fix, but it didn't work). Only option is to stick as v1.5.0 or lower and wait for a working fix from espressif. Please add your support to the bug report.

[raburton]

Just updated rBoot (not yet put it in Sming, but you can update it manually to test). Looks like the problem is much larger than anticipated packets of data coming from the network stack. These cause need to be written across multiple sectors, and my code didn't erase them all, then the flash write function didn't complain when it tried to write to those non-erased sectors. Give it a try and let me know how you get on...

[icodk]

@raburton Firstely thanks for the vital information. May be we should add a readme per example that states the last sdk it runs on. I haven't imagine that this can be an issue in a Sming release that is 3 month old. Good there are people with better imagination then mine...Secondly You say problem much larger then anticipated. If you can't get it to work, there is a very little chance I can (I will try tomorrow). Meanwhile I noticed your exchange with Espressif http://bbs.espressif.com/viewtopic.php?f=7&t=1664&p=6366&hilit=ota#p6371 from today(160406) Is the problem solved?

[raburton]

Have you seen the message I posted to this issue 6 hours ago? It's fixed (subject to a bit more testing), get the latest rBoot code from my repo (rBoot repo, not Sming).

[icodk]

Should I also apply the libmain_for_ESP8266_NONOS_SDK_V1.5.2.zip fix from Espressif before testing your fix? Will test it tomorrow and let you know

[raburton]

No need.

[icodk]

Still gets the same error: Rom 1 is bad. here is the beginning of the download, the first packet is 4380 bytes Also the size reported by the download does not match the actual file size: Actual size: 260.032 bytes Download size is only 194496 bytes :

Firmware download finished!
 - item: 0, addr: 202000, len: 194496 bytes
 - item: 1, addr: 300000, len: 65536 bytes
Firmware updated.
In callback...
Firmware updated, rebooting to rom 1...
state: 5 -> 0 (0)
rm 0
pm close 7
del if0
usl

 ets Jan  8 2013,rst cause:2, boot mode:(3,6)

load 0x40100000, len 1340, room 16 
tail 12
chksum 0xe9
ho 0 tail 12 room 4
load 0x3ffe8000, len 660, room 12 
tail 8
chksum 0xcd
csum 0xcd

rBoot v1.3.0 - richardaburton@gmail.com
Flash Size:   32 Mbit
Flash Mode:   QIO
Flash Speed:  40 MHz
rBoot Option: Big flash

Rom 1 is bad.
Booting rom 0.
don't use rtc mem data
{dS

Beginning of the download

Updating...
+TCP connection
Download file:
    (0) http://192.168.1.200:8000/static/upgrade/rom0.bin -> 202000
Download: http://192.168.1.200:8000/static/upgrade/rom0.bin
connect to: 192.168.1.200
TcpConnection::connect result:, 0
realloc 60 -> 191
OnConnected
TCP connected
onReadyToSendData: 0
TcpClient request completed
TCP sent: 62
onReadyToSendData: 2
Header pos: 277
Content-Length === 260032
X-Powered-By === web2py
Last-Modified === Thu, 07 Apr 2016 20:23:04 GMT
Pragma === cache
Cache-Control === private
Content-Type === application/octet-stream
Date === Thu, 07 Apr 2016 20:38:57 GMT
Server === Rocket 1.2.6 Python/2.7.9
Connection === close
TCP received: 281 bytes
onReadyToSendData: 1
TCP received: 4380 bytes
onReadyToSendData: 1
TCP received: 1460 bytes
onReadyToSendData: 1

Any idea ?

[raburton]

That's a useful snippet of log. As you say the download size doesn't match the file size. rBoot doesn't do the downloading, that's done by higher level code in Sming so I'd suggest opening a bug against Sming to look into it (I haven't had the time for any real involvement recently, although I have pushed the other fix into Sming development branch yesterday). What you could try though, is reading the rom back and seeing what's actually been flashed, preferably a binary diff to catch any subtle differences. You never know, it might have written an html error page to the flash! Or the server might have sent it in chunked format without indicating that in the header. I know other people have had problems with serving from python before, usually splitting the header into multiple packets which doesn't look like what you are seeing, but give it a try with a real webserver and see if you get a better result (e.g. Apache or IIS).

[icodk]

@raburton Thanks. I will try another web server ASAP(later today)

[icodk]

It works with another web server(nginx). Tryed it several times without problem Both report the correct Content-Length=260032 However nginx manage to get the right number of bytes: 260032. nginx reporets Content-Type === text/plain. Rocket server(Server === Rocket 1.2.6 Python/2.7.9) reports Content-Type === application/octet-stream which actually more correct

Here is the beginning, middle and the end of the download :

Updating...
+TCP connection
Download file:
    (0) http://192.168.1.200:8080/rom0.bin -> 2000
Download: http://192.168.1.200:8080/rom0.bin
connect to: 192.168.1.200
TcpConnection::connect result:, 0
realloc 45 -> 176
OnConnected
TCP connected
onReadyToSendData: 0
TcpClient request completed
TCP sent: 47
onReadyToSendData: 2
Header pos: 234
Server === nginx/1.8.1
Date === Fri, 08 Apr 2016 21:34:20 GMT
Content-Type === text/plain
Content-Length === 260032
Last-Modified === Fri, 08 Apr 2016 21:27:51 GMT
Connection === close
ETag === "57082257-3f7c0"
Accept-Ranges === bytes
TCP received: 1460 bytes
onReadyToSendData: 1
TCP received: 1460 bytes
onReadyToSendData: 1
TCP received: 1460 bytes
onReadyToSendData: 1
TCP received: 1460 bytes
onReadyToSendData: 1
TCP received: 1460 bytes
onReadyToSendData: 1
TCP received: 1460 bytes
onReadyToSendData: 1
TCP received: 1460 bytes
onReadyToSendData: 1

Change to spiff

TCP received: 390 bytes
onReadyToSendData: 1
TCP received: (null)
TCP connection closing
-TCP connection
Download file:
    (1) http://192.168.1.200:8080/spiff_rom.bin -> 100000
Download: http://192.168.1.200:8080/spiff_rom.bin
+TCP connection
connect to: 192.168.1.200
TcpConnection::connect result:, 0
realloc 50 -> 181
OnConnected
TCP connected
onReadyToSendData: 0
TcpClient request completed
TCP sent: 52
onReadyToSendData: 2
Header pos: 233
Server === nginx/1.8.1
Date === Fri, 08 Apr 2016 21:34:26 GMT
Content-Type === text/plain
Content-Length === 65536
Last-Modified === Fri, 08 Apr 2016 21:27:51 GMT
Connection === close
ETag === "57082257-10000"
Accept-Ranges === bytes
TCP received: 1460 bytes
onReadyToSendData: 1
TCP received: 1460 bytes

Bottom

TCP received: 1460 bytes
onReadyToSendData: 1
TCP received: 1460 bytes
onReadyToSendData: 1
TCP received: 73 bytes
onReadyToSendData: 1
TCP received: (null)
TCP connection closing
-TCP connection

Firmware download finished!
 - item: 0, addr: 2000, len: 260032 bytes
 - item: 1, addr: 100000, len: 65536 bytes
Firmware updated.
In callback...
Firmware updated, rebooting to rom 0...

[raburton]

Jolly good. Must be something up with the http stream that Sming isn't handling well. You could take network traces and have a look, or just forget about it and enjoy your new server!