Improved Debugging

[jomjol]

Hallo @jomjol
Ich habe die Rolling Version vom 25.9.2020 als Ausgangspunkt genommen und diverse Änderungen im Code vorgenommen. Leider habe ich nur sehr,sehr rudimentäre Erfahrungen mit collaborativen Arbeiten mit GIT.
In den neueren Code habe ich noch nicht reingesehen.

Da ich den Wasserzähler leider nicht stabil bekommen habe, habe ich mich an meinem Gaszähler versucht.
Da werden doch häufiger Ziffern richtig erkannt.

Um die Beleuchtung regulieren zu können, habe ich ledc_timer verwendet. da muss man wegen der Verwendung einiger Timer durch die Kamera aufpassen. Ich verwende LEDC_Timer_2 und LED_Channel_7.
Die SD-Card habe ich auf slot_config.width = 1 eingestellt, damit wird GPIO04 frei.

Alle Versuche, den zweiten I2C-Bus zu nutzen ( z.B. für ein OLED-Display) sind gescheitert

Ich habe viele Logging- Funktionen auf ESP_LOGI(TAG," "); umgestellt
Die Logfilegröße habe ich beschränkt und lege die alten Log_files in einem separaten Verzeichnis ab.

Du verwendest stb_xx.h files . Gibt es dazu eine API-Dokumentation?
Wo werden Funktionen verwendet, die in Referenzparametern Ergebnisse zurückliefern,
Bekommen die beim Aufruf einen Ergebnisspeicherblock mitgeliefert oder allozieren die selber Speicher.
Du verwendest an verschiedenen Stelllen user_ctx->scratch, da steht meistens nur ein Namesstring drin, ich habe aber irgendwo auch einmal ein Malloc gesehen, finde das aber nicht mehr

Gruß Hike

[jomjol]

Zu deinen Fragen:
Collaboratives Arbeit:
Ist an sich recht einfach - du brauchst ein GitHub-Konto, dann kannst du einen eigene Kopie (Fork) von meinem Code erzeugen und deine Änderungen per Merge wieder für meinen Hauptzweig zurückspielen. Wenn du das mit einem GitHub-Client auf deinem lokalen System verbindest, geht das recht einfach und du hast noch eine History / Backup. Geht auch unter Win10 problemlos.

Rolling vom 25.09.
An der Beleuchtung, Wiring, Treiber etc. hat sich nichts geändert --> passt also!

SD-Card Anbindung
Das stand schon auf slot_witdh 1, da bei dem verwendet Modus SDMMC_HOST_SLOT_1 (= 4bit) automatisch der slot_width auf 1 gestellt wird - siehe esp-idf Docu: https://docs.espressif.com/projects/esp-idf/en/v3.1.7/api-reference/peripherals/sdmmc_host.html
ABER: GPIO4 wird dabei nicht frei - zumindest laut dieser Doku:

Beleuchtung
Ich würde dort einen LED-Streifen mit WS2812 Controller Chip verwenden (z.B: NeoPixel). Die hat den Vorteil, dass sie nur eine einen einzigen GPIO als Steuerleitung belegt und es auch viele Implementierungen zur Ansteuerung gibt. Wenn du ein RGB-Version verwendest, kannst du neben der Helligkeit auch noch die Farbe zur Kontrasterhöhung ansteuern. Ich verwende die überall, wo es um Licht geht u.a. auch in der Hardware-Version 1 des Wasserzählers

stb_xx.h
Da habe ich eine sehr schlanke Implementierung gefunden - Doku ist im Code direkt. Alles in dem h-File - etwas gewöhnungsbedürftig, aber läuft. Download von hier: https://github.com/nothings/stb

user_ctx->scratch
Das findest du jeweils im Code, wo die web-handler registriert werden - typischweise steht dort ein fester char-string drin. Du kannst von der main.cpp starten:

    server = start_webserver();   
    register_server_camera_uri(server); 
    register_server_tflite_uri(server);
    register_server_file_uri(server, "/sdcard");
    register_server_ota_sdcard_uri(server);
    register_server_main_uri(server, "/sdcard");

Wenn du in die jeweiligen register_server_xxx reinschaust, findest du den user_ctx Inhalt.

Gruß,
jomjol

[hike6688]

Den GPIO4 habe ich so frei bekommen, die BlitzLED läßt sich so wie beschrieben nutzen.
damit braucht man nur GPOI15,GPIO14 und GPio 2.
GPIO12 und GPIO13 lassen sich aber nicht für den zweiten I2C-Bus nutzen, da der I2C-Bus wegen der Pullups auch beim Start immer high ist.

sdmmc_host_t host = SDMMC_HOST_DEFAULT();
host.flags = SDMMC_HOST_FLAG_1BIT;
host.max_freq_khz = SDMMC_FREQ_HIGHSPEED; // Added 2020_10_06
sdmmc_slot_config_t slot_config = SDMMC_SLOT_CONFIG_DEFAULT();
slot_config.width = 1; //Added 2020_10_06

Meine früheren Erfahrungen auf einer anderen Maschine mit einer guten git-Konfiguration waren nicht so prickelnd.
Da muss ich erst viel Arbeit reinstecken, muss aber wohl sein

Deshalb erst mal ein paar Erfahrungen:

Ich habe eine Reihe von Test gemacht und dabei ESP Heap, Min Free Heap und largest block on Heap untersucht.
Das scheint ziemlich stabil zu sein ud sieht nicht nach zu wenig Platz aus.
Trotzdem fliege ich immer wieder raus, z.B so

0x401f8852: flatbuffers::Vector const* flatbuffers::Table::GetPointer const*>(unsigned short) at G:\aktuelle_ESP-Projekte_2019\Platformio_2020\AI-on-the-edge-device-rolling_2020_09_25\code/lib\tfmicro\tensorflow\lite\micro/micro_interpreter.cc line 163
: (inlined by) flatbuffers::Vector const* flatbuffers::Table::GetPointer const*>(unsigned short) const at G:\aktuelle_ESP-Projekte_2019\Platformio_2020\AI-on-the-edge-device-rolling_2020_09_25\code/lib/tfmicro/flatbuffers/flatbuffers.h line 2446
: (inlined by) tflite::SubGraph::outputs() const at G:\aktuelle_ESP-Projekte_2019\Platformio_2020\AI-on-the-edge-device-rolling_2020_09_25\code/lib/tfmicro/tensorflow/lite/schema/schema_generated.h line 10300
: (inlined by) tflite::MicroInterpreter::outputs_size() const at G:\aktuelle_ESP-Projekte_2019\Platformio_2020\AI-on-the-edge-device-rolling_2020_09_25\code/lib\tfmicro\tensorflow\lite\micro/micro_interpreter.h line 115
: (inlined by) tflite::MicroInterpreter::output(unsigned int) at G:\aktuelle_ESP-Projekte_2019\Platformio_2020\AI-on-the-edge-device-rolling_2020_09_25\code/lib\tfmicro\tensorflow\lite\micro/micro_interpreter.cc line 272
0x401c2261: CTfLiteClass::GetClassFromImage(std::__cxx11::basic_string , std::allocator >) at G:\aktuelle_ESP-Projekte_2019\Platformio_2020\AI-on-the-edge-device-rolling_2020_09_25\code/lib\jomjol_tfliteclass/CTfLiteClass.cpp line 27
0x4010154d: ZNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEE12_Alloc_hiderC4EPcOS3 at c:\users\vkdevel10.platformio\packages\toolchain-xtensa32\xtensa-esp32-elf\include\c++\8.2.0\bits/basic_string.h line 149
: (inlined by) ZNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEC4ERKS4 at c:\users\vkdevel10.platformio\packages\toolchain-xtensa32\xtensa-esp32-elf\include\c++\8.2.0\bits/basic_string.h line 439
: (inlined by) ClassFlowAnalog::doNeuralNetwork(std::__cxx11::basic_string , std::allocator >) at G:\aktuelle_ESP-Projekte_2019\Platformio_2020\AI-on-the-edge-device-rolling_2020_09_25\code/lib\jomjol_flowcontroll/ClassFlowAnalog.cpp line 251
0x40102432: ClassFlowAnalog::doFlow(std::__cxx11::basic_string , std::allocator >) at G:\aktuelle_ESP-Projekte_2019\Platformio_2020\AI-on-the-edge-device-rolling_2020_09_25\code/lib\jomjol_flowcontroll/ClassFlowAnalog.cpp line 148
0x400f76dd: std::vector >::operator[](unsigned int) at c:\users\vkdevel10.platformio\packages\toolchain-xtensa32\xtensa-esp32-elf\include\c++\8.2.0\bits/stl_vector.h line 933
: (inlined by) ClassFlowControll::doFlow(std::__cxx11::basic_string , std::allocator >) at G:\aktuelle_ESP-Projekte_2019\Platformio_2020\AI-on-the-edge-device-rolling_2020_09_25\code/lib\jomjol_flowcontroll/ClassFlowControll.cpp line 163
0x400d501f: doflow() at G:\aktuelle_ESP-Projekte_2019\Platformio_2020\AI-on-the-edge-device-rolling_2020_09_25\code/src/server_tflite.cpp line 85
0x400d8751: task_autodoFlow(void*) at G:\aktuelle_ESP-Projekte_2019\Platformio_2020\AI-on-the-edge-device-rolling_2020_09_25\code/src/server_tflite.cpp line 523 (discriminator 8)
0x40093bdd: vPortTaskWrapper at C:\users\vkdevel10.platformio\packages\framework-espidf\components\freertos/port.c line 436

Mir sind fünf Dinge in CTfLineClass aufgefallen:

1. OwnMicroErrorReporter::Report tut nichts ausser true zurückliefern
2. CTfLiteClass::Invoke() ist void , aber interpreter->Invoke(); liefert einen TfLiteStatus zurück
   Da könnte ein kTfLiteError zurückgeliefert werden.
   Ansonsten scheint der Heap vor Invoke und nach Invoke konstant zu sein wenn alles gut geht

2020-11-02_20-58-10: CTfLiteClass::Invoke Start Free Heap Size: 2607316 Min Free Heap Size: 894004 largest Block Size: 2590704
2020-11-02_20-58-13: CTfLiteClass::Invoke Done Free Heap Size: 2607316 Min Free Heap Size: 894004 largest Block Size: 2590704

2.1
CTfLiteClass::GetClassFromImage
Was passiert, wenn Invoke() mit einem Fehler zurückkehrt, anschließen GetOiutClassification() aufgerufen wird, die auf
TfLiteTensor* output2 = interpreter->output(0); zugreift, Hier testest Du auf output2 == NULL

