Server Cannot start inMem-objects on port 9001

[flugwelle]

@glasfaser Ich soll jetzt jede Zeile einzeln ausprobieren? Nicht wirklich - oder?

[Glasfaser]

@flugwelle

Du brauchst doch nur den Hauptordner anwählen !!!

oder per Befehl

iob list objects admin.* | wc -l

[flugwelle]

@glasfaser Schon klar ... aber ich muss das bei jedem Hauptordner machen. Das mit dem iob list ist da schon praktischer - danke.

Ich glaube ich habe auch schon einen Kandidaten gefunden - der Unifi-Protect Baum hat schlappe 35K Objekte ...

[Chris_90]

Hallo zusammen,
Ich wollte kurz mal eine Meldung zu dem Thema abgeben.
Mir war es vor kurzem zweimal im Abstand von wenigen Wochen zu dem eingangs erwähnten Problem gekommen.
Meine Objects.json1 Datei war plötzlich 500M groß.

Auf meinem iobroker läuft auch so gut wie nix, ich nutze es nur für 1x Heizungsthermostat, 3 Steckdosen, 1 Lampe und ein paar Fensterkontakte. Insofern war das für mich ganz und gar unerklärlich.
Wenn ich aktuell die Anzahl der Objects abfrage zeigt mir der iobroker ganze 31 an. Die objects.json1 ist 7,6M groß, also nicht besorgniserregend.

Um das Teil zum fliegen zu bekommen musste ich beide male restoren.

Langfristig abhilfe geschafft hat vermutlich der Hinweis von @AlCalzone: fix: avoid huge DB files by compressing daily

Ich hatte aber im Zuge dessen nochmal eingehends geprüft, dass mein OS und die iobroker Installation auf dem aktuellsten Stand ist. (war noch auf buster im repo eingestellt)

Fazit: Meine Installation läuft jetzt wieder seit mehr als 1 Monat ohne zwischenfälle!

[apollon77]

@chris_90 Danke für Feedback. Wir bereiten gerade einen js-controller 4.0.24 vor der das dann für alle bringt.

[micw42]

Hallo,
auch ich kann berichten, dass ich alle paar Wochen diesen Fehler habe und der iobroker dann nicht mehr erreichbar ist.
Ich komme in dem Fall auch nicht mehr mit ssh auf den pi, ein ping funktioniert komischerweise aber noch.
Muss dann den Stecker ziehen, danach läuft wieder alles.

Das nur zur Info, ich warte dann mal auf das Update ...

[apollon77]

@micw42 naja sttooooppp ... wie kommst Du darauf das diese Beschreibung von Dir zu dem Fehler passt um den es hier geht?

Dein Fehlerbild würde eher bedeuten das du zuviel RAM verbrauchst und er dann startet zu Swappen und da nicht mehr rauskommt - das wäre was ganz anderes und auch ganz anders zu lösen.

Wen Wenn du den hier beschriebenen Fehler hättest, würde er auch nach deine Strom-weg nicht mehr starten. AM besten details in eigenem Thread liefern

[micw42]

Hm, weil diese Meldung immer die letzte im Log ist, wenn es passiert:

2022-11-21 08:17:22.426 - info: host.raspberrypi iobroker.js-controller version 4.0.23 js-controller starting
2022-11-21 08:17:22.433 - info: host.raspberrypi Copyright (c) 2014-2022 bluefox, 2014 hobbyquaker
2022-11-21 08:17:22.434 - info: host.raspberrypi hostname: raspberrypi, node: v14.20.0
2022-11-21 08:17:22.435 - info: host.raspberrypi ip addresses: 192.168.178.56 fd00::85ce:9c7a:3bcd:95ac fe80::3782:4c12:e099:c79e
2022-11-21 08:17:24.559 - error: host.raspberrypi-Server Cannot start inMem-objects on port 9001: Failed to lock DB file "/opt/iobroker/iobroker-data/objects.jsonl"!
2022-11-21 08:17:29.145 - info: host.raspberrypi iobroker.js-controller version 4.0.23 js-controller starting
2022-11-21 08:17:29.153 - info: host.raspberrypi Copyright (c) 2014-2022 bluefox, 2014 hobbyquaker
2022-11-21 08:17:29.153 - info: host.raspberrypi hostname: raspberrypi, node: v14.20.0
2022-11-21 08:17:29.154 - info: host.raspberrypi ip addresses: 192.168.178.56 fd00::85ce:9c7a:3bcd:95ac fe80::3782:4c12:e099:c79e
2022-11-21 08:17:31.270 - error: host.raspberrypi-Server Cannot start inMem-objects on port 9001: Failed to lock DB file "/opt/iobroker/iobroker-data/objects.jsonl"!
2022-11-21 09:22:54.527 - info: host.raspberrypi iobroker.js-controller version 4.0.23 js-controller starting

