Jahresrückblick 2025 – unser neuer Blogbeitrag ist online! ✨

[LJSven]

Hallo zusammen,

ich bekomme mein System nicht stabil und habe keine Idee, wo ich suchen muss / soll. Würde mich über Hilfe freuen. Im Log stehen des öfteren Einträge wie:

2019-03-02 08:50:31.904 - error: admin.0 already running
2019-03-02 08:50:32.076 - error: host.bananapimaster instance system.adapter.admin.0 terminated with code 7 (Adapter already running)
2019-03-02 08:50:32.078 - info: host.bananapimaster Restart adapter system.adapter.admin.0 because enabled

Wo kann da der Fehler sein? Es sind auch mal unteschiedliche Adapter.

[Homoran]

@LJSven
Bei code7 ist es zu einem restart der Instanz gekommen, ohne dass der alte Prozess auf linux Ebene beendet wurde.
Daher laufen zwei Prozesse.

Bitte bpi rebooten
Oder den prozess sauber beenden und anschließend iobroker start admin durchführen

[LJSven]

Habe ich gemacht. Die Frage ist, warum das passiert?

[Homoran]

@LJSven sagte in BananaPi Master / RaspberryPi Slave - läuft nicht stabil:

warum das passiert?

Gute Frage, nächste Frage ;-)

Was war denn zum Zeitpunkt als die Meldungen anfingen?

[LJSven]

So sieht die Log aus ->

Spoiler

2019-03-02 03:37:46.543 - error: iot.0 read ECONNRESET
2019-03-02 03:37:46.545 - info: iot.0 Connection changed: disconnect
2019-03-02 03:37:46.546 - info: iot.0 Connection lost
2019-03-02 03:37:50.806 - info: alexa2.0 Alexa-Push-Connection disconnected - retry: Retry Connection in 5s
2019-03-02 03:37:51.845 - info: iot.0 Connection changed: connect
2019-03-02 03:37:56.898 - info: alexa2.0 Alexa-Push-Connection established. Disable Polling
2019-03-02 03:38:04.955 - error: telegram.0 polling_error:EFATAL, EFATAL: Error: read ECONNRESET
2019-03-02 03:38:20.822 - info: alexa2.0 Alexa-Push-Connection disconnected - retry: Retry Connection in 5s
2019-03-02 03:38:26.708 - info: alexa2.0 Alexa-Push-Connection established. Disable Polling
2019-03-02 04:00:00.175 - info: host.bananapimaster instance system.adapter.ical.0 started with pid 25111
2019-03-02 04:00:05.225 - info: ical.0 starting. Version 1.7.0 in /opt/iobroker/node_modules/iobroker.ical, node: v8.15.0
2019-03-02 04:00:13.286 - info: host.bananapimaster instance system.adapter.ical.0 terminated with code 0 (OK)
2019-03-02 04:29:56.006 - error: sonoff.0 websocket error
2019-03-02 04:29:56.019 - error: sonoff.0 Error: websocket error
at WS.Transport.onError (/opt/iobroker/node_modules/iobroker.js-controller/node_modules/engine.io-client/lib/transport.js:64:13)
at WebSocket.ws.onerror (/opt/iobroker/node_modules/iobroker.js-controller/node_modules/engine.io-client/lib/transports/websocket.js:150:10)
at WebSocket.onError (/opt/iobroker/node_modules/iobroker.js-controller/node_modules/ws/lib/EventTarget.js:109:16)
at emitOne (events.js:116:13)
at WebSocket.emit (events.js:211:7)
at WebSocket.finalize (/opt/iobroker/node_modules/iobroker.js-controller/node_modules/ws/lib/WebSocket.js:182:41)
at emitOne (events.js:116:13)
at Socket.emit (events.js:211:7)
at emitErrorNT (internal/streams/destroy.js:66:8)
at _combinedTickCallback (internal/process/next_tick.js:139:11)
2019-03-02 05:04:00.081 - info: telegram.0 Scheduled restart.
2019-03-02 05:04:01.599 - info: telegram.0 terminating with timeout
2019-03-02 05:20:15.581 - info: javascript.0 script.js.common.Sonstige.Astro-Tageszeit: neue Tagezeit: Morgendämmerung
2019-03-02 05:20:15.583 - info: javascript.0 script.js.common.Sonstige.Astro-Tageszeit: nächte kommende Tagezeit: Sonnenaufgang
2019-03-02 07:18:17.604 - info: javascript.0 script.js.common.Sonstige.Astro-Tageszeit: neue Tagezeit: Sonnenaufgang
2019-03-02 07:18:17.606 - info: javascript.0 script.js.common.Sonstige.Astro-Tageszeit: nächte kommende Tagezeit: Morgen
2019-03-02 07:21:49.848 - info: javascript.0 script.js.common.Sonstige.Astro-Tageszeit: neue Tagezeit: Morgen
2019-03-02 07:21:49.850 - info: javascript.0 script.js.common.Sonstige.Astro-Tageszeit: nächte kommende Tagezeit: Vormittag

