[2.5.9 Fehler existiert] - Backup-Adapter erzeugt Fehler

[simatec]

@siggi0904 Kannst du bitte den Log posten?
Das Problem muss tiefer liegen und mit großer Wahrscheinlichkeit in nodejs liegen

[simatec]

@siggi0904 Wurde der Adapter vor auftreten des Problems neu gestartet? Wenn ja auch hier bitte den Debuglog vom restart des Adapters posten

[Siggi0904]

@simatec Hallo, nein. Ich hab über das System auf die neue Version aktualisiert und am folgenden Tag (vor 3 Tagen) lief es sauber durch.

Heute Morgen ist der Fehler aufgetreten.

Hast du eine Mail-Adresse, an die ich das senden kann?
Ist ja erstens viel und zweitens mit persönlichen Daten.

[simatec]

@siggi0904 Bitte poste hier nur den teil des Backups. Da sind keine Daten sichtbar

[Siggi0904]

@simatec
Super, der Fehler tritt nach dem Neustart des Adapters im Debug-Mode nicht auf.
Dann muss ich wieder ein paar Tage warten, bis der Fehler auftritt.

Dann hier die Logs:

Startup der Instanz mit Debug-Mode

2022-12-19 16:09:08.926 - info: backitup.0 (3064907) Got terminate signal TERMINATE_YOURSELF
2022-12-19 16:09:08.927 - info: backitup.0 (3064907) cleaned everything up...
2022-12-19 16:09:08.928 - info: backitup.0 (3064907) terminating
2022-12-19 16:09:08.929 - info: backitup.0 (3064907) Terminated (ADAPTER_REQUESTED_TERMINATION): Without reason
2022-12-19 16:09:09.162 - info: host.iobroker stopInstance system.adapter.backitup.0 send kill signal
2022-12-19 16:09:09.671 - info: host.iobroker instance system.adapter.backitup.0 terminated with code 11 (ADAPTER_REQUESTED_TERMINATION)
2022-12-19 16:09:12.300 - info: host.iobroker instance system.adapter.backitup.0 started with pid 989622
2022-12-19 16:09:13.615 - debug: backitup.0 (989622) Redis Objects: Use Redis connection: 127.0.0.1:9001
2022-12-19 16:09:13.660 - debug: backitup.0 (989622) Objects client ready ... initialize now
2022-12-19 16:09:13.756 - debug: backitup.0 (989622) Objects create System PubSub Client
2022-12-19 16:09:13.757 - debug: backitup.0 (989622) Objects create User PubSub Client
2022-12-19 16:09:13.890 - debug: backitup.0 (989622) Objects client initialize lua scripts
2022-12-19 16:09:13.903 - debug: backitup.0 (989622) Objects connected to redis: 127.0.0.1:9001
2022-12-19 16:09:13.951 - debug: backitup.0 (989622) Redis States: Use Redis connection: 127.0.0.1:9000
2022-12-19 16:09:14.046 - debug: backitup.0 (989622) States create System PubSub Client
2022-12-19 16:09:14.047 - debug: backitup.0 (989622) States create User PubSub Client
2022-12-19 16:09:14.123 - debug: backitup.0 (989622) States connected to redis: 127.0.0.1:9000
2022-12-19 16:09:14.282 - debug: backitup.0 (989622) Plugin sentry Initialize Plugin (enabled=true)
2022-12-19 16:09:14.938 - info: backitup.0 (989622) starting. Version 2.5.9 in /opt/iobroker/node_modules/iobroker.backitup, node: v16.18.1, js-controller: 4.0.23
2022-12-19 16:09:14.999 - debug: backitup.0 (989622) Backitup has recognized a linux system
2022-12-19 16:09:15.085 - info: backitup.0 (989622) [iobroker] backup was activated at 01:00 every 2 day(s)
2022-12-19 16:09:15.158 - debug: backitup.0 (989622) [iobroker] 10 00 01 */2 * *
2022-12-19 16:09:15.159 - info: backitup.0 (989622) [ccu] backup was activated at 01:15 every 3 day(s)
2022-12-19 16:09:15.176 - debug: backitup.0 (989622) [ccu] 10 15 01 */3 * *
2022-12-19 16:09:15.218 - debug: backitup.0 (989622) noserverino option: false
2022-12-19 16:09:15.218 - debug: backitup.0 (989622) cifs-mount command: "sudo mount -t cifs -o username=admin,password=****,rw,file_mode=0777,dir_mode=0777,vers=2.0 //Datenschlampe/Backup/Homematic-Pi/iobroker/standard /opt/iobroker/backups"
2022-12-19 16:09:20.159 - debug: backitup.0 (989622) mount successfully completed
2022-12-19 16:09:22.891 - debug: backitup.0 (989622) detect backup file 1 from NAS: iobroker_2022_12_03-01_00_27_backupiobroker.tar.gz
2022-12-19 16:09:22.891 - debug: backitup.0 (989622) detect backup file 2 from NAS: iobroker_2022_12_05-01_00_24_backupiobroker.tar.gz
2022-12-19 16:09:22.892 - debug: backitup.0 (989622) detect backup file 3 from NAS: iobroker_2022_12_07-01_00_27_backupiobroker.tar.gz
2022-12-19 16:09:22.892 - debug: backitup.0 (989622) detect backup file 4 from NAS: iobroker_2022_12_15-01_00_25_backupiobroker.tar.gz
2022-12-19 16:09:22.892 - debug: backitup.0 (989622) detect backup file 5 from NAS: iobroker_2022_12_17-01_00_25_backupiobroker.tar.gz
2022-12-19 16:09:22.893 - debug: backitup.0 (989622) detect last backup file: iobroker_2022_12_17-01_00_25_backupiobroker.tar.gz
2022-12-19 16:09:25.087 - debug: backitup.0 (989622) mount activ... umount in 2 Seconds!!
2022-12-19 16:09:27.493 - debug: backitup.0 (989622) umount successfully completed

