Amikor az ESP8266 elszáll (0x40201c2f hiba és társai)

[csabeszq]

Ifjú éveimben amikor a program elszállt 0x40201c2f általános védelmi hibával, mindenki tudta, hogy mit hol kell javítani. Azóta eltelt jópár év, az emberek elkényelmesedtek és mikor az ESP azt dobja, hogy:

Kód: Egész kijelölése

epc1=0x40201c2f epc2=0x00000000 epc3=0x00000000 excvaddr=0x456789ab depc=0x00000000

akkor megáll az élet. Akár azt is írhatta volna, hogy "bakker, eltoltam", a program írója meg néz mint Rozi a moziban. Nem volt ez mindig így, 20 évvel ezelőtt természetes volt, hogy a programok így üzengettek, az informatikusok mégis megértették a néma gyermeket.

Vegyünk egy programot, amelyik fagyizik:

Kód: Egész kijelölése

void setup() {
  Serial.begin(115200);
  Serial.println("Elindultam...");
  delay(2000);
}

void ittFogunkFagyizni(int szamlalo)
{
  if( szamlalo == 123 )
    *(int *)0x456789AB = 13;
}

int szamlalo = 0;

void loop() {
  ittFogunkFagyizni(szamlalo++);
}

És amit dob:

Kód: Egész kijelölése

Exception (9):
epc1=0x40201c2f epc2=0x00000000 epc3=0x00000000 excvaddr=0x456789ab depc=0x00000000

ctx: cont 
sp: 3ffef1c0 end: 3ffef390 offset: 01a0

>>>stack>>>
3ffef360:  00000000 00000000 00000001 40202001  
3ffef370:  3fffdad0 00000000 3ffee358 4020202c  
3ffef380:  feefeffe feefeffe 3ffee370 40100114  
<<<stack<<<

Ha tehát a programunk epc1-nél elszállt (0x40201c2f), akkor a következő a teendő:
- Keressük meg hogy az Arduino hová fordította a progamunkat (nálam sketch_dec03b.ino.elf a lefordított kód neve).
- Keressük meg az xtensa alkalmazásokat (xtensa-lx106-elf-addr2line)
Azért nem írok teljes elérési utat, mert ahány Arduino, annyi helyen lehet.

Miután megtaláltuk a lefordított elf fájlt és az xtensa binárist, adjuk ki a következő parancsot:

Kód: Egész kijelölése

> xtensa-lx106-elf-addr2line -f -C -e sketch_dec03b.ino.elf 0x40201c2f
ittFogunkFagyizni(int)
/home/ckarai/avr/arduino/projects/sketch_dec03b/sketch_dec03b.ino:10

Amint látjuk, a kód a sketch_dec03b.ino 10. sorában az ittFogunkFagyizni(int) függvényben szállt el. Megértettük a néma gyermeket.

A nagyon elvadult informatika mániások akár ki is listázhatják a kódot:

Kód: Egész kijelölése

>xtensa-lx106-elf-objdump -s -S sketch_dec03b.ino.elf


40201c24 <_Z17ittFogunkFagyiznii>:

