UNSOLVED ioBroker (JS Controller) stürzt alle 6-8 Tage ab

[Homoran]

@RoE19xx sagte in ioBroker (JS Controller) stürzt alle 6-8 Tage ab:

Warum wird der Adapter "sicher" nicht der Verursacher sein?

Weil der Adapter bei hunderten usern ohne Probleme läuft.
Lediglich bei usern, bei denen das RAM zu knapp ist, kommt es zu Speicherproblemen.

Also ist in fiesen Fällen nicht der Adapter, sondern das mangelnde RAM der Verursacher.

@RoE19xx sagte in ioBroker (JS Controller) stürzt alle 6-8 Tage ab:

Ich weiß zwar nicht wie es zum Zeitpunkt vom Absturz ausgeschaut hat.

Das wäre aber bei deiner Argumentationskette schon wichtig.

@RoE19xx sagte in ioBroker (JS Controller) stürzt alle 6-8 Tage ab:

auf einer VM in einem NUC und hat 4 GB RAM zur Verfügung (davon aktuell laut ioBroker noch 1,3 GB frei).

Auch in solchen Fällen kam es kurzfristig zu Speicherproblemen.

@RoE19xx sagte in ioBroker (JS Controller) stürzt alle 6-8 Tage ab:

Nach Deiner Theorie müßte der Adapter (beim komprimieren der Daten) die meistens ioBroker RPi's mit 1 GB Gesamtspeicher an ihre Grenzen bringen.

Nur wenn das backup extrem umfangreich ist.
So war es bei einem user eindeutig immer ein total backup, während das minimal brav durchlief

[RoE19xx]

Es ging mir hier nie eine Schuldfrage, sondern immer nur um die Ursache meiner Systemabstürze.

Ich ziehe meinen Hut davor, wieviel von so vielen zu diesem Projekt beigetragen wird. Und es wird würde mir nicht in den Sinn kommen mit dem Finger auf irgendjemand oder irgendetwas zu zeigen nur weil es bei meiner Installation zu Problemen kommt.
Das war auch nie die Absicht, falls das irgendwie so rübergekommen ist.

Ich bin schwer begeistert vom ioBroker und das schon ziemlich lange. Mein System ist mittlerweile doch schon etwas gewachsen und lief bis zum ersten erwähnten Absturz absolut stabil.

Nachdem es dann einige Änderungen am System gab (die genannten Updates), aber auch von Zeit zu Zeit neue Adapter getestet dazugekommen sind, gibt es viele mögliche Ursachen.

Und mit „Ursache“ meine ich lediglich, „welche Änderung hat dazu geführt, das es nun zu Systemabstürzen kommt“.

Ob das nun ein neu verwendeter Adapter ist, oder Updates oder auch eine Kombination aus alledem ist im Grunde erst mal egal. Ich möchte nur herausfinden, so dass ich Maßnahmen setzen kann um mein System wieder in einen stabilen Zustand zu bringen.

Da ich bei der Analyse irgendwann angestanden bin, ging es eben mit Try & Error und dem Ausschließungsprinzip weiter. Nach dem Denkanstoß von @darkiop habe ich dann einfach mal auf gut Glück den BackitUp Adapter wieder deaktiviert.

Und wenn mein System nach dem deaktivieren von einem (in meiner Installation) neuen Adapter wieder stabil laufen sollte und nach erneutem Aktivieren wieder Abstürze auftreten, dann Freue ich mich im ersten Moment einfach nur die Ursache gefunden zu haben.

Wenn es mit dem Adapter am Ende gar nichts zu tun hat, dann geht die Suche eben weiter.

Da ich aber dazu beitragen möchte das Problem genauer zu analysieren, lasse ich nun im ersten Schritt vorerst den Adapter noch eine gewisse Zeit deaktiviert.
Wenn es dabei nicht zu Abstürzen kommt, werde ich eine andere (markante) Backup Zeit als 02:00 einstellen und schauen ob die Abstürze wieder auftreten.
Wenn ja dann finde ich hier ja ggf. Unterstützung wie ich mein System monitoren (Speicherauslastung aufzeichnen) kann um herauszufinden ob wirklich ein Speicherengpass den Absturz hervorruft.