Log vom Backup (Leider ohne Fehler):

2022-12-19 16:12:26.816 - debug: backitup.0 (989622) Backup has started ...
2022-12-19 16:12:36.816 - debug: backitup.0 (989622) [iobroker/mount] noserverino option: false
2022-12-19 16:12:36.817 - debug: backitup.0 (989622) [iobroker/mount] cifs-mount command: "sudo mount -t cifs -o username=admin,password=****,rw,file_mode=0777,dir_mode=0777,vers=2.0 //Datenschlampe/Backup/Homematic-Pi/iobroker/standard /opt/iobroker/backups"
2022-12-19 16:12:41.581 - debug: backitup.0 (989622) [iobroker/mount] mount successfully completed
2022-12-19 16:12:41.583 - debug: backitup.0 (989622) [iobroker/mount] done
2022-12-19 16:12:44.936 - debug: backitup.0 (989622) [iobroker/iobroker] host.iobroker 7667 states saved
2022-12-19 16:12:45.076 - debug: backitup.0 (989622) [iobroker/iobroker] host.iobroker 9295 objects saved
2022-12-19 16:12:48.650 - debug: backitup.0 (989622) [iobroker/iobroker] Backup created: /opt/iobroker/backups/iobroker_2022_12_19-16_12_41_backupiobroker.tar.gz
2022-12-19 16:12:49.718 - debug: backitup.0 (989622) [iobroker/iobroker] done
2022-12-19 16:12:50.022 - debug: backitup.0 (989622) [iobroker/mysql] MySql-Backup started ...
2022-12-19 16:14:36.723 - debug: backitup.0 (989622) [iobroker/mysql] MySql File deleted!
2022-12-19 16:14:36.726 - debug: backitup.0 (989622) [iobroker/mysql] MySql-Backup for is finish
2022-12-19 16:14:36.726 - debug: backitup.0 (989622) [iobroker/mysql] done
2022-12-19 16:14:37.977 - debug: backitup.0 (989622) [iobroker/javascripts] Created javascript_tmp directory: "/opt/iobroker/backups/tmpScripts"
2022-12-19 16:14:38.312 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Klima-Wohnzimmer
2022-12-19 16:14:38.313 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Wechselschaltung
2022-12-19 16:14:38.313 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Fenster_geschlossen
2022-12-19 16:14:38.313 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Klima-Bad
2022-12-19 16:14:38.314 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Klima-Schlafzimmer
2022-12-19 16:14:38.314 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Tests
2022-12-19 16:14:38.314 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Fenster_geschlossen
2022-12-19 16:14:38.314 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Fenster_geschlossen
2022-12-19 16:14:38.314 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Fenster_geschlossen
2022-12-19 16:14:38.315 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: BattUeberwachung
2022-12-19 16:14:38.315 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: FensterOffenLichtAnSteckdosenEin
2022-12-19 16:14:38.315 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Licht_überall_aus
2022-12-19 16:14:38.315 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Steckdosen_überall_aus
2022-12-19 16:14:38.315 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Eingangstür_offen
2022-12-19 16:14:38.315 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: BattUeberwachungAlexa
2022-12-19 16:14:38.318 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Alarmanlage
2022-12-19 16:14:38.319 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: ErreichbarkeitAlexa
2022-12-19 16:14:38.319 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Aqara_Zauberwürfel
2022-12-19 16:14:38.319 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: MorgensLichtEinArbeit
2022-12-19 16:14:38.320 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: EingangstürAlexa
2022-12-19 16:14:38.321 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: TemperaturAnsage
2022-12-19 16:14:38.321 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: TemperaturAnsage
2022-12-19 16:14:38.321 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: TemperaturAnsage
2022-12-19 16:14:38.321 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: TemperaturAnsage
2022-12-19 16:14:38.321 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: LuftfeuchtigkeitAnsage
2022-12-19 16:14:38.322 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: LuftdruckAnsage
2022-12-19 16:14:38.322 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: LuftdruckAnsage
2022-12-19 16:14:38.322 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: LuftfeuchtigkeitAnsage
2022-12-19 16:14:38.322 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: LuftfeuchtigkeitAnsage
2022-12-19 16:14:38.322 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: LuftdruckAnsage
2022-12-19 16:14:38.322 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: LuftdruckAnsage
2022-12-19 16:14:38.323 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: LuftfeuchtigkeitAnsage
2022-12-19 16:14:38.323 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: AnwesenheitTaster
2022-12-19 16:14:38.323 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: AnwesenheitHandy
2022-12-19 16:14:38.323 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: TestHandyErreichbarkeit
2022-12-19 16:14:38.323 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: PersonKommt
2022-12-19 16:14:38.323 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: WillkommenZuhause
2022-12-19 16:14:38.324 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: HandyLaden100%
2022-12-19 16:14:38.324 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: HandystatusAnsage
2022-12-19 16:14:38.326 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: HandyAkkustandMinimal
2022-12-19 16:14:38.326 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: TabletStatusAnsage
2022-12-19 16:14:38.327 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: TabletAkkustandMinimal
2022-12-19 16:14:38.327 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: TabletLaden100%
2022-12-19 16:14:38.327 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: AdapterNeustarten
2022-12-19 16:14:38.327 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: CarportLichtAus
2022-12-19 16:14:38.327 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: CarportLichtMorgensEin
2022-12-19 16:14:38.327 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: CarportLichtAbendsEin
2022-12-19 16:14:38.328 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: AstroDaten
2022-12-19 16:14:38.328 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Jalousiesteuerung
2022-12-19 16:14:38.328 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Helligkeit-AußenAnsage
2022-12-19 16:14:38.330 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Klima-AußenAnsage
2022-12-19 16:14:38.331 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Jalousiesteuerung
2022-12-19 16:14:38.331 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Xiaomi_Geräte
2022-12-19 16:14:38.331 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: LuftreinigerEinAus
2022-12-19 16:14:38.331 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: LuftqualitätAnsage
2022-12-19 16:14:38.331 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Nachtmodus
2022-12-19 16:14:38.331 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: BenzinpreiseAnsage
2022-12-19 16:14:38.332 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: NachttischAus
2022-12-19 16:14:38.332 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: StatusHomeMatic
2022-12-19 16:14:38.332 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: WeckerAusUrlaubKrank
2022-12-19 16:14:38.332 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: IchBinWeg
2022-12-19 16:14:38.335 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: AnwesenheitBewegung
2022-12-19 16:14:38.335 - debug: backitup.0 (989622) [iobroker/javascripts] found Script: Eiswarnung
2022-12-19 16:14:38.931 - debug: backitup.0 (989622) [iobroker/javascripts] Try deleting the Javascript tmp directory: "/opt/iobroker/backups/tmpScripts"
2022-12-19 16:14:39.085 - debug: backitup.0 (989622) [iobroker/javascripts] Javascript tmp directory "/opt/iobroker/backups/tmpScripts" successfully deleted
2022-12-19 16:14:39.086 - debug: backitup.0 (989622) [iobroker/javascripts] Backup created: /opt/iobroker/backups/javascripts_2022_12_19-16_14_37_backupiobroker.tar.gz
2022-12-19 16:14:39.086 - debug: backitup.0 (989622) [iobroker/javascripts] done
2022-12-19 16:14:39.538 - debug: backitup.0 (989622) [iobroker/cifs] used copy path: /Backup/Homematic-Pi/iobroker/standard
2022-12-19 16:14:39.538 - debug: backitup.0 (989622) [iobroker/cifs] done
2022-12-19 16:14:40.141 - debug: backitup.0 (989622) [iobroker/clean] done
2022-12-19 16:14:41.057 - debug: backitup.0 (989622) [iobroker/historyHTML] new history html values created
2022-12-19 16:14:41.058 - debug: backitup.0 (989622) [iobroker/historyHTML] done
2022-12-19 16:14:41.322 - debug: backitup.0 (989622) [iobroker/historyJSON] new history json values created
2022-12-19 16:14:41.323 - debug: backitup.0 (989622) [iobroker/historyJSON] done
2022-12-19 16:14:41.492 - debug: backitup.0 (989622) [iobroker/umount] mount activ, umount is started ...
2022-12-19 16:14:46.709 - debug: backitup.0 (989622) [iobroker/umount] umount successfully completed
2022-12-19 16:14:46.711 - debug: backitup.0 (989622) [iobroker/umount] done
2022-12-19 16:14:46.863 - debug: backitup.0 (989622) [iobroker] exec: done

