Files already synced are being (supposedly) synced again

Taking a look at recent log files I noticed something strange. Some old files, which had already been synced, are being reported as “copied (new)”. But not even Dropbox shows this new “copy”.

The files are not modified in the source folder, and Dropbox does not inform a new version.

Today log:

2018/04/03 22:26:24 INFO  : 04.Biblioteca/BOW TIE/gerenciamento_bowtie.pdf: Copied (new)

File in source folder:
source

File in destination (Dropbox):

History in dropbox:

That is, the log shows that the file was copied (and should not, since it was not modified), but not even Dropbox shows this new “version”.

And there’s nothing in the --backup-dir folder.

This is a folder with a few thousand files, and this is happening with a few dozen files in the last runs, and different files with each run.

Any idea?

Hmm there is another thread on the forum with a similar issue (may not be related though!)

What happens if you try rclone check from the source to the dest?

Can you try rclone ls the remote a few times and see if it gives the same results every time? It is as though there are files missing from the directory listing.

Here is the result of check:

2018/04/04 11:16:21 NOTICE: Dropbox root 'ioioioio': 59 files missing
2018/04/04 11:16:21 NOTICE: Local file system at ioioioio: 44 files missing
2018/04/04 11:16:21 NOTICE: Dropbox root 'ioioioio': 106 differences found
2018/04/04 11:16:21 Failed to check: 106 differences found

And rclone ls reported three times (consistently):

11562 files on local folder

and

11547 files on Dropbox folder

I’ve run the script (sync) three more times, and now check shows me:

2018/04/04 20:23:16 NOTICE: Dropbox root 'ioioioio': 2 files missing
2018/04/04 20:23:16 NOTICE: Dropbox root 'ioioioio': 4 differences found
2018/04/04 20:23:16 Failed to check: 4 differences found

It is noteworthy that in the meantime some files were changed at the source, and were correctly synchronized to the destination.

Can you send me a log of the sync run with -vv please? I’d like to see exactly what is going on.

Can you email it to nick@craig-wood.com with a link to this page so I know what it is about - thanks!

I finally got some time to verify the check output to identify the “4 differences”, and see what I found:

Line 6: 2018/04/04 20:11:19 ERROR : .dropbox: File not in Dropbox root '[storage at Dropbox]'
Line 7: 2018/04/04 20:11:19 ERROR : desktop.ini: File not in Dropbox root '[storage at Dropbox]'
Line 8790: 2018/04/04 20:19:25 ERROR : [file1]: DropboxHash differ
Line 10728: 2018/04/04 20:21:45 ERROR : [file2]: DropboxHash differ

.dropbox and desktop.ini are excluded by the --filter-from parameter, and I actually forgot to put it in this specific check script.

And regarding the two other files:

2018/04/04 20:19:25 DEBUG : [file1]: DropboxHash = 0c2396ab40fc4c1cc7f7e743f61aee6d660acee477cf9f3866edd7e5d8d188a1 (Local file system at [local folder])
2018/04/04 20:19:25 DEBUG : [file1]: DropboxHash = 28c3770bb48d69259c6dfa57bbc390d5ff03fdb33a681b37091cbd4bcc042a27 (Dropbox root '[storage at Dropbox]')
2018/04/04 20:19:25 ERROR : [file1]: DropboxHash differ

2018/04/04 20:21:45 DEBUG : [file2]: DropboxHash = 2cdb3b927f932bbcbc6def885b727121fd5e704014268db543cc698bceead0a2 (Local file system at [local folder])
2018/04/04 20:21:45 DEBUG : [file2]: DropboxHash = 47672db9b1368630eb0bb096425ba2e77a32b37dc5d882da1329fc662cbb7269 (Dropbox root '[storage at Dropbox]')
2018/04/04 20:21:45 ERROR : [file2]: DropboxHash differ

These two files above have not been changed recently, the first one had the last change on March 8 and the other in 2017:

Capturar-1Capturar-2

The modification dates/times of the files in Dropbox are exactly the same:

file1file2

What may have happened to change the hash? How can I check this?

And the main doubt: at the beginning of this post I had 106 “differences”. Running sync script several times reduced to only 2. But what is the reason for these “differences”?

I saw this Dropbox page, but I didn’t find anything that would help to explain:

Either the local file changed or the remote file changed, or the hash is wrong in the dropbox database.

I suggest you download the file and check it against your local copy and see if it is different in any way

It would be helpful to see some more log with -vv as it is difficult to know what is going on without it.

Is it possible that those files never got uploaded properly in the first place? Or possibly their modification times got changed locally?

I just sent the logs, I had forgotten.

