[gelöst] air-Q started regelmäßig neu

sscheib

Hallo zusammen,

Ich frage mittels Python Messwerte vom Air Q alle 1,5 Sekunden ab, um diese Daten dann zu einer Zabbix Instanz zu senden.
Ferner, monitore ich auch den Uptime-Status des Air Q und dieser startet sich in in unregelmäßigen Abständen neu; Ich schließe das aus dem Wert uptime
vom API-Endpoint /data.

Mein Air Q hat sich an folgenden Tagen neugestartet:

20.11.2022: 04:23:53
20.11.2022: 21:26:04
20.11.2022: 21:50:04
21.11.2022: 12:18:57
22.11.2022: 05:38:10
23.11.2022: 15:39:15
24.11.2022: 12:17:05

Es läst sich aufgrund der aufgetretenen Ereignisse kein Muster erkennen.
Im Log konnte ich einige Informationen finden:

2022-11-10T20:21:13+00:00 Error 1.80.0-rc4 WLANconnect Connecting to network failed - Type: OSError; Reason: the requested operation failed
2022-11-10T20:21:18+00:00 Error 1.80.0-rc4 WLANconnect Connecting to network failed - Type: OSError; Reason: the requested operation failed
2022-11-10T20:36:43+00:00 Error 1.79 writeSD Last run timestamp could not be read from SD card - Type: ; Reason: invalid syntax for integer with base 10
2022-11-10T20:36:54+00:00 Error 1.79 writeSD Last run timestamp could not be read from SD card - Type: ; Reason: invalid syntax for integer with base 10
2022-11-10T20:47:57+00:00 Error 1.79 writeSD Last run timestamp could not be read from SD card - Type: ; Reason: invalid syntax for integer with base 10
2022-11-10T20:48:10+00:00 Error 1.79 writeSD Last run timestamp could not be read from SD card - Type: ; Reason: invalid syntax for integer with base 10
2022-11-13T00:44:08+00:00 Error 1.79 sensors Sensors could not be read - Type: ; Reason: Status
2022-11-13T00:44:08+00:00 Error 1.79 sensors Sensor values could not be averaged - Type: ; Reason: timestamp; Traceback: None
2022-11-13T12:51:24+00:00 Error 1.79 main overwatch loop detected that the main loop timed out (POS:MQTT Cloud Upload, AWS MQTT POS: Find unsent data points): machine restarted
2022-11-17T17:42:54+00:00 Error 1.80.0 main main() loop detected that the overwatch loop timed out (POS: 6): machine restarted
2022-11-17T17:43:32+00:00 Error 1.80.0 WLANconnect Connecting to network failed - Type: OSError; Reason: the requested operation failed
2022-11-20T03:13:46+00:00 Error 1.80.0 main overwatch loop detected that the main loop timed out (POS:Cloud update device shadow): machine restarted
2022-11-20T20:50:17+00:00 Error 1.80.0 WLANconnect Connecting to network failed - Type: OSError; Reason: the requested operation failed
2022-11-21T06:46:00+00:00 Error 1.80.0 pressure Cannot read from pressure sensor - Type: TypeError; Reason: unsupported types for __add__: 'float', 'slice'
2022-11-22T04:38:08+00:00 Error 1.80.0 WLANconnect Connecting to network failed - Type: OSError; Reason: the requested operation failed
2022-11-22T22:43:33+00:00 Error 1.80.0 pressure Cannot read from pressure sensor - Type: TypeError; Reason: object of type 'slice' has no len()
2022-11-23T16:13:25+00:00 Error 1.80.0 pressure Cannot read from pressure sensor - Type: TypeError; Reason: object of type 'slice' has no len()
2022-11-24T06:42:40+00:00 Error 1.80.0 LTC2499 Reading ADC failed (POS:390) - Type: AttributeError; Reason: 'str' object has no attribute 'append'

Diese Daten korrelieren allerdings nicht mit den Neustarts des Gerätes. Mich macht schlicht stutzig, dass das Gerät so häufig neustartet - aus mir unersichtlichen Gründen.
Beispielsweise:

main overwatch loop detected that the main loop timed out (POS:MQTT Cloud Upload, AWS MQTT POS: Find unsent data points): machine restarted

Obige Fehlermeldung klingt für mich danach, dass das Gerät neugestartet wurde, weil ein Upload in the Cloud nicht möglich war. Warum sollte das Gerät dafür neustarten?

Mir stellen sich nun folgende Fragen:

Ist das so gewollt oder sind das schlicht noch Bugs in der Firmware?
Ist es relevant, ob der Air Q neustartet (außer, dass ich einige Messdaten verliere) - zum Beispiel im Bezug auf die Aufwärmphase der Sensoren?
Kann es sein, dass ich den Air Q "überlaste" indem ich alle 1,5 Sekunden die aktuellen Messwerte abfrage (würde für mich bei einem Scientific-Gerät keinen Sinn ergeben)?

Und eine Bitte: Wäre es möglich einen API Endpoint einzuführen, bei dem man die aktuellen Log-Daten auslesen kann oder ein Log-Forwarding (zB. an zentrale syslog-Server) zu implementieren?

Vielen Dank!

Viele Grüße
Steffen

Micha

Auch ich habe häufige Restarts bei meinem Air-Q, allerdings deutlich weniger; selten mehr wie einmal pro Woche.
Da ich nur alle 5 Minuten die Daten in einer Datenbank poste, fehlen mir höchstens 1-2 Werte. Aufwärmphasen und damit verbundene weitere Verluste an Daten kommen bei mir so gut wie gar nicht vor. Somit habe ich persönlich mit den Restarts kein wirkliches Problem.

Alle 1,5 Sek. die Daten abzufragen, halte ich für sportlich. Im Air-Q sitzt meines Wissens nach ein Mikrocontroller der ESP-Familie. Ich kann mir schon vorstellen, dass er da an ein Limit kommt. Was machst Du mit soviel Daten?

SD-Kartenfehler: Halte ich für kritisch. Prüfe doch mal die SD-Karte oder setze gleich eine Neue ein. Solche Fehler können sich auf der SD-Karte "aufschaukeln" bis gar nichts mehr geht.

WLANconnect Fehler: Das WLAN-Modul im ESP ist nicht besonders stark. Versuche Air-Q und WLAN-Router näher beieinander zu platzieren oder setze einen Repeater ein. Ist bei mir noch nie vorgekommen; allerdings ist bei mir der Abstand zwischen Router und Air-Q kleiner 3m.

main overwatch loop detected that the main loop timed out: Bei mir fast jedes Mal der letzte Eintrag vor dem Restart.

Sensors could not be read, Cannot read from pressure sensor: kam bei mir noch nie vor. Vielleicht deutet das auf ein Problem mit dem Sensor hin, aber das können sicher die Fachleute bei Corant besser beurteilen.

LTC2499 Reading ADC failed: Hatte ich auch noch nie. Sieht vom Text ein wenig nach einem Programmierfehler aus, aber auch das kann ich nicht wirklich beurteilen.

sscheib

Danke für deine Antwort, Micha!
Um auf deine Fragen und Bemerkungen einzugehen:

@Micha sagte in Air-Q started regelmäßig neu:

Alle 1,5 Sek. die Daten abzufragen, halte ich für sportlich. Im Air-Q sitzt meines Wissens nach ein Mikrocontroller der ESP-Familie. Ich kann mir schon vorstellen, dass er da an ein Limit kommt

Das wäre meiner Meinung nach nicht akzeptabel, wenn das Gerät keine Abfragen alle mindestens 1,8 Sekunden ab könnte, da ja effektiv damit geworben wird, dass der Air Q alle ~ 1,8 Sekunden misst; Hat man nun die Science Version, möchte man sicherlich diese Vielfalt an Daten auch abfragen und bewerten. Sonst nützt mir eine Messung alle 1,8 Sekunden recht wenig, wenn ich die Daten beispielsweise nur alle Minute abfrage.
Das ist meine persönliche Meinung und ich möchte hier auch niemanden angreifen, aber ich denke für knappe 700 Euro sollte das schon drin sein.