Das würde den Entwickler vermutlich auch interessieren, da zwangsläuft mit wachsenden Installationen (wird bei den meisten begeisterten Anwendern der Fall sein) auch mit zunehmenden Ausfällen zu rechnen wäre. Und ein Backup Adapter findet sicher bei sehr vielen Anwendern Anklang.

Soweit erst mal mein Plan wie ich weiter vorgehen möchte.

Beim BackitUp Adapter hatte ich bisher nur das Standardbackup im Einsatz. Das Komplettbackup oder auch andere Möglichkeiten habe ich noch gar nicht genutzt bzw. aktiviert.

[darkiop]

Nabend Habe leider zur Zeit wenig freie Zeit für die Analyse - aber: Ich habe seit ein paar Tagen das Komplett Backup deaktviert und beobachte auch seit längerem keinen Absturz mehr. ioBroker läuft bei mir im Docker-Container. Die Aussage von @Homoran könnte hier also passen. Ich stelle das bei Gelegenheit aber nochmal nach.

[darkiop]

Wie es Murphy will, ist heute Nacht der Kollege ioBroker abgestürzt Ich habe gestern Abend die Anzahl der Backups für die CCU im Backitup Adapter erhöht (von 7 auf 14, analog meinen Minimal Backups) ... um 5 Uhr ist der ioBroker Prozess dann abgestürzt (das sehe ich gut an meinen dauerhaft aufgezeichneten Werten wie z.B. dem Stromverbrauch) - um 5 Uhr läuft auch das Minimal Backup.

[smartboart]

Will noch kurz meine Lösung posten...Also bei mir war das von mir oben beschrieben Verhalten dem Speichernotstand geschuldet. Hatte also nur indirekt mit redis zu tun...Auch wenn die Probleme mit file system nicht mehr auftraten Die Ursache dafür war das der Chromium Browser bei jedem Bildwechsel immer mehr Speicher vereinnahmt. Da ich meine Vis über view in widget mittel einem State umschalte damit ich nur eine Basisview habe, welche immer gleich ist und die restlichen views im widget angezeigt werden ( muss bei viewwechsel nicht immer alles neu geladen werden) macht die Bedienung flotter...Das hat aber zufolge das alle Anzeigegeräte immer gleich sind also mit umschalten. Mein Schaltschrank Einbau hat nun ein eigens Projekt erhalten und schaltet somit nicht mehr mit um...Somit bleibt der verfügbare Speicher nun bei 500MB. Danke für die Unterstützung...

[darkiop]

Heute bei mir wieder, 5:00 Uhr - der Zeitpunkt des Minimal Backups. Dieses wurde dann auch nicht erstellt. Hab dann die Reste vom iobroker mittels kill -9 beendet und dabei über ps -ef festgestellt das der js-controller backup Prozess auch noch aktiv war. Dem Container stehen theretisch 12GB RAM zur Verfügung, kann mir eigentlich nicht vorstellen das hier etwas knapp wird - zumal die Backups ja auch einige Tage gut laufen und es bei einem manuellen Aufruf bisher auch nie Probleme gab.

[darkiop]

Der Kollege ioBroker hat heute wieder das zeitliche gesegnet .... ich helfe mir jetzt mit einem kleinen Bash Skript das den Docker Container neu startet (läuft alle 15min):

#!/bin/bash
if [[ $(sudo docker exec -it iobroker-odin sh -c "iobroker status") = *not* ]]; then
  echo "$(date '+%Y-%m-%d %H:%M:%S') ioBroker Prozess im Container ist nicht aktiv,  Container wird neu gestartet." 2>&1 | tee /volume1/docker/check-iobroker.log
  sudo docker restart iobroker-odin 2>&1 >/dev/null
else
  echo "$(date '+%Y-%m-%d %H:%M:%S') ioBroker Prozess im Container ist aktiv." 2>&1 | tee /volume1/docker/check-iobroker.log
fi

[simatec]

Was mir hier in der ganzen Diskussion aufgefallen ist, dass hier diskutiert wird, ob backitup an dem Absturz schuld ist, aber kein einziger Log im debug Modus von backitup mal gepostet wird.
Backitup kann vom Aufbau der Backup-Ausführung nicht der Verursacher sein.

Eventuell müssten bei euch mal die Rechte kontrolliert werden.
Dafür gibt es einen Fix für den iobroker Installer (siehe Signatur).

