UPDATE 31.10.: Amazon Alexa - ioBroker Skill läuft aus ?

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

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

[woehrer]

@thomas-braun

Bin jetzt mal hoch auf v16

woehrer@iobrokerifa:/opt/iobroker$ node -v
v16.19.0
woehrer@iobrokerifa:/opt/iobroker$ npm -v
8.19.3
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)
==========================================================================

OK:1 http://de.archive.ubuntu.com/ubuntu jammy InRelease
Holen:2 http://de.archive.ubuntu.com/ubuntu jammy-updates InRelease [114 kB]
OK:3 https://deb.nodesource.com/node_16.x jammy InRelease  
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 (576 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!

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!

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

Bekomme immernoch die Fehlermeldung und der admin Adapter startet weiterhin nicht. Alles andere scheint aber zu laufen

[Thomas Braun]

@woehrer

iobroker diag

ausführen und Ergebnisse bekannt geben.

[crunchip]

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

und der admin Adapter startet weiterhin nicht

iob logs --watch

iob list instances

[woehrer]

@woehrer

======================= SUMMARY =======================
                        v.2022-12-13


Operatingsystem:        Ubuntu 22.04.1 LTS
Installation:           microsoft
Timezone:               Europe/Berlin
User-ID:                1000
X-Server:               false

Pending OS-Updates:     0

Nodejs-Installation:    /usr/bin/nodejs         v16.19.0
                        /usr/bin/node           v16.19.0
                        /usr/bin/npm            8.19.3

ioBroker Core:          js-controller           4.0.23
                        admin                   6.3.3

ioBroker Status:        iobroker is running on this host.


Objects type: jsonl
States  type: jsonl

Pending iob updates:    2

Active repo(s): stable

Objects:                6726
States:                 6193

Size of iob-Database:

7.5M    /opt/iobroker/iobroker-data/objects.jsonl
4.7M    /opt/iobroker/iobroker-data/objects.json.migrated
4.7M    /opt/iobroker/iobroker-data/objects.json.bak.migrated
5.0M    /opt/iobroker/iobroker-data/states.jsonl
1.2M    /opt/iobroker/iobroker-data/states.json.migrated
1.2M    /opt/iobroker/iobroker-data/states.json.bak.migrated


====================== END OF SUMMARY ==================

2022-12-22 09:47:26.773  - info: host.iobrokerifa instance system.adapter.admin.0 started with pid 3788
2022-12-22 09:47:26.773  - info: host.iobrokerifa instance system.adapter.admin.0 started with pid 3788
2022-12-22 09:47:27.787  - info: admin.0 (3788) starting. Version 6.3.3 in /opt/iobroker/node_modules/iobroker.admin, node: v16.19.0, js-controller: 4.0.23
2022-12-22 09:47:27.814  - info: admin.0 (3788) requesting all states
2022-12-22 09:47:27.816  - info: admin.0 (3788) requesting all objects
2022-12-22 09:47:27.956  - warn: admin.0 (3788) Cannot check node.js versions: Error: unexpected end of file
2022-12-22 09:47:28.326  - info: admin.0 (3788) received all objects
2022-12-22 09:47:28.438  - info: admin.0 (3788) Request actual repository...
2022-12-22 09:47:28.523  - info: admin.0 (3788) http server listening on port 8081
2022-12-22 09:47:28.523  - info: admin.0 (3788) Use link "http://localhost:8081" to configure.
2022-12-22 09:47:28.527  - info: admin.0 (3788) socket.io server listening on port 8081
2022-12-22 09:47:28.539  - error: admin.0 (3788) uncaught exception: Cannot read properties of null (reading '_acl')
2022-12-22 09:47:28.539  - error: admin.0 (3788) TypeError: Cannot read properties of null (reading '_acl')
    at SocketCommandsAdmin.subscribe (/opt/iobroker/node_modules/@iobroker/socket-classes/lib/socketCommands.js:288:117)
    at SocketAdmin.subscribe (/opt/iobroker/node_modules/@iobroker/socket-classes/lib/socketAdmin.js:181:23)
    at initSocket (/opt/iobroker/node_modules/iobroker.admin/main.js:499:12)
    at Immediate.<anonymous> (/opt/iobroker/node_modules/iobroker.admin/lib/web.js:1048:29)
    at processImmediate (node:internal/timers:468:21)
2022-12-22 09:47:28.540  - error: admin.0 (3788) Cannot read properties of null (reading '_acl')
2022-12-22 09:47:28.556  - info: admin.0 (3788) terminating http server on port 8081
2022-12-22 09:47:28.560  - info: admin.0 (3788) terminating
2022-12-22 09:47:28.561  - warn: admin.0 (3788) Terminated (UNCAUGHT_EXCEPTION): Without reason
2022-12-22 09:47:28.779  - info: host.iobrokerifa Updating repository "stable" under "http://download.iobroker.net/sources-dist.json"
2022-12-22 09:47:28.814  - error: host.iobrokerifa Caught by controller[0]: TypeError: Cannot read properties of null (reading '_acl')
2022-12-22 09:47:28.814  - error: host.iobrokerifa Caught by controller[0]:     at SocketCommandsAdmin.subscribe (/opt/iobroker/node_modules/@iobroker/socket-classes/lib/socketCommands.js:288:117)
2022-12-22 09:47:28.814  - error: host.iobrokerifa Caught by controller[0]:     at SocketAdmin.subscribe (/opt/iobroker/node_modules/@iobroker/socket-classes/lib/socketAdmin.js:181:23)
2022-12-22 09:47:28.814  - error: host.iobrokerifa Caught by controller[0]:     at initSocket (/opt/iobroker/node_modules/iobroker.admin/main.js:499:12)
2022-12-22 09:47:28.814  - error: host.iobrokerifa Caught by controller[0]:     at Immediate.<anonymous> (/opt/iobroker/node_modules/iobroker.admin/lib/web.js:1048:29)
2022-12-22 09:47:28.814  - error: host.iobrokerifa Caught by controller[0]:     at processImmediate (node:internal/timers:468:21)
2022-12-22 09:47:28.814  - error: host.iobrokerifa instance system.adapter.admin.0 terminated with code 1 (JS_CONTROLLER_STOPPED)
2022-12-22 09:47:28.814  - info: host.iobrokerifa Restart adapter system.adapter.admin.0 because enabled
2022-12-22 09:47:27.787  - info: admin.0 (3788) starting. Version 6.3.3 in /opt/iobroker/node_modules/iobroker.admin, node: v16.19.0, js-controller: 4.0.23
2022-12-22 09:47:27.814  - info: admin.0 (3788) requesting all states
2022-12-22 09:47:27.816  - info: admin.0 (3788) requesting all objects
2022-12-22 09:47:27.956  - warn: admin.0 (3788) Cannot check node.js versions: Error: unexpected end of file
2022-12-22 09:47:28.326  - info: admin.0 (3788) received all objects
2022-12-22 09:47:28.438  - info: admin.0 (3788) Request actual repository...
2022-12-22 09:47:28.523  - info: admin.0 (3788) http server listening on port 8081
2022-12-22 09:47:28.523  - info: admin.0 (3788) Use link "http://localhost:8081" to configure.
2022-12-22 09:47:28.527  - info: admin.0 (3788) socket.io server listening on port 8081
2022-12-22 09:47:28.539  - error: admin.0 (3788) uncaught exception: Cannot read properties of null (reading '_acl')
2022-12-22 09:47:28.539  - error: admin.0 (3788) TypeError: Cannot read properties of null (reading '_acl')
    at SocketCommandsAdmin.subscribe (/opt/iobroker/node_modules/@iobroker/socket-classes/lib/socketCommands.js:288:117)
    at SocketAdmin.subscribe (/opt/iobroker/node_modules/@iobroker/socket-classes/lib/socketAdmin.js:181:23)
    at initSocket (/opt/iobroker/node_modules/iobroker.admin/main.js:499:12)
    at Immediate.<anonymous> (/opt/iobroker/node_modules/iobroker.admin/lib/web.js:1048:29)
    at processImmediate (node:internal/timers:468:21)
2022-12-22 09:47:28.540  - error: admin.0 (3788) Cannot read properties of null (reading '_acl')
2022-12-22 09:47:28.556  - info: admin.0 (3788) terminating http server on port 8081
2022-12-22 09:47:28.560  - info: admin.0 (3788) terminating
2022-12-22 09:47:28.561  - warn: admin.0 (3788) Terminated (UNCAUGHT_EXCEPTION): Without reason
2022-12-22 09:47:28.779  - info: host.iobrokerifa Updating repository "stable" under "http://download.iobroker.net/sources-dist.json"
2022-12-22 09:47:28.814  - error: host.iobrokerifa Caught by controller[0]: TypeError: Cannot read properties of null (reading '_acl')
2022-12-22 09:47:28.814  - error: host.iobrokerifa Caught by controller[0]:     at SocketCommandsAdmin.subscribe (/opt/iobroker/node_modules/@iobroker/socket-classes/lib/socketCommands.js:288:117)
2022-12-22 09:47:28.814  - error: host.iobrokerifa Caught by controller[0]:     at SocketAdmin.subscribe (/opt/iobroker/node_modules/@iobroker/socket-classes/lib/socketAdmin.js:181:23)
2022-12-22 09:47:28.814  - error: host.iobrokerifa Caught by controller[0]:     at initSocket (/opt/iobroker/node_modules/iobroker.admin/main.js:499:12)
2022-12-22 09:47:28.814  - error: host.iobrokerifa Caught by controller[0]:     at Immediate.<anonymous> (/opt/iobroker/node_modules/iobroker.admin/lib/web.js:1048:29)
2022-12-22 09:47:28.814  - error: host.iobrokerifa Caught by controller[0]:     at processImmediate (node:internal/timers:468:21)
2022-12-22 09:47:28.814  - error: host.iobrokerifa instance system.adapter.admin.0 terminated with code 1 (JS_CONTROLLER_STOPPED)
2022-12-22 09:47:28.814  - info: host.iobrokerifa Restart adapter system.adapter.admin.0 because enabled

[Thomas Braun]

@woehrer

Das ist WSL2 oder sowas?