@Micha sagte in Air-Q started regelmäßig neu:

Was machst Du mit soviel Daten?

Mir geht es vorallem um die Lärm-Sensor Daten um eventuell auftretende kurze Lärm-Peaks zu isolieren. Bei allen anderen Werten stimme ich dir zu, die ändern sich nicht so häufig, dass sich ein Abfragen tatsächlich rentiert. Leider gibt es (meines Wissens nach) keinen API Endpoint, der mich speziell einen Sensor abfragen lässt, daher muss ich zwangsgedrungen alle Sensoren abfragen (über den API Endpoint) /data - wenn ich die Daten schonmal abgefragt habe, kann ich sie natürlich auch gleich vorhalten. 1,5 Sekunden deshalb, weil der Air Q alle 1,8 Sekunden eine Messung vornimmt (bzw. vornehmen sollte) und ich somit keinen Messpunkt verpasse (Verbindung zum Air Q muss ja aufgebaut werden und Daten abgefragt werden, sprich ich rechne eine Toleranz von 300ms ein).
In der Praxis schnellt der Wert measure_time manchmal (seltener) bis auf ~3 Sekunden hoch.
Natürlich könnte man über /file gehen und alle N Minuten die gesammelten Datenpunkte abfragen, aber dann hätte ich ja keine Live-Daten, sondern historische Werte. Die Frage bleibt natürlich offen, ob das tatsächlich die Last verringern würde, da schließlich die ganze Datei übertragen werden muss (die vermutlich schon verschlüsselt vorliegt).

@Micha sagte in Air-Q started regelmäßig neu:

WLANconnect Fehler

Luftlinie sind das bei mir von Access Point (AP) zu Air Q weniger als drei Meter. Was ich mir vorstellen könnte ist, dass der Air Q meinen anderen AP (der als Repeater dient) kontaktiert, was aber keinen Sinn machen würde, da das Signal deutlich schwächer ist. Da ich auch meine APs monitore und die Logs etwas durchforstet habe, kann ich das auch mit 99% Sicherheit ausschließen.

@Micha sagte in Air-Q started regelmäßig neu:

main overwatch loop detected that the main loop timed out

Gut, dann muss ich mir hier wohl keine Sorgen machen :)

@Micha sagte in Air-Q started regelmäßig neu:

SD-Kartenfehler: Halte ich für kritisch. Prüfe doch mal die SD-Karte oder setze gleich eine Neue ein.

Ich habe noch SD-Karten, die ich nutzen kann, allerdings habe ich keine Info gefunden

welche SD Karten supported sind (natürlich Micro SD, aber ggf. gibt es Hersteller, welche nicht [so gut] funktionieren, o.Ä.)
welches Dateisystem auf der SD-Karte zu verwenden ist oder ob der Air Q die Karte selbständig formatiert
wie ein Austausch vorzunehmen ist (muss ich dem Air Q vor dem Tausch irgendwie Bescheid geben, gibt es weitere Dinge zu beachten?)

Natürlich ist klar, dass die Daten auf der SD-Karte verloren gehen, wenn ich eine neue SD-Karte einsetze, da ich aber meine Daten sowieso extern (Zabbix) vorhalte, stört mich das überhaupt nicht.

Vielen Dank!

Viele Grüße
Steffen

Micha

Hallo @sscheib,
ob man eine Datenrate von 1,5 sek. braucht oder nicht hängt natürlich von individuellen Fragestellungen ab. Da ich hauptsächlich statistische Auswertungen fahren reichen mir alle 5 Min. sehr gut. Will man irgendetwas steuern oder wie Du exakte Peaks isolieren, braucht man natürlich engere Abfrageintervalle. Dazu wäre dann sicher ein API Endpoint pro Sensor sehr nützlich. Bei zumindest wenig größeren Intervallen könnte auch die Errorrate, die es für jeden Sensor gibt, eventuell weiterhelfen? Über /file zu gehen ist sicher keine Alternative.