Beim Minimal Backup wird der gleiche Prozess aufgerufen, wie beim manuellen Backup über Konsole mit "iobroker backup".

Wenn ihr bei einem Total Backup iobroker stoppt, werden ebenfalls die gleichen Befehle aufgerufen wie beim manuellen starten und stoppen von iobroker.
Wenn euren iobroker User die Rechte fehlen, kann auch dies dazu führen, dass iobroker nicht mehr gestartet wird.

Auch besteht die Möglichkeit, des fehlenden RAM.
Bei einem Total Backup wird der komplette iobroker Ordner gepackt, was je nach Installationsgröße schon etwas RAM benötigt.
Um hier aber weiter Spekulationen auszuschließen, wäre es wichtig die Instanz von backitup mal auf debug zu stellen und dann im Log zu schauen, was passiert.

[darkiop]

Hallo @simatec,

hatte in der Vergangenheit keine Logs gefunden die auf den Absturz hinwiesen. Habe jetzt aber backitup sowohl in den Optionen selbst als auch die Instanz in den Debug Modus gesetzt. Beim nächsten mal wird dann nochmal geschaut.

Bin allerdings sehr sicher das backitup der Auslöser ist (was ja nicht bedeuten muss das backitup 'Schuld' ist :)), denn

• Die Uhrzeit des Absturzes stimmt immer mit der Uhrzeit des Backups (bei mir nur das Standard + CCU Backup) überein
• Kontrolliert man nach dem Absturz mittels ps -ef die Prozesse sieht man das der js-controller Prozess mit dem Backup Aufruf noch läuft (aber nichts macht, denn die Kontrolle kann durchaus auch mal einige Stunden nach dem Absturz gewesen sein).
• Im folgenden Screen sieht man das es beim minimal Backup (bei mir) passieren muss (immer alle 4-6 Tage ...):

Bei manuellen Backups direkt auf der Shell bzw. aus dem ioBroker WebUI heraus ist mir das Verhalten noch nicht aufgefallen. Werde das aber ggf. heut einfach einige viele male von Hand starten und beobachten.

ioBroker läuft bei mir im Docker Container unter root - also noch ohne Installfix ... der letzte vor ein paar Wochen ging schief, hatte noch keine Zeit das nochmal anzugehen. Therotisch stehen dem Container 12GB RAM zur Verfügung, das sollte also gut ausreichen.

Grüße Thorsten

[darkiop]

Ok - Update: Habe einige Backups auf der Shell laufen lassen und dabei geht auch der js-controller irgendwann auf die Bretter:

[eumats]

Hi. Ich habe das gleiche Problem auf einem Raspi3. Alle 3-4 Tage stürzt auch bei mir der js-controller im Zeitpunkte des Backups (minimal) ab. Mit einer geänderten Backupzeit ist auch die Absturzzeit des js-controllers auch "gewandert". Das Komprimieren in gz scheint den Rechner dabei lahm zu legen.
Ich habe bei Backitup den Debug-Level auf silly gesetzt. Anbei die Ausgaben. Aus meiner Sicht ist nichts besonderes zu sehen. Außer das 2min nach dem Start des Backup der Raspi faxen macht...

Wäre ein "nice -n 19" für das tar Kommando vielleicht eine Möglichkeit der Lösung?

