FreeFileSync behavior

[matthewaholtz]

First post. Hopefully this is the appropriate location.


We have a client using FFS and discovered some critical files were missing from their backup. In looking at their Sync logs, on 8 April they files were successfully backed up to the share. During their first sync on the morning of 9 April, the Sync log displayed an error saying that it couldn’t move the filename.ffs_tmp (this was individual files) to the backup share, and wrote an Access Denied error in the log. All subsequent logs had error messages indicating that both the source and destination files had changed, and therefore would get sync’d. The result of this was that the critical files were deleted from the storage location and not resync’d. Somehow, the sync.ffs_db file on the server indicated that the file on the server and the file on the PC had both changed, and therefore would not be sync’d.

We know the user didnt directly modify the files on the backup location, but something within FFS indicated that the file was changed. My thought is that during the Overwrite attempt on the morning of the 9th where it errored out, it deleted the files, but for some reason an Access Denied message was returned. At the same time, the sync.ffs_db file indicated that both files had changed thus resulting in the specific files no longer synchronizing, ending with loss of data.

We need to understand how to prevent this from happening to others in the future. I have seen numerous logs recently that indicate files have been modified both on the server and on the PC, and I’m concerned we could end up with a similar situation as described above on other systems.

Log excerpt 8 April:

[17:37:01] Info: Creating file '\\BackupServer\BackupShareName\%user%\%user%\Documents\Introduction allometry question based approach SWOT.docx'
[17:37:01] Info: Overwriting file '\\BackupServer\BackupShareName\%user%\%user%\Documents\Introduction.docx'
[17:37:01] Info: Overwriting file '\\BackupServer\BackupShareName\%user%\%user%\Documents\PREDICT-TB\Candidate Selection Criteria.pptx'

Log excerpt morning of 9 April:

[08:45:17] Info: Overwriting file '\\BackupServer\BackupShareName\%user%\%user%\Documents\Introduction allometry question based approach SWOT.docx'
[08:47:32] Error: Cannot move file '\\BackupServer\BackupShareName\%user%\%user%\Documents\Introduction allometry question based approach SWOT.docx.ffs_tmp' to '\\BackupServer\BackupShareName\%user%\%user%\Documents\Introduction allometry question based approach SWOT.docx'.
Windows Error Code 5: Access is denied.
[08:47:32] Info: Overwriting file '\\BackupServer\BackupShareName\%user%\%user%\Documents\PREDICT-TB\Candidate Selection Criteria.pptx'
[08:49:56] Error: Cannot move file '\\BackupServer\BackupShareName\%user%\%user%\Documents\PREDICT-TB\Candidate Selection Criteria.pptx.ffs_tmp' to '\\BackupServer\BackupShareName\%user%\%user%\Documents\PREDICT-TB\Candidate Selection Criteria.pptx'.
Windows Error Code 5: Access is denied.

Subsequent log excerpts:

[13:09:34] Warning: The following items have unresolved conflicts and will not be synchronized:
'PREDICT-TB\Candidate Selection Criteria.pptx': Both sides have changed since last synchronization!
'Introduction allometry question based approach SWOT.docx': Both sides have changed since last synchronization!

[Zenju]

The following happened:

1. The file, shortened "SWOT.docx" was changed on one side, but not on the backup drive, so FFS's two-way sync mode detected that this file should be updated on the backup drive.

2. During synchronization the update of the file "SWOT.docx" on the backup drive consists of three steps: First "SWOT.docx.ffs_tmp" is created, then "SWOT.docx" is deleted and finally "SWOT.docx.ffs_tmp" is renamed to "SWOT.docx". The last step failed.

3. From FFS's perspective both sides have changed since the last sync, because in addition to the change on the source side, the file was deleted on the backup drive by FFS in step 2.

This indicates a permission issue: FFS was able to successfully create the tmp file on the backup drive, even allowed to delete the old file, but the move operation was denied.