Sollte tatsächlich, wie ich vermute, der Air-Q auf einem ESP-Mikrocontroller basieren, dann fällt mir noch ein Problem auf, mit dem ich in anderen ESP-Projekten manchmal zu kämpfen hatte. Der ESP kann auch "in die Knie gehen", wenn parallel mehrere Clients die Daten abfragen.
Gibt es bei Dir diese Situation? Wenn ja dann prüfe, ob diese Fehler auch auftreten, wenn nur ein Client ständig die Daten pollt.
Ich selbst nutze die Push-Funktion vom Air-Q und bringe damit die Daten auf einen MQTT-Broker und in eine Datenbank. Alle Clients holen sich dann die Daten vom Broker (oder von der DB), und kein Client pollt den Air-Q. Aber bei 1.5 Sek. Intervall ist das auch keine Alternative.

Noch zu :

Und eine Bitte: Wäre es möglich einen API Endpoint einzuführen, bei dem man die aktuellen Log-Daten auslesen kann oder ein Log-Forwarding (zB. an zentrale syslog-Server) zu implementieren?

Man kann bereits die aktuellen Logs abfragen. Siehe dazu auch https://forum.air-q.com/topic/127/logdatei-lesen-ohne-die-sd-karte-zu-entfernen?_=1669308772299

sscheib

@Micha sagte in Air-Q started regelmäßig neu:

Bei zumindest wenig größeren Intervallen könnte auch die Errorrate, die es für jeden Sensor gibt, eventuell weiterhelfen?

Stehe gerade auf dem Schlauch, inwiefern könnte das helfen?

@Micha sagte in Air-Q started regelmäßig neu:

Sollte tatsächlich, wie ich vermute, der Air-Q auf einem ESP-Mikrocontroller basieren, dann fällt mir noch ein Problem auf, mit dem ich in anderen ESP-Projekten manchmal zu kämpfen hatte. Der ESP kann auch "in die Knie gehen", wenn parallel mehrere Clients die Daten abfragen.
Gibt es bei Dir diese Situation?

Ich habe lediglich zusätzlich hin- und wieder die Air-Q Android App genutzt im Bezug auf einen Client der Daten abfrägt.
Allerdings habe ich bei Zabbix auch ein Ping-Template hinterlegt, welches alle 60 Sekunden einige Pings an den Air-Q sendet, zwecks Verfügbarkeitsprüfung, ICMP Loss, ICMP High Ping Prüfung. Diesen habe ich nun testweise mal deaktiviert.
Ich werde das weiterhin beobachten.

@Micha sagte in Air-Q started regelmäßig neu:

Man kann bereits die aktuellen Logs abfragen.

Das ist perfekt, Danke. Wusste gar nicht, dass es den API Endpoint /log gibt - aber das kann ich nun natürlich auch in den Zabbix packen :)

Micha

@sscheib sagte in Air-Q started regelmäßig neu:

@Micha sagte in Air-Q started regelmäßig neu:

Bei zumindest wenig größeren Intervallen könnte auch die Errorrate, die es für jeden Sensor gibt, eventuell weiterhelfen?

Stehe gerade auf dem Schlauch, inwiefern könnte das helfen?

Du pollst z.B. alle 5 Sek. Dann könnte es passieren, dass innerhalb eines 5 Sek.-Intervalls ein Peak liegt, den Du so nicht mitbekommst. Aber über die Errorrate erfährst Du, dass innerhalb dieses Intervalls ein Peak lag. Die Uhrzeit kennst Du dann allerdings nur +/- 5 Sek. Da sowieso alle Uhrzeiten nicht immer sekundengenau funktionieren, würde ich diese Unschärfe vernachlässigen.

Daniel [air-Q]

