Backup kann nicht eingespielt werden - iobroker stürzt ab

[oetzi]

@glasfaser
Der Fußweg über die Konsole hat tatsächlich funktioniert. Gucke mir später noch in Ruhe an, ob alles läuft wie es soll.

Dennoch wäre es ja interessant zu wissen, warum der Adapter backitup nicht (mehr) funktioniert. Da er ja vor einigen Wochen mal erfolgreich gelaufen ist, kann es eher nicht an meinem Grundsetting liegen.

Interessanterweise hat der Kollege @th-g im verlinkten Thread (https://forum.iobroker.net/topic/50419/erledigt-probleme-mit-backitup/43) genau das gleiche Problem beschrieben wie ich:

"Der Restore startet, der bunte Kreis dreht sich, im zweiten Fenster kommt die Meldung "Website ist nicht erreichbar" und das wars.

Der iobroker wird dann auch im Container gestoppt."

@simatec
Falls du dem Problem auf den Grund gehen möchtest kann ich dir anbieten zu unterstützen.

Mein Netzwerk ist übrigens auf MAC_VLAN eingestellt, falls das noch eine Rolle spielen kann.

[simatec]

@oetzi Denke wir fangen mal am Anfang an ...
Wenn du Backitup auf debug stellst, sollte nach dem Neustart des Adapters ein Debuglog kommen, in dem steht, welches System erkannt wurde.

backitup.0 2022-07-03 19:45:36.143	debug	Backitup has recognized a Docker system

Poste bitte mal die Log-Ausgaben.

[oetzi]

@simatec

Mhh, leider nicht so wirklich:

2022-07-04 19:23:09.981 - info: host.iobroker stopInstance system.adapter.backitup.0 (force=false, process=true)
2022-07-04 19:23:09.989 - info: backitup.0 (476) Got terminate signal TERMINATE_YOURSELF
2022-07-04 19:23:09.990 - info: backitup.0 (476) cleaned everything up...
2022-07-04 19:23:09.991 - info: backitup.0 (476) terminating
2022-07-04 19:23:09.992 - debug: backitup.0 (476) Plugin sentry destroyed
2022-07-04 19:23:09.993 - info: backitup.0 (476) Terminated (ADAPTER_REQUESTED_TERMINATION): Without reason
2022-07-04 19:23:10.027 - info: host.iobroker stopInstance system.adapter.backitup.0 send kill signal
2022-07-04 19:23:10.617 - info: host.iobroker instance system.adapter.backitup.0 terminated with code 11 (ADAPTER_REQUESTED_TERMINATION)
2022-07-04 19:23:13.115 - info: host.iobroker instance system.adapter.backitup.0 started with pid 1062
2022-07-04 19:23:20.214 - debug: backitup.0 (1062) Redis Objects: Use Redis connection: 127.0.0.1:9001
2022-07-04 19:23:20.293 - debug: backitup.0 (1062) Objects client ready ... initialize now
2022-07-04 19:23:20.296 - debug: backitup.0 (1062) Objects create System PubSub Client
2022-07-04 19:23:20.298 - debug: backitup.0 (1062) Objects create User PubSub Client
2022-07-04 19:23:20.345 - debug: backitup.0 (1062) Objects client initialize lua scripts
2022-07-04 19:23:20.366 - debug: backitup.0 (1062) Objects connected to redis: 127.0.0.1:9001
2022-07-04 19:23:20.391 - debug: backitup.0 (1062) Redis States: Use Redis connection: 127.0.0.1:9000
2022-07-04 19:23:20.401 - debug: backitup.0 (1062) States create System PubSub Client
2022-07-04 19:23:20.403 - debug: backitup.0 (1062) States create User PubSub Client
2022-07-04 19:23:20.423 - debug: backitup.0 (1062) States connected to redis: 127.0.0.1:9000
2022-07-04 19:23:20.490 - debug: backitup.0 (1062) Plugin sentry Initialize Plugin (enabled=true)
2022-07-04 19:23:21.580 - info: backitup.0 (1062) starting. Version 2.1.13 in /opt/iobroker/node_modules/iobroker.backitup, node: v16.15.1, js-controller: 4.0.21
2022-07-04 19:23:21.740 - info: backitup.0 (1062) [iobroker] backup was activated at 02:00 every 7 day(s)
2022-07-04 19:23:21.822 - info: backitup.0 (1062) [ccu] backup was activated at 01:30 every 7 day(s)
2022-07-04 19:23:21.834 - debug: backitup.0 (1062) No backup file was found

[Thomas Braun]

@oetzi sagte in Backup kann nicht eingespielt werden - iobroker stürzt ab:

js-controller: 4.0.21

Bring das System auf Stand. Und beweg den Zeitpunkt des Backups von 2 Uhr weg auf was 'krummes'.

[simatec]

@oetzi Backitup v2.1.13?
Die ist fast 2 Jahre alt … Bring erstmal dein System auf aktuellen Stand.
2.4.9 ist aktuell

[Thomas Braun]

@simatec

Ach, weißt du doch: 'Never change a rotten system'. Oder so ähnlich.

@oetzi Was gammelt denn da sonst noch so herum?

iobroker update -i
sudo ln -s /usr/bin/node /usr/bin/nodejs
uname -m && which nodejs node npm && nodejs -v && node -v && npm -v && whoami && pwd && sudo apt update &> /dev/null && sudo apt update && apt policy nodejs
 

[oetzi]

@thomas-braun
@simatec

Stop!!
Das war der Stand von dem Backup, welches ich vor einigen Wochen erfolgreich (über backitup) wiederherstellen konnte. Hatte gestern beim manuellen Backup die falsche Datei erwischt.
Bin gerade dabei über den manuellen Weg einen recht aktuellen (Stand ca. vor 2 Monate) Stand einzuspielen.

Aber davon mal kurz unabhängig: Wenn ich einen Stand X einspiele, der damals lauffähig war, sollte dann nicht auch wieder das Backitup von damals laufen?!

[Thomas Braun]

@oetzi

Naja, so ein uraltes Backup braucht ja auch kein Mensch.

[oetzi]

@thomas-braun said in Backup kann nicht eingespielt werden - iobroker stürzt ab:

@oetzi

Naja, so ein uraltes Backup braucht ja auch kein Mensch.

In wie weit soll so ein Kommentar jetzt genau helfen...?

Das Backup selbst war ca. ein halbes Jahr alt. Mag sein, dass die Adapter damals nicht alle auf dem aktuellsten Stand waren. Es war aber ein lauffähiges System, was gesichert wurde und daher hätte ich wie eben geschrieben stark erwartet, dass das System wieder vollständig läuft, wenn ich es wiederherstelle.

Wie auch immer, hier ein aktuelles Debug Log:

2022-07-04 19:50:49.223 - info: backitup.0 (685) Got terminate signal TERMINATE_YOURSELF
2022-07-04 19:50:49.225 - info: backitup.0 (685) cleaned everything up...
2022-07-04 19:50:49.229 - info: backitup.0 (685) terminating
2022-07-04 19:50:49.230 - debug: backitup.0 (685) Plugin sentry destroyed
2022-07-04 19:50:49.230 - info: backitup.0 (685) Terminated (ADAPTER_REQUESTED_TERMINATION): Without reason
2022-07-04 19:50:49.300 - info: host.iobroker stopInstance system.adapter.backitup.0 send kill signal
2022-07-04 19:50:49.807 - info: host.iobroker instance system.adapter.backitup.0 terminated with code 11 (ADAPTER_REQUESTED_TERMINATION)
2022-07-04 19:50:52.385 - info: host.iobroker instance system.adapter.backitup.0 started with pid 1812
2022-07-04 19:50:53.529 - debug: backitup.0 (1812) Redis Objects: Use Redis connection: 127.0.0.1:9001
2022-07-04 19:50:53.588 - debug: backitup.0 (1812) Objects client ready ... initialize now
2022-07-04 19:50:53.599 - debug: backitup.0 (1812) Objects create System PubSub Client
2022-07-04 19:50:53.601 - debug: backitup.0 (1812) Objects create User PubSub Client
2022-07-04 19:50:53.634 - debug: backitup.0 (1812) Objects client initialize lua scripts
2022-07-04 19:50:53.641 - debug: backitup.0 (1812) Objects connected to redis: 127.0.0.1:9001
2022-07-04 19:50:53.666 - debug: backitup.0 (1812) Redis States: Use Redis connection: 127.0.0.1:9000
2022-07-04 19:50:53.678 - debug: backitup.0 (1812) States create System PubSub Client
2022-07-04 19:50:53.680 - debug: backitup.0 (1812) States create User PubSub Client
2022-07-04 19:50:53.739 - debug: backitup.0 (1812) States connected to redis: 127.0.0.1:9000
2022-07-04 19:50:53.802 - debug: backitup.0 (1812) Plugin sentry Initialize Plugin (enabled=true)
2022-07-04 19:50:54.142 - info: backitup.0 (1812) starting. Version 2.4.6 in /opt/iobroker/node_modules/iobroker.backitup, node: v16.15.1, js-controller: 4.0.21
2022-07-04 19:50:54.196 - debug: backitup.0 (1812) Backitup has recognized a Docker system
2022-07-04 19:50:54.219 - info: backitup.0 (1812) [iobroker] backup was activated at 02:00 every 7 day(s)
2022-07-04 19:50:54.327 - info: backitup.0 (1812) [ccu] backup was activated at 01:30 every 7 day(s)
2022-07-04 19:50:54.350 - debug: backitup.0 (1812) No backup file was found

Teste jetzt gleich mal, ob ich von diesem Stand aus über backitup arbeiten kann.

[oetzi]

Nope

Hab ein frisches Backup erstellen lassen und versucht dieses direkt wieder einzuspielen.

[simatec]

@oetzi Naja mit der Version war Docker noch nicht vollumfänglich unterstützt.
Darum bitte erst mal auf aktuellen Stand bringen.

[Thomas Braun]

@oetzi sagte in Backup kann nicht eingespielt werden - iobroker stürzt ab:

Version 2.4.6 in /opt/iobroker/node_modules/iobroker.backitup, node: v16.15.1, js-controller: 4.0.21

Immer noch keine aktuellen Versionen. Patch das System durch. Komplett, ganz, total, ALLES.

[simatec]

@oetzi Zeige doch mal, was in der Debugkonsole deines Browsers steht.
Hast du nur Firefox? Versuche sonst mal bitte zum testen Chrome.

Unabhängig von der fehlenden Verfügbarkeit der Restore Page sollte der Restore im Hintergrund laufen

Bitte auch nochmal ein Debuglog vom Start des Adapters. Wird Docker erkannt?

[simatec]

@thomas-braun korrekt… js-Controller ist auch sehr alt

[oetzi]

@simatec said in Backup kann nicht eingespielt werden - iobroker stürzt ab:

@thomas-braun korrekt… js-Controller ist auch sehr alt

Ach kommt...

Wo ist das denn bitte "sehr alt"?!

Aber okay, neben backitup auf 2.4.9 habe ich auch das Update des js-controllers gemacht.

@simatec said in Backup kann nicht eingespielt werden - iobroker stürzt ab:

Bitte auch nochmal ein Debuglog vom Start des Adapters. Wird Docker erkannt?

Hier das aktuelle Log. Diesmal auch mit "Backitup has recognized a Docker system"

2022-07-04 20:46:57.923 - info: host.iobroker "system.adapter.backitup.0" enabled
2022-07-04 20:46:58.136 - info: host.iobroker instance system.adapter.backitup.0 started with pid 1828
2022-07-04 20:46:59.395 - debug: backitup.0 (1828) Redis Objects: Use Redis connection: 127.0.0.1:9001
2022-07-04 20:46:59.464 - debug: backitup.0 (1828) Objects client ready ... initialize now
2022-07-04 20:46:59.468 - debug: backitup.0 (1828) Objects create System PubSub Client
2022-07-04 20:46:59.469 - debug: backitup.0 (1828) Objects create User PubSub Client
2022-07-04 20:46:59.504 - debug: backitup.0 (1828) Objects client initialize lua scripts
2022-07-04 20:46:59.512 - debug: backitup.0 (1828) Objects connected to redis: 127.0.0.1:9001
2022-07-04 20:46:59.537 - debug: backitup.0 (1828) Redis States: Use Redis connection: 127.0.0.1:9000
2022-07-04 20:46:59.548 - debug: backitup.0 (1828) States create System PubSub Client
2022-07-04 20:46:59.549 - debug: backitup.0 (1828) States create User PubSub Client
2022-07-04 20:46:59.587 - debug: backitup.0 (1828) States connected to redis: 127.0.0.1:9000
2022-07-04 20:46:59.656 - debug: backitup.0 (1828) Plugin sentry Initialize Plugin (enabled=true)
2022-07-04 20:47:00.155 - info: backitup.0 (1828) starting. Version 2.4.9 in /opt/iobroker/node_modules/iobroker.backitup, node: v16.15.1, js-controller: 4.0.23
2022-07-04 20:47:00.212 - debug: backitup.0 (1828) Backitup has recognized a Docker system
2022-07-04 20:47:00.234 - info: backitup.0 (1828) [iobroker] backup was activated at 02:00 every 7 day(s)
2022-07-04 20:47:00.471 - info: backitup.0 (1828) [ccu] backup was activated at 01:30 every 7 day(s)
2022-07-04 20:47:00.494 - debug: backitup.0 (1828) No backup file was found

Mit dem Chrome sieht es so aus:

Zwar weniger Text, aber wohl das gleiche Problem.

[Thomas Braun]

@oetzi sagte in Backup kann nicht eingespielt werden - iobroker stürzt ab:

Wo ist das denn bitte "sehr alt"?!

Alles was als 'updateable' markiert ist ist veraltet.

[simatec]

@oetzi hast du https aktiv?
Was sagt die Browserkonsole? Gibt es da eine Fehlermeldung?

[oetzi]

@simatec
Nein, kein https.

Die Browserkonsole schmeißt Fehler:

Hier der Inhalt des Screenshot nochmal als Text:

21:28:32.449 "Started restore ...": {"en": "Started restore ...", "de": "Started restore ...", "ru": "Started restore ...", "pt": "Started restore ...", "nl": "Started restore ...", "fr": "Started restore ...", "es": "Started restore ...", "pl": "Started restore ...", "it": "Started restore ...", "zh-cn": "Started restore ..."}, translate.js:24:17
21:28:32.454 "ioBroker will be stopped and started again. Please wait": {"en": "ioBroker will be stopped and started again. Please wait", "de": "ioBroker will be stopped and started again. Please wait", "ru": "ioBroker will be stopped and started again. Please wait", "pt": "ioBroker will be stopped and started again. Please wait", "nl": "ioBroker will be stopped and started again. Please wait", "fr": "ioBroker will be stopped and started again. Please wait", "es": "ioBroker will be stopped and started again. Please wait", "pl": "ioBroker will be stopped and started again. Please wait", "it": "ioBroker will be stopped and started again. Please wait", "zh-cn": "ioBroker will be stopped and started again. Please wait"}, translate.js:24:17
21:28:32.484 Restore finish! tab_m.js:334:53
21:28:32.485 Restore Url: http://192.168.178.200:8091/backitup-restore.html tab_m.js:337:57
21:28:34.284
[2022-07-04T19:28:34.284Z] ws connection error: CLOSE_ABNORMAL 6.0126dbd0.chunk.js:2:6258764
21:28:34.307 [2022-07-04T19:28:34.307Z] Start reconnect 0 6.0126dbd0.chunk.js:2:6258764
21:28:34.312 [2022-07-04T19:28:34.313Z] Try to connect 6.0126dbd0.chunk.js:2:6258764
21:28:34.313
[2022-07-04T19:28:34.313Z] ws connection error: CLOSE_ABNORMAL socket.io.js:61:32
21:28:34.313 [2022-07-04T19:28:34.313Z] Start reconnect 0 socket.io.js:59:41
21:28:34.313 [2022-07-04T19:28:34.313Z] Try to connect socket.io.js:59:41
21:28:36.390 Source map error: Error: NetworkError when attempting to fetch resource.
Resource URL: http://192.168.178.200:8081/static/js/6.0126dbd0.chunk.js
Source Map URL: 6.0126dbd0.chunk.js.map

21:28:36.638 Firefox can’t establish a connection to the server at ws://192.168.178.200:8081/?sid=1656962914313&name=admin. socket.io.js:94:21
21:28:36.639 [2022-07-04T19:28:36.639Z] Start reconnect 1 6.0126dbd0.chunk.js:2:6258764
21:28:36.639
[2022-07-04T19:28:36.640Z] ws connection error: CLOSE_ABNORMAL 6.0126dbd0.chunk.js:2:6258764
21:28:36.639 [2022-07-04T19:28:36.640Z] Reconnect is already running 1 6.0126dbd0.chunk.js:2:6258764
21:28:37.320 [2022-07-04T19:28:37.321Z] No READY flag received in 3 seconds. Re-init socket.io.js:60:32
21:28:37.321 [2022-07-04T19:28:37.321Z] Start reconnect 1 socket.io.js:59:41
21:28:37.321 Firefox can’t establish a connection to the server at ws://192.168.178.200:8081/?sid=1656962914313. socket.io.js:94:21
21:28:37.322 The connection to ws://192.168.178.200:8081/?sid=1656962914313 was interrupted while the page was loading. socket.io.js:94:21
21:28:37.322 [2022-07-04T19:28:37.322Z] Reconnect is already running 1 socket.io.js:59:41
21:28:37.322
[2022-07-04T19:28:37.322Z] ws connection error: CLOSE_ABNORMAL socket.io.js:61:32
21:28:37.322 [2022-07-04T19:28:37.322Z] Reconnect is already running 1

[Glasfaser]

@oetzi

Logausgaben bitte in Code-Tags </>

das kann keiner lesen .!

EDIT :

und diese Ausgabe ist immer gekürzt im Browser !!

[Thomas Braun]

@oetzi

iobroker update -i