Log says it uploaded files, but then says "0 bytes uploaded"

backup

#1

The backup takes 6 hours to go through 1.3TB, and I’m not sure if it’s being slowed down as it tries to upload literally every file, or if I should just ignore the “INFO UPLOAD_FILE” lines.

The log starts like this:

Running backup command from C:\Users\Rob/.duplicacy-web/repositories/localhost/0 to back up D:/Resilio_Sync/Archive
Options: [-log backup -storage Synolog2019-06-02 00:00:2019-06-02 00:00:01.539 INFO REPOSITORY_SET Repository set to D:/Resilio_Sync/Archive
2019-06-02 00:00:01.539 INFO STORAGE_SET Storage set to sftp://Backup@192.12019-06-02 00:002019-06-02 00:00:46.266 INFO BACKUP_START Last backup at revision 2296 found
2019-06-02 00:00:46.266 INFO BACKUP_INDEXING Indexing D:\Resilio_Sync\Archive
2019-06-02 00:00:46.266 INFO SNAPSHOT_FILTER Parsing filter file \\?\C:\Users\Rob\.duplicacy-web\repositories\localhost\0\.duplicacy\filters
2019-06-02 00:00:46.266 INFO SNAPSHOT_FILTER Loaded 4 include/exclude pattern(s)

Does nothing for 6 hours, then gives me a line for seemingly every file in the repository, saying it’s trying to upload it:

2019-06-02 06:26:15.602 INFO UPLOAD_FILE Uploaded audio_test_sourcecode/Test/.DS_Store (6148)
2019-06-02 06:26:15.602 INFO UPLOAD_FILE Uploaded audio_test_sourcecode/Test/Test.sesx (97718)
2019-06-02 06:26:15.602 INFO UPLOAD_FILE Uploaded audio_test_sourcecode/Test/Conformed Files/ModifiedMumble 48000 1.pkf (105160)
2019-06-02 06:26:15.602 INFO UPLOAD_FILE Uploaded audio_test_sourcecode/Test/Conformed Files/ModifiedMumble 48000 1.wav (2526192)
2019-06-02 06:26:15.602 INFO UPLOAD_FILE Uploaded audio_test_sourcecode/Test/Conformed Files/StandardMumble 48000 1.pkf (108520)
2019-06-02 06:26:15.602 INFO UPLOAD_FILE Uploaded audio_test_sourcecode/Test/Conformed Files/StandardMumble 48000 1.wav (2606832)
2019-06-02 06:26:15.602 INFO UPLOAD_FILE Uploaded blog/Summer Check-In.pages (120970)

Then finally ends with this:

2019-06-02 06:26:16.221 INFO BACKUP_END Backup for D:\Resilio_Sync\Archive at revision 2258 completed
2019-06-02 06:26:16.221 INFO BACKUP_STATS Files: 38052 total, 1330G bytes; 38052 new, 1330G bytes
2019-06-02 06:26:16.221 INFO BACKUP_STATS File chunks: 265983 total, 1330G bytes; 0 new, 0 bytes, 0 bytes uploaded
2019-06-02 06:26:16.221 INFO BACKUP_STATS Metadata chunks: 11 total, 32,815K bytes; 0 new, 0 bytes, 0 bytes uploaded
2019-06-02 06:26:16.221 INFO BACKUP_STATS All chunks: 265994 total, 1331G bytes; 0 new, 0 bytes, 0 bytes uploaded
2019-06-02 06:26:16.221 INFO BACKUP_STATS Total running time: 06:26:15

My other Duplicacy backups, on much less data, don’t give me all of these “INFO UPLOAD_FILE” lines. Is this expected?


#2

Is something updating the timestamps on these files between backups?

Are you using the -hash option for your backups?


#3

I don’t believe anything is updating the timestamps on those files. When I look through them, the timestamps don’t seem to have been modified. Also the smaller backup I’m running which doesn’t have this problem, is backing up the root folder. Let me explain the setup:

Backup 1: D:/Resilio_Sync/
(with a filter to ignore the “Archive” folder)
Runs every hour

Backup 2: D:/Resilio_Sync/Archive
Runs once a week

Backup 1 doesn’t have this problem. Backup 2 does.

Is it possible that nesting the backups this way is causing this problem? I’m using the latest Web UI version, and the Option field is blank, so I don’t believe it’s using the -hash option.


#4

I can’t think of why it would.

Are your snippets from the log file from a single backup job? These two lines are confusing me – specifically, that the revisions aren’t sequential.


#5

Another possibility, other than changed timestamps or the -hash option, is that these files do not exist in the previous revision. This can happen if you use the same repository id for different repositories, or if the last backup didn’t backup the entire directory for some reason.