I downloaded the file and compared to the local version, and the hashes are really different, although the dates, etc are the same.

Capturar-2

Capturar-1

No, I just opened the file I downloaded (an excel worksheet) and it opened perfectly, even in the same position (a cell at the end) of the local file.

Nope, see the post above, the dates and times in the local folder and Dropbox are exactly the same.

Some more hash information related to one of these files:

file dbhashsum at dropbox:
28c3770bb48d69259c6dfa57bbc390d5ff03fdb33a681b37091cbd4bcc042a27  

file dbhashsum original local:
2910081e3ab46c347d8df036ad852dbffcb66e5e643881ffcc687c581ae28032  

downloaded file dbhashsum:
b68bb41669043f25cc128c2cee35bfdb0a99f300ae93d38523a66a478b283bf0


file md5sum original local:
47581e3b2d1f5bf1cf54a19ebedeb337

downloaded file md5sum:
c25f547ead378c8bb0f875ea13f4481f 

Can you determine which version of the file is correct? What we’d like to know is whether the file changed/got corrupted locally or on dropbox?

From my point of view as a user, all are correct and equal. It is an Excel spreadsheet. The original file opens perfectly, the file downloaded from the backup opens identically (even in the same cell) and this same file opens in Dropbox via the web interface.

As a user, I would not even notice the different hashes.

By doing a binary comparison between the files, I noticed a small difference in the last line:

***** file 1
21781:
21782:  @±é═Ë■   
21783:
***** file 2
21781:
21782:  á7<═Ë■   
21783:

Yet the mysteries remain: how can they be different if the modification times are the same? Could it be that Dropbox did something? Why only in this file, and a few others?

Anyway, it does not seem to be a problem with Rclone, it’s some exogenous factor.

Rclone is working properly, because the files have the same timestamp but different hashes, and Rclone is not synchronizing them because I don’t use the --checksum option.

I wonder if I should take this option as default …:thinking:

This issue just got reported: https://github.com/ncw/rclone/issues/2218 which explains the initial part of your query - the files being synced again.

What I normally do is just do modtime syncing, but every now and again do an rclone check which will check the hashes.

Well, not exactly, because in this #2218 issue the modification times are different, and in my case (from the start with that “2014” file) the modification times are the same.

But I keep my opinion that in my case it’s not a problem with Rclone, but some external factor.

I’ll leave the job running normally (daily) and in a few days I’ll run a check to see if any new hash issues have come up.

OK great - let me know what happens!

So as I said above, I left the script running daily in these last days.

Today I checked again and:

Line 8804: 2018/04/09 20:12:34 ERROR : [file1]: DropboxHash differ
Line 10751: 2018/04/09 20:16:48 ERROR : [file2]: DropboxHash differ

(The same two files)

This time I’ll do it differently: I’ll delete these 2 files above in Dropbox and see what happens in the next executions of sync. If there were no more errors, then there was some problem with these files (some external cause, Dropbox, etc) and life goes on.

If, on the other hand, new hash errors appear in other files, then I’ll start to get worried.

Note: the files have the same modtime and open perfectly.

OK, that sounds like a good experiment!

Well, unfortunately the hash problem came up in a new file (and did not appear any more for the other two above):

Line 973: 2018/04/13 12:43:58 ERROR : [file 3]: DropboxHash differ

But I think I managed to identify something: all problems occurred with files that are in a folder shared with another Dropbox user. I’ve identified that this new [file 3] with hash issues was recently modified by this user.

What I do not understand is:

  1. Why, after all synchronized and with rclone sync running multiple times, with modtimes and content the same in all locations, there is still a hash difference.

  2. Why other files (a lot) that this other user changed do not present the same problem?

The following is a schematic of the configuration, to clarify:

dropbox

dbhashsum - local file:
e0d4e46c53cb2bb10dbbb5a99b913abdcfdf4c399125b2943dd16ebca77be6b2

dbhashsum - Dropbox file:
e0d4e46c53cb2bb10dbbb5a99b913abdcfdf4c399125b2943dd16ebca77be6b2

dbhashsum - Dropbox BACKUP file:
85aa4eaeeea3dd5ca4801aea2d9285db2f2e45b6201b1d984722f228bc4630f5

Anyway, the problem does not disturb my backup (rclone sync), since the new versions are being copied correctly.

The problem is that it generates “false positives” in the check command, so I can not get consistent results for an automated backup verification script.

I’m sure that if I delete the file in the backup folder and reupload it, the hashes will become equal, as the other two previous files.

Something very strange is happening, I opened a ticket on Dropdobx support…

File versions history in Dropbox:

File at Dropbox folder:

File at local folder:

file_local_folder

File at Dropbox backup folder: