"./sync.test -test.v -test.timeout 1h0m0s -remote TestFileFabric: -verbose -test.run '^TestServerSideMoveDeleteEmptySourceDirs$'" - Starting (try 3/5) 2021/06/01 07:08:04 DEBUG : Creating backend with remote "TestFileFabric:rclone-test-zadejit5xopecuq1xosabad1" 2021/06/01 07:08:04 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2021/06/01 07:08:04 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: checkPathExists(map[path:rclone-test-zadejit5xopecuq1xosabad1 pid:120673762]) options=[] 2021/06/01 07:08:05 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:08:05 DEBUG : Creating backend with remote "/tmp/rclone160852141" === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:176: Remote "filefabric root 'rclone-test-zadejit5xopecuq1xosabad1'", Local "Local file system at /tmp/rclone160852141", Modify Window "1s" 2021/06/01 07:08:05 DEBUG : Creating backend with remote "TestFileFabric:rclone-test-foboqop2gelowip3nuyunek5" 2021/06/01 07:08:05 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': rpc: checkPathExists(map[path:rclone-test-foboqop2gelowip3nuyunek5 pid:120673762]) options=[] 2021/06/01 07:08:05 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Success (ok), err= 2021/06/01 07:08:05 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': 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/06/01 07:08:06 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:08:06 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: doCreateNewFolder(map[fi_name:rclone-test-zadejit5xopecuq1xosabad1 fi_pid:120673762]) options=[] 2021/06/01 07:08:10 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:08:10 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:potato2 fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:potato2 fi_pid:120934166 fi_size:60 responsetype:json]) options=[] 2021/06/01 07:08:11 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:08:12 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: doCompleteUpload(map[fi_size:60 remotetime:2001-02-03 04:05:06 uploadcode:0468066c1589069cbb3c93e4fe5aff14]) options=[] 2021/06/01 07:08:14 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:08:14 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:empty space fi_localtime:2011-12-25 12:59:59 fi_modified:2011-12-25 12:59:59 fi_name:empty space fi_pid:120934166 fi_size:1 responsetype:json]) options=[] 2021/06/01 07:08:15 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:08:17 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: doCompleteUpload(map[fi_size:1 remotetime:2011-12-25 12:59:59 uploadcode:1fb5b3dc5dd588c2ff5c649d8a82c79d]) options=[] 2021/06/01 07:08:18 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:08:18 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:potato3 fi_localtime:2011-12-25 12:59:59 fi_modified:2011-12-25 12:59:59 fi_name:potato3 fi_pid:120934166 fi_size:68 responsetype:json]) options=[] 2021/06/01 07:08:19 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:08:21 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: doCompleteUpload(map[fi_size:68 remotetime:2011-12-25 12:59:59 uploadcode:ebc19f261423ebb24cc3332bf87a8a73]) options=[] 2021/06/01 07:08:23 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:08:23 DEBUG : tomatoDir: Making directory 2021/06/01 07:08:23 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: getFolderContents(map[count:1000 fi_pid:120934166 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/06/01 07:08:24 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:08:24 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: doCreateNewFolder(map[fi_name:tomatoDir fi_pid:120934166]) options=[] 2021/06/01 07:08:28 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:08:28 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: getFolderContents(map[count:1000 fi_pid:120934166 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/06/01 07:08:29 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:08:29 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: getFolderContents(map[count:1000 fi_pid:120934170 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/06/01 07:08:31 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= sync_test.go:1245: Server side move (if possible) filefabric root 'rclone-test-zadejit5xopecuq1xosabad1' -> filefabric root 'rclone-test-foboqop2gelowip3nuyunek5' 2021/06/01 07:08:31 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': 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/06/01 07:08:32 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Success (ok), err= 2021/06/01 07:08:32 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': rpc: doCreateNewFolder(map[fi_name:rclone-test-foboqop2gelowip3nuyunek5 fi_pid:120673762]) options=[] 2021/06/01 07:08:36 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Success (ok), err= 2021/06/01 07:08:36 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:empty space fi_localtime:2011-12-25 12:59:59 fi_modified:2011-12-25 12:59:59 fi_name:empty space fi_pid:120934171 fi_size:1 responsetype:json]) options=[] 2021/06/01 07:08:37 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Success (ok), err= 2021/06/01 07:08:39 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': rpc: doCompleteUpload(map[fi_size:1 remotetime:2011-12-25 12:59:59 uploadcode:af0b0dc3ac1bfd23f762e87e7767bf3f]) options=[] 2021/06/01 07:08:40 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Success (ok), err= 2021/06/01 07:08:40 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:potato3 fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:potato3 fi_pid:120934171 fi_size:60 responsetype:json]) options=[] 2021/06/01 07:08:41 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Success (ok), err= 2021/06/01 07:08:43 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': rpc: doCompleteUpload(map[fi_size:60 remotetime:2001-02-03 04:05:06 uploadcode:a571f50b10ae2932e87162ecc389188c]) options=[] 2021/06/01 07:08:44 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Success (ok), err= 2021/06/01 07:08:44 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': rpc: getFolderContents(map[count:1000 fi_pid:120934171 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/06/01 07:08:46 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Success (ok), err= 2021/06/01 07:08:46 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': Using server-side directory move 2021/06/01 07:08:46 INFO : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2021/06/01 07:08:46 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: getFolderContents(map[count:1000 fi_pid:120934166 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/06/01 07:08:46 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': rpc: getFolderContents(map[count:1000 fi_pid:120934171 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/06/01 07:08:46 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:08:46 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Success (ok), err= 2021/06/01 07:08:46 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1s) 2021/06/01 07:08:46 DEBUG : empty space: Unchanged skipping 2021/06/01 07:08:46 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: doDeleteFile(map[completedeletion:n fi_id:120934168]) options=[] 2021/06/01 07:08:46 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: getFolderContents(map[count:1000 fi_pid:120934170 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/06/01 07:08:46 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2021/06/01 07:08:46 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': rpc: doMoveFiles(map[dir_id:120934171 fi_ids:120934167]) options=[] 2021/06/01 07:08:46 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': rpc: doDeleteFile(map[completedeletion:n fi_id:120934173]) options=[] 2021/06/01 07:08:47 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:08:47 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': Waiting for checks to finish 2021/06/01 07:08:58 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Success (ok), err= 2021/06/01 07:08:58 INFO : potato3: Deleted 2021/06/01 07:08:58 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': rpc: doMoveFiles(map[dir_id:120934171 fi_ids:120934169]) options=[] 2021/06/01 07:08:59 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:08:59 INFO : empty space: Deleted 2021/06/01 07:08:59 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': Waiting for transfers to finish 2021/06/01 07:09:13 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Succcess. (ok), err= 2021/06/01 07:09:13 INFO : potato2: Moved (server-side) 2021/06/01 07:09:25 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Succcess. (ok), err= 2021/06/01 07:09:25 INFO : potato3: Moved (server-side) 2021/06/01 07:09:25 DEBUG : tomatoDir: Removing directory 2021/06/01 07:09:25 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: getFolderContents(map[count:1000 fi_pid:120934170 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/06/01 07:09:25 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:09:25 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: doDeleteFolder(map[fi_id:120934170]) options=[] 2021/06/01 07:09:28 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:09:28 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': deleted 1 directories 2021/06/01 07:09:28 INFO : There was nothing to transfer 2021/06/01 07:09:28 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: getFolderContents(map[count:1000 fi_pid:120934166 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/06/01 07:09:28 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:09:28 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: getFolderContents(map[count:1000 fi_pid:120934166 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/06/01 07:09:29 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:09:29 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': rpc: getFolderContents(map[count:1000 fi_pid:120934171 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/06/01 07:09:30 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Success (ok), err= 2021/06/01 07:09:30 DEBUG : Creating backend with remote "TestFileFabric:rclone-test-soyigus2mebilut9vijezuk8" 2021/06/01 07:09:30 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: checkPathExists(map[path:rclone-test-soyigus2mebilut9vijezuk8 pid:120673762]) options=[] 2021/06/01 07:09:30 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:09:30 DEBUG : tomatoDir: Making directory 2021/06/01 07:09:30 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': rpc: getFolderContents(map[count:1000 fi_pid:120934171 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/06/01 07:09:31 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Success (ok), err= 2021/06/01 07:09:31 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': rpc: doCreateNewFolder(map[fi_name:tomatoDir fi_pid:120934171]) options=[] 2021/06/01 07:09:34 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Success (ok), err= 2021/06/01 07:09:34 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Using server-side directory move 2021/06/01 07:09:34 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': 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/06/01 07:09:35 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:09:35 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: doRenameFolder(map[fi_id:120934171 fi_name:rclone-test-soyigus2mebilut9vijezuk8]) options=[] 2021/06/01 07:09:47 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:09:47 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getUserBackgroundTasks(map[taskid:1195897]) options=[] 2021/06/01 07:09:49 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:09:49 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Waiting for task ID 1195897: Rename folder S3 Storage/smestoragencw/rclone-test-soyigus2mebilut9vijezuk8: to completed for 1s - waited 1.216206356s already 2021/06/01 07:09:50 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getUserBackgroundTasks(map[taskid:1195897]) options=[] 2021/06/01 07:09:51 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:09:51 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Waiting for task ID 1195897: Rename folder S3 Storage/smestoragencw/rclone-test-soyigus2mebilut9vijezuk8: to completed for 1s - waited 3.34115643s already 2021/06/01 07:09:52 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getUserBackgroundTasks(map[taskid:1195897]) options=[] 2021/06/01 07:09:53 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:09:53 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Waiting for task ID 1195897: Rename folder S3 Storage/smestoragencw/rclone-test-soyigus2mebilut9vijezuk8: to completed for 1s - waited 5.564020212s already 2021/06/01 07:09:54 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getUserBackgroundTasks(map[taskid:1195897]) options=[] 2021/06/01 07:09:55 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:09:55 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Waiting for task ID 1195897: Rename folder S3 Storage/smestoragencw/rclone-test-soyigus2mebilut9vijezuk8: to completed for 1s - waited 7.749853354s already 2021/06/01 07:09:56 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getUserBackgroundTasks(map[taskid:1195897]) options=[] 2021/06/01 07:09:57 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:09:57 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Waiting for task ID 1195897: Rename folder S3 Storage/smestoragencw/rclone-test-soyigus2mebilut9vijezuk8: to completed for 1s - waited 9.920644549s already 2021/06/01 07:09:58 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getUserBackgroundTasks(map[taskid:1195897]) options=[] 2021/06/01 07:09:59 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:09:59 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Waiting for task ID 1195897: Rename folder S3 Storage/smestoragencw/rclone-test-soyigus2mebilut9vijezuk8: to completed for 1s - waited 12.18953564s already 2021/06/01 07:10:00 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getUserBackgroundTasks(map[taskid:1195897]) options=[] 2021/06/01 07:10:02 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:10:02 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Waiting for task ID 1195897: Rename folder S3 Storage/smestoragencw/rclone-test-soyigus2mebilut9vijezuk8: to completed for 1s - waited 14.332216734s already 2021/06/01 07:10:03 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getUserBackgroundTasks(map[taskid:1195897]) options=[] 2021/06/01 07:10:04 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:10:04 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Waiting for task ID 1195897: Rename folder S3 Storage/smestoragencw/rclone-test-soyigus2mebilut9vijezuk8: to completed for 1s - waited 16.509423479s already 2021/06/01 07:10:05 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getUserBackgroundTasks(map[taskid:1195897]) options=[] 2021/06/01 07:10:06 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:10:06 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Waiting for task ID 1195897: Rename folder S3 Storage/smestoragencw/rclone-test-soyigus2mebilut9vijezuk8: to completed for 1s - waited 18.713493984s already 2021/06/01 07:10:07 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getUserBackgroundTasks(map[taskid:1195897]) options=[] 2021/06/01 07:10:08 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:10:08 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Waiting for task ID 1195897: Rename folder S3 Storage/smestoragencw/rclone-test-soyigus2mebilut9vijezuk8: to completed for 1s - waited 21.007797048s already 2021/06/01 07:10:09 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getUserBackgroundTasks(map[taskid:1195897]) options=[] 2021/06/01 07:10:10 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:10:10 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Waiting for task ID 1195897: Rename folder S3 Storage/smestoragencw/rclone-test-soyigus2mebilut9vijezuk8: to completed for 1s - waited 23.114888887s already 2021/06/01 07:10:11 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getUserBackgroundTasks(map[taskid:1195897]) options=[] 2021/06/01 07:10:12 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:10:12 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Waiting for task ID 1195897: Rename folder S3 Storage/smestoragencw/rclone-test-soyigus2mebilut9vijezuk8: to completed for 1s - waited 25.205822442s already 2021/06/01 07:10:13 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getUserBackgroundTasks(map[taskid:1195897]) options=[] 2021/06/01 07:10:15 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:10:15 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Waiting for task ID 1195897: Rename folder S3 Storage/smestoragencw/rclone-test-soyigus2mebilut9vijezuk8: to completed for 1s - waited 27.457067432s already 2021/06/01 07:10:16 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getUserBackgroundTasks(map[taskid:1195897]) options=[] 2021/06/01 07:10:17 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:10:17 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Waiting for task ID 1195897: Rename folder S3 Storage/smestoragencw/rclone-test-soyigus2mebilut9vijezuk8: to completed for 1s - waited 29.569038701s already 2021/06/01 07:10:18 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getUserBackgroundTasks(map[taskid:1195897]) options=[] 2021/06/01 07:10:19 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:10:19 INFO : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Server side directory move succeeded 2021/06/01 07:10:19 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': 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/06/01 07:10:21 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:10:21 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getFolderContents(map[count:1000 fi_pid:120934171 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/06/01 07:10:22 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:10:22 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: getFolderContents(map[count:1000 fi_pid:120934179 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/06/01 07:10:23 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:10:23 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': 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/06/01 07:10:25 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Success (ok), err= 2021/06/01 07:10:25 ERROR : : error listing: directory not found 2021/06/01 07:10:25 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': 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/06/01 07:10:25 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Success (ok), err= 2021/06/01 07:10:25 ERROR : : error listing: directory not found 2021/06/01 07:10:25 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': Purge remote 2021/06/01 07:10:25 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': rpc: doDeleteFolder(map[fi_id:120934171]) options=[] 2021/06/01 07:10:27 DEBUG : filefabric root 'rclone-test-soyigus2mebilut9vijezuk8': >rpc: result=Success (ok), err= 2021/06/01 07:10:27 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': Purge remote 2021/06/01 07:10:27 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': 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/06/01 07:10:28 DEBUG : filefabric root 'rclone-test-foboqop2gelowip3nuyunek5': >rpc: result=Success (ok), err= 2021/06/01 07:10:28 purge failed: directory not found 2021/06/01 07:10:28 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: getFolderContents(map[count:1000 fi_pid:120934166 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/06/01 07:10:30 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= 2021/06/01 07:10:30 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: getFolderContents(map[count:1000 fi_pid:120934166 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/06/01 07:10:30 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= --- PASS: TestServerSideMoveDeleteEmptySourceDirs (145.24s) PASS 2021/06/01 07:10:30 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': Purge remote 2021/06/01 07:10:30 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': rpc: doDeleteFolder(map[fi_id:120934166]) options=[] 2021/06/01 07:10:32 DEBUG : filefabric root 'rclone-test-zadejit5xopecuq1xosabad1': >rpc: result=Success (ok), err= "./sync.test -test.v -test.timeout 1h0m0s -remote TestFileFabric: -verbose -test.run '^TestServerSideMoveDeleteEmptySourceDirs$'" - Finished OK in 2m27.557377533s (try 3/5)