Hallo @sscheib und @Micha,
danke für den regen Austausch @Micha.
Bei dem Controller handelt es sich tatsächlich um einen ESP32. Dieser hat - wie sich leider herausgestellt hat - diverse Hardware-Bugs. Der Hersteller Espressif bringt immer neue Versionen des zugrundeliegenden Compilers heraus, die diese Bugs durch Software beseitigen (sollen). Mit jeder neuen Firmware setzen wir immer die neueste Version ein. Das hat auch schon zu stark verbesserte Stabilität geführt. Wir selbst bauen auch Workarounds in die air-Q Firmware ein, wenn wir eine Stelle identifizieren, die besonders anfällig ist. Daran ausgerichtet sind auch die Fehlermeldungen im Log. Sie sollen dazu dienen, solche Häufungen ausfindig zu machen. Es laufen mehrere Threads für unterschiedliche Tasks, die gegenseitig prüfen, ob sie noch laufen. Sollte ein Thread einfrieren, steht loop timed out im Log. Inzwischen ist der Stand aber so, dass keine Häufungen mehr an einer Stelle auftreten, sondern nur noch an zufällig Stellen.

Einige Fehler werden durch die Firmware abgefangen. Die stehen dann im Log. Hin und wieder kommt es aber auch zu einem Core-Dump des Controllers oder dessen komplettes Einfrieren. Diese Fehler stehen dann nicht im Error-Log - weil die Firmware hier nicht mehr greift - können aber durch Setzen des Konfigurationsschlüssels {"logging": "Warning"} indirekt aufgezeichnet werden, denn dann werden auch Neustarts ins Log eingetragen.

Fehler wie invalid syntax for integer with base 10 und 'str' object has no attribute 'append' scheinen Speicheradressfehler zu sein. Eine Variable hat plötzlich einen ganz anderen Inhalt, weil der Controller auf den falschen Speicherbereich verweist. Ich hatte gehofft, dass der neue Espressif-Compiler da Abhilfe schafft denn ein Speicherfix war angekündigt. Allerdings offenbar nicht für dieses Problem.

Wir arbeiten weiterhin daran und mit jeder Firmware wird es weniger wahrscheinlich!

Die Abfrage alle 1,5 Sekunden sollte regulär funktionieren. Auch parallele Abfragen sollten zu keinem Problem führen. Den in 1.79 neu eingeführten und um Größenordnungen robusteren Webserver, haben wir intensiv mit sehr langen Massenabfragen bombardiert. Er hat sich dem als gewachsen erwiesen. Ich will trotzdem nicht ausschließen, dass die Controller-Fehler dadurch wahrscheinlicher werden. @sscheib, wäre es möglich zu schauen, wie es sich auswirkt, wenn das Abfrageintervall reduziert wird? Zumdindest für ein paar Tage? Dann könnte man schon einen statistischen Zusammenhang erahnen.

Einen SD-Karten-Fehler vermute ich hier nicht. Alles was mit SD-Karte zu tun hat, scheint mir der Speicheradress-Bug des Controllers zu sein, nicht die SD-Karte selbst.
Die Anregungen zur Erklärung was bei der SD-Karte zu beachten ist, werde ich demnächst in die Doku mit aufnehmen. Kurz: FAT32, keine Herstellerpräferenz, einfach leere Karte rein oder Karte auf die die alten Daten drauf kopiert worden sind

Der interessanteste Log-Eintrag ist für mich Connecting to network failed - Type: OSError; Reason: the requested operation failed. Da wurde in Firmware 1.80.0 etwas Finetuning am Timing durchgeführt. Trat das in 1.79 auch schon auf?
Ich kann nicht ausschließen, dass selbst das einen Einfluss auf die Reboots hat.

Die Gute Nachricht zum Schluss: Die Reboots haben keinen Einfluss, außer dass ein paar Messpunkte fehlen.

sscheib

Hallo @Daniel,

Danke für deine ausführliche Antwort!

@Daniel-air-Q sagte in Air-Q started regelmäßig neu:

@sscheib, wäre es möglich zu schauen, wie es sich auswirkt, wenn das Abfrageintervall reduziert wird? Zumdindest für ein paar Tage? Dann könnte man schon einen statistischen Zusammenhang erahnen.

Ich habe testweise mal den ICMP Ping weggelassen, welcher jede Minuten gelaufen ist und der Air Q hat volle drei Tage durchgehalten. Das ist immer noch nicht optimal, aber deutlich besser als davor; Da hat er teilweise mehrfach am Tag neu gestartet. Ich werde das jetzt mal weiter beobachten und melde mich regelmäßig mit neuen Erkenntnissen.

