IoBroker stürzt ab

[apollon77]

@toki1973 Naja ein paar mehr Details wären super ... alles oben erfragt bei den anderen.

Beschreibung was wann passiert ?
ioBroker-Log?
/var/log/syslog ?

[toki1973]

@apollon77 said in IoBroker stürzt ab:

@toki1973 Naja ein paar mehr Details wären super ... alles oben erfragt bei den anderen.

/var/log/syslog ?

Vielen Dank für die Unterstützung. Hier ist das syslog File

Oct 10 07:14:09 ioBroker-Pi bash[1913]: Send diag info: {"uuid":"9c13f06b-5a02-053d-9b9c-d3533e21fbcc","language":"de","country":"Germany","hosts":[{"version":"1.5.7","platform":"Javascript/Node.js","type":"linux"}],"node":"v8.15.1","arch":"arm","adapters":{"admin":{"version":"3.6.4","platform":"Javascript/Node.js"},"discovery":{"version":"2.0.0","platform":"Javascript/Node.js"},"alexa2":{"version":"2.6.4","platform":"Javascript/Node.js"},"web":{"version":"2.4.1","platform":"Javascript/Node.js"},"vis":{"version":"1.2.0","platform":"Javascript/Node.js"},"sonos":{"version":"1.7.7","platform":"Javascript/Node.js"},"sonoff":{"version":"2.2.2","platform":"Javascript/Node.js"},"mihome-vacuum":{"version":"1.1.5","platform":"Javascript/Node.js"},"node-red":{"version":"1.10.1","platform":"Javascript/Node.js"},"pushover":{"version":"1.0.4","platform":"Javascript/Node.js"},"rpi2":{"version":"1.0.0","platform":"javascript/Node.js"},"javascript":{"version":"4.1.16","platform":"Javascript/Node.js"},"tankerkoenig":{"version":"2.0.6","platform":"javascript/Node.js"},"backitup":{"version":"1.2.0","platform":"Javascript/Node.js"},"samsung":{"version":"0.2.9","platform":"Javascript/Node.js"},"synology":{"version":"0.0.4","platform":"Javascript/Node.js"},"weatherunderground":{"version":"3.1.1","platform":"Javascript/Node.js"},"zigbee":{"version":"0.11.3","platform":"Javascript/Node.js"},"mqtt-client":{"version":"1.1.1","platform":"Javascript/Node.js"},"telegram":{"version":"1.4.3","platform":"Javascript/Node.js"},"mqtt":{"version":"2.1.0","platform":"Javascript/Node.js"},"cloud":{"version":"2.6.2","platform":"Javascript/Node.js"},"vis-hqwidgets":{"version":"1.1.2","platform":"Javascript/Node.js"},"lightify":{"version":"0.2.16","platform":"Javascript/Node.js"},"text2command":{"version":"1.2.5","platform":"Javascript/Node.js"},"terminal":{"version":"0.1.2","platform":"Javascript/Node.js"},"info":{"version":"1.3.7","platform":"Javascript/Node.js"},"vis-metro":{"version":"1.1.2","platform":"Javascript/Node.js"},"vis-rgraph":{"version":"0.0.2","platform":"Javascript/Node.js"},
Oct 10 07:14:09 ioBroker-Pi bash[1913]: "vis-weather":{"version":"2.3.0","platform":"Javascript/Node.js"},"vis-plumb":{"version":"1.0.2","platform":"Javascript/Node.js"},"vis-material":{"version":"0.1.3","platform":"Javascript/Node.js"},"vis-jqui-mfd":{"version":"1.0.12","platform":"Javascript/Node.js"},"hue":{"version":"1.1.0","platform":"Javascript/Node.js"},"mihome":{"version":"1.2.6","platform":"javascript/Node.js"},"material":{"version":"0.10.6","platform":"javascript/Node.js"},"icons-material-png":{"version":"0.1.0","platform":"javascript/Node.js"},"habpanel":{"version":"0.3.4","platform":"javascript/Node.js"},"vis-timeandweather":{"version":"1.1.7","platform":"Javascript/Node.js"},"icons-ultimate-png":{"version":"1.0.1","platform":"javascript/Node.js"},"ble":{"version":"0.9.0","platform":"Javascript/Node.js"},"icons-material-svg":{"version":"0.1.0","platform":"javascript/Node.js"},"icons-open-icon-library-png":{"version":"0.1.3","platform":"javascript/Node.js"},"icons-mfd-svg":{"version":"1.0.2","platform":"javascript/Node.js"},"radar2":{"version":"1.0.7","platform":"Javascript/Node.js"},"ical":{"version":"1.7.0","platform":"Javascript/Node.js"},"ping":{"version":"1.3.2","platform":"Javascript/Node.js"},"history":{"version":"1.8.6","platform":"Javascript/Node.js"},"mobile":{"version":"0.5.0","platform":"javascript/Node.js"},"pollenflug":{"version":"1.0.3","platform":"Javascript/Node.js"},"ds18b20":{"version":"1.0.2","platform":"Javascript/Node.js"}},"model":"ARMv7 Processor rev 4 (v7l)","cpus":4,"mem":972234752,"ostype":"Linux","city":"76694 Forst","vis":408}