Aus der Historie (log von heute vor dem Restart des Adapters), der Fehler:

2022-12-19 15:44:32.227 - error: backitup.0 (3064907) [iobroker/iobroker] node:internal/bootstrap/switches/does_own_process_state:126
2022-12-19 15:44:32.229 - error: backitup.0 (3064907) [iobroker/iobroker] cachedCwd = rawMethods.cwd();
2022-12-19 15:44:32.229 - error: backitup.0 (3064907) [iobroker/iobroker] ^
2022-12-19 15:44:32.229 - error: backitup.0 (3064907) [iobroker/iobroker] Error: ENOENT: no such file or directory, uv_cwd
2022-12-19 15:44:32.230 - error: backitup.0 (3064907) [iobroker/iobroker] at process.wrappedCwd (node:internal/bootstrap/switches/does_own_process_state:126:28)
2022-12-19 15:44:32.230 - error: backitup.0 (3064907) [iobroker/iobroker] at Object.process.cwd (/opt/iobroker/node_modules/graceful-fs/polyfills.js:10:19)
2022-12-19 15:44:32.230 - error: backitup.0 (3064907) [iobroker/iobroker] at fe.Yargs (/opt/iobroker/node_modules/iobroker.js-controller/node_modules/yargs/build/index.cjs:1:61304)
2022-12-19 15:44:32.230 - error: backitup.0 (3064907) [iobroker/iobroker] at Argv (/opt/iobroker/node_modules/iobroker.js-controller/node_modules/yargs/index.cjs:12:16)
2022-12-19 15:44:32.230 - error: backitup.0 (3064907) [iobroker/iobroker] at Object. (/opt/iobroker/node_modules/iobroker.js-controller/node_modules/yargs/index.cjs:7:1)
2022-12-19 15:44:32.235 - error: backitup.0 (3064907) [iobroker/iobroker] at Module._compile (node:internal/modules/cjs/loader:1155:14)
2022-12-19 15:44:32.235 - error: backitup.0 (3064907) [iobroker/iobroker] at Object.Module._extensions..js (node:internal/modules/cjs/loader:1209:10)
2022-12-19 15:44:32.236 - error: backitup.0 (3064907) [iobroker/iobroker] at Module.load (node:internal/modules/cjs/loader:1033:32)
2022-12-19 15:44:32.236 - error: backitup.0 (3064907) [iobroker/iobroker] at Function.Module._load (node:internal/modules/cjs/loader:868:12)
2022-12-19 15:44:32.236 - error: backitup.0 (3064907) [iobroker/iobroker] at Module.require (node:internal/modules/cjs/loader:1057:19) {
2022-12-19 15:44:32.236 - error: backitup.0 (3064907) [iobroker/iobroker] errno: -2,
2022-12-19 15:44:32.236 - error: backitup.0 (3064907) [iobroker/iobroker] code: 'ENOENT',
2022-12-19 15:44:32.237 - error: backitup.0 (3064907) [iobroker/iobroker] syscall: 'uv_cwd'
2022-12-19 15:44:32.237 - error: backitup.0 (3064907) [iobroker/iobroker] }

[Thomas Braun]

@siggi0904

Smb vers=2.0 dürfte falsch sein. Mittlerweile sollte eigentlich alles auf Version 3 sein.

[Siggi0904]

@thomas-braun Ne, NAS ist auf Minimum 2.0 und Maximum 3.0 eingestellt (Synology DSM 6).
Das sollte also passen und das Backup läuft ja auch grundsätzlich.

[Thomas Braun]

@siggi0904

Dann stell es im Backitup-Adapter auf 3.0.

[simatec]

@siggi0904 Poste mal die Ausgaben von:

npm -v
node -v
nodjs -v

[Siggi0904]

@simatec sagte in [Mit Version 2.5.9 behoben] - Backup-Adapter erzeugt Fehler:

npm -v

8.19.2
v16.18.1
v16.18.1

@thomas-braun sagte in [Mit Version 2.5.9 behoben] - Backup-Adapter erzeugt Fehler:

@siggi0904

Dann stell es im Backitup-Adapter auf 3.0.

Behebt das, das Problem?

[Thomas Braun]

@siggi0904 sagte in [Mit Version 2.5.9 behoben] - Backup-Adapter erzeugt Fehler:

Behebt das, das Problem?

Möglicherweise...

[simatec]

@thomas-braun
Das Problem liegt hier eher tiefer im nodejs oder npm.
Es wird bei einer handvoll User der auszuführende Pfad des iobroker Backups nicht gefunden bzw. kann nicht drauf zugegriffen werden.

Das sagt dieses uv_cwd oder so aus

[Thomas Braun]

@simatec

Weiß ich.

[simatec]

@thomas-braun
Wir suchen aktuell nach Lösungen dieses Bugs.
In meiner Welt eher schwierig, da es sich nicht auf Backitup zurückführen lässt.

Der Bug kam mit irgendeiner Node Version oder auch npm.

Ein npm clear cache oder reboot behebt das Problem temporär

[skinni]

Ich bin ja der Meinung er kam bei mir mit dem node Update von 14 auf 16. Seit ich aber mein System neu aufgesetzt habe, hatte ich bisher Ruhe.. Dafür hab ich seit dem "Cannot check node.js versions", aber das ist jetzt hier nicht das Thema

[Thomas Braun]

@simatec

Da passt was mit den Pfaden / den Berechtigungen nicht. Kann auch mit mount optionen oder dem verwendeten Protokoll zusammenhängen.

[Siggi0904]

Das merkwürdige ist, dass der Fehler auftritt wenn man ein Addon aktualisiert hat.
Wenn ich am System nichts ändere, läuft das super durch.

[Thomas Braun]

@siggi0904

Was für ein 'Addon'?

[Siggi0904]

@thomas-braun egal welches. Sobald eine Aktualisierung läuft, kommt beim nächsten Backup-Lauf der Fehler.

Aber das ist nur ein Gefühl. Ich stellte aber das Verhalten so fest.

[simatec]

@thomas-braun sagte in [Mit Version 2.5.9 behoben] - Backup-Adapter erzeugt Fehler:

@simatec

Da passt was mit den Pfaden / den Berechtigungen nicht. Kann auch mit mount optionen oder dem verwendeten Protokoll zusammenhängen.

Da gehe ich nicht von aus. Denn der Fehler besagt, dass er den Backup Prozess nicht ausführen kann, da der Pfad in Benutzung und somit blockiert ist.
Damit wird aber nicht der Backuppfad sondern der Pfad zum js-controller gemeint