Crashing in SonOff Pow R2 v2.0 (v 1.13.5)

[JavierAder]

Hi, my SonOff Pow R2 v2.0 with Espurna 1.13.5 (binay release) is restarting after a certain time.

I only have enabled ThingSpeak (with Clear Cache, and reporting the 7 sensors, current, voltage, etc) and Telnet in STA mode (without this last one also happens). Some screenshots of various telnet commands:

Any suggestions?

[mcspr]

Can you upgrade to the dev version? See https://github.com/mcspr/espurna-nightly-builder/releases
(and please post crashes as text, if they happen again:)
Did it crash on it's own or after accessing webui?

May be related to the #1720, but I am trending towards increased loop delay as a solution for this if it is only related to normal operation. current 1.13.6-dev should space things out more evenly. Another option is that tspk queue eventually fragments the memory (flush method), so webui can crash things.

[JavierAder]

Hi mcspr; I will try (but I am having problems building under Windows; ok, it's another subject).

Two things:

• power : 3138 mV. Is not it too low? Maybe I have a problem hardware and the micro is simply resetting due to low voltage....
• Does Thingspeak use SSL? I think I read that SSL can cause instability, but I'm not sure

[mcspr]

• based on some brief research, I would not trust that voltage value too much. I'm more inclined to treat this a sw bug first
• no. it uses plain http, unless you built the firmware yourself and included async ssl libraries, it actually can't open secure connections

[JavierAder]

Offtopic: Finally I was able to build the current dev version (commit 0998110; task Build (itead-sonoff-pow-r2)). Now what? Can I simply use esptool to flash firmware.bin (generated in .pioenvs/itead-sonoff-pow-r2/) in my Sonoff Pow R2? Is this correct?

[JavierAder]

Hi,
"Did it crash on it's own or after accessing webui?"
Crash on it's own, in SAT mode, only thingspeak enabled. The first time that I realized that was because the energy plot in thingspeak was droping to zero after some time; now, it doesn't happen with you build... but when I look the uptime via telnet it seems like is crashing.

info after 24 hours running:

Welcome!
uptime
[919363] Uptime: 17919 seconds
[919364] +OK
info
[924440]

---8<-------

[924441] [MAIN] ESPURNA 1.13.6-dev (0998110)
[924441] [MAIN] xose.perez@gmail.com
[924441] [MAIN] http://tinkerman.cat

[924441] [MAIN] CPU chip ID: 0x3D64E1
[924442] [MAIN] CPU frequency: 80 MHz
[924442] [MAIN] SDK version: 1.5.3(aec24ac9)
[924442] [MAIN] Core version: 2.3.0
[924442] [MAIN] Core revision: 159542381
[924442] [MAIN] Build time: 1560147312
[924443]
[924443] [MAIN] Flash chip ID: 0x1640EF
[924444] [MAIN] Flash speed: 40000000 Hz
[924444] [MAIN] Flash mode: DOUT
[924444]
[924445] [MAIN] Flash size (CHIP)   :  4194304 bytes / 1024 sectors (   0 to 1023)
[924447] [MAIN] Flash size (SDK)    :  4194304 bytes / 1024 sectors (   0 to 1023)
[924447] [MAIN] Reserved            :     4096 bytes /    1 sectors (   0 to    0)
[924447] [MAIN] Firmware size       :   494816 bytes /  121 sectors (   1 to  121)
[924448] [MAIN] Max OTA size        :   528384 bytes /  129 sectors ( 122 to  250)
[924448] [MAIN] EEPROM size         :     4096 bytes /    1 sectors ( 251 to  251)
[924448] [MAIN] Reserved            :    16384 bytes /    4 sectors ( 252 to  255)
[924448]
[924449] [MAIN] EEPROM sectors: 1019, 1018, 1017, 1016
[924449] [MAIN] EEPROM current: 1018
[924449]
[924450] [MAIN] EEPROM:  4096 bytes initially |  1373 bytes used (33%) |  2723 bytes free (66%)
[924451] [MAIN] Heap  : 34552 bytes initially | 18632 bytes used (53%) | 15920 bytes free (46%)
[924451] [MAIN] Stack :  4096 bytes initially |  1272 bytes used (31%) |  2824 bytes free (68%)
[924452]
[924453] [MAIN] Boot version: 31
[924453] [MAIN] Boot mode: 1
[924453] [MAIN] Last reset reason: Software/System restart
[924453] [MAIN] Last reset info: Fatal exception:0 flag:4 (SOFT_RESTART) epc1:0x00000000 epc2:0x00000000 epc3:0x00000000 excvaddr:0x00000000 depc:0x00000000
[924453]
[924454] [MAIN] Board: ITEAD_SONOFF_POW_R2
[924454] [MAIN] Support: ALEXA API BROKER BUTTON DEBUG_TELNET DEBUG_WEB DOMOTICZ HOMEASSISTANT LED MDNS_SERVER MQTT NTP SCHEDULER SENSOR TELNET TERMINAL THINGSPEAK WEB
[924454] [MAIN] Sensors: CSE7766
[924455] [MAIN] WebUI image: SENSOR
[924455]
[924455] [MAIN] Firmware MD5: 33d87223d88c2541fc8ac8308beeecdf
[924456] [MAIN] Power: 3138 mV
[924456] [MAIN] Power saving delay value: 10 ms
[924456]


---8<-------

[068503] +OK

crash
[043993] [DEBUG] Latest crash was at 3967006 ms after boot
[043994] [DEBUG] Reason of restart: 2
[043994] [DEBUG] Exception cause: 28
[043994] [DEBUG] epc1=0x4021ac1f epc2=0x00000000 epc3=0x00000000
[043994] [DEBUG] excvaddr=0x00000000 depc=0x00000000
[043994] [DEBUG] sp=0x3ffffe70 end=0x3fffffb0
[043994] [DEBUG] >>>stack>>>
[DEBUG] 3ffffe70: 000005a0 00000000 3fff7354 4021ac34
[DEBUG] 3ffffe80: 00000000 3fff733c 00000000 402128b2
[DEBUG] 3ffffe90: 3fff7354 3fff7434 00000000 4021acb0
[DEBUG] 3ffffea0: 3fff7284 00000000 3fff7284 402433fc
[DEBUG] 3ffffeb0: 3fff2afc 3fff2b08 00000006 3fff2910
[DEBUG] 3ffffec0: 3fff7284 3fff2918 3fff2914 4021acfb
[DEBUG] 3ffffed0: 3fff7284 3fff2918 3fff2914 40243f78
[DEBUG] 3ffffee0: 000002a7 6764a8c0 00000018 000002a7
[DEBUG] 3ffffef0: 00000018 00000000 3fff1204 401075fc
[DEBUG] 3fffff00: 40100000 00000000 00000064 3fff2b00
[DEBUG] 3fffff10: 3ffed154 3fff2b08 3fff7434 402427fd
[DEBUG] 3fffff20: 00754208 3fff69e4 3fff69e4 3ffeff90
[DEBUG] 3fffff30: 00000000 3fff7434 0000001c 3fff69e4
[DEBUG] 3fffff40: 3ffed146 00000000 3fff7434 40241879
[DEBUG] 3fffff50: 17561634 00000303 00000000 00000013
[DEBUG] 3fffff60: 00000002 00000018 40231063 3ffee980
[DEBUG] 3fffff70: 3ffed120 3fffdcc0 3ffeb070 3ffeb070
[DEBUG] 3fffff80: 40230fd6 3ffee980 00000000 3fff6a34
[DEBUG] 3fffff90: 3fffdc80 00000000 3fff7434 402394f3
[DEBUG] 3fffffa0: 40000f49 3fffdab0 3fffdab0 40000f49
[DEBUG] <<<stack<<<
[044053] +OK

17919 seconds= 5 hours.....

I don't understand why if it is crashing energy data is not resetting; was there some change related to that between 1.13.5 and your build?

[JavierAder]

Well.... It seems that it is not crashing (with your build), but uptime is wrong (maybe there is a overflow in uptime). I did switch off (unplug) my sonoff and then swith on, and energy IS resetted...

[mcspr]

Since 820d8c4 it will keep energy value in RAM between reboots. If you power-off, it will try to recover energy value from flash (if you enabled that option)

Note that crash will output the latest crash. And it will not invalidate it until read, it may stay there for a long time. info message shows that you restarted manually, no exception. so crash log may be from some other time before that

What do you mean by uptime overflow? Does it stay the same and not increasing between the times you checked?

[JavierAder]

"Since 820d8c4 it will keep energy value in RAM between reboots. If you power-off, it will try to recover energy value from flash (if you enabled that option)"
Ok, then reboot and power-off/power-on are differents things.

"What do you mean by uptime overflow? Does it stay the same and not increasing between the times you checked?"

That maybe the variable storing the uptime was too small, but it is not the case ....

Ok, maybe what is wrong is the command uptime:
In terminal.ino

    terminalRegisterCommand(F("UPTIME"), [](Embedis* e) {
        DEBUG_MSG_P(PSTR("Uptime: %d seconds\n"), getUptime());

%d? Is it correct? I'm not sure tha it makes any difference but in other parts of the code is used %lu for debug unsigned longs.

[JavierAder]

after 1 day and 16 hours running

Welcome!
uptime
[439945] Uptime: 2439 seconds
[439946] +OK
info
[442176]

---8<-------

[442177] [MAIN] ESPURNA 1.13.6-dev (0998110)
[442177] [MAIN] xose.perez@gmail.com
[442177] [MAIN] http://tinkerman.cat

[442178] [MAIN] CPU chip ID: 0x3D64E1
[442178] [MAIN] CPU frequency: 80 MHz
[442178] [MAIN] SDK version: 1.5.3(aec24ac9)
[442178] [MAIN] Core version: 2.3.0
[442179] [MAIN] Core revision: 159542381
[442179] [MAIN] Build time: 1560147312
[442179]
[442179] [MAIN] Flash chip ID: 0x1640EF
[442180] [MAIN] Flash speed: 40000000 Hz
[442180] [MAIN] Flash mode: DOUT
[442180]
[442181] [MAIN] Flash size (CHIP)   :  4194304 bytes / 1024 sectors (   0 to 1023)
[442182] [MAIN] Flash size (SDK)    :  4194304 bytes / 1024 sectors (   0 to 1023)
[442182] [MAIN] Reserved            :     4096 bytes /    1 sectors (   0 to    0)
[442182] [MAIN] Firmware size       :   494816 bytes /  121 sectors (   1 to  121)
[442182] [MAIN] Max OTA size        :   528384 bytes /  129 sectors ( 122 to  250)
[442183] [MAIN] EEPROM size         :     4096 bytes /    1 sectors ( 251 to  251)
[442183] [MAIN] Reserved            :    16384 bytes /    4 sectors ( 252 to  255)
[442183]
[442184] [MAIN] EEPROM sectors: 1019, 1018, 1017, 1016
[442184] [MAIN] EEPROM current: 1016
[442184]
[442184] [MAIN] EEPROM:  4096 bytes initially |  1373 bytes used (33%) |  2723 bytes free (66%)
[442185] [MAIN] Heap  : 34552 bytes initially | 18488 bytes used (53%) | 16064 bytes free (46%)
[442186] [MAIN] Stack :  4096 bytes initially |  1168 bytes used (28%) |  2928 bytes free (71%)
[442187]
[442187] [MAIN] Boot version: 31
[442187] [MAIN] Boot mode: 1
[442188] [MAIN] Last reset reason: Software/System restart
[442188] [MAIN] Last reset info: Fatal exception:0 flag:4 (SOFT_RESTART) epc1:0x00000000 epc2:0x00000000 epc3:0x00000000 excvaddr:0x00000000 depc:0x00000000
[442188]
[442189] [MAIN] Board: ITEAD_SONOFF_POW_R2
[442189] [MAIN] Support: ALEXA API BROKER BUTTON DEBUG_TELNET DEBUG_WEB DOMOTICZ HOMEASSISTANT LED MDNS_SERVER MQTT NTP SCHEDULER SENSOR TELNET TERMINAL THINGSPEAK WEB
[442189] [MAIN] Sensors: CSE7766
[442189] [MAIN] WebUI image: SENSOR
[442189]
[442190] [MAIN] Firmware MD5: 33d87223d88c2541fc8ac8308beeecdf
[442191] [MAIN] Power: 3139 mV
[442191] [MAIN] Power saving delay value: 10 ms
[442191]

---8<-------

[442191] +OK
crash
[445467] [DEBUG] Latest crash was at 28247293 ms after boot
[445468] [DEBUG] Reason of restart: 2
[445469] [DEBUG] Exception cause: 28
[445469] [DEBUG] epc1=0x4021ac1f epc2=0x00000000 epc3=0x00000000
[445469] [DEBUG] excvaddr=0x00000000 depc=0x00000000
[445469] [DEBUG] sp=0x3ffffe70 end=0x3fffffb0
[445469] [DEBUG] >>>stack>>>
[DEBUG] 3ffffe70: 000002d3 3fff2b10 3fff71fc 4021ac34
[DEBUG] 3ffffe80: 00000000 3fff7194 00000000 402128b2
[DEBUG] 3ffffe90: 3fff71fc 3fff76fc 00000000 4021acb0
[DEBUG] 3ffffea0: 3fff75b4 00000000 3fff75b4 402433fc
[DEBUG] 3ffffeb0: 3fff2afc 3fff2b08 00000006 3fff2910
[DEBUG] 3ffffec0: 3fff75b4 3fff2918 3fff2914 4021acfb
[DEBUG] 3ffffed0: 3fff75b4 3fff2918 3fff2914 40243f78
[DEBUG] 3ffffee0: 000002a7 6764a8c0 00000018 000002a7
[DEBUG] 3ffffef0: 00000018 00000000 3ffef360 401075fc
[DEBUG] 3fffff00: 40100000 00000000 00000064 3fff2b00
[DEBUG] 3fffff10: 3ffeb844 3fff2b08 3fff76fc 402427fd
[DEBUG] 3fffff20: 013a4208 3fff69e4 3fff69e4 3ffeff90
[DEBUG] 3fffff30: 00000000 3fff76fc 0000001c 3fff69e4
[DEBUG] 3fffff40: 3ffeb836 00000000 3fff76fc 40241879
[DEBUG] 3fffff50: 17561634 00000303 00000000 0000000b
[DEBUG] 3fffff60: 00000002 00000018 40231063 3ffee980
[DEBUG] 3fffff70: 3ffeb810 3fffdcc0 3ffeafa8 3ffeafa8
[DEBUG] 3fffff80: 40230fd6 3ffee980 00000000 3fff6a3c
[DEBUG] 3fffff90: 3fffdc80 00000000 3fff76fc 402394f3
[DEBUG] 3fffffa0: 40000f49 3fffdab0 3fffdab0 40000f49
[DEBUG] <<<stack<<<
[445532] +OK

[mcspr]

Thanks! Seems like something in async client... Need to take a closer look at thingspeak sender

[JavierAder]

Hi, platform,ini references to the async library versión 1.1.3
https://github.com/me-no-dev/ESPAsyncTCP#55cd520
in my .piolibdeps there are this version and the 1.2.0 (I don't know why)

What is the correct version to use?

[JavierAder]

Also; if you can, checks this commit:
me-no-dev/ESPAsyncTCP@0450e61
it fixes something that throws a exception 28

[mcspr]

You can use --verbose flag to see which espasynctcp source directory it chooses.
me-no-dev/ESPAsyncTCP@0450e61 looks like a solution, have you tried firmware with this patch applied?

[JavierAder]

Not yet..,. Right now I am trying dump objects from firmware.elf to figure what code trhrows the exception; it is located in addres 0x4021ac1f in the two last crashes (using your build), but I am a newby in ESP8266...
I read in "Kolban’s book on the ESP8266"

If we know the location of the exception, we can analyze the executable (app.out) to
figure out what piece of code caused the problem. For example:
xtensa-lx106-elf-objdump -x app.out -d

Is in PlatformIO some similar tool?