[Thomas Braun]

@micw42 sagte in Server Cannot start inMem-objects on port 9001:

raspberrypi, node: v14.20.0

Auf nodejs 16 gehen.

[apollon77]

@micw42 das so alleine sagt nichts. Kann auch sein das einfach das Tanzeinlagen restart Loop war. Dann kann das auch passieren. Am Ende musst du ja rausfinden warum der Host nicht mehr reagiert. Das andere ist ggf nur ein folgethema.

Ich würde mal in /var/log/syslog schauen ob da was mit „oom“ steht. Ich tippe ja

[micw42]

Habe mal reingeguckt.
Von oom keine Spur. Der pi scheint zum besagten Zeitpunkt einen Neustart gemacht zu haben:

Nov 21 08:17:01 raspberrypi CRON[30132]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Nov 21 08:17:05 raspberrypi kernel: [ 0.000000] Booting Linux on physical CPU 0x0
...
Nov 21 08:17:34 raspberrypi systemd[1]: Stopped ioBroker Server.
Nov 21 08:17:34 raspberrypi systemd[1]: Started ioBroker Server.
Nov 21 09:22:54 raspberrypi systemd-timesyncd[318]: Synchronized to time server for the first time 217.91.44.17:123 (2.debian.pool.ntp.org).
Nov 21 09:23:01 raspberrypi systemd[1]: systemd-hostnamed.service: Succeeded.

Habt ihr da eine Erklärung für?

[apollon77]

@micw42 Zeit na mehr log bitte … viiiieeel mehr (Textdatei anhängen).

[micw42]

Ok, hier mal der log um den Zeitpunkt herum:
log.txt

[apollon77]

@micw42 Also ja ... hat rebootet ... grund unbekannt ... STromversorgung prüfen und beobachten warum er das tut ... am Ende hast Du im Log ausser 3 Zeilen primär den Reboot drin ... also was pot. "davor" war sieht man nicht ...

[micw42]

Davor und danach sind jeweils immer nur sehr oft im Wechsel

raspberrypi kernel: [2254835.001317] device eth0 left promiscuous mode
raspberrypi kernel: [2254859.166294] device eth0 entered promiscuous mode

zu sehen.

Ja, der Reboot ist sehr merkwürdig. Auch warum ich danach nicht mehr auf den pi/iobroker komme und was das mit dem DB lock zu tun haben könnte.

Ich warte dann einfach auf das nächste Mal und gucke, ob der Ablauf der gleiche ist.

[apollon77]

@micw42 Also im log steht das iobroker gestartet ist und zu dem Zeitopunkt im Log war keine DB locked ...

[micw42]

Also wenn ich den iobroker-log und den System-log zusammenfasse:

