problems reading file list from backend

[GoogleCodeExporter]

What steps will reproduce the problem?
1. running incremental backup
2. backend is ssh
3.

What is the expected output? What do you see instead?
Expected: working backup

Seen (r953):

Error: System.Exception: Gemäß Sicherungslisten-Datei sollte die Datei mit 
duplicati-inc-signature.20111021T040342Z.vol1.zip.gpg benannt sein, aber deren 
Name ist duplicati-inc-signature.20111021T040342Z.vol1.zip.
Wenn der Fehler nicht behoben werden kann, können Sie entweder einen neues 
Voll-Backup erstellen, oder die fehlerhaften Sicherungslisten-Dateien händisch 
löschen - gefolgt von einer anschließenden Bereinigung. Die widersprechenden 
Sicherungslisten-Dateien sind:

duplicati-inc-manifestA.20111027T041404Z.manifest.gpg
duplicati-inc-manifestA.20111026T102658Z.manifest.gpg
duplicati-inc-manifestA.20111025T040334Z.manifest.gpg
duplicati-inc-manifestA.20111024T130742Z.manifest.gpg
duplicati-inc-manifestA.20111023T040350Z.manifest.gpg
duplicati-inc-manifestA.20111022T120119Z.manifest.gpg
duplicati-inc-manifestA.20111021T040342Z.manifest.gpg

   bei Duplicati.Library.Main.Interface.VerifyBackupChainWithFiles(BackendWrapper backend, ManifestEntry entry)
   bei Duplicati.Library.Main.Interface.Backup(String[] sources)
   bei Duplicati.GUI.DuplicatiRunner.ExecuteTask(IDuplicityTask task)
Ergebnis des Aufräumens:

Note: The file is there, and it's named correctly. 

Alternatively, I also get (r946):

Error: System.Exception: Die Sicherungslisten-Datei 
duplicati-inc-manifestA.20111022T120119Z.manifest.gpg zeigt an, dass 1 Volumes 
vorhanden sein sollten, aber die Dateiliste zeigt nur 0
Wenn der Fehler nicht behoben werden kann, können Sie entweder einen neues 
Voll-Backup erstellen, oder die fehlerhaften Sicherungslisten-Dateien händisch 
löschen - gefolgt von einer anschließenden Bereinigung. Die widersprechenden 
Sicherungslisten-Dateien sind:

duplicati-inc-manifestA.20111027T041404Z.manifest.gpg
duplicati-inc-manifestA.20111026T102658Z.manifest.gpg
duplicati-inc-manifestA.20111025T040334Z.manifest.gpg
duplicati-inc-manifestA.20111024T130742Z.manifest.gpg
duplicati-inc-manifestA.20111023T040350Z.manifest.gpg
duplicati-inc-manifestA.20111022T120119Z.manifest.gpg

   bei Duplicati.Library.Main.Interface.VerifyBackupChainWithFiles(BackendWrapper backend, ManifestEntry entry)
   bei Duplicati.Library.Main.Interface.Backup(String[] sources)
   bei Duplicati.GUI.DuplicatiRunner.ExecuteTask(IDuplicityTask task)
Ergebnis des Aufräumens:

What version of Duplicati are you using? On what operating system?
1.2.3 r953 (and earlier r946) on Windows XP 32bit

What backend (destination) are you using?
ssh (hidrive.strato.com) [note: if you need a test account, let me know]

Please provide any additional information below.
I sometimes (esp. with r946) could solve this by just running the same backup 
again (incremental, as before).

This is probably related to issue #472.

I've attached a complete file list of the backup folder.

Original issue reported on code.google.com by mathias....@gmail.com on 28 Oct 2011 at 3:16

Attachments:

• ftp.txt

[GoogleCodeExporter]

The first error message is really weird. It indicates that the manifest file 
exists in both encrypted and non-encrypted versions. Do you know if this could 
be the case?
The file list does not indicate that this should happen.

The second error means that Duplicati found the manifest "20111022T120119Z" but 
that either the content or signature (or both) could not be found. However, 
looking at the file list, they are both there. This seems to indicate that the 
file listing goes bad.

Does the first error occur repeatedly?
Does the second error always show the same filename or does it change?

Original comment by kenneth@hexad.dk on 5 Nov 2011 at 9:05

• Changed state: Accepted
• Added labels: Priority-High
• Removed labels: Priority-Medium

[GoogleCodeExporter]

It seems that the first error doesn't occur anymore, maybe with the changed 
versions now. However, I do see the second error repeatedly.
Sometimes, after a few days of everything working fine, Duplicati starts 
producing this error, and this repeats when trying again. However, the numbers 
Duplicati complains about change. (The files are all there on the backend, I 
checked.) FYI, when using an ftp client, the file listing takes quite some time 
(in case, this could be something to do with the error).
Strangely enough, I have this behaviour only with this backend and host 
(hidrive.strato.com), a second one also running daily works fine.