@Daniel-air-Q sagte in Air-Q started regelmäßig neu:

Die Abfrage alle 1,5 Sekunden sollte regulär funktionieren. Auch parallele Abfragen sollten zu keinem Problem führen.

Da bin ich wirklich beruhigt - ich hätte mich sehr geärgert, wenn das nicht möglich gewesen wäre.

@Daniel-air-Q sagte in Air-Q started regelmäßig neu:

Da wurde in Firmware 1.80.0 etwas Finetuning am Timing durchgeführt. Trat das in 1.79 auch schon auf?

Das kann ich leider nicht sagen, da ich den Air Q wirklich erst seit sehr kurzer Zeit habe (~14 Tage) und dann auch direkt auf die 1.80 Beta Version gegangen bin.

@Daniel-air-Q sagte in Air-Q started regelmäßig neu:

Die Gute Nachricht zum Schluss: Die Reboots haben keinen Einfluss, außer dass ein paar Messpunkte fehlen.

Das ist wirklich eine gute Nachricht, ich hatte befürchtet, dass die Sensoren sich erst wieder warm laufen müssen.

@Daniel-air-Q sagte in Air-Q started regelmäßig neu:

Kurz: FAT32, keine Herstellerpräferenz, einfach leere Karte rein oder Karte auf die die alten Daten drauf kopiert worden sind

Danke, das hilft! :)

@Daniel-air-Q sagte in Air-Q started regelmäßig neu:

Diese Fehler stehen dann nicht im Error-Log - weil die Firmware hier nicht mehr greift - können aber durch Setzen des Konfigurationsschlüssels {"logging": "Warning"} indirekt aufgezeichnet werden, denn dann werden auch Neustarts ins Log eingetragen.

Danke für den Hinweis. Wäre es ggf. generell möglich den Log nicht bei jedem Neustart zu leeren? Oder den Log nach einem Neustart zu rotieren (sprich in eine neue Datei zu packen)?
Ich denke das würde bei der Fehleranalyse helfen, da ich jetzt nicht mehr die Möglichkeit habe die Logs vor dem Neustart zu sehen.
Ich weiß jetzt leider nicht, ob die Logs bereits rotiert werden (was eventuell schon geschieht, wenn man sich den Namen des Logfiles ansieht: log.0.html); Sollte das der Fall sein, wäre es eventuell sinnvoll den API Endpoint log insofern zu erweitern, dass ich eine Zeitspanne angeben kann, von dem ich den Log sehen möchte. Das würde auch immens beim ständigen Auslesen der Daten helfen, um diese bspw. in Zabbix zu packen.
Ich hatte mir initial überlegt, die Logs in Zabbix zu packen, allerdings habe ich hier neben der oben genannten Schwierigkeit, die "Schwierigkeit", dass die Logs mit HTML-Tags formatiert sind; Es wäre schön, wenn die Daten wie bei allen anderen API Endpoints im JSON Format zurück geliefert werden könnten.

Zum Schluss noch etwas Lob: Ich bin wirklich glücklich mit dem Air Q! Ich kann soviele detailierte Daten über die Luftqualität messen und auch sinnvoll auslesen über die API - da habt ihr anderen Herstellern wirklich einiges voraus!
Deshalb an dieser Stelle: Super arbeit, vielen lieben Dank!

Viele Grüße
Steffen

sscheib

Kurzes Update nach 5 Tagen:
Leider immer noch häufige Neustarts:

2022-11-27 07:11:35
2022-11-29 21:57:39
2022-11-30 05:18:39
2022-12-01 15:54:51
2022-12-02 13:48:30

Ich habe gerade die Zeit zwischen den Abfragen meines Scripts auf 30 Sekunden erhöht.
Ich schaue mir weiter an wie es läuft und melde mich regelmäßig wieder.

sscheib

Ein weiteres Update: Seit dem letzten Update des AirQs sind die Neustarts deutlich weniger geworden. Schätzungsweise alle 2-3 Wochen.