void ittFogunkFagyizni(int szamlalo)
{
  if( szamlalo == 123 )
40201c24:       7ba032          movi    a3, 123
40201c27:       069237          bne     a2, a3, 40201c31 <_Z17ittFogunkFagyiznii+0xd>
    *(int *)0x456789AB = 13;
40201c2a:       fffd21          l32r    a2, 40201c20 <setup+0x34>
40201c2d:       d30c            movi.n  a3, 13
40201c2f:       0239            s32i.n  a3, a2, 0
40201c31:       f00d            ret.n

Utoljára 2004 felé lehetett, hogy ilyen formában túrtam a kódot és nézegettem, hogy mi hol szállt el a 500 MHz-es Pentiumon főmunkaidőben. Egy kis retro persze sosem árt.

[aaszabo]

Ez egy nagyon hasznos infó!
Köszönöm, hogy megosztottad.

Ma este ki is próbálom, mert van egy elszállás, ami most a túlterheléses tesztelés alatt jött elő.
16 párhuzamos klienssel folyamatosan behívok az általam írt kis AP-n futó szerverre. Kb 5-6 percig állja is a rohamot és 1000 körüli kérést ki is szolgál.
Úgy tűnik, hogy ha a Heap méret 3500 alá csökken jön egy WDT reset és az általad is mutatotthoz hasonló adatsor.

Attól félek, hogy az elszállás nem is az én kódomban jön és nem is egyszerű programhiba.
A gyakori sok hívás kezelésétől elfogy a memória terület az AP-t működtető ESP kódban.

Végül is három területet tudok elképzelni a probléma helyeként:
saját kód
valamilyen lib
ESP belső kódja

Mindegyiket meg tudom nézni valahogy ezzel a módszerrel? Van erre tapasztalatod?
Elvileg a feltöltendő kódban a kernel is mindig benne van.

[csabeszq]

Ebbe minden benne van. SDK, a kódod, az összes lib. Sőt a stack trace-t is látod.

Kód: Egész kijelölése

>>>stack>>>
3ffef360:  00000000 00000000 00000001 40202001  
3ffef370:  3fffdad0 00000000 3ffee358 4020202c  
3ffef380:  feefeffe feefeffe 3ffee370 40100114  
<<<stack<<<

Ezek a függvények:
40202001
4020202c
40100114

Ezek mind metódusok. Nincs más dolgod mint kikeresni, hogy melyik függvényhez tartoznak és látod, hogy ki hívott kit a fagyásnál.

[aaszabo]

Hát amiben elszállt arra nem tudott mit mondani, csak ezt:
??
??:0

A stack többi függvényére ad értelmes sorokat, pl:
String::replace(String const&, String const&)

Viszont egy sima reset nem elég a feléledéshez. Akkor működik csak, ha táptalanítom, aztán megint visszakapcsolom a tápra.
Jó lenne egy megoldás, ami ilyen elszállás után is újraindítja az áramkört.

Kód: Egész kijelölése

Exception (28):
epc1=0x4000bf0e epc2=0x00000000 epc3=0x00000000 excvaddr=0x00000000 depc=0x00000000

ctx: cont
sp: 3fff29f0 end: 3fff2cc0 offset: 01a0

>>>stack>>>
3fff2b90:  3ffe0032 3fff084c 3fff084c 4020724b
3fff2ba0:  3fff10f8 3fff084c 3fff2c20 4020759a
3fff2bb0:  3fff10f8 3fff084c 3fff0828 40206a53
3fff2bc0:  00000000 0000002f 0000002f 3fff66a4
3fff2bd0:  0000000f 0000000b 3fff64c4 0000000f
3fff2be0:  00000004 3fff7174 000000ff 00000000
3fff2bf0:  3fffb294 0000000f 00000000 3fff665c
3fff2c00:  0000003f 00000031 3fff6614 0000003f
3fff2c10:  00000001 3fff66e4 0000000f 00000003
3fff2c20:  3fff65bc 0000004f 00000011 4020465c
3fff2c30:  3fff0868 3fffb294 00000000 00000000
3fff2c40:  00000000 40204be8 00000004 402045e6
3fff2c50:  00000000 00000000 3fff0828 3fff1c94
3fff2c60:  000000c8 3fff084c 3fff0828 4020586b
3fff2c70:  3ffe9d40 00000000 000003e8 40207e68
3fff2c80:  00000000 3fff8c34 00000000 40206e5e
3fff2c90:  3fffdad0 00000000 3fff1c8c 402039cd
3fff2ca0:  3fffdad0 00000000 3fff1c8c 40207df8
3fff2cb0:  feefeffe feefeffe 3fff1ca0 40100718
<<<stack<<<
ets Jan  8 2013,rst cause:2, boot mode:(1,6)
ets Jan  8 2013,rst cause:4, boot mode:(1,6)
wdt reset

[Robert]

Táphiba nem lehet? Megrántja és resetel? (BOD illetve elfogy a szufla?)

[aaszabo]

Nem gondolnék táphibára.
Sima terhelésnél (3sec/request) 48 órás működést gond nélkül bírt.
Ugyanolyan összeállításban, változtatás nélkül próbálva már nem ez a helyzet.
Rendszeresen elszáll 5-6 perc után, ha túlterhelem (16 kliens folyamatos kéréseket küld párhuzamosan)
A logokban azt látom, hogy a Heap Size vészesen lecsökken (utolsó érték 3500byte körüli).
Mi az a BOD?

[Robert]

Brown Out Detection: alacsony tápfesz-reset.

16 kérés? A modul egyidejűleg 4+1 kiszolgálására alkalmas!
Azaz sikerül túlterhelni az eszközt. Ez egy IOT holmi, nem egy szerver!

[csabeszq]

Te magad is tudod a választ. A String replace-ben elszáll, mert elfogy a memória.

Amikor elfogy a memória, a malloc/realloc 0-t ad vissza. Ezt próbálja a kód címezni, azért fagy. Az excvaddr láthatóan nulla.

A stacktraceből kiderült amit eddig is tudtál.

Kérdés, hogy van-e olyan változó, amit lefoglalsz és nem szabadítasz fel.

[csabeszq]

A reset programozás után fagy. Ha tápról indítod, úgy száll el, akkor resetre is újra kellene indulnia.

El van az esp fuserálva és nem ellenőrzi a gpiok állapotát és az uart bootloadert indítja el programozás utáni fagyásnál.

[aaszabo]

Tudom, hogy nem 16 kliensre van kitalálva. De pont hogy a nem várt eseményekre, direkt támadások kivédésére akarom felkészíteni.
Minden nem fizikai behatás után, ami nem okoz fizikai változást normál üzemi állapotba kell tudnia kerülni.

Tudom, hogy nem létezik tökéletes program és akkor is vissza kell tudni állni a rendszernek, ha nem az én programomban van a hiba, hanem a kernel sérülékeny.

A legbiztonságosabbnak egy külső HW figyelő áramkört gondolok, ami négyszögjelet vár az egyik GPIO-n. Ha nem jön, akkor egy ideig elveszi a tápfeszt, hogy újrainduljon a rendszer.

[aaszabo]

Egyébként, miután release verziót fordítottam és nem Debugost nem száll el az extrém túlterhelés alatt sem. Egy órán keresztül bombáztam és 8k alá nem csökkent a Heap mérete.
A két verzió között az a különbség, hogy nem iratok ki a soros portra debug szintű logot. A kiiratandó információhóz használok elég sok String concat-ot, ami helyigényes.

A memória felszabadítási ötletre én is gondoltam. Az a helyzet, ha nem nagy a terhelés, akkor nem fogy a memória. Ebből arra gondolok, hogy a memória felszabadítás működik, csak túlterhelés hatására a core program és az én programom kvázi párhuzamos futása miatt foglalódik túl. Adódik olyan állapot, amikor az én programom lefoglal területet és a felszabadítás előtt még egy yield visszaadja a vezérlést a core-nak, ahol szintén foglal memóriát. Itt még megnézem, hogy a vezérlés visszaadása előtt legyen felszabadítás, ha az időzítésbe biztonságosan belefér.

Nincs pontos adatom meddig futhat a saját program a loop()-ból, mielőtt visszaadja a vezérlést a core-nak.
Erről van tapasztalatotok?

[Robert]

Van ennél a jóembernél egyéb érdekesség is:)
https://github.com/me-no-dev/EspExceptionDecoder