2019-05-02 02:00:10.054 - silly: backitup.1 inMem message backitup.1.oneClick.* backitup.1.oneClick.minimal val=true, ack=true, ts=1556755210039, q=0, from=system.adapter.backitup.1, user=system.user.admin, lc=1556755210039
2019-05-02 02:00:20.242 - debug: backitup.1 [minimal/mount] done
2019-05-02 02:02:47.757 - debug: backitup.1 [minimal/minimal] done
2019-05-02 02:02:47.881 - silly: backitup.1 transport close
2019-05-02 02:02:47.916 - debug: backitup.1 [minimal/cifs] done
2019-05-02 02:02:47.923 - debug: backitup.1 [minimal/clean] done
2019-05-02 02:02:47.927 - debug: backitup.1 [minimal/telegram] [minimal] used Telegram-Instance: telegram.0
2019-05-02 02:02:47.937 - debug: backitup.1 sendTo "send" to system.adapter.telegram.0 from system.adapter.backitup.1
2019-05-02 02:02:47.937 - debug: backitup.1 [minimal/telegram] done
2019-05-02 02:02:48.101 - error: cloud.0 Ping timeout
2019-05-02 02:02:48.606 - warn: web.0 Reconnection to DB.
2019-05-02 02:02:48.710 - warn: web.0 Reconnection to DB.
2019-05-02 02:02:48.713 - warn: backitup.1 Reconnection to DB.
2019-05-02 02:02:48.636 - warn: sonos.0 Reconnection to DB.
2019-05-02 02:02:48.729 - warn: sonos.0 Reconnection to DB.
2019-05-02 02:02:48.710 - warn: admin.0 Reconnection to DB.
2019-05-02 02:02:48.741 - warn: backitup.1 Reconnection to DB.
2019-05-02 02:02:48.743 - warn: admin.0 Reconnection to DB.
2019-05-02 02:02:48.828 - warn: shelly.0 Reconnection to DB.
2019-05-02 02:02:48.881 - warn: shelly.0 Reconnection to DB.
2019-05-02 02:02:48.894 - debug: backitup.1 statesDB connected
2019-05-02 02:02:48.912 - debug: backitup.1 statesDB connected
2019-05-02 02:02:48.952 - warn: cloud.0 Reconnection to DB.
2019-05-02 02:02:48.930 - warn: sayit.0 Reconnection to DB.
2019-05-02 02:02:49.020 - warn: cloud.0 Reconnection to DB.
2019-05-02 02:02:49.045 - info: backitup.1 starting. Version 1.1.4 in /opt/iobroker/node_modules/iobroker.backitup, node: v8.15.1
2019-05-02 02:02:49.060 - warn: sayit.0 Reconnection to DB.
2019-05-02 02:02:49.011 - warn: deconz.0 Reconnection to DB.
2019-05-02 02:02:49.057 - warn: text2command.0 Reconnection to DB.
2019-05-02 02:02:49.163 - warn: deconz.0 Reconnection to DB.
2019-05-02 02:02:49.192 - warn: text2command.0 Reconnection to DB.
2019-05-02 02:02:49.319 - warn: tradfri.0 Reconnection to DB.
2019-05-02 02:02:49.475 - debug: backitup.1 mount activ... umount in 2 Seconds!!
2019-05-02 02:02:49.756 - warn: tradfri.0 Reconnection to DB.
2019-05-02 02:02:49.760 - info: backitup.1 [minimal] backup was activated at 02:00 every 1 day(s)
2019-05-02 02:02:49.755 - warn: telegram.0 Reconnection to DB.
2019-05-02 02:02:49.803 - debug: backitup.1 [minimal] 10 00 02 */1 * *
2019-05-02 02:02:49.803 - info: backitup.1 [total] backup was activated at 02:30 every 3 day(s)
2019-05-02 02:02:49.822 - debug: backitup.1 [total] 10 30 02 */3 * *
2019-05-02 02:02:49.965 - debug: backitup.1 [minimal/history] backitup.1.history.html
2019-05-02 02:02:49.977 - warn: telegram.0 Reconnection to DB.
2019-05-02 02:02:49.999 - info: admin.0 starting. Version 3.6.0 in /opt/iobroker/node_modules/iobroker.admin, node: v8.15.1
2019-05-02 02:02:50.001 - warn: javascript.0 Reconnection to DB.
2019-05-02 02:02:50.031 - info: backitup.1 starting. Version 1.1.4 in /opt/iobroker/node_modules/iobroker.backitup, node: v8.15.1
2019-05-02 02:02:50.067 - debug: backitup.1 [minimal/umount] mount activ... umount in 60 Seconds!!
2019-05-02 02:02:50.077 - debug: backitup.1 mount activ... umount in 2 Seconds!!
2019-05-02 02:02:50.186 - info: backitup.1 [minimal] backup was activated at 02:00 every 1 day(s)
2019-05-02 02:02:50.220 - info: admin.0 starting. Version 3.6.0 in /opt/iobroker/node_modules/iobroker.admin, node: v8.15.1
2019-05-02 02:02:50.241 - info: javascript.0 starting. Version 4.1.12 in /opt/iobroker/node_modules/iobroker.javascript, node: v8.15.1
2019-05-02 02:02:50.228 - info: admin.0 requesting all states
2019-05-02 02:02:50.229 - info: admin.0 requesting all objects
2019-05-02 02:02:50.231 - info: admin.0 Request actual repository...
2019-05-02 02:02:50.256 - debug: backitup.1 [minimal] 10 00 02 */1 * *
2019-05-02 02:02:50.257 - info: backitup.1 [total] backup was activated at 02:30 every 3 day(s)
2019-05-02 02:02:50.293 - debug: backitup.1 [total] 10 30 02 */3 * *
2019-05-02 02:02:50.303 - info: javascript.0 requesting all states
2019-05-02 02:02:50.305 - info: javascript.0 requesting all objects
2019-05-02 02:02:50.336 - info: javascript.0 starting. Version 4.1.12 in /opt/iobroker/node_modules/iobroker.javascript, node: v8.15.1
2019-05-02 02:02:50.340 - info: javascript.0 requesting all states
2019-05-02 02:02:50.341 - info: javascript.0 requesting all objects
2019-05-02 02:02:50.342 - warn: javascript.0 Reconnection to DB.
2019-05-02 02:02:50.462 - error: web.0 port 8082 already in use
2019-05-02 02:02:50.516 - error: host.homepi-client instance system.adapter.web.0 terminated with code 1 ()
2019-05-02 02:02:50.517 - info: host.homepi-client Restart adapter system.adapter.web.0 because enabled
2019-05-02 02:02:50.683 - error: javascript.0 Longitude or latitude does not set. Cannot use astro.
2019-05-02 02:02:50.693 - error: javascript.0 Error in callback: TypeError: Cannot read property 'toLocaleTimeString' of undefined
2019-05-02 02:02:50.694 - error: javascript.0 at Object. (script.js.common.SK_Astro:346:47)
...

