"./sync.test -test.v -test.timeout 1h0m0s -remote TestFileFabric: -verbose -test.run '^TestSyncBackupDirWithSuffix$'" - Starting (try 3/5) 2021/03/04 06:37:39 DEBUG : Creating backend with remote "TestFileFabric:rclone-test-luqojem1lowosap4namobef5" 2021/03/04 06:37:39 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: checkPathExists(map[path:rclone-test-luqojem1lowosap4namobef5 pid:120673762]) options=[] 2021/03/04 06:37:39 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:37:39 DEBUG : Creating backend with remote "/tmp/rclone550706435" === RUN TestSyncBackupDirWithSuffix run.go:176: Remote "filefabric root 'rclone-test-luqojem1lowosap4namobef5'", Local "Local file system at /tmp/rclone550706435", Modify Window "1s" 2021/03/04 06:37:39 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120673762 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:37:40 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:37:40 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doCreateNewFolder(map[fi_name:rclone-test-luqojem1lowosap4namobef5 fi_pid:120673762]) options=[] 2021/03/04 06:37:43 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:37:43 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859513 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:37:44 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:37:44 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doCreateNewFolder(map[fi_name:dst fi_pid:120859513]) options=[] 2021/03/04 06:37:47 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:37:47 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:one fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:one fi_pid:120859514 fi_size:3 responsetype:json]) options=[] 2021/03/04 06:37:49 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:37:50 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doCompleteUpload(map[fi_size:3 remotetime:2001-02-03 04:05:06 uploadcode:38415f6ff3f16d8bb6e895c8aefa8e68]) options=[] 2021/03/04 06:37:51 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:37:51 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:two fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:two fi_pid:120859514 fi_size:3 responsetype:json]) options=[] 2021/03/04 06:37:52 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:37:54 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doCompleteUpload(map[fi_size:3 remotetime:2001-02-03 04:05:06 uploadcode:47d160fbe691d4a5dd65f45770424833]) options=[] 2021/03/04 06:37:55 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:37:55 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:text/plain; charset=utf-8 fi_filename:three.txt fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:three.txt fi_pid:120859514 fi_size:5 responsetype:json]) options=[] 2021/03/04 06:37:57 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:37:58 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doCompleteUpload(map[fi_size:5 remotetime:2001-02-03 04:05:06 uploadcode:ca54e34e6648c40ea691484b182bf00e]) options=[] 2021/03/04 06:37:59 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:37:59 DEBUG : dst/three.txt: Correcting mime type from "text/plain" to "text/plain; charset=utf-8" 2021/03/04 06:37:59 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doModifyFile(map[data:fi_contenttype=text/plain; charset=utf-8 fi_id:120859518]) options=[] 2021/03/04 06:37:59 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:37:59 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859513 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:38:00 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:38:00 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859514 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:38:01 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:38:01 DEBUG : Creating backend with remote "TestFileFabric:rclone-test-luqojem1lowosap4namobef5/dst" 2021/03/04 06:38:01 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': rpc: checkPathExists(map[path:rclone-test-luqojem1lowosap4namobef5/dst pid:120673762]) options=[] 2021/03/04 06:38:01 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': >rpc: result=Success (ok), err= 2021/03/04 06:38:01 DEBUG : Creating backend with remote "TestFileFabric:rclone-test-luqojem1lowosap4namobef5/backup" 2021/03/04 06:38:01 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: checkPathExists(map[path:rclone-test-luqojem1lowosap4namobef5/backup pid:120673762]) options=[] 2021/03/04 06:38:02 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:38:02 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': rpc: getFolderContents(map[count:1000 fi_pid:120859514 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:38:02 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': >rpc: result=Success (ok), err= 2021/03/04 06:38:02 DEBUG : one: Sizes differ (src 4 vs dst 3) 2021/03/04 06:38:02 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: getFolderContents(map[count:1000 fi_pid:120673762 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:38:02 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/03/04 06:38:02 DEBUG : two: Unchanged skipping 2021/03/04 06:38:02 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': Waiting for checks to finish 2021/03/04 06:38:03 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:38:03 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: getFolderContents(map[count:1000 fi_pid:120859513 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:38:04 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:38:04 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: getFolderContents(map[count:1000 fi_pid:120859513 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:38:05 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:38:05 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: doCreateNewFolder(map[fi_name:backup fi_pid:120859513]) options=[] 2021/03/04 06:38:08 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:38:08 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: doRenameFile(map[fi_id:120859515 fi_name:one.bak.tuludid0]) options=[] 2021/03/04 06:38:16 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:38:16 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: doMoveFiles(map[dir_id:120859519 fi_ids:120859515]) options=[] 2021/03/04 06:38:39 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Succcess. (ok), err= 2021/03/04 06:38:39 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: doRenameFile(map[fi_id:120859515 fi_name:one.bak]) options=[] 2021/03/04 06:38:48 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:38:48 INFO : one: Moved (server-side) to: one.bak 2021/03/04 06:38:48 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': Waiting for transfers to finish 2021/03/04 06:38:48 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:one fi_localtime:2011-12-25 12:59:59 fi_modified:2011-12-25 12:59:59 fi_name:one fi_pid:120859514 fi_size:4 responsetype:json]) options=[] 2021/03/04 06:38:49 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': >rpc: result=Success (ok), err= 2021/03/04 06:38:50 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': rpc: doCompleteUpload(map[fi_size:4 remotetime:2011-12-25 12:59:59 uploadcode:015059b0f9c81473a13fce9d5bbb2318]) options=[] 2021/03/04 06:38:51 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': >rpc: result=Success (ok), err= 2021/03/04 06:38:51 INFO : one: Copied (new) 2021/03/04 06:38:51 DEBUG : Waiting for deletions to finish 2021/03/04 06:38:51 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: checkPathExists(map[path:three.txt.bak pid:120859519]) options=[] 2021/03/04 06:38:51 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:38:51 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: doRenameFile(map[fi_id:120859518 fi_name:three.txt.bak.yizekob8]) options=[] 2021/03/04 06:39:00 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:39:00 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: doMoveFiles(map[dir_id:120859519 fi_ids:120859518]) options=[] 2021/03/04 06:39:23 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Succcess. (ok), err= 2021/03/04 06:39:23 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: doRenameFile(map[fi_id:120859518 fi_name:three.txt.bak]) options=[] 2021/03/04 06:39:34 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:39:34 INFO : three.txt: Moved (server-side) to: three.txt.bak 2021/03/04 06:39:34 INFO : three.txt: Moved into backup dir 2021/03/04 06:39:34 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859513 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:35 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:35 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859514 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:35 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859519 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:37 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:37 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= fstest.go:297: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:300: Flushing the directory cache 2021/03/04 06:39:38 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120673762 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:39 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:39 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859513 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:39 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:39 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859514 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:39 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859519 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:39 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:39 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= fstest.go:297: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:300: Flushing the directory cache 2021/03/04 06:39:41 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120673762 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:41 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:41 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859513 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:42 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:42 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859514 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:42 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859519 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:42 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:42 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= fstest.go:297: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:300: Flushing the directory cache fstest.go:304: Error Trace: fstest.go:304 fstest.go:337 fstest.go:349 sync_test.go:1767 sync_test.go:1798 Error: Should be true Test: TestSyncBackupDirWithSuffix Messages: listing wrong, want backup/one.bak (3), backup/three.txt.bak (5), dst/one (4), dst/two (3) got backup/one.bak (3), backup/three.txt.bak.txt (5), dst/one (4), dst/two (3) fstest.go:190: Error Trace: fstest.go:190 fstest.go:307 fstest.go:337 fstest.go:349 sync_test.go:1767 sync_test.go:1798 Error: Should be true Test: TestSyncBackupDirWithSuffix Messages: Unexpected file "backup/three.txt.bak.txt" fstest.go:202: Not found "backup/three.txt.bak" fstest.go:205: Error Trace: fstest.go:205 fstest.go:309 fstest.go:337 fstest.go:349 sync_test.go:1767 sync_test.go:1798 Error: Not equal: expected: 0 actual : 1 Test: TestSyncBackupDirWithSuffix Messages: 1 objects not found 2021/03/04 06:39:46 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120673762 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:46 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:46 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859513 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:46 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:46 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:text/plain; charset=utf-8 fi_filename:three.txt fi_localtime:2011-12-25 12:59:59 fi_modified:2011-12-25 12:59:59 fi_name:three.txt fi_pid:120859514 fi_size:6 responsetype:json]) options=[] 2021/03/04 06:39:47 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:49 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doCompleteUpload(map[fi_size:6 remotetime:2011-12-25 12:59:59 uploadcode:769159da0184d179d1675a5881995dc0]) options=[] 2021/03/04 06:39:50 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:50 DEBUG : dst/three.txt: Correcting mime type from "text/plain" to "text/plain; charset=utf-8" 2021/03/04 06:39:50 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doModifyFile(map[data:fi_contenttype=text/plain; charset=utf-8 fi_id:120859543]) options=[] 2021/03/04 06:39:51 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:51 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859513 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:51 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:51 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859514 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:51 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859519 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:51 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:52 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= fstest.go:297: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:300: Flushing the directory cache 2021/03/04 06:39:53 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120673762 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:54 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:54 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859513 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:54 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:54 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859514 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:54 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859519 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:55 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:55 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= fstest.go:297: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:300: Flushing the directory cache 2021/03/04 06:39:57 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120673762 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:58 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:58 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859513 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:58 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:58 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859519 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:58 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859514 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:39:58 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:39:58 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= fstest.go:297: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:300: Flushing the directory cache fstest.go:304: Error Trace: fstest.go:304 fstest.go:337 fstest.go:349 sync_test.go:1773 sync_test.go:1798 Error: Should be true Test: TestSyncBackupDirWithSuffix Messages: listing wrong, want backup/one.bak (3), backup/three.txt.bak (5), dst/one (4), dst/three.txt (6), dst/two (3) got backup/one.bak (3), backup/three.txt.bak.txt (5), dst/one (4), dst/three.txt (6), dst/two (3) fstest.go:190: Error Trace: fstest.go:190 fstest.go:307 fstest.go:337 fstest.go:349 sync_test.go:1773 sync_test.go:1798 Error: Should be true Test: TestSyncBackupDirWithSuffix Messages: Unexpected file "backup/three.txt.bak.txt" fstest.go:202: Not found "backup/three.txt.bak" fstest.go:205: Error Trace: fstest.go:205 fstest.go:309 fstest.go:337 fstest.go:349 sync_test.go:1773 sync_test.go:1798 Error: Not equal: expected: 0 actual : 1 Test: TestSyncBackupDirWithSuffix Messages: 1 objects not found 2021/03/04 06:40:02 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': rpc: getFolderContents(map[count:1000 fi_pid:120859514 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:40:03 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': >rpc: result=Success (ok), err= 2021/03/04 06:40:03 DEBUG : one: Sizes differ (src 5 vs dst 4) 2021/03/04 06:40:03 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: checkPathExists(map[path:one.bak pid:120859519]) options=[] 2021/03/04 06:40:03 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/03/04 06:40:03 DEBUG : two: Unchanged skipping 2021/03/04 06:40:03 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': Waiting for checks to finish 2021/03/04 06:40:03 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:40:03 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: doDeleteFile(map[completedeletion:n fi_id:120859515]) options=[] 2021/03/04 06:40:15 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:40:15 INFO : one.bak: Deleted 2021/03/04 06:40:15 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: doRenameFile(map[fi_id:120859525 fi_name:one.bak.fexuyen5]) options=[] 2021/03/04 06:40:24 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:40:24 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: doMoveFiles(map[dir_id:120859519 fi_ids:120859525]) options=[] 2021/03/04 06:40:45 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Succcess. (ok), err= 2021/03/04 06:40:45 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: doRenameFile(map[fi_id:120859525 fi_name:one.bak]) options=[] 2021/03/04 06:40:54 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:40:54 INFO : one: Moved (server-side) to: one.bak 2021/03/04 06:40:54 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': Waiting for transfers to finish 2021/03/04 06:40:54 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:one fi_localtime:2011-12-30 12:59:59 fi_modified:2011-12-30 12:59:59 fi_name:one fi_pid:120859514 fi_size:5 responsetype:json]) options=[] 2021/03/04 06:40:55 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': >rpc: result=Success (ok), err= 2021/03/04 06:40:56 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': rpc: doCompleteUpload(map[fi_size:5 remotetime:2011-12-30 12:59:59 uploadcode:47095970fc7826d55913f83149236507]) options=[] 2021/03/04 06:40:57 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': >rpc: result=Success (ok), err= 2021/03/04 06:40:57 INFO : one: Copied (new) 2021/03/04 06:40:57 DEBUG : Waiting for deletions to finish 2021/03/04 06:40:57 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: checkPathExists(map[path:three.txt.bak pid:120859519]) options=[] 2021/03/04 06:40:57 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:40:57 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: doRenameFile(map[fi_id:120859543 fi_name:three.txt.bak.zetaguy6]) options=[] 2021/03/04 06:41:07 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:41:07 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: doMoveFiles(map[dir_id:120859519 fi_ids:120859543]) options=[] 2021/03/04 06:41:28 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=Succcess. (ok), err= 2021/03/04 06:41:28 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': rpc: doRenameFile(map[fi_id:120859543 fi_name:three.txt.bak]) options=[] 2021/03/04 06:41:30 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5/backup': >rpc: result=There is a file with the same name in the folder. (error), err=There is a file with the same name in the folder. (error) 2021/03/04 06:41:30 ERROR : three.txt: Couldn't move: failed to rename leaf: There is a file with the same name in the folder. (error) 2021/03/04 06:41:30 ERROR : three.txt: Couldn't move into backup dir: failed to rename leaf: There is a file with the same name in the folder. (error) 2021/03/04 06:41:30 ERROR : filefabric root 'rclone-test-luqojem1lowosap4namobef5/dst': not deleting directories as there were IO errors sync_test.go:1779: Error Trace: sync_test.go:1779 sync_test.go:1798 Error: Received unexpected error: failed to delete 1 files github.com/rclone/rclone/fs/operations.DeleteFilesWithBackupDir /home/rclone/go/src/github.com/rclone/rclone/fs/operations/operations.go:727 github.com/rclone/rclone/fs/sync.(*syncCopyMove).deleteFiles /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:533 github.com/rclone/rclone/fs/sync.(*syncCopyMove).run /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:877 github.com/rclone/rclone/fs/sync.runSyncCopyMove /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:1078 github.com/rclone/rclone/fs/sync.Sync /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:1084 github.com/rclone/rclone/fs/sync.testSyncBackupDir /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1778 github.com/rclone/rclone/fs/sync.TestSyncBackupDirWithSuffix /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1798 testing.tRunner /usr/local/go/src/testing/testing.go:1123 runtime.goexit /usr/local/go/src/runtime/asm_amd64.s:1374 Test: TestSyncBackupDirWithSuffix 2021/03/04 06:41:30 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120673762 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:41:31 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:41:31 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859513 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:41:32 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:41:32 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859519 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:41:32 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859514 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:41:33 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:41:33 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doDeleteFile(map[completedeletion:n fi_id:120859525]) options=[] 2021/03/04 06:41:33 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:41:46 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:41:46 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doDeleteFile(map[completedeletion:n fi_id:120859518]) options=[] 2021/03/04 06:41:54 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:41:54 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doDeleteFile(map[completedeletion:n fi_id:120859543]) options=[] 2021/03/04 06:42:02 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:42:02 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doDeleteFile(map[completedeletion:n fi_id:120859552]) options=[] 2021/03/04 06:42:10 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:42:10 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doDeleteFile(map[completedeletion:n fi_id:120859516]) options=[] 2021/03/04 06:42:18 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:42:18 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859514 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:42:19 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:42:19 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doDeleteFolder(map[fi_id:120859514]) options=[] 2021/03/04 06:42:21 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:42:21 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859519 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:42:22 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:42:22 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doDeleteFolder(map[fi_id:120859519]) options=[] 2021/03/04 06:42:24 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= 2021/03/04 06:42:24 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: getFolderContents(map[count:1000 fi_pid:120859513 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/03/04 06:42:25 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= --- FAIL: TestSyncBackupDirWithSuffix (285.27s) FAIL 2021/03/04 06:42:25 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': Purge remote 2021/03/04 06:42:25 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': rpc: doDeleteFolder(map[fi_id:120859513]) options=[] 2021/03/04 06:42:25 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': Sleeping for 6s to wait for "error_background" error to clear 2021/03/04 06:42:31 DEBUG : pacer: low level retry 1/10 (error The requested operation cannot be completed. A delete operation is already being processed in this folder. Please try again later. (error_background)) 2021/03/04 06:42:31 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2021/03/04 06:42:31 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': Sleeping for 6s to wait for "error_background" error to clear 2021/03/04 06:42:37 DEBUG : pacer: low level retry 2/10 (error The requested operation cannot be completed. A delete operation is already being processed in this folder. Please try again later. (error_background)) 2021/03/04 06:42:37 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2021/03/04 06:42:38 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': Sleeping for 6s to wait for "error_background" error to clear 2021/03/04 06:42:44 DEBUG : pacer: low level retry 3/10 (error The requested operation cannot be completed. A delete operation is already being processed in this folder. Please try again later. (error_background)) 2021/03/04 06:42:44 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2021/03/04 06:42:44 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': Sleeping for 6s to wait for "error_background" error to clear 2021/03/04 06:42:50 DEBUG : pacer: low level retry 4/10 (error The requested operation cannot be completed. A delete operation is already being processed in this folder. Please try again later. (error_background)) 2021/03/04 06:42:50 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2021/03/04 06:42:51 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': Sleeping for 6s to wait for "error_background" error to clear 2021/03/04 06:42:57 DEBUG : pacer: low level retry 5/10 (error The requested operation cannot be completed. A delete operation is already being processed in this folder. Please try again later. (error_background)) 2021/03/04 06:42:57 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2021/03/04 06:42:57 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': Sleeping for 6s to wait for "error_background" error to clear 2021/03/04 06:43:03 DEBUG : pacer: low level retry 6/10 (error The requested operation cannot be completed. A delete operation is already being processed in this folder. Please try again later. (error_background)) 2021/03/04 06:43:03 DEBUG : pacer: Rate limited, increasing sleep to 1.28s 2021/03/04 06:43:05 DEBUG : pacer: Reducing sleep to 960ms 2021/03/04 06:43:05 DEBUG : filefabric root 'rclone-test-luqojem1lowosap4namobef5': >rpc: result=Success (ok), err= "./sync.test -test.v -test.timeout 1h0m0s -remote TestFileFabric: -verbose -test.run '^TestSyncBackupDirWithSuffix$'" - Finished ERROR in 5m25.708991361s (try 3/5): exit status 1: Failed [TestSyncBackupDirWithSuffix]