2.2 ClassFlowAnalog:
:: doNeuralNetwork
tflite->Invoke();
f1 = tflite->GetOutputValue(0);
darin TfLiteTensor* output2 = this->interpreter->output(0); da wird nicht auf NULL getestet

3. Beim obigen Crash geht möglicherweise in ClassFlowAnalog::doNeuralNetwork() bei tflite->MakeAllocate() etwas schief,
   Siehe Zeile 175 , wenn nicht kTfLiteOk dann soll der error_reporter was sagen , der tut aber nichts, siehe (1)
   das könnte den Fehler in LoadInputImage erklären , das kommt zwar sehr selten vor,
   Könnte dann input_data_ptr ein NullPointer sein oder der Block dahinter nicht die richtige Größe haben?

4. Wenn im Browser einmal die Startseite aufgebaut ist, werden in 5 Min Abstand Werte aktualisiert indem neben anderem der Webserver /setPrevvalue.html liefern soll.
   Das geht immer gut, wenn zu diesem Zeitpunkt kein Flow läuft. Manchmal kracht es dann aber und eine GURU Panic ist fällig nebst anschließendem reboot. Man kann das gut nach mehreren Durchläufen beobachten, da die beiden Prozesse nicht syncronisiert sein können, kommt es nach einiger Zeit zu zu einer /setPrevvalue.html Anforderung mitten in einem laufenden invoke(). Das führt regelmäßig zu einer GURU Panic

5. Dann gibt es noch das Problem mit dem Watchdog

