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

[Rico Sander]

@simatec

pi@iobroker:~ $ iob stop history
The adapter "history.0" was stopped.

2025-02-07 16:19:28.717 - debug: backitup.0 (72377) Backup has started ...
2025-02-07 16:19:38.719 - debug: backitup.0 (72377) [iobroker/mount] cifs-mount command: "sudo mount -t cifs -o username=xxx,password=****,domain=xxx,rw,forceuid,uid=iobroker,forcegid,gid=iobroker,file_mode=0777,dir_mode=0777,vers=3.1.1 //192.168.178.x/usbshare1/iobroker_backup /opt/iobroker/backups"
2025-02-07 16:19:38.838 - debug: backitup.0 (72377) [iobroker/mount] mount successfully completed
2025-02-07 16:19:38.840 - debug: backitup.0 (72377) [iobroker/mount] done
2025-02-07 16:19:43.249 - debug: backitup.0 (72377) [iobroker/iobroker] host.iobroker 5444 objects saved
2025-02-07 16:19:43.724 - debug: backitup.0 (72377) [iobroker/iobroker] host.iobroker 4379 states saved
2025-02-07 16:19:43.726 - debug: backitup.0 (72377) [iobroker/iobroker] host.iobroker Validating backup ...
2025-02-07 16:19:43.730 - debug: backitup.0 (72377) [iobroker/iobroker] host.iobroker "config.json" is valid
2025-02-07 16:19:43.731 - debug: backitup.0 (72377) [iobroker/iobroker] host.iobroker "objects.jsonl" exists
2025-02-07 16:19:43.731 - debug: backitup.0 (72377) [iobroker/iobroker] host.iobroker "states.jsonl" exists
2025-02-07 16:19:44.260 - debug: backitup.0 (72377) [iobroker/iobroker] host.iobroker JSONL lines are valid
2025-02-07 16:19:44.266 - debug: backitup.0 (72377) [iobroker/iobroker] host.iobroker The backup is valid!
2025-02-07 16:19:45.214 - debug: backitup.0 (72377) [iobroker/iobroker] Backup created: /opt/iobroker/backups/iobroker_2025_02_07-16_19_38_Raspi4_9_backupiobroker.tar.gz
2025-02-07 16:19:45.215 - debug: backitup.0 (72377) [iobroker/iobroker] This backup can only be restored with js-controller version 7.0 or higher
2025-02-07 16:19:46.267 - debug: backitup.0 (72377) [iobroker/iobroker] done
2025-02-07 16:19:47.171 - debug: backitup.0 (72377) [iobroker/historyDB] compress from historyDB started ...
2025-02-07 16:19:57.172 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 15MB so far...
2025-02-07 16:20:07.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 32MB so far...
2025-02-07 16:20:17.172 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 48MB so far...
2025-02-07 16:20:27.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 65MB so far...
2025-02-07 16:20:37.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 83MB so far...
2025-02-07 16:20:47.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 101MB so far...
2025-02-07 16:20:57.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 119MB so far...
2025-02-07 16:21:07.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 139MB so far...
2025-02-07 16:21:17.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 159MB so far...
2025-02-07 16:21:27.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 179MB so far...
2025-02-07 16:21:37.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 197MB so far...
2025-02-07 16:21:47.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 217MB so far...
2025-02-07 16:21:53.698 - debug: backitup.0 (72377) [iobroker/historyDB] Backup created: /opt/iobroker/backups/historyDB_2025_02_07-16_19_47_Raspi4_9_backupiobroker.tar.gz
2025-02-07 16:21:53.698 - debug: backitup.0 (72377) [iobroker/historyDB] done
2025-02-07 16:21:55.506 - debug: backitup.0 (72377) [iobroker/cifs] used copy path: /usbshare1/iobroker_backup
2025-02-07 16:21:55.506 - debug: backitup.0 (72377) [iobroker/cifs] done
2025-02-07 16:21:56.109 - warn: backitup.0 (72377) [iobroker/clean] No older backup files are deleted, because this backup was started manually
2025-02-07 16:21:56.110 - debug: backitup.0 (72377) [iobroker/clean] done
2025-02-07 16:21:56.266 - debug: backitup.0 (72377) [iobroker/historyHTML] new history html values created
2025-02-07 16:21:56.364 - debug: backitup.0 (72377) [iobroker/historyHTML] done
2025-02-07 16:21:56.525 - debug: backitup.0 (72377) [iobroker/historyJSON] new history json values created
2025-02-07 16:21:56.526 - debug: backitup.0 (72377) [iobroker/historyJSON] done
2025-02-07 16:21:56.693 - debug: backitup.0 (72377) [iobroker/umount] mount active, umount is started ...
2025-02-07 16:22:01.767 - debug: backitup.0 (72377) [iobroker/umount] umount successfully completed
2025-02-07 16:22:01.768 - debug: backitup.0 (72377) [iobroker/umount] done
2025-02-07 16:22:12.078 - debug: backitup.0 (72377) [iobroker/email] done
2025-02-07 16:22:12.081 - info: email.0 (39359) Send email: {"text":"Backitup:\nEin neues iobroker (Raspi4_9) Backup wurde am 07. Februar 2025 um 16:22 Uhr erstellt.\n\nSpeicherorte:\n1. NAS (CIFS) (//192.168.178.x/usbshare1/iobroker_backup)\n","to":"xxx@yyy.de","subject":"Backitup","from":"iob@yyy.de"}
2025-02-07 16:22:12.427 - info: email.0 (39359) sent to xxx@yyy.de
2025-02-07 16:22:14.137 - debug: backitup.0 (72377) [iobroker/notification] done
2025-02-07 16:22:14.294 - debug: backitup.0 (72377) [iobroker] exec: done

Reicht Dir das?

[Homoran]

@wcag22 sagte in Fehler im BackUp der history DB:

Reicht Dir das?

Vielleicht noch die Info, ob das Backup (nicht) defekt ist

[Rico Sander]

@homoran
Gern:

[Rico Sander]

@homoran @simatec

Hinweis:
Die Sache mit dem USB3 Port hat sich erledigt. Der Stick steckte entgegen meiner Annahme doch im USB2 Port.
Hatte ich nicht auf dem Schirm. Dachte, ich hätte ihn in den USB3 gesteckt.

Somit fällt das auch erst einmal vermutlich als Ursache weg. Schade eigentlich...

[Homoran]

@wcag22 Danke!

hab gerade noch das letzte Backup angesehen

soweit ohne Probleme.

Hab dann übermütig gedacht çmal eben" zu entpacken.
Wird aber auf dem Tablet wohl mehrere Stunden dauern

[simatec]

@wcag22 Ist denn nun das Backup mit gestoppten History Adapter in ordnung?

[Rico Sander]

@simatec
Gesagt - getan. Leider kein wirklich aussagekräftiges Ergebnis.
Um überhaupt belastbare Daten zu haben, habe ich sowohl mit aktivem BackItUp Adapter, als auch mit gestoppten Adapter jeweils 10 Sicherungen durchgeführt.

Ergebnis mit laufendem History-Adapter: (60% Fehler)
10_03_28 mit history fehlefrei
10_10_28 mit history unerwartetes Datenende
11_01_28 mit history unerwartetes Datenende
11_20_28 mit history fehlerfrei
11_28_28 mit history Headersfehler & Warnungen
12_00_28 mit history Headersfehler & Warnungen
12_20_28 mit history fehlerfrei
12_35_28 mit history fehlerfrei
12_45_28 mit history Headersfehler & Warnungen
12_55_28 mit history unerwartetes Datenende

Ergebnis bei gestopptem History Adapter: (40% Fehler)
13_06_01 ohne history - fehlerfrei
13_16_01 ohne history - Headersfehler & Warnungen
13_25_01 ohne history - fehlerfrei
13_30_01 ohne history - fehlerfrei
13_43_01 ohne history - fehlerfrei
13_49_01 ohne history - fehlerfrei
14_37_01 ohne history - Headersfehler & Warnungen
14_44_01 ohne history - unerwartetes Dateiende
14_53_01 ohne history - fehlerfrei
14_59_01 ohne history - unerwartetes Dateiende

Die Fehlerquote ist zwar ohne aktiven BackItUp- History Adapter deutlich geringer, aber ein klares Ergebnis sieht anders aus.

simatec

pi@iobroker:~ $ iob stop history
The adapter "history.0" was stopped.

2025-02-07 16:19:28.717 - debug: backitup.0 (72377) Backup has started ...
2025-02-07 16:19:38.719 - debug: backitup.0 (72377) [iobroker/mount] cifs-mount command: "sudo mount -t cifs -o username=xxx,password=****,domain=xxx,rw,forceuid,uid=iobroker,forcegid,gid=iobroker,file_mode=0777,dir_mode=0777,vers=3.1.1 //192.168.178.x/usbshare1/iobroker_backup /opt/iobroker/backups"
2025-02-07 16:19:38.838 - debug: backitup.0 (72377) [iobroker/mount] mount successfully completed
2025-02-07 16:19:38.840 - debug: backitup.0 (72377) [iobroker/mount] done
2025-02-07 16:19:43.249 - debug: backitup.0 (72377) [iobroker/iobroker] host.iobroker 5444 objects saved
2025-02-07 16:19:43.724 - debug: backitup.0 (72377) [iobroker/iobroker] host.iobroker 4379 states saved
2025-02-07 16:19:43.726 - debug: backitup.0 (72377) [iobroker/iobroker] host.iobroker Validating backup ...
2025-02-07 16:19:43.730 - debug: backitup.0 (72377) [iobroker/iobroker] host.iobroker "config.json" is valid
2025-02-07 16:19:43.731 - debug: backitup.0 (72377) [iobroker/iobroker] host.iobroker "objects.jsonl" exists
2025-02-07 16:19:43.731 - debug: backitup.0 (72377) [iobroker/iobroker] host.iobroker "states.jsonl" exists
2025-02-07 16:19:44.260 - debug: backitup.0 (72377) [iobroker/iobroker] host.iobroker JSONL lines are valid
2025-02-07 16:19:44.266 - debug: backitup.0 (72377) [iobroker/iobroker] host.iobroker The backup is valid!
2025-02-07 16:19:45.214 - debug: backitup.0 (72377) [iobroker/iobroker] Backup created: /opt/iobroker/backups/iobroker_2025_02_07-16_19_38_Raspi4_9_backupiobroker.tar.gz
2025-02-07 16:19:45.215 - debug: backitup.0 (72377) [iobroker/iobroker] This backup can only be restored with js-controller version 7.0 or higher
2025-02-07 16:19:46.267 - debug: backitup.0 (72377) [iobroker/iobroker] done
2025-02-07 16:19:47.171 - debug: backitup.0 (72377) [iobroker/historyDB] compress from historyDB started ...
2025-02-07 16:19:57.172 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 15MB so far...
2025-02-07 16:20:07.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 32MB so far...
2025-02-07 16:20:17.172 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 48MB so far...
2025-02-07 16:20:27.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 65MB so far...
2025-02-07 16:20:37.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 83MB so far...
2025-02-07 16:20:47.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 101MB so far...
2025-02-07 16:20:57.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 119MB so far...
2025-02-07 16:21:07.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 139MB so far...
2025-02-07 16:21:17.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 159MB so far...
2025-02-07 16:21:27.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 179MB so far...
2025-02-07 16:21:37.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 197MB so far...
2025-02-07 16:21:47.171 - debug: backitup.0 (72377) [iobroker/historyDB] Packed 217MB so far...
2025-02-07 16:21:53.698 - debug: backitup.0 (72377) [iobroker/historyDB] Backup created: /opt/iobroker/backups/historyDB_2025_02_07-16_19_47_Raspi4_9_backupiobroker.tar.gz
2025-02-07 16:21:53.698 - debug: backitup.0 (72377) [iobroker/historyDB] done
2025-02-07 16:21:55.506 - debug: backitup.0 (72377) [iobroker/cifs] used copy path: /usbshare1/iobroker_backup
2025-02-07 16:21:55.506 - debug: backitup.0 (72377) [iobroker/cifs] done
2025-02-07 16:21:56.109 - warn: backitup.0 (72377) [iobroker/clean] No older backup files are deleted, because this backup was started manually
2025-02-07 16:21:56.110 - debug: backitup.0 (72377) [iobroker/clean] done
2025-02-07 16:21:56.266 - debug: backitup.0 (72377) [iobroker/historyHTML] new history html values created
2025-02-07 16:21:56.364 - debug: backitup.0 (72377) [iobroker/historyHTML] done
2025-02-07 16:21:56.525 - debug: backitup.0 (72377) [iobroker/historyJSON] new history json values created
2025-02-07 16:21:56.526 - debug: backitup.0 (72377) [iobroker/historyJSON] done
2025-02-07 16:21:56.693 - debug: backitup.0 (72377) [iobroker/umount] mount active, umount is started ...
2025-02-07 16:22:01.767 - debug: backitup.0 (72377) [iobroker/umount] umount successfully completed
2025-02-07 16:22:01.768 - debug: backitup.0 (72377) [iobroker/umount] done
2025-02-07 16:22:12.078 - debug: backitup.0 (72377) [iobroker/email] done
2025-02-07 16:22:12.081 - info: email.0 (39359) Send email: {"text":"Backitup:\nEin neues iobroker (Raspi4_9) Backup wurde am 07. Februar 2025 um 16:22 Uhr erstellt.\n\nSpeicherorte:\n1. NAS (CIFS) (//192.168.178.x/usbshare1/iobroker_backup)\n","to":"xxx@yyy.de","subject":"Backitup","from":"iob@yyy.de"}
2025-02-07 16:22:12.427 - info: email.0 (39359) sent to xxx@yyy.de
2025-02-07 16:22:14.137 - debug: backitup.0 (72377) [iobroker/notification] done
2025-02-07 16:22:14.294 - debug: backitup.0 (72377) [iobroker] exec: done

[Homoran]

@wcag22 sagte in Fehler im BackUp der history DB:

ohne aktivem BackItUp-Adapter

???

hast du mal was anderes als 7z versucht?

[Rico Sander]

@homoran
Ja, winzip.
Da sind aber nur die Meldungen anders und nichts so ausführlich. Außerdem habe ich eine betagte Version. 7zip habe schon deshalb genommen, weil ich winzip nicht über den Weg getraut hatte :-) und 7zip in der aktuellen Version wohl mehr der Gegenwart entspricht, als ein ergrautes ehemals kostpflichtiges Tool von anno dunnemals.

Ich habe natürlich auch noch nicht geschaut und kontrolliert, ob es auf Grund von RAM-Fehlern auf dem Desktop zu Problemen in den Archiven beim kopieren gibt. So etwas ähnliches hatte ich schon mal im Zusammenhang mit video-Dateien und einem Video-Bearbeitungsprogramm. Das muss dann über die Fingerprints (?) der Dateien erfolgen. "hashmyfiles" hieß das Tool so weit ich mich erinnere.
Es gibt sicher noch mehr Gründe, warum Archive (plötzlich?) Fehler haben.

Aber all das bringt uns m. E. nicht weiter.

Denn:
Auf die Spur der fehlerhaften Archive bin ich ja nur deshalb gekommen, weil ioB eben das Restore wegen fehlerhafter Archive verweigerte. Und eine andere Möglichkeit die Archive zu validieren, als sie durch ein Packer zu testen, sehe ich nicht.
Es sei denn:
Es wird sogleich auf dem Raspi unter Linux gemacht. Aber dazu fehlen mir (derzeit) die Kenntnisse.

Es wäre natürlich gut, wenn andere Nutzer den oder die Fehler bzw. Ursachen nachvollziehen könnten. Dann würde man ein lokales Problem hier schon mal ausschließen können. So eindeutig die Ergebnisse auch sind, geheuer ist mir das nicht. Nicht dass ich da auf einem völlig falschen Pfad bin.
Eine zweite oder dritte Meinung wäre schon gut.

[Rico Sander]

@wcag22 @Homoran @simatec

So, weiter gehts im Thema.
Da der Thread schon ganz schön lang geworden ist - tl;dr - hier mal die Zusammenfassung:

Ein am Pi4/8GB USB2-Port angeschlossener USB-Stick (32GB, SanDisk) nimmt die history DB auf. Die auf dem Stick liegenden history-Daten im laufenden Betrieb sind fehlerfrei, es deutet nichts auf Probleme an dieser Stelle hin.

Die tägliche Sicherung via BackItUp -Adapter erfolgt auf einen USB-Stick an der Synology.

Phase 1:
Das Problem:
Die knappe Mehrzahl der generierten Archive der historyDB (*.tar.gz) ist fehlerhaft.

BackUp-Testreihen mit laufendem history-Adapter brachten gegenüber einem gestoppten history-Adapter kein eindeutiges Ergebnis. Die Annahme, dass Zugriffe auf die history DB währen des Packvorganges ursächlich sein könnten, konnte nicht eindeutig bestätigt werden.

Phase 2:
Da das Archiv der täglichen Sicherung erneut fehlerhaft war, habe ich nun den Pfad der history DB wieder auf default gesetzt.
Also auf: /opt/iobroker/iobroker-data /history/

Ein manuell ausgelöstes BackUp (mit laufendem History-Adapter) war sofort fehlerfrei.
Drei weitere Sicherung wiederum mit Fehler.

Das legt zunächst den Gedanken nahe, dass der USB-Stick als Pfad für die history DB beim erzeugen der Archive nicht ursächlich ist.

Ein weiteres BackUp mit gestopptem history-Adapter führte auch - wie drei weitere Versuche - zu einem fehlerhaften Archiv.

Damit fällt der aktive History-Adapter in dieser Konstellation auch als Ursache vermulich aus.

Da verschiedene Sicherungsziele an der NAS (USB1, USB2 HDD) keinen Einfluss auf die bisherigen Ergebnis hatten, kann hier auch eher nicht die Ursache zu finden sein.

Was bleibt noch als Fehlerquelle?
Wenn Jemand Ideen hat, bitte her damit

Schönes WE

[simatec]

@wcag22 Was läuft denn da für ein Dateisystem auf dem USB Stick?

[Homoran]

@wcag22 sagte in Fehler im BackUp der history DB:

kann hier auch eher nicht die Ursache zu finden sein.

...außer beim Datentransfer iob <-> NAS

[Rico Sander]

@simatec sagte in Fehler im BackUp der history DB:

@wcag22 Was läuft denn da für ein Dateisystem auf dem USB Stick?

Stand eigentlich im output von diag.
sda5

 

*** FILESYSTEM ***
Filesystem     Type      Size  Used Avail Use% Mounted on
udev           devtmpfs  3.6G     0  3.6G   0% /dev
tmpfs          tmpfs     781M  1.2M  780M   1% /run
/dev/mmcblk0p2 ext4       29G  9.6G   18G  36% /
tmpfs          tmpfs     3.9G     0  3.9G   0% /dev/shm
tmpfs          tmpfs     5.0M   16K  5.0M   1% /run/lock
/dev/mmcblk0p1 vfat      510M   57M  454M  12% /boot/firmware

/dev/sda5      ext4       27G  2.2G   24G   9% /media/USBintern

tmpfs          tmpfs     781M     0  781M   0% /run/user/1000

[Rico Sander]

@homoran sagte in Fehler im BackUp der history DB:

@wcag22 sagte in Fehler im BackUp der history DB:

kann hier auch eher nicht die Ursache zu finden sein.

...außer beim Datentransfer iob <-> NAS

Das ist richtig. An das LAN Kabel hatte ich auch schon gedacht :-)
Spass beiseite.

Nachdem das Problem auch mit dem Verschieben der history in den default Path nicht behoben wurde, der USB-Stick also komplet außen vor ist - wäre das eines der nächsten Dinge, die getestet werden könnten.

BTW: Im Moment ist jede Sicherung fehlerhaft.

Was mir noch einfällt:
Die SD Card, auf der das OS und ioB läuft,
der RAM des neuen 8G-Pi4.

Bei Ersterem müsste bekannt sein, ob die SD Card überhaupt im Prozess des Packens eine Rolle spielt (also geschrieben und gelesen wird) oder ob das nur um RAM passiert.

Die zweite Annahme ist sicher im Bereich des Möglichen, aber das wäre natürlich der Super GAU.

[Rico Sander]

@homoran sagte in Fehler im BackUp der history DB:

@wcag22 sagte in Fehler im BackUp der history DB:

kann hier auch eher nicht die Ursache zu finden sein.

Nachtrag:

...außer beim Datentransfer iob <-> NAS

An was denkst Du dabei?
Der / die Zieldatenträger fallen aus, da der Fehler in allen drei Konstellationen (2 unterschiedliche USB-Sticks, an 2 unterschiedlichen NAS-Ports und eine HD, die von der Synology als "gesund" gemeldet wird) auftrat.

Aber, warte mal:
Auf dem LAN-Strang hängt am switch noch ein Powerline Gerät. Die sind bekannt auch für anderweitige Störungen.

Cool - muss ich morgen gleich probieren. Danke für den Gedankenanstoss.

Edit:
Naja, das mit der Übertragung ist bei nochmaligem Nachdenken nicht ganz schlüssig. Denn da ist das Archiv ja schon fertig gepackt. Ob da Störungen einzelne Dateien innerhalb des Archives beeinflussen können , weiß ich nicht.

Edit2:
Der Fehler liegt auch immer im *.tar - Teil des Gesamtarchives *.tar.gz

[simatec]

@wcag22 Beobachte mal mit htop deine RAM Auslastung beim Schreiben des Backups

[Rico Sander]

@simatec sagte in Fehler im BackUp der history DB:

@wcag22 Beobachte mal mit htop deine RAM Auslastung beim Schreiben des Backups

Weil eventuell die 8 GB RAM nicht zum Packen einer gut 2 GB großen DB reichen?
Ok, kann ich mal machen.

[simatec]

@wcag22 sagte in Fehler im BackUp der history DB:

Weil eventuell die 8 GB RAM nicht zum Packen einer gut 2 GB großen DB reichen?

Da könnte das Problem liegen