2022-11-21 08:17:22.426 - info: host.raspberrypi iobroker.js-controller version 4.0.23 js-controller starting
2022-11-21 08:17:22.433 - info: host.raspberrypi Copyright (c) 2014-2022 bluefox, 2014 hobbyquaker
2022-11-21 08:17:22.434 - info: host.raspberrypi hostname: raspberrypi, node: v14.20.0
2022-11-21 08:17:22.435 - info: host.raspberrypi ip addresses: 192.168.178.56 fd00::85ce:9c7a:3bcd:95ac fe80::3782:4c12:e099:c79e
2022-11-21 08:17:24.559 - error: host.raspberrypi-Server Cannot start inMem-objects on port 9001: Failed to lock DB file "/opt/iobroker/iobroker-data/objects.jsonl"!
Nov 21 08:17:24 raspberrypi systemd[1]: iobroker.service: Main process exited, code=exited, status=24/n/a
Nov 21 08:17:24 raspberrypi systemd[1]: iobroker.service: Failed with result 'exit-code'.
Nov 21 08:17:27 raspberrypi systemd[1]: iobroker.service: Service RestartSec=3s expired, scheduling restart.
Nov 21 08:17:27 raspberrypi systemd[1]: iobroker.service: Scheduled restart job, restart counter is at 1.
Nov 21 08:17:27 raspberrypi systemd[1]: Stopped ioBroker Server.
Nov 21 08:17:27 raspberrypi systemd[1]: Started ioBroker Server.
2022-11-21 08:17:29.145 - info: host.raspberrypi iobroker.js-controller version 4.0.23 js-controller starting
2022-11-21 08:17:29.153 - info: host.raspberrypi Copyright (c) 2014-2022 bluefox, 2014 hobbyquaker
2022-11-21 08:17:29.153 - info: host.raspberrypi hostname: raspberrypi, node: v14.20.0
2022-11-21 08:17:29.154 - info: host.raspberrypi ip addresses: 192.168.178.56 fd00::85ce:9c7a:3bcd:95ac fe80::3782:4c12:e099:c79e
2022-11-21 08:17:31.270 - error: host.raspberrypi-Server Cannot start inMem-objects on port 9001: Failed to lock DB file "/opt/iobroker/iobroker-data/objects.jsonl"!
Nov 21 08:17:31 raspberrypi systemd[1]: iobroker.service: Main process exited, code=exited, status=24/n/a
Nov 21 08:17:31 raspberrypi systemd[1]: iobroker.service: Failed with result 'exit-code'.
Nov 21 08:17:34 raspberrypi systemd[1]: iobroker.service: Service RestartSec=3s expired, scheduling restart.
Nov 21 08:17:34 raspberrypi systemd[1]: iobroker.service: Scheduled restart job, restart counter is at 2.
Nov 21 08:17:34 raspberrypi systemd[1]: systemd-fsckd.service: Succeeded.
Nov 21 08:17:34 raspberrypi systemd[1]: Stopped ioBroker Server.
Nov 21 08:17:34 raspberrypi systemd[1]: Started ioBroker Server.

Es sieht doch für mich so aus, als wenn der pi (aus welchem Grund auch immer) neu gestartet ist, der iobroker aber wegen des DB locks nicht starten konnte?
Erst mit Ziehen des Steckers und nochmaligem Neustart lief wieder alles.

Oder sehe ich das komplett falsch?

[Thomas Braun]

@micw42 sagte in Server Cannot start inMem-objects on port 9001:

Erst mit Ziehen des Steckers

???? Nie einfach den Stecker ziehen!

systemctl status iobroker

sagt? Bitte in CodeTags eingebettet posten.

[apollon77]

@micw42 Also ja ok ... hatte nicht gesehen das der eine Start 1h später war.

Das interessante ist das das letze im Log der "dritte "Started" ist und dann weder im syslog oder woanders nochwas kommt. Und wenn du auch sagst das SSH nicht mehr ging dann hat das system irgendwas. Weil dann ist das ja scheinbar komplett hängen geblieben - keine AHung ob es nicht auch passiert wäre wenn iobroker gestartet wäre.

Aber ja es kann sein das bei so einem harten restart vom host das DLB Lock file noch da ist und es so beim Reboot zu diesem Fehler kommt weil halt das lock File der DB noch da ist ... das expired glaube ich 5 Minuten später oder so. Aber normalerweise gibt das dann einfach mehrere Startversuche bis dann einer tut.

Das komisch bei dir ist das der rechner komplett nach 2 versuchen einfriert (weil SSH ja auch nicht geht) ... also da ist was anderes als ioBroker im Argen.
Und dein Problem ist daher definitiv was anderes

[micw42]

@apollon77 Danke für die Hilfe! Ich muss also "nur" rausfinden, warum sich der pi rebootet ...