[apollon77]

@toki1973 Naja das ist eine Zeile daraus. Und ist leider komplett uninteressant.

Ok, dann mal an den Anfang zurück:

Dein Problem ist das Irgendwann zwischen Zeitpunkt X und Y dein ioBroker abstürzt und nicht mehr erreichbar ist und Du ihn nurmanuell neu starten kannst? Korrekt?

Dann musst Du Die Logfiles in diesem Zeitraum untersuchen. Im ioBroker Logfile (/opt/iobroker/log/...) könntest DU sehen wann es vor deinem Neustart den letzten Log-Eintrag gab. Das wäre mal ein Anhaltspunkt.
Wenn da im Logfile Fehler sind wären weitere Anhaltspunkte.

Im /var/log/syslog kannst Du dann ggf auch in dem Zeitraum schauen. Wenn da irgendwas mit "oom"(oder OOM?) vorkommt ist das ein sicheres Anzeichen das dir der RAM ausgegangen ist.

Also: MEHR LOGS!

[toki1973]

@apollon77 said in IoBroker stürzt ab:

@toki1973 Naja ein paar mehr Details wären super ... alles oben erfragt bei den anderen.

Beschreibung was wann passiert ?
ioBroker-Log?

2019-10-10 02:15:18.161  - ^[[32minfo^[[39m: host.ioBroker-Pi Delete log file iobroker.2019-10-03.log
2019-10-10 02:17:40.067  - ^[[32minfo^[[39m: sonoff.0 Client [Garten_rechts] reconnected. Old secret 1570655753966_8482. New secret 1570666660065_1541
2019-10-10 02:38:52.558  - ^[[32minfo^[[39m: sonoff.0 Client [Garten_rechts] reconnected. Old secret 1570666660065_1541. New secret 1570667932557_6056
2019-10-10 03:09:58.633  - ^[[32minfo^[[39m: sonoff.0 Client [Garten_rechts] reconnected. Old secret 1570667932557_6056. New secret 1570669798632_4864
2019-10-10 03:21:52.719  - ^[[32minfo^[[39m: sonoff.0 Client [Garten_rechts] reconnected. Old secret 1570669798632_4864. New secret 1570670512717_2455
2019-10-10 03:54:31.431  - ^[[32minfo^[[39m: sonoff.0 Client [Bridge] reconnected. Old secret 1570645015338_1662. New secret 1570672471430_1284
2019-10-10 05:30:12.431  - ^[[32minfo^[[39m: sonoff.0 Client [Garten_rechts] reconnected. Old secret 1570670512717_2455. New secret 1570678212430_2257
2019-10-10 06:23:31.340  - ^[[32minfo^[[39m: sonoff.0 Client [Garten_rechts] reconnected. Old secret 1570678212430_2257. New secret 1570681411338_9467
2019-10-10 06:32:24.614  - ^[[32minfo^[[39m: sonoff.0 Client [Garten_rechts] reconnected. Old secret 1570681411338_9467. New secret 1570681944612_6876
2019-10-10 07:14:03.200  - ^[[32minfo^[[39m: sonoff.0 Client [Bridge] reconnected. Old secret 1570672471430_1284. New secret 1570684443104_8401
2019-10-10 07:14:11.821  - ^[[33mwarn^[[39m: sonoff.0 Old client Bridge with secret 1570672471430_1284 sends pingreq. Ignore! Actual secret is 1570684443104_8401
"iobroker.2019-10-10.log" 4999 lines, 528010 characters

[apollon77]

@toki1973 sagte in IoBroker stürzt ab:

2019-10-10 06:32:24.614 - ^[[32minfo^[[39m: sonoff.0 Client [Garten_rechts] reconnected. Old secret 1570681411338_9467. New secret 1570681944612_6876

Ok, dann schau mal gegen 6:30 (fang mal 6:25 oder so an) im syslog.

Um diese Zeit laufen üblicherweise Update-Checks und tägliche Aufgaben in einem Debian/Ubuntu System ...

[toki1973]

Der Teil hier sieht seltsam aus. Ich habe radar2.0 und ble.0 über putty mal gestoppt.

2019-10-10 09:49:11.436 - error: radar2.0 no connection to objects DB
2019-10-10 09:49:11.428 - error: ble.0 no connection to objects DB
2019-10-10 09:48:54.750 - error: telegram.0 no connection to objects DB
2019-10-10 09:49:18.637 - error: terminal.0 no connection to objects DB
2019-10-10 09:49:20.769 - error: Caught by controller[0]: FATAL ERROR: NewSpace::Rebalance Allocation failed - process out of memory
2019-10-10 09:49:20.770 - warn: host.ioBroker-Pi instance system.adapter.admin.1 terminated due to SIGABRT
2019-10-10 09:49:20.770 - error: host.ioBroker-Pi instance system.adapter.admin.1 terminated with code null ()
2019-10-10 09:49:20.771 - info: host.ioBroker-Pi Restart adapter system.adapter.admin.1 because enabled
2019-10-10 09:49:20.922 - error: Caught by controller[0]: FATAL ERROR: Committing semi space failed. Allocation failed - process out of memory
2019-10-10 09:49:20.923 - warn: host.ioBroker-Pi instance system.adapter.node-red.0 terminated due to SIGABRT
2019-10-10 09:49:20.923 - error: host.ioBroker-Pi instance system.adapter.node-red.0 terminated with code null ()
2019-10-10 09:49:20.923 - info: host.ioBroker-Pi Restart adapter system.adapter.node-red.0 because enabled
2019-10-10 09:49:21.045 - error: Caught by controller[0]: FATAL ERROR: Committing semi space failed. Allocation failed - process out of memory
2019-10-10 09:49:21.046 - warn: host.ioBroker-Pi instance system.adapter.sonoff.0 terminated due to SIGABRT
2019-10-10 09:49:21.046 - error: host.ioBroker-Pi instance system.adapter.sonoff.0 terminated with code null ()
2019-10-10 09:49:21.047 - info: host.ioBroker-Pi Restart adapter system.adapter.sonoff.0 because enabled
2019-10-10 09:49:21.118 - warn: backitup.0 Reconnection to DB.
2019-10-10 09:49:21.143 - warn: web.0 Reconnection to DB.
2019-10-10 09:49:21.152 - warn: alexa2.0 Reconnection to DB.
2019-10-10 09:49:21.149 - warn: zigbee.0 Reconnection to DB.
2019-10-10 09:49:21.328 - warn: backitup.0 Reconnection to DB.
2019-10-10 09:49:21.335 - warn: alexa2.0 Reconnection to DB.
2019-10-10 09:49:21.348 - warn: zigbee.0 Reconnection to DB.
2019-10-10 09:49:21.349 - warn: web.0 Reconnection to DB.
2019-10-10 09:49:21.589 - warn: javascript.0 Reconnection to DB.
2019-10-10 09:49:21.656 - error: javascript.0 already running
2019-10-10 09:49:21.672 - error: web.0 already running
2019-10-10 09:49:21.727 - error: zigbee.0 already running
2019-10-10 09:49:21.762 - error: backitup.0 already running
2019-10-10 09:49:21.994 - error: host.ioBroker-Pi instance system.adapter.web.0 terminated with code 7 (Adapter already running)
2019-10-10 09:49:21.994 - info: host.ioBroker-Pi Restart adapter system.adapter.web.0 because enabled
2019-10-10 09:49:22.114 - error: host.ioBroker-Pi instance system.adapter.javascript.0 terminated with code 7 (Adapter already running)
2019-10-10 09:49:22.115 - info: host.ioBroker-Pi Restart adapter system.adapter.javascript.0 because enabled
2019-10-10 09:49:22.222 - error: host.ioBroker-Pi instance system.adapter.backitup.0 terminated with code 7 (Adapter already running)
2019-10-10 09:49:22.223 - info: host.ioBroker-Pi Restart adapter system.adapter.backitup.0 because enabled
2019-10-10 09:49:22.331 - error: host.ioBroker-Pi instance system.adapter.zigbee.0 terminated with code 7 (Adapter already running)
2019-10-10 09:49:22.331 - info: host.ioBroker-Pi Restart adapter system.adapter.zigbee.0 because enabled
2019-10-10 09:49:22.359 - info: alexa2.0 starting. Version 2.6.4 in /opt/iobroker/node_modules/iobroker.alexa2, node: v8.15.1
2019-10-10 09:49:22.902 - info: alexa2.0 starting. Version 2.6.4 in /opt/iobroker/node_modules/iobroker.alexa2, node: v8.15.1
2019-10-10 09:49:23.464 - info: terminal.0 starting. Version 0.1.2 in /opt/iobroker/node_modules/iobroker.terminal, node: v8.15.1
2019-10-10 09:49:23.884 - info: radar2.0 starting. Version 1.0.7 in /opt/iobroker/node_modules/iobroker.radar2, node: v8.15.1
2019-10-10 09:49:24.271 - info: terminal.0 http server listening on port 8088
2019-10-10 09:49:24.579 - info: ble.0 starting. Version 0.9.0 in /opt/iobroker/node_modules/iobroker.ble, node: v8.15.1
2019-10-10 09:49:25.173 - info: ble.0 loaded plugins: Xiaomi, mi-flora, ruuvi-tag, _default
2019-10-10 09:49:25.509 - info: telegram.0 starting. Version 1.4.3 in /opt/iobroker/node_modules/iobroker.telegram, node: v8.15.1
2019-10-10 09:49:25.914 - warn: radar2.0 Promise failed @ '' error: { TypeError: Cannot read property 'name' of undefined at seriesOf.i (/opt/iobroker/node_modules/iobroker.radar2/node_modules/@frankjoke/myadapter/myAdapter.js:265:56) at p.then (/opt/iobroker/node_modules/iobroker.radar2/node_modules/@frankjoke/myadapter/myAdapter.js:794:37) at [stack]: 'TypeError: Cannot read property \'name\' of undefined\n at seriesOf.i (/opt/iobroker/node_modules/iobroker.radar2/node_modules/@frankjoke/myadapter/myAdapter.js:265:56)\n at p.then (/opt/iobroker/node_modules/iobroker.radar2/node_modules/@frankjoke/myadapter/myAdapter.js:794:37)\n at ', [message]: 'Cannot read property \'name\' of undefined' }
2019-10-10 09:49:26.061 - info: radar2.0 radar2 initialization started...
2019-10-10 09:49:25.191 - info: ble.0 enabled plugins: _default
2019-10-10 09:49:25.193 - info: ble.0 monitored services: 
2019-10-10 09:49:26.148 - info: ble.0 starting scan for services []

[apollon77]

@toki1973 sagte in IoBroker stürzt ab:

process out of memory

Das ist doch recht eindeutig ... Da solltest Du in /var/log/syslog was finden.

Das bringt mich zur Frage: Scheint ja ein System mit 1GB RAM zu sein. Wieviele Instanzen hast Du denn so laufen?

[toki1973]

Ja das ist ein Raspberry 3 - ich habe die meisten deaktiviert und hoffe das damit kein Speicher verbraucht wird.
Die Andriod App die den Status das RP anzeigt zeigt 576 von 927 MiB an. Auslagerung 36 von 100, Dateisystem hat 11 von 11Gb frei

bind: 0.0.0.0, run as: admin
+ system.adapter.admin.1                 : admin       -  enabled, port: 8081, bind: 0.0.0.0, run as: admin
+ system.adapter.alexa2.0                : alexa2      -  enabled
+ system.adapter.backitup.0              : backitup    -  enabled
  system.adapter.ble.0                   : ble         - disabled
  system.adapter.cloud.0                 : cloud       - disabled
  system.adapter.discovery.0             : discovery   - disabled
  system.adapter.habpanel.0              : habpanel    - disabled
  system.adapter.history.0               : history     - disabled
  system.adapter.hue.0                   : hue         - disabled, port: 80
  system.adapter.ical.0                  : ical        - disabled
  system.adapter.icons-material-png.0    : icons-material-png -  enabled
  system.adapter.icons-material-svg.0    : icons-material-svg -  enabled
  system.adapter.icons-mfd-svg.0         : icons-mfd-svg -  enabled
  system.adapter.icons-open-icon-library-png.0: icons-open-icon-library-png -  enabled
  system.adapter.icons-ultimate-png.0    : icons-ultimate-png -  enabled
  system.adapter.info.0                  : info        - disabled
+ system.adapter.javascript.0            : javascript  -  enabled
  system.adapter.lightify.0              : lightify    - disabled
  system.adapter.mihome-vacuum.0         : mihome-vacuum - disabled, port: 54321
  system.adapter.mihome.0                : mihome      - disabled, port: 9898, bind: 0.0.0.0
  system.adapter.mobile.0                : mobile      -  enabled
  system.adapter.mqtt-client.0           : mqtt-client - disabled, port: 1884
  system.adapter.mqtt.0                  : mqtt        - disabled, port: 1884
+ system.adapter.node-red.0              : node-red    -  enabled, port: 1880, bind: 0.0.0.0
  system.adapter.ping.0                  : ping        - disabled
  system.adapter.pollenflug.0            : pollenflug  - disabled
  system.adapter.pushover.0              : pushover    - disabled
  system.adapter.pushover.1              : pushover    - disabled
  system.adapter.radar2.0                : radar2      - disabled
  system.adapter.rpi2.0                  : rpi2        - disabled
  system.adapter.samsung.0               : samsung     - disabled
+ system.adapter.sonoff.0                : sonoff      -  enabled, port: 1884, bind: 0.0.0.0
  system.adapter.synology.0              : synology    - disabled, port: 5000
  system.adapter.tankerkoenig.0          : tankerkoenig - disabled
  system.adapter.telegram.0              : telegram    - disabled, port: 8443, bind: 0.0.0.0
+ system.adapter.terminal.0              : terminal    -  enabled, port: 8088, bind: 0.0.0.0, run as: admin
  system.adapter.text2command.0          : text2command - disabled
  system.adapter.vis-hqwidgets.0         : vis-hqwidgets -  enabled
  system.adapter.vis-jqui-mfd.0          : vis-jqui-mfd -  enabled
  system.adapter.vis-metro.0             : vis-metro   -  enabled
  system.adapter.vis-plumb.0             : vis-plumb   -  enabled
  system.adapter.vis-rgraph.0            : vis-rgraph  -  enabled
  system.adapter.vis-timeandweather.0    : vis-timeandweather -  enabled
  system.adapter.vis-weather.0           : vis-weather -  enabled
  system.adapter.vis.0                   : vis         -  enabled
  system.adapter.weatherunderground.0    : weatherunderground - disabled
+ system.adapter.web.0                   : web         -  enabled, port: 8082, bind: 0.0.0.0, run as: admin
  system.adapter.web.1                   : web         - disabled, port: 8082, bind: 0.0.0.0, run as: admin
+ system.adapter.zigbee.0                : zigbee      -  enabled, port: /dev/serial/by-id/usb-Texas_Instruments_TI_CC2531_USB_CDC___0X00124B0018E1F563-if00

+ instance is alive

[apollon77]

@toki1973 Also mit 9+1 Prozessen kann die Zahl 576 MB durchaus passen.

Am Ende ists jetzt so: IRGENDWAS passiert auf dem System was Speicher braucht ... von daher wäre /var/log/syslog mit check nach "OOM" immer noch mega interessant .... Das hat ggf nichts mit ioBroker zu tun.

Dein System hat "im normalen Betrieb" 300MB freien RAM ... je nachdem was da passiert kann das recht schnell verbraucht sein. Keine Ahnung Backitup und Paketaktualisierung via apt-get läuft beides parallel gegen 6:30 ... beides braucht ggf einiges an RAM kurzzeitig ... und schon machts Bumm

Wann macht Backitup das Backup?

[toki1973]

@apollon77 Okay danke schonmal. Um 2 Uhr mach ich die Backups. Im syslog ist nicht von OOM zu sehen.

Heut morgen konnte ich über die web Schnittstelle verbinden und wollte ein Script erstellen. Nach kurzer Zeit brach die Verbindung ab. Und ich komme per Web nicht mehr drauf. Auslastung ist lt. APP bei bei 44% Temperatur bei 49 Grad

[apollon77]

@toki1973 naja mit der Meldung im Log ist Dir der Speicher ausgegangen ... Wodurch ... puuhhh...

[toki1973]

Naja, aber aktuell habe ich Speicher und komme nicht mehr auf den Admin. admin.1 Instanz läuft aber. VIS funktioniert ebenfalls. Kann es an der nicht verwendeten admin.0 Instanz liegen?

[apollon77]

@toki1973 Mit dem Log oben und den doppelt laufenden Adaptern und allem kann alles und nichts duie Ursache sein. AM besten reboot und gut.

Du musst rausfinden was genau passiert wenn der RAM ausgeht und welcher Prozess "schuld" ist. Wenn Du das nicht findest ist blöd.
Lass eine Shell mit "top" offen und versuche es irgendwie zu provozieren und dann schau was top sagt. Welcher Prozess braucht grad mehr RAM als sonst und so

[toki1973]

iobroker Restart und dann der Versuch mich zu Verbinden bleibt hängen:

[apollon77]

@toki1973 Ja direkt beim Start wenn alle Adapter hochkommen kann schon bissl Last entstehen ... Immer noch so danach?

[sigi234]

@apollon77 sagte in IoBroker stürzt ab:

@toki1973 Ja direkt beim Start wenn alle Adapter hochkommen kann schon bissl Last entstehen ... Immer noch so danach?

Hm, vielleicht ein Skript was läuft?

[toki1973]

@apollon77 Aktuell funktioniert es. Ich lasse jetzt mal das htop offen und warte bis es wieder hängt und schaue dann die die var/logs.
Vielen Dank für deine Tipps und Geduld!

[Mapio90]

Hallo kann mir jemand bei der Fehlermeldung vom Log weiterhelfen? Wollte den Slave updaten auf die neuste Version...

host.Master 2019-11-19 17:27:41.076 error Objects 192.168.178.73:56888 (Init=false) Redis error:Error: Invalid Chunk: parse failed
host.Master 2019-11-19 17:27:36.063 error Objects 192.168.178.73:56886 (Init=false) Redis error:Error: Invalid Chunk: parse failed

[apollon77]

@Mapio90 ich muss jetzt zuerst diese Frage stellen: nen schlechter passenden thread für diese Frage hast du nicht gefunden?!

Ziemlich off topic?!

Schau mal in die faq zu Controller 2.0 thread (Post #2). Da wird genau diese Frage beantwortet.

[Mapio90]

@apollon77 du hast recht, entschuldige. Ich hatte es gestern eillig und deswegen meine Fehler schnell zur frage stellen wollen.

Ich habe, wie du sagtest über die Suchfunktion den zweiten Beitrag gefunden und unter Nummer 9 alles ausgeführt. Habe leider trotzdem noch die Fehlermeldung wie im oberen zu sehen ist.