Current error message collection from today:

Error: System.Exception: The manifest file 
duplicati-inc-manifestB.20111128T050224Z.manifest.gpg indicates that there 
should be 55 volumes, but the file list indicates 8
If this error cannot be resolved, you can either create a new full backup or 
delete the offending manifests manually, followed by a cleanup command. The 
offending manifest files are:

duplicati-inc-manifestA.20111203T050433Z.manifest.gpg
duplicati-inc-manifestA.20111201T050312Z.manifest.gpg
duplicati-inc-manifestB.20111130T005424Z.manifest.gpg
duplicati-inc-manifestB.20111128T050224Z.manifest.gpg

   at Duplicati.Library.Main.Interface.VerifyBackupChainWithFiles(BackendWrapper backend, ManifestEntry entry)
   at Duplicati.Library.Main.Interface.Backup(String[] sources)
   at Duplicati.GUI.DuplicatiRunner.ExecuteTask(IDuplicityTask task)

Error: System.Exception: The manifest file 
duplicati-inc-manifestA.20111130T005424Z.manifest.gpg indicates that there 
should be 2 volumes, but the file list indicates 1
If this error cannot be resolved, you can either create a new full backup or 
delete the offending manifests manually, followed by a cleanup command. The 
offending manifest files are:

duplicati-inc-manifestA.20111203T050433Z.manifest.gpg
duplicati-inc-manifestA.20111201T050312Z.manifest.gpg
duplicati-inc-manifestA.20111130T005424Z.manifest.gpg

   at Duplicati.Library.Main.Interface.VerifyBackupChainWithFiles(BackendWrapper backend, ManifestEntry entry)
   at Duplicati.Library.Main.Interface.Backup(String[] sources)
   at Duplicati.GUI.DuplicatiRunner.ExecuteTask(IDuplicityTask task)

Error: System.Exception: The manifest file 
duplicati-inc-manifestB.20111130T005424Z.manifest.gpg indicates that there 
should be 2 volumes, but the file list indicates 0
If this error cannot be resolved, you can either create a new full backup or 
delete the offending manifests manually, followed by a cleanup command. The 
offending manifest files are:

duplicati-inc-manifestA.20111203T050433Z.manifest.gpg
duplicati-inc-manifestA.20111201T050312Z.manifest.gpg
duplicati-inc-manifestB.20111130T005424Z.manifest.gpg

   at Duplicati.Library.Main.Interface.VerifyBackupChainWithFiles(BackendWrapper backend, ManifestEntry entry)
   at Duplicati.Library.Main.Interface.Backup(String[] sources)
   at Duplicati.GUI.DuplicatiRunner.ExecuteTask(IDuplicityTask task)

Error: System.Exception: The manifest file 
duplicati-inc-manifestA.20111130T005424Z.manifest.gpg indicates that there 
should be 2 volumes, but the file list indicates 1
If this error cannot be resolved, you can either create a new full backup or 
delete the offending manifests manually, followed by a cleanup command. The 
offending manifest files are:

duplicati-inc-manifestA.20111203T050433Z.manifest.gpg
duplicati-inc-manifestA.20111201T050312Z.manifest.gpg
duplicati-inc-manifestA.20111130T005424Z.manifest.gpg

   at Duplicati.Library.Main.Interface.VerifyBackupChainWithFiles(BackendWrapper backend, ManifestEntry entry)
   at Duplicati.Library.Main.Interface.Backup(String[] sources)
   at Duplicati.GUI.DuplicatiRunner.ExecuteTask(IDuplicityTask task)

Original comment by mathias....@gmail.com on 6 Dec 2011 at 9:25

[GoogleCodeExporter]

We are a little bit helpless about this issue. Let me try to summarize it to 
make sure we got it correctly:

* You are connecting to the Strato HiDrive with SFTP (SSH).

* Sometimes files seem to be missing.

* Connecting to the same account with FTP reveals that the server responds very 
slowly.

* This only happens sometimes but during that times it can be reproduced. 

* In most cases everything is fine.

Is that a correct summary?

Original comment by rst...@gmail.com on 6 Dec 2011 at 5:56

[GoogleCodeExporter]

Nearly correct.

When I connect by hand to check if all files are actually there, I'm using 
FileZilla and SFTP (i.e. SSH as well). The listing seemed slow to me (6s) but 
it contains nearly 1000 files by now (a full backup has around 140 volumes).