[Homoran]

@LJSven
Das log geht nur bis 7:21, da ist noch kein code7 drin.

Im anderen Ausschnitt war es 8:50

[LJSven]

Das stimmt - der Auslöser warum das System in die Knie gegangen ist, war aber um 4:29 Uhr

Hier der Log nach 8 (war schon nach dem Neustart):

Spoiler

2019-03-02 08:39:41.406 - info: host.bananapimaster instance system.adapter.iot.0 started with pid 2815
2019-03-02 08:39:46.150 - info: host.bananapimaster instance system.adapter.info.0 started with pid 2862
2019-03-02 08:39:49.357 - info: vis-google-fonts.0 starting. Version 0.1.0 in /opt/iobroker/node_modules/iobroker.vis-google-fonts, node: v8.15.0
2019-03-02 08:39:50.413 - info: host.bananapimaster instance system.adapter.vis-google-fonts.0 terminated while should be started once
2019-03-02 08:40:01.698 - error: info.0 no connection to objects DB
2019-03-02 08:40:05.339 - warn: backitup.0 Reconnection to DB.
2019-03-02 08:40:05.344 - warn: backitup.0 Reconnection to DB.
2019-03-02 08:40:05.360 - warn: zigbee.0 Reconnection to DB.
2019-03-02 08:40:05.373 - warn: zigbee.0 Reconnection to DB.
2019-03-02 08:40:05.542 - error: backitup.0 already running
2019-03-02 08:40:05.556 - error: zigbee.0 already running
2019-03-02 08:40:05.870 - warn: admin.0 Reconnection to DB.
2019-03-02 08:40:05.880 - warn: admin.0 Reconnection to DB.
2019-03-02 08:40:06.275 - error: host.bananapimaster instance system.adapter.backitup.0 terminated with code 7 (Adapter already running)
2019-03-02 08:40:06.277 - info: host.bananapimaster Restart adapter system.adapter.backitup.0 because enabled
2019-03-02 08:40:06.296 - error: host.bananapimaster instance system.adapter.zigbee.0 terminated with code 7 (Adapter already running)
2019-03-02 08:40:06.296 - info: host.bananapimaster Restart adapter system.adapter.zigbee.0 because enabled
2019-03-02 08:40:06.413 - error: admin.0 already running
2019-03-02 08:40:06.621 - error: host.bananapimaster instance system.adapter.admin.0 terminated with code 7 (Adapter already running)
2019-03-02 08:40:06.559 - info: tr-064.0 starting. Version 0.4.18 in /opt/iobroker/node_modules/iobroker.tr-064, node: v8.15.0
2019-03-02 08:40:06.623 - info: host.bananapimaster Restart adapter system.adapter.admin.0 because enabled
2019-03-02 08:40:06.862 - info: info.0 starting. Version 1.1.3 in /opt/iobroker/node_modules/iobroker.info, node: v8.15.0
2019-03-02 08:40:08.273 - info: iot.0 starting. Version 0.3.1 in /opt/iobroker/node_modules/iobroker.iot, node: v8.15.0
2019-03-02 08:40:08.350 - info: iot.0 Connecting with a18wym7vjdl22g.iot.eu-west-1.amazonaws.com
2019-03-02 08:40:09.381 - warn: opi.0 Reconnection to DB.
2019-03-02 08:40:09.398 - warn: opi.0 Reconnection to DB.
2019-03-02 08:40:15.660 - info: iot.0 Connection changed: connect
2019-03-02 08:40:15.685 - error: iot.0 Cannot report device state: null
2019-03-02 08:40:15.688 - warn: iot.0 Invalid URL key. Status update is disabled: {"error":"Unsupported version"}
2019-03-02 08:40:36.356 - info: host.bananapimaster instance system.adapter.backitup.0 started with pid 3311
2019-03-02 08:40:36.445 - info: host.bananapimaster instance system.adapter.zigbee.0 started with pid 3316
2019-03-02 08:40:36.707 - info: host.bananapimaster instance system.adapter.admin.0 started with pid 3323

[Homoran]

@LJSven
Und genau zwischen den beiden logs musst du suchen

