"./sync.test -test.v -test.timeout 1h0m0s -remote TestFileFabric: -verbose -test.run '^TestSyncBackupDirWithSuffix$'" - Starting (try 5/5) 2021/03/04 06:48:18 DEBUG : Creating backend with remote "TestFileFabric:rclone-test-mavaqez7kuqadog6lemomel5" 2021/03/04 06:48:18 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: checkPathExists(map[path:rclone-test-mavaqez7kuqadog6lemomel5 pid:120673762]) options=[] 2021/03/04 06:48:19 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:48:19 DEBUG : Creating backend with remote "/tmp/rclone919063670" === RUN TestSyncBackupDirWithSuffix run.go:176: Remote "filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5'", Local "Local file system at /tmp/rclone919063670", Modify Window "1s" 2021/03/04 06:48:19 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': 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:48:20 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:48:20 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: doCreateNewFolder(map[fi_name:rclone-test-mavaqez7kuqadog6lemomel5 fi_pid:120673762]) options=[] 2021/03/04 06:48:23 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:48:23 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859604 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:48:24 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:48:24 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: doCreateNewFolder(map[fi_name:dst fi_pid:120859604]) options=[] 2021/03/04 06:48:27 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:48:27 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': 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:120859605 fi_size:3 responsetype:json]) options=[] 2021/03/04 06:48:29 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:48:30 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: doCompleteUpload(map[fi_size:3 remotetime:2001-02-03 04:05:06 uploadcode:ed3b17d8065977af682494720510d80a]) options=[] 2021/03/04 06:48:31 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:48:31 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': 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:120859605 fi_size:3 responsetype:json]) options=[] 2021/03/04 06:48:32 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:48:33 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: doCompleteUpload(map[fi_size:3 remotetime:2001-02-03 04:05:06 uploadcode:58f5c4fef24e9a00f4f7fce7ad39edae]) options=[] 2021/03/04 06:48:35 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:48:35 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': 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:120859605 fi_size:5 responsetype:json]) options=[] 2021/03/04 06:48:36 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:48:37 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: doCompleteUpload(map[fi_size:5 remotetime:2001-02-03 04:05:06 uploadcode:4f07ccf428d1f51e86478a50fe212f9d]) options=[] 2021/03/04 06:48:38 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:48:38 DEBUG : dst/three.txt: Correcting mime type from "text/plain" to "text/plain; charset=utf-8" 2021/03/04 06:48:38 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: doModifyFile(map[data:fi_contenttype=text/plain; charset=utf-8 fi_id:120859609]) options=[] 2021/03/04 06:48:38 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:48:38 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859604 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:48:39 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:48:39 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859605 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:48:40 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:48:40 DEBUG : Creating backend with remote "TestFileFabric:rclone-test-mavaqez7kuqadog6lemomel5/dst" 2021/03/04 06:48:40 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/dst': rpc: checkPathExists(map[path:rclone-test-mavaqez7kuqadog6lemomel5/dst pid:120673762]) options=[] 2021/03/04 06:48:40 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/dst': >rpc: result=Success (ok), err= 2021/03/04 06:48:40 DEBUG : Creating backend with remote "TestFileFabric:rclone-test-mavaqez7kuqadog6lemomel5/backup" 2021/03/04 06:48:40 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: checkPathExists(map[path:rclone-test-mavaqez7kuqadog6lemomel5/backup pid:120673762]) options=[] 2021/03/04 06:48:41 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:48:41 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/dst': rpc: getFolderContents(map[count:1000 fi_pid:120859605 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:48:41 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/dst': >rpc: result=Success (ok), err= 2021/03/04 06:48:41 DEBUG : one: Sizes differ (src 4 vs dst 3) 2021/03/04 06:48:41 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/dst': Waiting for checks to finish 2021/03/04 06:48:41 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/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:48:41 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/03/04 06:48:41 DEBUG : two: Unchanged skipping 2021/03/04 06:48:42 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:48:42 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: getFolderContents(map[count:1000 fi_pid:120859604 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:48:42 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:48:42 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: getFolderContents(map[count:1000 fi_pid:120859604 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:48:43 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:48:43 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: doCreateNewFolder(map[fi_name:backup fi_pid:120859604]) options=[] 2021/03/04 06:48:47 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:48:47 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: doRenameFile(map[fi_id:120859606 fi_name:one.bak.caduloj4]) options=[] 2021/03/04 06:48:55 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:48:55 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: doMoveFiles(map[dir_id:120859610 fi_ids:120859606]) options=[] 2021/03/04 06:49:19 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Succcess. (ok), err= 2021/03/04 06:49:19 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: doRenameFile(map[fi_id:120859606 fi_name:one.bak]) options=[] 2021/03/04 06:49:28 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:49:28 INFO : one: Moved (server-side) to: one.bak 2021/03/04 06:49:28 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/dst': Waiting for transfers to finish 2021/03/04 06:49:28 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/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:120859605 fi_size:4 responsetype:json]) options=[] 2021/03/04 06:49:29 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/dst': >rpc: result=Success (ok), err= 2021/03/04 06:49:30 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/dst': rpc: doCompleteUpload(map[fi_size:4 remotetime:2011-12-25 12:59:59 uploadcode:493eeba23a3fc1b400bcb1f051691f6b]) options=[] 2021/03/04 06:49:32 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/dst': >rpc: result=Success (ok), err= 2021/03/04 06:49:32 INFO : one: Copied (new) 2021/03/04 06:49:32 DEBUG : Waiting for deletions to finish 2021/03/04 06:49:32 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: checkPathExists(map[path:three.txt.bak pid:120859610]) options=[] 2021/03/04 06:49:32 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:49:32 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: doRenameFile(map[fi_id:120859609 fi_name:three.txt.bak.vayavof1]) options=[] 2021/03/04 06:49:41 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:49:41 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: doMoveFiles(map[dir_id:120859610 fi_ids:120859609]) options=[] 2021/03/04 06:50:02 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Succcess. (ok), err= 2021/03/04 06:50:02 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: doRenameFile(map[fi_id:120859609 fi_name:three.txt.bak]) options=[] 2021/03/04 06:50:12 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:50:12 INFO : three.txt: Moved (server-side) to: three.txt.bak 2021/03/04 06:50:12 INFO : three.txt: Moved into backup dir 2021/03/04 06:50:12 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859604 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:50:13 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:13 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859605 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:50:13 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859610 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:50:14 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:14 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >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:50:15 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': 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:50:16 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:16 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859604 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:50:17 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:17 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859605 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:50:17 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859610 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:50:17 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:18 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >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:50:20 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': 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:50:20 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:20 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859604 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:50:21 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:21 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859605 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:50:21 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859610 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:50:21 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:21 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >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:50:25 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': 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:50:26 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:26 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859604 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:50:26 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:26 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': 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:120859605 fi_size:6 responsetype:json]) options=[] 2021/03/04 06:50:27 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:29 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: doCompleteUpload(map[fi_size:6 remotetime:2011-12-25 12:59:59 uploadcode:655a6e5818c6d0570f7f819bab69f375]) options=[] 2021/03/04 06:50:30 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:30 DEBUG : dst/three.txt: Correcting mime type from "text/plain" to "text/plain; charset=utf-8" 2021/03/04 06:50:30 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: doModifyFile(map[data:fi_contenttype=text/plain; charset=utf-8 fi_id:120859620]) options=[] 2021/03/04 06:50:30 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:30 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859604 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:50:31 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:31 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859610 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:50:31 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859605 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:50:32 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:32 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >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:50:33 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': 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:50:34 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:34 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859604 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:50:35 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:35 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859605 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:50:35 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859610 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:50:35 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:35 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >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:50:37 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': 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:50:38 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:38 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859604 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:50:39 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:39 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859605 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:50:39 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859610 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:50:39 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:50:39 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >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:50:43 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/dst': rpc: getFolderContents(map[count:1000 fi_pid:120859605 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:50:43 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/dst': >rpc: result=Success (ok), err= 2021/03/04 06:50:43 DEBUG : one: Sizes differ (src 5 vs dst 4) 2021/03/04 06:50:43 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: checkPathExists(map[path:one.bak pid:120859610]) options=[] 2021/03/04 06:50:43 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/03/04 06:50:43 DEBUG : two: Unchanged skipping 2021/03/04 06:50:43 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/dst': Waiting for checks to finish 2021/03/04 06:50:44 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:50:44 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: doDeleteFile(map[completedeletion:n fi_id:120859606]) options=[] 2021/03/04 06:50:53 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:50:53 INFO : one.bak: Deleted 2021/03/04 06:50:53 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: doRenameFile(map[fi_id:120859615 fi_name:one.bak.kazeyuq9]) options=[] 2021/03/04 06:51:02 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:51:02 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: doMoveFiles(map[dir_id:120859610 fi_ids:120859615]) options=[] 2021/03/04 06:51:22 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Succcess. (ok), err= 2021/03/04 06:51:22 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: doRenameFile(map[fi_id:120859615 fi_name:one.bak]) options=[] 2021/03/04 06:51:32 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:51:32 INFO : one: Moved (server-side) to: one.bak 2021/03/04 06:51:32 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/dst': Waiting for transfers to finish 2021/03/04 06:51:32 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/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:120859605 fi_size:5 responsetype:json]) options=[] 2021/03/04 06:51:33 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/dst': >rpc: result=Success (ok), err= 2021/03/04 06:51:34 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/dst': rpc: doCompleteUpload(map[fi_size:5 remotetime:2011-12-30 12:59:59 uploadcode:56d26740dcfe826985e35e2cf9a24d0a]) options=[] 2021/03/04 06:51:36 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/dst': >rpc: result=Success (ok), err= 2021/03/04 06:51:36 INFO : one: Copied (new) 2021/03/04 06:51:36 DEBUG : Waiting for deletions to finish 2021/03/04 06:51:36 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: checkPathExists(map[path:three.txt.bak pid:120859610]) options=[] 2021/03/04 06:51:36 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:51:36 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: doRenameFile(map[fi_id:120859620 fi_name:three.txt.bak.ferivuk8]) options=[] 2021/03/04 06:51:45 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Success (ok), err= 2021/03/04 06:51:45 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: doMoveFiles(map[dir_id:120859610 fi_ids:120859620]) options=[] 2021/03/04 06:52:06 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': >rpc: result=Succcess. (ok), err= 2021/03/04 06:52:06 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/backup': rpc: doRenameFile(map[fi_id:120859620 fi_name:three.txt.bak]) options=[] 2021/03/04 06:52:08 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/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:52:08 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:52:08 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:52:08 ERROR : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5/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:52:08 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': 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:52:09 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:52:09 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859604 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:52:10 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:52:10 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859610 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:52:10 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859605 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:52:11 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:52:11 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: doDeleteFile(map[completedeletion:n fi_id:120859625]) options=[] 2021/03/04 06:52:11 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:52:20 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:52:20 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: doDeleteFile(map[completedeletion:n fi_id:120859607]) options=[] 2021/03/04 06:52:27 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:52:27 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: doDeleteFile(map[completedeletion:n fi_id:120859615]) options=[] 2021/03/04 06:52:40 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:52:40 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: doDeleteFile(map[completedeletion:n fi_id:120859620]) options=[] 2021/03/04 06:52:48 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:52:48 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: doDeleteFile(map[completedeletion:n fi_id:120859609]) options=[] 2021/03/04 06:52:56 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:52:56 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859605 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:52:57 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:52:57 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: doDeleteFolder(map[fi_id:120859605]) options=[] 2021/03/04 06:52:58 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:52:58 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859610 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:52:59 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:52:59 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: doDeleteFolder(map[fi_id:120859610]) options=[] 2021/03/04 06:53:02 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= 2021/03/04 06:53:02 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: getFolderContents(map[count:1000 fi_pid:120859604 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:53:04 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= --- FAIL: TestSyncBackupDirWithSuffix (285.08s) FAIL 2021/03/04 06:53:04 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': Purge remote 2021/03/04 06:53:04 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': rpc: doDeleteFolder(map[fi_id:120859604]) options=[] 2021/03/04 06:53:04 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': Sleeping for 6s to wait for "error_background" error to clear 2021/03/04 06:53:10 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:53:10 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2021/03/04 06:53:10 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': Sleeping for 6s to wait for "error_background" error to clear 2021/03/04 06:53:16 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:53:16 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2021/03/04 06:53:17 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': Sleeping for 6s to wait for "error_background" error to clear 2021/03/04 06:53:23 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:53:23 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2021/03/04 06:53:23 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': Sleeping for 6s to wait for "error_background" error to clear 2021/03/04 06:53:29 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:53:29 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2021/03/04 06:53:30 DEBUG : pacer: Reducing sleep to 240ms 2021/03/04 06:53:30 DEBUG : filefabric root 'rclone-test-mavaqez7kuqadog6lemomel5': >rpc: result=Success (ok), err= "./sync.test -test.v -test.timeout 1h0m0s -remote TestFileFabric: -verbose -test.run '^TestSyncBackupDirWithSuffix$'" - Finished ERROR in 5m12.03674874s (try 5/5): exit status 1: Failed [TestSyncBackupDirWithSuffix]