Server Cannot start inMem-objects on port 9001

[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 ...

[apollon77]

@micw42 ja damit würde ich starten ;-)) sorry das ich da nicht mehr helfen kann. Ich persönlich würde mit dem Netzteil anfangen.

[woehrer]

Hallo,

ich habe jetzt hier schon einiges gelesen aber leider war die richtige Lösung für mich noch nicht greifbar. Habe natürlich auch schon das ein oder andere versucht.

woehrer@iobrokerifa:/opt/iobroker/iobroker-data$ cd ..
woehrer@iobrokerifa:/opt/iobroker$ iob version
4.0.23
woehrer@iobrokerifa:/opt/iobroker$ iob status
iobroker is running on this host.


Objects type: jsonl
States  type: jsonl
woehrer@iobrokerifa:/opt/iobroker$ node node_modules/iobroker.js-controller/controller.js --logs
2022-12-22 08:42:12.631  - info: host.iobrokerifa iobroker.js-controller version 4.0.23 js-controller starting
2022-12-22 08:42:12.635  - info: host.iobrokerifa Copyright (c) 2014-2022 bluefox, 2014 hobbyquaker
2022-12-22 08:42:12.636  - info: host.iobrokerifa hostname: iobrokerifa, node: v14.21.1
2022-12-22 08:42:12.636  - info: host.iobrokerifa ip addresses: 192.168.20.70 fe80::11:32ff:fe27:dee
2022-12-22 08:42:14.720  - error: host.iobrokerifa-Server Cannot start inMem-objects on port 9001: Failed to lock DB file "/opt/iobroker/iobroker-data/objects.jsonl"!
woehrer@iobrokerifa:/opt/iobroker$ node -v
v14.21.1
woehrer@iobrokerifa:/opt/iobroker$ npm -v
6.14.17
woehrer@iobrokerifa:/opt/iobroker$ sudo ss -tulpn | grep LISTEN
tcp   LISTEN 0      511             127.0.0.1:9000       0.0.0.0:*    users:(("iobroker.js-con",pid=672,fd=26))
tcp   LISTEN 0      511             127.0.0.1:9001       0.0.0.0:*    users:(("iobroker.js-con",pid=672,fd=20))
tcp   LISTEN 0      511               0.0.0.0:50001      0.0.0.0:*    users:(("io.sia.0",pid=1748,fd=26))
tcp   LISTEN 0      4096        127.0.0.53%lo:53         0.0.0.0:*    users:(("systemd-resolve",pid=654,fd=14))
tcp   LISTEN 0      128               0.0.0.0:22         0.0.0.0:*    users:(("sshd",pid=720,fd=3))
tcp   LISTEN 0      511                     *:8082             *:*    users:(("io.web.0",pid=1152,fd=27))
tcp   LISTEN 0      128                  [::]:22            [::]:*    users:(("sshd",pid=720,fd=4))
tcp   LISTEN 0      511                     *:8087             *:*    users:(("io.simple-api.0",pid=1863,fd=26))

Wäre echt super wenn mir da noch jemand ein Tipp hätte.

[Thomas Braun]

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

ein Tipp hätte.

NodeJS v16 fahren.

[apollon77]

@woehrer Also als allererstes:

• iob stop
• 1 Minute warten
• iob fix - dort dann vor allem bitte schauen bei "Step 3" und Ausgabe posten bzw sagen wie lang das bedauert hat
• iob start

tuts dann?

[woehrer]

@apollon77 :

Der komplette fix ist in ca 15 Sekunden durchgelaufen. Das hatte ich schon versucht. Läuft leider trotzdem nicht.

woehrer@iobrokerifa:/opt/iobroker$ iobroker fix
library: loaded
Library version=2022-12-09

==========================================================================

    Welcome to the ioBroker installation fixer!
    Script version: 2022-12-09

    You might need to enter your password a couple of times.

==========================================================================


==========================================================================
    Installing prerequisites (1/4)
==========================================================================

[sudo] password for woehrer:
OK:1 https://deb.nodesource.com/node_14.x focal InRelease
OK:2 http://de.archive.ubuntu.com/ubuntu jammy InRelease
Holen:3 http://de.archive.ubuntu.com/ubuntu jammy-updates InRelease [114 kB]
Holen:4 http://de.archive.ubuntu.com/ubuntu jammy-backports InRelease [99,8 kB]
Holen:5 http://de.archive.ubuntu.com/ubuntu jammy-security InRelease [110 kB]
Es wurden 324 kB in 1 s geholt (501 kB/s).
Paketlisten werden gelesen… Fertig
Installed gcc-c++

==========================================================================
    Checking ioBroker user and directory permissions (2/4)
==========================================================================

Created /etc/sudoers.d/iobroker
Fixing directory permissions...

==========================================================================
    Database maintenance (3/4)
==========================================================================

Checking for uncompressed JSONL databases... This might take a while!

npx: Installierte 12 in 4.456s
No path given, using /opt/iobroker/iobroker-data
Compressing /opt/iobroker/iobroker-data/states.jsonl
Compressing /opt/iobroker/iobroker-data/objects.jsonl
Compressed 2 JSONL files. Done

==========================================================================
    Checking autostart (4/4)
==========================================================================

Enabling autostart...
Autostart enabled!

==========================================================================

    Your installation was fixed successfully
    Run iobroker start to start ioBroker again!

==========================================================================