[LJSven]

Okay, es tut mir leid - ich kann da nichts sehen. Die erste Frage ist ja, was die Meldung um 4:29 Uhr bedeutet?! Da hat sich das System verabschiedet. Die 2. Frage ist, warum nach einem Reboot diese code7 Meldungen kommen.

[Homoran]

@LJSven sagte in BananaPi Master / RaspberryPi Slave - läuft nicht stabil:

warum nach einem Reboot diese code7 Meldungen kommen.

Reboot oder restart?

Nach einem reboot sollten sie nicht kommen

[LJSven]

Ich mache folgendes als root

cd /opt/iobroker
iobroker stop
reboot

nachdem heute Nacht um 4:29 Uhr sich das System mit der o.g. Fehlermeldung aufgehangen hat. Nach dem Neustart kommen dann die Meldungen mit code7

[Homoran]

Auch im ersten log fehlt die eigentliche ursache.

Was man da sieht ist nur, dass es anschließend verbindungsprobleme gibt.

Das könnte z.b. wegen der Zwangstrennung des ISP sein.
Dein ioBroker kommt dann nicht mehr ins Internet

[LJSven]

Die Zwangstrennung war um 03:37 - danach hat er die Verbindung auch wieder aufgebaut. Habe gerade nochmal in der Fritzbox nachgeschaut, danach war von Seiten des ISP kein Abbruch mehr.

Spoiler

2019-03-02 03:37:46.543 - error: iot.0 read ECONNRESET
2019-03-02 03:37:46.545 - info: iot.0 Connection changed: disconnect
2019-03-02 03:37:46.546 - info: iot.0 Connection lost
2019-03-02 03:37:50.806 - info: alexa2.0 Alexa-Push-Connection disconnected - retry: Retry Connection in 5s
2019-03-02 03:37:51.845 - info: iot.0 Connection changed: connect
2019-03-02 03:37:56.898 - info: alexa2.0 Alexa-Push-Connection established. Disable Polling
2019-03-02 03:38:04.955 - error: telegram.0 polling_error:EFATAL, EFATAL: Error: read ECONNRESET
2019-03-02 03:38:20.822 - info: alexa2.0 Alexa-Push-Connection disconnected - retry: Retry Connection in 5s
2019-03-02 03:38:26.708 - info: alexa2.0 Alexa-Push-Connection established. Disable Polling
2019-03-02 04:00:00.175 - info: host.bananapimaster instance system.adapter.ical.0 started with pid 25111
2019-03-02 04:00:05.225 - info: ical.0 starting. Version 1.7.0 in /opt/iobroker/node_modules/iobroker.ical, node: v8.15.0
2019-03-02 04:00:05.994 - info: ical.0 processing URL: Müllabfuhr https://calendar.google.com/calendar/ical/iv3htfrk6ua9t038g9u35c02uo%40group.calendar.google.com/private-dee65d06cf0190e3c162d7f916e3ed0b/basic.ics
2019-03-02 04:00:07.228 - info: ical.0 processing URL: ItaloBrothers https://calendar.google.com/calendar/ical/0ah106cilokm7mvs5i3v7cpm64%40group.calendar.google.com/private-a8dd673b0bad076698a352d940c2d828/basic.ics
2019-03-02 04:00:13.286 - info: host.bananapimaster instance system.adapter.ical.0 terminated with code 0 (OK)
2019-03-02 04:29:56.006 - error: sonoff.0 websocket error
2019-03-02 04:29:56.019 - error: sonoff.0 Error: websocket error
at WS.Transport.onError (/opt/iobroker/node_modules/iobroker.js-controller/node_modules/engine.io-client/lib/transport.js:64:13)
at WebSocket.ws.onerror (/opt/iobroker/node_modules/iobroker.js-controller/node_modules/engine.io-client/lib/transports/websocket.js:150:10)
at WebSocket.onError (/opt/iobroker/node_modules/iobroker.js-controller/node_modules/ws/lib/EventTarget.js:109:16)
at emitOne (events.js:116:13)
at WebSocket.emit (events.js:211:7)
at WebSocket.finalize (/opt/iobroker/node_modules/iobroker.js-controller/node_modules/ws/lib/WebSocket.js:182:41)
at emitOne (events.js:116:13)
at Socket.emit (events.js:211:7)
at emitErrorNT (internal/streams/destroy.js:66:8)
at _combinedTickCallback (internal/process/next_tick.js:139:11)
2019-03-02 05:04:00.081 - info: telegram.0 Scheduled restart.
2019-03-02 05:04:01.599 - info: telegram.0 terminating with timeout