␛[0;31mE (4741240) task_wdt: Task watchdog got triggered. The following tasks did not reset the watchdog in time:␛[0m
␛[0;31mE (4741240) task_wdt: - IDLE0 (CPU 0)␛[0m
␛[0;31mE (4741240) task_wdt: Tasks currently running:␛[0m
␛[0;31mE (4741240) task_wdt: CPU 0: task_autodoFlow␛[0m
␛[0;31mE (4741240) task_wdt: CPU 1: IDLE1␛[0m

Damit kenne ich mich aber nicht aus, insbesondere nicht was das Zurücksetzen des Watchdogs über esp_task_wdt_reset() anrichten würde.

P.S meine Tastatur hat machmal so ihre Macken und produziert Schreibfehler, die findet man beim Nachlesen nicht immer alle.
Gruß Hike

[jomjol]

Die CTFLiteClass ist im wesentlichen ein Wrapper für die Google Tensorflow Lite Bibliothek. Da bin ich ehrlich gesagt froh, dass es so läuft, wie es tut. Ich müsste mal prüfen, ob Google dort vielleicht eine neue Version rausgebracht hat, die einige Bugs beseitigt.
Das ist auch noch kein wirklich stabiler Code ich musste dort in den Tiefen u.a. Array vergrößert etc. damit die recht großen CNNs überhaupt verarbeitbar waren.

zu 1) Daher auch der Dummy OwnMicroErrorReporter. Dort liefert die Bibliothek jede Menge Output, die die serielle Schnittstelle sehr schnell füllt.

zu 5) Dieser Watchdog kommt daher, dass die Berechnung des neuronalen Netzes sehr lange braucht und in den verwendeten Bibliotheken (Tensorflow/Lite) kein Reset des Watchdogs vorkommt. Er kommt dort schlicht nicht aus der Schleife raus.

[hike6688]

Hallo, ich habe master geforked.
Bei der Compilation gibt es einen Fehler: esp_mqtt_event_id_t esp_mmqtt_ID = MQTT_EVENT_ANY;
MQTT_EVENT_ANY not defined.
Auch in dem enum taucht das nicht auf.

[jomjol]

Ich kann den Fehler nicht nachvollziehen. Habe es gerade mit einem Clean und dann einen Build laufen lassen. Compiliert ohne Fehler - sehe nur die üblichen Warnungen.

[hike6688]

Hallo Jomjol,
kann es sein dass dein framwork-espidf eine andere Version von mqtt.client.h verwendet bzw die esp-mqtt verschieden ist?
Das Datum bei mir steht auf 22.08.2020

[jomjol]

Hi Hike,

ich kompiliere mit framework-espidf 3.4 - das ist die aktuelle. Weitere Details:

Platform Manager

Platform espressif32

Updating platformio/espressif32 2.0.0 [Up-to-date]
Updating platformio/toolchain-xtensa32 2.50200.80 @ ~2.50200.0 [Up-to-date]
Updating platformio/toolchain-esp32ulp 1.22851.191205 @ ~1.22851.0 [Up-to-date]
Updating platformio/framework-arduinoespressif32 3.10004.201016 @ ~3.10004.191002 [Up-to-date]
Updating platformio/framework-espidf 3.40100.200827 @ ~3.40100.0 [Up-to-date]
Updating platformio/tool-esptoolpy 1.20600.0 @ ~1.20600.0 [Up-to-date]
Updating platformio/tool-mkspiffs 2.230.0 @ ~2.230.0 [Up-to-date]
Updating platformio/tool-cmake 3.16.4 @ ~3.16.0 [Up-to-date]
Updating platformio/tool-ninja 1.9.0 @ ^1.7.0 [Up-to-date]
Updating platformio/tool-mconf 1.4060000.20190628 @ ~1.4060000.0 [Up-to-date]
Updating platformio/tool-idf 1.0.1 @ ~1.0.1 [Up-to-date]

[hike6688]

Da gibt es Probleme und Unterschiede:
Der Reihe nach:
Wenn ich den alten Code in dem alten Rolling-code vom 25.9.2020 mit Open Folder öffne
und von der powershell console pio aufrufe erhalte ich:
pio update --dry-run liefert bei mir
...
Checking platformio/framework-espidf 3.40001.200521 @ ~3.40001.0 [Up-to-date]
Checking platformio/tool-esptoolpy 1.20600.0 @ ~1.20600.0 [Up-to-date]
Checking platformio/tool-mkspiffs 2.230.0 @ ~2.230.0 [Up-to-date]
Checking platformio/tool-cmake 3.16.4 @ ~3.16.0 [Up-to-date]
Checking platformio/tool-ninja 1.9.0 @ ^1.7.0 [Up-to-date]
Checking platformio/tool-mconf 1.4060000.20190628 @ ~1.4060000.0 [Up-to-date]
Checking platformio/tool-idf 1.0.1 @ ~1.0.1 [Up-to-date]

Offensichtlich habe ich eine andere framework-espidf , die aber trotzdem als [up-to-date] ausgewiesen wird.
Diese Version von Code übersetzt und erzeugt ein flashbares binary und flasht es auch
Das ist das erste Problem.

In dem neuen Code ( master vom 3.11.2020, geforked ) scheitert die Übersetzung mit dem obigen fehler esp_mqtt_event_id_t esp_mmqtt_ID = MQTT_EVENT_ANY;

Versuche ich von da pio -h aufzurufen, bekomme ich beim Aufruf von pio -h aus der Powershell die Fehlermeldung:
pio : Die Benennung "pio" wurde nicht als Name eines Cmdlet, einer Funktion, einer Skriptdatei oder eines ausführbaren Programms erkannt. Überprüfen Sie die Schreibweise des
Namens, oder ob der Pfad korrekt ist (sofern enthalten), und wiederholen Sie den Vorgang.
In Zeile:1 Zeichen:1

• pio -h

•   + CategoryInfo          : ObjectNotFound: (pio:String) [], CommandNotFoundException  
    + FullyQualifiedErrorId : CommandNotFoundException
  
  

Ich komme da nicht weiter, will mir aber auch nicht die funktionierende Umgebung vom 25.9 zerschiessen.

Außerdem werden ein paar changes notifiziert in sdkconfig , version.cpp , version.cpp src
Offensichtlich gibt es Änderungen bei den git referenzen ( Muss vermutlich so sein, da ich mein Repository benutze)

Ich habe PlatformIO nochmal auf einem neuen Benutzer neu von Grund auf aufgesetzt. Um die Installation zu testen, habe ich ein neues Testprojekt mit der idf gebaut und den ersten Teil vom main (InstallNVS..) eingebaut. Die IDF hat jetzt Rev 2.0.0
Compiliert, flashest und läuft.
Versuch ich dann #include gibt es Fehler.
Wenn man #include <st tippt., erhält man einen Verweis auf eine Datei:
C:\Users\espdevel.platformio\packages\toolchain-xtensa32\xtensa-esp32-elf\include\c++\8.2.0\string

Dieser Pfad existiert nicht, zwischen espdevel und .platformio müsste ein \ stehen.
Das ist wohl der Fehler. Lösung ????

[jomjol]

Da hatte ich noch nie. Pfadprobleme kenne ich weder aus der Win 10, noch aus der Ubuntu Umgebung. Da hilft nur googeln.

[stan23]

Hallo,
angespornt durch diesen Thread habe ich auch versucht das Projekt zu bauen.
Nach anfänglichen Problemen (Space und Umlaut im Pfad) klappt es (Windows 10)

PACKAGES:
 - framework-espidf 3.40100.200827 (4.1.0)
 - tool-cmake 3.16.4
 - tool-esptoolpy 1.20600.0 (2.6.0)
 - tool-idf 1.0.1
 - tool-mconf 1.4060000.20190628 (406.0.0) 
 - tool-ninja 1.9.0
 - toolchain-esp32ulp 1.22851.191205 (2.28.51)
 - toolchain-xtensa32 2.80200.200827 (8.2.0)

[hike6688]

Hallo stan23,
sehr interessant.
Wie hast Du die obige Information erzeugt? Bei der alten Version konnte ich aus dem Terminal und der powershell mit pio update --dry-run liefert wie oben beschrieben eine Übersicht erzeugen. In der neuen Version bekoome ich die commandnotFound exception.
Ich sehe im Augenblick nicht, wie ich an diese package Infomation bekomme.

Ich habe was gefunden : Über das graphische PIO Home -->Platforms -->installed Espressive32
-->Packages
dort als vorletzen Eintrag:

toolchain-xtensa32 | toolchain |   | ~2.50200.0 | 2.50200.80 (5.2.0)

alle anderen Einträge haben dieselbe Versionnummer wie bei Dir
z.B.

toolchain-esp32ulp | toolchain |   | ~1.22851.0 | 1.22851.191205 (2.28.51)

[stan23]

Hi,
die Übersicht kommt wenn ich einen Build starte.

[hike6688]

Danke,

bei wir steht jetzt auch
PACKAGES:

• framework-espidf 3.40100.200827 (4.1.0)
• tool-cmake 3.16.4
• tool-esptoolpy 1.20600.0 (2.6.0)
• tool-idf 1.0.1
• tool-mconf 1.4060000.20190628 (406.0.0)
• tool-mkspiffs 2.230.0 (2.30)
• tool-ninja 1.9.0
• toolchain-esp32ulp 1.22851.191205 (2.28.51)
• toolchain-xtensa32 2.80200.200827 (8.2.0)

[hike6688]

Kannst Du über PIO-Home ein neues Projekt bauen mit

platformio.ini
[env:esp32cam]
platform = espressif32
board = esp32cam
framework = espidf
monitor_speed = 115200
board_build.partitions = partition.csv (aus dem ai-projekt)

und main.c
#include "freertos/FreeRTOS.h"
#include "freertos/task.h"
#include "freertos/event_groups.h"
#include "sdkconfig.h"

#include "esp_err.h"
#include "esp_log.h"

static const char *TAGMAIN = "main";
void test() {
ESP_LOGI(TAGMAIN, "test");
}

void app_main() {
test();
}

Das sollte problemlos übersetzt werden

Versuche anschlließend mal
#include <str einzufügen dann sollte daneben ein Kasten aufgehen mit string
rechts hinter dem ersten Eintrag öffnet sich dann ein weiterer Kasten. Was steht da bei dir drin?
Bei mir C:\Users\espdevel.platformio\packages\toolchain-xtensa32\xtensa-esp32-elf\include\c++\8.2.0\string
Da fehlt bei mir ein Backslash vor dem Punkt bei .platformio

[stan23]

C:\Users\marco.platformio ...

Der Backslash fehlt bei mir auch,aber macht das was aus?
Wenn ich den Cursor auf den vollen Dateinamen <str.h> setze und F12 drücke, dann öffnet PIO trotzden die Datei.
Und der Compiler scheint sie auch zu finden.

[hike6688]

Nach mehrfachen Hin und Her zwischen den Benutzerkonten sind die Pfadprobleme bei espdevel auf einmal wie weggeflogen.
In main.cpp waren alle includes unterschlängelt und ein Zufriff auf die source , z.B. bei esp_err_t mit F12 oder rechter Maustaste war nicht möglich. Außerdem hatte ich trotz erfolgreichem Build (-->success) eine lange Latte von Fehlern (Quelle nicht gefunden .. ) unter problems.
Die einzige Änderung die ich erkennen kann ist dass .vscode/c_cpp_properties.json vorher so gut wie leer war, jetzt aber sowohl unter "path" und "includePath" haufenweise Referenzen stehen, die man so erwartet. Da das ein autogeneriertes file ist, muss wohl vorher was schiefgegangen sein.
Was mich so irritiert hatte, dass der Compiler alles findet, aber die Verweise im Editor/onTheFlyCheck Fehler ausgeworfen haben
Schlussfolgerung: Meine Maschine wollte mich wohl ärgern.
Nochmal vielen Dank für die Rückmeldungen

Problem gelöst
Das Problem lag wahrscheinlich an der verzögerten Erstellung der Datei .vscode/c_cpp-properties.json.
Die wird im Hintergrund erzeugt und sorgt augenscheinlich dafür das bei den inkrementellen Check im Editor die include-Pfade bekannt sind. Das würde auch erklären, wieso der Übersetzungsprozeß über build ohne Fehler durchgelaufen ist.

[hike6688]

Hallo Jomol,
ich habe einige Ergänzungen zum Loggen des Heaps eingebaut und einige längere Tests gefahren.
Für die Tests wird dein ursprungliches /config/reference.pg anstelle eines neuen Bildes nach img_tmp/raw.jpg kopiert. Dafür gibt es den neuen Parameter Testdevice = True im Paragraph [Debug].
Außerdem kann die maximals Größe des Logfiles gesetzt werden.

[Debug]
Logfile = True
LogFileMaxSize = 100000
Testdevice = True

Das alte logfile wird dann nach /log/oldlogs/log_date_time.log kopiert.
Zusätzlich wird jetzt nach jeder Runde die veränderung des Heaps nach heap/diff-log.txt geschrieben.

heap_diff_log.txt

Auf meinem Testdevice bekomme ich regelmäßig nach 43 Runden einen Reboot.
Das erste Mal in log mit 199 Runden lag daran, dass die Kamera nicht erkannt wurde und somit auch kein Buffer alloziert wurde.
199 Runden

2020-11-11_22-18-57: Round: 1 Heap diff this round: 1136 Heap diff from task start: 1164
2020-11-11_22-18-57: Round: 1 Free Heap Size: 3239252 Min Free Heap Size: 897640 largest Block Size: 3207328 ......
2020-11-12_08-11-13: Round: 199 Heap diff this round: 336 Heap diff from task start: 68224
2020-11-12_08-11-13: Round: 199 Free Heap Size: 4189216 Min Free Heap Size: 1859980 largest Block Size: 4167332
2020-11-12_08-15-29: Round: 1 Heap diff this round: 940 Heap diff from task start: 972

43 Runden

2020-11-12_08-15-29: Round: 1 Heap diff this round: 940 Heap diff from task start: 972
2020-11-12_08-15-29: Round: 1 Free Heap Size: 3239452 Min Free Heap Size: 898788 largest Block Size: 3207328 ....
2020-11-12_10-15-15: Round: 43 Heap diff this round: 348 Heap diff from task start: 15276
2020-11-12_10-15-15: Round: 43 Free Heap Size: 3225148 Min Free Heap Size: 895764 largest Block Size: 3207328

43 Runden

2020-11-12_10-19-37: Round: 1 Heap diff this round: 760 Heap diff from task start: 792
2020-11-12_10-19-37: Round: 1 Free Heap Size: 3239620 Min Free Heap Size: 898784 largest Block Size: 3207328 ...
2020-11-12_12-19-21: Round: 43 Heap diff this round: 344 Heap diff from task start: 15432
2020-11-12_12-19-21: Round: 43 Free Heap Size: 3224980 Min Free Heap Size: 895724 largest Block Size: 3207328

Dabei kann man sehen, wie die Differenz zur 1. Runde immer anwächst, bis es irgenwann zu einer GURU panic und einem Neustart kommt.
Die Differenz scheint bei ~ 15300 -15400 zu liegen.
Die Heap Differenz bei einer Runde zur nächsten ist meistens 330 - 340 Byte.

Könnte es sein, das das Ergebnis für die alte Runde nicht richtig freigegeben wird?

Es scheint auch mehrere Heaps zu geben, leider habe ich bisher noch nicht rausgefunden wie man die unterscheiden kann. Die Größe spricht dafür, dass RAM und PSRAM zusammen gezählt werden, insbesondere die Größe wenn der Kamerabuffer nicht initialisiert wurde. Auch ändert sich largest Block size die ganze Zeit nicht.

[jomjol]

Super Ergebnisse und eine heiße Spur. Kannst ich deinen Code irgendwo runter laden oder kannst du ihn als eigenen "Branch" hier zur Verfügung stellen? Ich habe ein paar Ideen, wie ich schnell eingrenzen kann, wo die 340k allokiert werden.

[hike6688]

Der Code liegt unter hike6688 auf github im Branch find-reboots.
Es sieht so aus, als würde bei jedem FlowDigit 168 Bytes und bei FlowAnalog 164 Bytes verbraucht werden.
Irgendwo dazwischen verschwinden noch mal ein paar Bytes.
Das Ganze spielt sich im Internal Heap ab. Der hat anfangs nur 32660 Bytes Der SPI-Ram Heap ( 3207328 Bytes ) bleibt die ganze Zeit unverändert.
Ich vermute, das die Bytes in den Ergebnissen verschwinden und der ROI-Vektor nicht richtig aufgeräumt wird.
Die zusammengefassten Ergebnisse werden nach /sdcard/heap_diff_log.txt geschrieben.
In TFLIte, FlowDigit und FlowAnalog stehen oben im File flags debugdetail....

Ich hab etwas länger gebraucht um den Trick mit dem Auslesen des Internen Heaps zu finden. Siehe Helper.cpp
Da muss ich den Code noch aufräumen..
Sollten negative Werte bei Heap diff auftreten scheint das daran zu liegen dass parallel dazu der Webserver das Protokoll ausgeliefert hat.

[jomjol]

Vielen Dank - habe es gerade runtergeladen und auf mein Testdevice gespielt. Hatte gestern nach deinem Hinweis mit den 340B auch mal schnell meinen Code gescreent und den ROI-Vector im Verdacht, obwohl ich dort eigentlich ein delete verwende. Vielleicht muss ich bei der Vector Konstruktion noch irgendetwas beachten. Ich lasse es jetzt mal den Tag laufen und schaue mir das am WE an.

[hike6688]

Ohne den Code genauer zu kennen: Mir fällt auf, dass in CTFliteClass ein expliziter Destruktor implementiiert ist , in verschieden anderen Klassen aber nicht,

Es ist übrigens sehr interesant zu sehen wieviel internen Heap die Kamera und der Webserver beansprucht. Manchmal geht die Initialisierung der Kamera schief

␛[0;31mE (17419) server_part_camera: Camera Init Failed␛[0m ...
␛[0;32mI (19729) LogFile: task_autodoFlow before flow Heap: 4257432 Min Free: 4252300 larg. Block: 4167332 SPI Heap: 4167332 NOT_SPI Heap: 90100 Internal Heap: 90100 Internal Min Heap free: 84968␛[0m

Dann startet das Ganze mit 90100 Bytes anstelle von 32676 Bytes internal heap.
Vielleicht kann man die Kamera ja überreden auf den SPI-Heap zu gehen

[hike6688]

Ich glaube etwas gefunden zu haben in ClassFlowAnalog:

Anscheinend gibt es ein Problem beim Aufräumen von TFLite

2020-11-13_17-32-53: FlowControll.doFlow - ClassFlowAnalog
2020-11-13_17-32-53: ClassFlowAnalog::doFlow Heap Internal at Start: 31524
2020-11-13_17-33-00: ClassFlowAnalog::doFlow Heap Internal after Align: 31524
2020-11-13_17-33-00: FlowAnalog::doNeuralNetwork at Start internal heap: 31464
2020-11-13_17-33-00: FlowAnalog::doNeuralNetwork after create TFLite internal heap: 31416 diff_1: 48
2020-11-13_17-33-00: FlowAnalog::doNeuralNetwork after Load Model internal heap: 31372 diff_2: 92
2020-11-13_17-33-00: FlowAnalog::doNeuralNetwork after MakeAllocate internal heap: 31212 diff_3: 252
2020-11-13_17-33-00: in loop Analog 0 - TfLite internal heap: 31212
2020-11-13_17-33-03: Result sin, cos: 0.966814, -0.261991 internal heap: 31220
2020-11-13_17-33-03: Result sin, cos, ziffer: 0.966814, -0.261991, 0.292117
2020-11-13_17-33-03: ROI 0 Result 2.921170 HeapSize Diff: -8
2020-11-13_17-33-03: in loop Analog 1 - TfLite internal heap: 31220
2020-11-13_17-33-06: Result sin, cos: 0.686627, 0.729445 internal heap: 31220
2020-11-13_17-33-06: Result sin, cos, ziffer: 0.686627, 0.729445, 0.120189
2020-11-13_17-33-06: ROI 1 Result 1.201891 HeapSize Diff: 0
2020-11-13_17-33-06: in loop Analog 2 - TfLite internal heap: 31220
2020-11-13_17-33-10: Result sin, cos: 0.726583, -0.689562 internal heap: 31220
2020-11-13_17-33-10: Result sin, cos, ziffer: 0.726583, -0.689562, 0.370840
2020-11-13_17-33-10: ROI 2 Result 3.708403 HeapSize Diff: 0
2020-11-13_17-33-10: in loop Analog 3 - TfLite internal heap: 31220
2020-11-13_17-33-13: Result sin, cos: -0.499976, 0.864356 internal heap: 31220
2020-11-13_17-33-13: Result sin, cos, ziffer: -0.499976, 0.864356, 0.916537
2020-11-13_17-33-13: ROI 3 Result 9.165369 HeapSize Diff: 0
2020-11-13_17-33-13: FlowAnalog::doNeuralNetwork before delete TFLite internal heap: 31220 diff_4 244
2020-11-13_17-33-13: FlowAnalog::doNeuralNetwork after delete TFLite internal heap: 31268 diff_5 196
2020-11-13_17-33-13: FlowAnalog::doNeuralNetwork at end internal at start: 31464 at end : 31268 diff: 196
2020-11-13_17-33-13: ClassFlowAnalog::doFlow Heap Internal at Start: 31524 after align: 31524 at end: 31364 diff: 160

TFLite alloziert 48 Bytes Speicher:

2020-11-13_17-33-00: FlowAnalog::doNeuralNetwork after create TFLite internal heap: 31416 diff_1: 48
Beim Aufräumen werden auch 48 Bytes freigegeben , das ist die Differenz von 244 und 196.

2020-11-13_17-33-13: FlowAnalog::doNeuralNetwork before delete TFLite internal heap: 31220 diff_4 244
2020-11-13_17-33-13: FlowAnalog::doNeuralNetwork after delete TFLite internal heap: 31268 diff_5 196

aber ein Teil des Heapverbrauchs bei LoadModell und MakeAllocate wird nicht freigegben.
LoadModel verbraucht 92-48 = 44 bytes. makeAllocate 252 - 92 = 160.
Das sind genau die 160 Byte die in doFlow fehlen.

2020-11-13_17-33-13: ClassFlowAnalog::doFlow Heap Internal at Start: 31524 after align: 31524 at end: 31364 diff: 160

Da sieht für mich so aus, als würde der von LoadModell verbrauchte Heap freigegeben, aber der vom MakeAllocate nicht.

Die Zahlen sind nicht bei jedem Durchlauf identisch, aber sehr änlich.

Mal sehen, worans jetzt wirklich liegt, sollte auch ähnlich in FlowDigit sein

Die Tensor_arenea wird auf dem SPI-Heap angelegt und auch wieder freigegeben

this->kTensorArenaSize = 600 * 1024;
this->tensor_arena = new uint8_t[kTensorArenaSize];

Verdacht: this->interpreter = new tflite::MicroInterpreter(this->model, resolver, this->tensor_arena, this->kTensorArenaSize, this->error_reporter);

Ich finde kein delete this->interpreter

in LoadModel wird this->model über einen Funktionsaufruf gefüllt, für das CharArray gibt es malloc und free

[jomjol]

Wo genau hast du das denn gefunden. Das habe ich letzte Woche in der Rolling upgedated. Wann hast du sie den gezogen?
Sollen wir vielleicht mal kurz dazu skypen?

[hike6688]

Ein Fehler liegt hier:

CTfLiteClass::~CTfLiteClass()
{
delete this->tensor_arena;
delete this->interpreter; // neu
}

Dann wird der Heapverbrauch deutlich kleiner (von 320 byte auf 24 Byte)

2020-11-13_18-36-02: before auto_isrunning: Heap: 3240360 Min Free: 3235868 larg. Block: 3207328 SPI Heap: 3207328 NOT_SPI Heap: 33032 Internal Heap: 33032 Internal Min Heap free: 28540
2020-11-13_18-37-21: Round: 1 Heap diff this round: 764 Heap diff from task start: 796
2020-11-13_18-37-21: Round: 1 Heap: 3239628 Min Free: 898564 larg. Block: 3207328 SPI Heap: 3207328 NOT_SPI Heap: 32300 Internal Heap: 32300 Internal Min Heap free: 13772
2020-11-13_18-40-12: Round: 2 Heap diff this round: 0 Heap diff from task start: 1192
2020-11-13_18-40-12: Round: 2 Heap: 3239232 Min Free: 896864 larg. Block: 3207328 SPI Heap: 3207328 NOT_SPI Heap: 31904 Internal Heap: 31904 Internal Min Heap free: 12072
2020-11-13_18-43-03: Round: 3 Heap diff this round: -4 Heap diff from task start: 1188
2020-11-13_18-43-03: Round: 3 Heap: 3239236 Min Free: 896864 larg. Block: 3207328 SPI Heap: 3207328 NOT_SPI Heap: 31908 Internal Heap: 31908 Internal Min Heap free: 12072
2020-11-13_18-45-54: Round: 4 Heap diff this round: 24 Heap diff from task start: 1212
2020-11-13_18-45-54: Round: 4 Heap: 3239212 Min Free: 896864 larg. Block: 3207328 SPI Heap: 3207328 NOT_SPI Heap: 31884 Internal Heap: 31884 Internal Min Heap free: 12072
2020-11-13_18-48-45: Round: 5 Heap diff this round: 12 Heap diff from task start: 1224
2020-11-13_18-48-45: Round: 5 Heap: 3239200 Min Free: 896864 larg. Block: 3207328 SPI Heap: 3207328 NOT_SPI Heap: 31872 Internal Heap: 31872 Internal Min Heap free: 12072
2020-11-13_18-51-36: Round: 6 Heap diff this round: 24 Heap diff from task start: 1248
2020-11-13_18-51-36: Round: 6 Heap: 3239176 Min Free: 896864 larg. Block: 3207328 SPI Heap: 3207328 NOT_SPI Heap: 31848 Internal Heap: 31848 Internal Min Heap free: 12072

Warum bei der ersten und zweiten Runde noch Heapverbraucht wird habe ich noch nicht untersucht.

Ich mache gleich ein push auf github
ich habe mit find-reboot gearbeitet

[jomjol]

Vielleicht sind die verbliebenen 24 Byte im error_reporter. Dort gibt es auch kein delete. Wenn du dort noch folgendes ergänzt:

delete this->error_reporter;

Vielleicht haben wir es dann.

[hike6688]

was ist mit dem static tflite::AllOpsResolver resolver; in MakeAllocate?
Ich sehe zwar die Anforderung im Prototype, gebe aber gerne zu das ich die static Konstruktion in einer methode nicht verstehe.

da wir jetzt wissen das das ein Problem des schwindenden internal heap ist, könnte man ja auch organisiert nach einiger zeit rebooten. Die Grenze liegt irgendwo bei mir bei 17000 -18000 free internal heap.

Überschlägig sollte das für 500 Runden , also etwa 2 Tage reichen.

[jomjol]

Gute Idee, ich habe jetzt noch delete this->error_reporter; die geändert und jetzt teilweise tatsächlich eine Differenz von 0 bekommen:

2020-11-13_19-16-55: before auto_isrunning: Heap: 3228132 Min Free: 3227544 larg. Block: 3207328 SPI Heap: 3207328 NOT_SPI Heap: 20804 Internal Heap: 20804 Internal Min Heap free: 20216
2020-11-13_19-17-54: Round: 1 Heap diff this round: 772 Heap diff from task start: 324
2020-11-13_19-17-54: Round: 1 Heap: 3227872 Min Free: 889496 larg. Block: 3207328 SPI Heap: 3207328 NOT_SPI Heap: 20544 Internal Heap: 20544 Internal Min Heap free: 4704
2020-11-13_19-19-54: Round: 2 Heap diff this round: 0 Heap diff from task start: 572
2020-11-13_19-19-54: Round: 2 Heap: 3227624 Min Free: 889496 larg. Block: 3207328 SPI Heap: 3207328 NOT_SPI Heap: 20296 Internal Heap: 20296 Internal Min Heap free: 4704
2020-11-13_19-21-54: Round: 3 Heap diff this round: 0 Heap diff from task start: 572
2020-11-13_19-21-54: Round: 3 Heap: 3227624 Min Free: 889496 larg. Block: 3207328 SPI Heap: 3207328 NOT_SPI Heap: 20296 Internal Heap: 20296 Internal Min Heap free: 4704
2020-11-13_19-23-54: Round: 4 Heap diff this round: 8 Heap diff from task start: 1604
2020-11-13_19-23-54: Round: 4 Heap: 3226592 Min Free: 889496 larg. Block: 3207328 SPI Heap: 3207328 NOT_SPI Heap: 19264 Internal Heap: 19264 Internal Min Heap free: 4704

Zumindest in Runde 2 & 3.
Runde 4 hat dann 8 byte.

Echt super Verbesserung. Ich werde das jetzt mal in die Rolling implementieren. Dort hat jetzt zwerk2 auch noch eine rollierendes Löschen der Logfiles eingebaut, damit sollte die SD-Karte auch noch stabiler laufen.

[hike6688]

Bei mir wackelt die Zahl auch zwischen -4 , 0, 12, 16 20, 24 ist nach 21 Runden bei 16.
Was mich etwas wundert ist dein geringer internal min Heap mit 4704. ich liege meist bei 12072 aber auch stabil wie bei dir
ich lasse ihn jetzt erst mal laufen und schaue, ob es wieder seltsame Zwischenergebnisse gibt

[jomjol]

Hatte jetzt fast 48h keinen unverstandenen Reboot - außer bei intensiven Webzugriff.
Hat wirklich super geholfen. Ich dann im Laufe des Tages mal ein Master erzeugen.
Einverstanden, wenn wir den Issue erstmal schließen?

[jomjol]

s.o.