The chance of having a day with everything working seems to be rather 50/50 
(and I really have no idea what it could be).

Original comment by mathias....@gmail.com on 6 Dec 2011 at 6:39

[GoogleCodeExporter]

We now have a Strato SSH test account.
Rene has added some 8000+ files, but I always seem to get the full listing, 
even when using a 64kbps line :/

When the problem occurs, could you try to get a count of the number of files 
using something like FileZilla or sftp?
I am interrested in knowing if the file count reported by FileZilla differs 
when the problem is there compared to when the problem has gone away.

Original comment by kenneth@hexad.dk on 16 Dec 2011 at 8:36

[GoogleCodeExporter]

Here's this morning's error message:

Error: System.Exception: The manifest file 
duplicati-inc-manifestA.20111201T050312Z.manifest.gpg indicates that there 
should be 1 volumes, but the file list indicates 0
If this error cannot be resolved, you can either create a new full backup or 
delete the offending manifests manually, followed by a cleanup command. The 
offending manifest files are:

duplicati-inc-manifestA.20111215T050352Z.manifest.gpg
duplicati-inc-manifestA.20111212T050345Z.manifest.gpg
duplicati-inc-manifestA.20111210T050342Z.manifest.gpg
duplicati-inc-manifestA.20111208T050435Z.manifest.gpg
duplicati-inc-manifestA.20111203T050433Z.manifest.gpg
duplicati-inc-manifestA.20111201T050312Z.manifest.gpg

   at Duplicati.Library.Main.Interface.VerifyBackupChainWithFiles(BackendWrapper backend, ManifestEntry entry)
   at Duplicati.Library.Main.Interface.Backup(String[] sources)
   at Duplicati.GUI.DuplicatiRunner.ExecuteTask(IDuplicityTask task)
Cleanup output:

The file listing with FileZilla shows 984 files.

This is repeatable, I just tried again with the same result. Strangely enough, 
after a few days, the backup usually runs fine again. (I had a working backup 
on 16.12. with no files uploaded, one on 15.12. with one volume, errors on 14. 
and 13.12. and a working backup again on 12.12. with one volume.)

I'll check tomorrow again, and will update this in case the backup worked.

Original comment by mathias....@gmail.com on 17 Dec 2011 at 12:20

[GoogleCodeExporter]

Today's backup worked (it didn't upload anything, but that's correct).
I had one warning: "Auto-cleanup specified but there are 10 orphan files, and 
there should not be more than 2"

FileZilla still lists 984 files.

Original comment by mathias....@gmail.com on 18 Dec 2011 at 10:50

[GoogleCodeExporter]

I have no quick fix for this. I plan to add a full logging feature so that I 
can decisively figure out when/where the error occurs.

Original comment by kenneth@hexad.dk on 30 Dec 2011 at 5:47

[GoogleCodeExporter]

We have tried various approaches to try to provoke the error message "The 
manifest file indicates that there should be XX volumes, but the file list 
indicates YY", but to no avail. This error message means that something has 
changed unexpectedly on the remote server, but we do not know what/why exactly. 
Furthermore, we saw that message come and go with no changes in the meantime. 
The error message has been mentioned in issues #534, #472, #498, indicating 
that it is not a single defect server somewhere.

We have developed a new logging mechanism that will log all transactions 
performed against a backend, which will allow us to "replay" the sequence of 
operations that produces the error. The logging is done in a plain text/xml 
file with only archive filenames and sizes (i.e. no information about files 
being backed up or other personal information). With a log describing the 
operations that eventually caused the error, we should be able to figure out 
what went wrong and hopefully prevent it from happening in the future.

To assist in this, please do the following:
1) Download the latests development snapshot "Duplicati 1.3.1.1101"
2) Edit your backup job and set the advanced option "backend-log-database" to 
point to a non-existing file (e.g. "C:\duplicati-log.xml")
3) Use Duplicati as normal, until the error message appears
4) Send the file to us (please check that no sensitive information is included)

The file will newer reset, but you can delete it if you feel that it is 
becoming too big.
To disable the logging once again, simply remove the advanced option.

Original comment by kenneth@hexad.dk on 17 Jan 2012 at 1:59

[GoogleCodeExporter]

Thank you for implementing the logging mechanism, I'm happy I can finally do 
something to help tracking this.

I just added the log file option to my backup jobs, and on running one of them 
the error hit directly. I sent you the log via mail because I didn't want to 
put the log in here, I hope this is okay.

Original comment by mathias....@gmail.com on 17 Jan 2012 at 9:25

[GoogleCodeExporter]

Yes, I have the log file, thank you.
I will look through it when I have a moment.

Original comment by kenneth@hexad.dk on 18 Jan 2012 at 9:25