[simatec]

@darkiop
Also kann man backitup ausschließen.
Kamen Fehlermeldungen auf der Konsole?

[simatec]

@eumats
Das backup ist schon durch, bevor dein iobroker abstürzt.
Hast du mal dein Telegram überprüft? Beim senden der Telegram Nachricht bricht etwas ab

[eumats]

Hhmmm. Aber die Nachricht per Telegramm über das erfolgreiche Backup kam ohne Probleme an...

[simatec]

@eumats
Was passiert, wenn du das minimal über Konsole machst?

[darkiop]

@simatec Backitup kann mal als Ursache ausschließen, ist nur der Auslöser Ich stelle das heut Mittag nochmal nach - mit einem Blick auf das ioBroker/System Log.

[eumats]

@simatec
Da muss ich etwas ausholen....
Den von mir beschriebenen Fehlerfall konnte ich wieder auflösen, in dem ich admin und javascript wieder neu gestartet hatte. Aber in diesem Zustand, also nach dem Fehler aus meinem oben geposteten Log, konnte ich mit iobroker backup kein Backup mehr starten. Die Prozesse zum Backup wurden zwar gestartet, aber es kam nie zum Ende.
Erst nach einem Reboot beider Raspi (Master und Slave im Multihostsystem) konnte ich iobroker backup wieder ausführen. Innerhalb von 1-2 min konnte ich mehrfach (5-6x) ein Backup ohne Problem oder Absturz erzeugen.

Ich bin nun etwas ratlos, warum ist wirklich liegt, bzw. wo ich weiter suchen kann...

[eumats]

@darkiop
Kannst Du bitte mal Dein testbackup Skripte posten. Dann lasse ich das heute Abend auch mal auf meinen Raspi los...

EDIT: Hat sich erledigt. Ich habe mir selbst eins gebaut.

[eumats]

Ich habe jetzt mal 45min zyklisch Biobroker backup mit 30sek Pause dazwischen durchlaufen lassen. Und bisher ist das Problem nicht aufgetreten.

Mein Fehlerbild ist sehr ähnlich zu dem folgenden Thread:
https://forum.iobroker.net/topic/21541/probleme-mit-iobroker-bin-mit-meinem-latein-am-ende

Wobei es da auch noch keine Lösung gibt...

[darkiop]

Ich kann den Absturz immer wieder nachstellen, im ioBroker Log zu dem Zeitpunkt leider keine Meldungen: