Time Backup Fehler seit 01.10.2014

[ChristianH]

Hallo,

seit dem 01.10. habe ich das Problem, dass das Time Backup auf eine über OpenVPN angebundene DS109 nicht mehr sauber durchgeführt wird.

Im Protokoll sehe ich folgende Fehlermeldungen, wobei die Return-Codes etwas variieren: meistens 23, manchmal aber auch 10 oder 30. Weiter unten habe ich das Protokoll vom 30.09. abgedruckt zum Vergleich. Demnach kann es an "K_ERR:try to create SSH tunnel" nicht liegen.

Hat jemand eine Idee?

Vielen Dank im voraus!

Gruß
Christian

Automatisch von TB gestartet:
Oct 09 01:00:02 [24450]BK_INFO:task_7[My backup Set 1] starts running.
Oct 09 01:00:02 [24450]BK_INFO:Creating snapshots.
Oct 09 01:00:02 [24454]BK_ERR:try to create SSH tunnel
Oct 09 01:00:19 [24450]BK_INFO:Counting total size.
Oct 09 01:00:19 [24450]BK_INFOreparing copying data.
Oct 09 01:00:21 [24450]BK_INFO:Transferring: Reports_Protokolle_Logs
Oct 09 01:00:23 [24450]BK_INFO:Transferring: homes
Oct 09 01:37:05 [24450]BK_ERR:rsync return with error, return code = 23
Oct 09 01:37:05 [24450]BK_ERR:not implement undo remote job yet
Oct 09 01:37:05 [24450]BK_INFO:Transferring: photo
Oct 09 01:37:07 [24450]BK_ERR:rsync return with error, return code = 23
Oct 09 01:37:07 [24450]BK_ERR:not implement undo remote job yet
Oct 09 01:37:07 [24450]BK_INFO:Transferring finished.
Oct 09 01:37:10 [24450]BK_INFO:task_7[My backup Set 1] finished. Smart recycle working...
Oct 09 01:37:11 [24450]BK_INFO:task_7[My backup Set 1] smart recycle done.

Manuell angestoßen:
Oct 09 08:17:32 [31273]BK_INFO:task_7[My backup Set 1] starts running.
Oct 09 08:17:32 [31273]BK_INFO:Creating snapshots.
Oct 09 08:17:32 [31329]BK_ERR:try to create SSH tunnel
Oct 09 08:17:49 [31273]BK_INFO:Counting total size.
Oct 09 08:17:49 [31273]BK_INFOreparing copying data.
Oct 09 08:17:51 [31273]BK_INFO:Transferring: Reports_Protokolle_Logs
Oct 09 08:17:53 [31273]BK_INFO:Transferring: homes
Oct 09 08:18:57 [31273]BK_ERR:rsync return with error, return code = 10
Oct 09 08:18:57 [31273]BK_ERR:not implement undo remote job yet
Oct 09 08:18:57 [31273]BK_INFO:Transferring: photo
Oct 09 08:20:01 [31273]BK_ERR:rsync return with error, return code = 10
Oct 09 08:20:01 [31273]BK_ERR:not implement undo remote job yet
Oct 09 08:20:01 [31273]BK_INFO:Transferring finished.
Oct 09 08:20:13 [31273]BK_INFO:task_7[My backup Set 1] finished. Smart recycle working...
Oct 09 08:20:13 [31273]BK_INFO:task_7[My backup Set 1] smart recycle done.

Als noch alles ok war:
Sep 30 01:00:20 [19718]BK_INFO:task_7[My backup Set 1] starts running.
Sep 30 01:00:20 [19718]BK_INFO:Creating snapshots.
Sep 30 01:00:20 [19725]BK_ERR:try to create SSH tunnel
Sep 30 01:00:42 [19718]BK_INFO:Counting total size.
Sep 30 01:00:42 [19718]BK_INFOreparing copying data.
Sep 30 01:00:44 [19718]BK_INFO:Transferring: Reports_Protokolle_Logs
Sep 30 01:00:46 [19718]BK_INFO:Transferring: homes
Sep 30 01:01:18 [19718]BK_INFO:Transferring: photo
Sep 30 01:01:51 [19718]BK_INFO:Transferring finished.
Sep 30 01:01:55 [19718]BK_INFO:task_7[My backup Set 1] finished. Smart recycle working...
Sep 30 01:01:56 [19718]BK_INFO:task_7[My backup Set 1] smart recycle done.

 

[dil88]

Der rsync-exitcode 10 steht für "Error in socket I/O"". Kann es sein, dass der rsync-Server auf der 109 nicht mehr läuft?

 

[ChristianH]

Danke für die schnelle Antwort!
Wie bekomme ich das raus, ob der läuft?

Meistens war es aber Return-Code 23...

 

[dil88]

Sorry, steht ja oben. Exitcode 23 steht für "Partial transfer due to error". Das heißt m.E., dass er zwar etwas übertragen, dann aber wegen eines Fehlers abgebrochen hat. Im ersten Moment dachte ich an Sonderzeichen. Aber dass Du die am gleichen Tag auf den beiden Shares hinzugefügt hast, ist schon sehr unwahrscheinlich.

Wegen des rsync-Servers schau bitte einmal im DSM-Frontend der 209, ob der Netzsicherungsdienst (oder so ähnlich) läuft.

 

[ChristianH]

Ja, es ist richtig, teilweise wurde etwas übertragen, allerings immer weniger. Von ursprünglich mal 148 GB sind am Ende noch 1,8 MB übrig. Sage und schreibe 2 Dateien und noch alle Ordner - diese sind aber eben leer.

Auf meiner DS109 habe ich folgende Einstellungen zur Netzwerksicherung:

 

[dil88]

Das sieht richtig aus, aber im englischsprachigen Forum hatte einer das gleiche Problem (hier) und hat es so gelöst, dass er den Time-Backup-Dienst und den Netzwerk-Sicherungsdienst zunächst deaktiviert und dann wieder aktiviert hat. Bitte probiere das doch auch einmal aus.

 

[ChristianH]

Nun läuft das Backup schon 20 min... Ich wage es fast nicht zu hoffen, dass die Lösung so einfach war...
Ich melde mich nochmal, wenn es durch ist. Danke vorab!

 

[dil88]

Ich drücke die Daumen. Solche Lösungen gibt es öfter, insofern bin ich guter Hoffnung, dass es jetzt wieder geht.

 

[DKeppi]

Zur Not gäbe es auch noch das File /var/log/rsync.error auf der Syno (auffindbar per SSH)
Da steht manchmal mehr zur Fehlermeldung drinnen...

 

[ChristianH]

Leider doch zu früh gefreut... :-(

Oct 09 09:40:44 [4796]BK_INFO:task_7[My backup Set 1] starts running.
Oct 09 09:40:44 [4796]BK_INFO:Creating snapshots.
Oct 09 09:40:44 [4798]BK_ERR:try to create SSH tunnel
Oct 09 09:40:54 [4796]BK_INFO:Counting total size.
Oct 09 09:40:54 [4796]BK_INFOreparing copying data.
Oct 09 09:40:56 [4796]BK_INFO:Transferring: Reports_Protokolle_Logs
Oct 09 09:40:58 [4796]BK_INFO:Transferring: homes
Oct 09 10:18:54 [4796]BK_ERR:rsync return with error, return code = 23
Oct 09 10:18:54 [4796]BK_ERR:not implement undo remote job yet
Oct 09 10:18:54 [4796]BK_INFO:Transferring: photo
Oct 09 10:18:55 [4796]BK_ERR:rsync return with error, return code = 23
Oct 09 10:18:55 [4796]BK_ERR:not implement undo remote job yet
Oct 09 10:18:55 [4796]BK_INFO:Transferring finished.
Oct 09 10:18:58 [4796]BK_INFO:task_7[My backup Set 1] finished. Smart recycle working...
Oct 09 10:18:58 [4796]BK_INFO:task_7[My backup Set 1] smart recycle done.

Auszug aus dem rsync.error Log:

Von 10:04 bis 10:18:40 Einträge wie dieser:
Oct 09 10:04:32 (5641) [ERROR]: WARNING: homes/Christian/CloudStation/Bilder/2014/2014-04-19/22629_DSC03465.dng.bc failed verification -- update discarded (will try again).
Oct 09 10:04:34 (5641) [ERROR]: rsync: read errors mapping "/tmp/timebkp_4796/volume1/homes/Christian/CloudStation/Bilder/2014/2014-04-19/22629_DSC03465.dng.bc": Input/output error (5)

Ab 10:18:41 Einträge wie dieser:
Oct 09 10:18:41 (5641) [ERROR]: ERROR: homes/Christian/#recycle/CloudStation/Lightroom/Lightroom 5 Catalog_neu/Lightroom/Lightroom 5 Catalog_neu.lrcat failed verification -- update discarded.
Oct 09 10:18:41 (5641) [ERROR]: ERROR: homes/Christian/#recycle/CloudStation/Lightroom/Lightroom 5 Catalog_neu/Lightroom/@eaDir/Lightroom 5 Catalog_neu.lrcat/SYNO_DTIME failed verification -- update discarded.

Die letzte 5 Einträge:
Oct 09 10:18:53 (5641) [ERROR]: ERROR: homes/Christian/CloudStation/Bilder/2014/2014-06-13/24935_DSC05834.dng.bc failed verification -- update discarded.
Oct 09 10:18:53 (5641) [ERROR]: ERROR: homes/Christian/CloudStation/Bilder/2014/2014-06-13/FolderKey.bch failed verification -- update discarded.
Oct 09 10:18:54 (5641) [ERROR]: rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1240) [sender=3.0.9]
Oct 09 10:18:55 (24370) [ERROR]: rsync: link_stat "/tmp/timebkp_4796/volume1/photo" failed: No such file or directory (2)
Oct 09 10:18:55 (24370) [ERROR]: rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1240) [sender=3.0.9]

 

[dil88]

Ja, leider. Aber der Hinweis von DKeppi ist Gold wert, die rsync.error ist ja wesentlich informativer. Was sind denn das für *.bc-Files?

Und: Könntest Du einmal auf der 209 die SMART-Werte der Platten prüfen oder ggfs. hier Screenshots aller Werte posten?

 

[ChristianH]

Die bc-Files sind mit Boxcryptor verschlüsselt Files. Die habe ich aber schon immer und dürften nicht die Ursache des Problems sein.

Die SMART-Werte der DS109 (nur eine Platte):

 

[dil88]

Sorry, 109 natürlich ... Die SMART-Werte sind unauffällig, da gibts nicht zu meckern. Mir gehen so langsam die Ideen aus.

 

[ChristianH]

Schade.

Auffällig fand ich aber, dass das Deaktivieren und Aktivieren der Netzwerksicherung und TB offenbar dazu geführt hat, dass der Syncvorgang anders ablief. Zumindest dauerte er ja 40 min statt 1, auch wenn im Ergebnis nichts gesichert wurde.

Dann werde ich als letzte Möglichkeit ein Ticket bei Synology aufmachen müssen.

Aber danke für Deine Unterstützung.

 

[ChristianH]

Eine Sache ist mir noch aufgefallen: Mit Start des TB wird teilweise die OpenVPN-Verbindung abgebrochen und muss sich erst neu aufbauen. Gibt das vielleicht noch einen Hinweis?

 

[ChristianH]

Hallo,
ich muss das Thema nochmal aus der Versenkung holen. Mittlerweile hatte ich den Synology-Support angeschrieben. Der sagte mir, dass mit DSM 5.1 TimeBackup abgeschafft werden würde und das Standardtool "Datensicherung und Replikation" weitere Features wie Versionierung erhalten würde.
Ich stelle jetzt aber fest, dass TimeBackup sehr wohl noch existiert und das Standardtool keine neuen Funktionalitäten aufweist. Die "maximale Anzahl an Versionen" hat ja nichts mit der Versionierung der Sicherungskopien auf der Zielumgebung zu tun.
D.h. an dieser Stelle ist alles beim Alten - oder übersehe ich da etwas?
Gruß
Christian

PS: Meine Abbruchprobleme habe ich weiterhin in unterschiedlichster Form. D.h. seit Anfang Oktober keine reguläre Sicherungskopie mehr. :-(

 

[meagain]

Ich habe vom Synology Suppport auf meine Anfrage als Antwort erhalten, dass sich viele Kunden wegen der Abkündigung gemeldet hätten und Time Backup daher unter DSM 5.x noch weiter angeboten werde...

Nachtrag:

As many beta users requested us to keep supporting Time Backup, we decided to postponed the EOL of Time Backup. Therefore, Time Backup will still be available in DSM 5.x.

We have updated the release note of DSM5.1 beta and Time Backup package for DSM5.1 beta recently.

 

[ChristianH]

Danke für die Info.
Klingt dann aber nur nach "aufgeschoben ist nicht aufgehoben" - kann uns also noch blühen, dass TB tatsächlich ausgelistet wird.
Hoffentlich kann dann das Standardbackup etwas mehr als heute.

 

[meagain]

Sehe ich genau so... Aber wenn wir dereinst wieder alle dem Support schreiben, dass wir keinen würdigen Nachfolger sehen, wer weiss...

 

[anlatana]

Bei mir hat sich auch der oben beschriebene Fehler mit returncode 23 eingestellt.

Ich hatte den Verdacht, dass es zu sichernde Dateien gibt von gelöschten Benutzern. Der Fehler trat bei mir auf nachdem ich ein oder zwei Benutzer gelöscht habe. Einen wirklichen Zusammenhang bezweifele ich mittlerweile. Es war wohl Zufall.

Melde mich ggf. Mit neuen Erkenntnissen.