"go test -v -timeout 1h0m0s -remote TestFileFabric: -verbose -test.run '^TestIntegration$/^FsMkdir$/^(FsPutFiles|FsUploadUnknownSize)$/^(FromRoot|FsDirMove|FsIsFile|FsUpdateUnknownSize|ObjectMimeType|ObjectRemove|ObjectUpdate)$/^(List|ListEntries|Put)$/^Remove$'" - Starting (try 3/5) === RUN TestIntegration fstests.go:418: Using remote "TestFileFabric:" 2021/07/25 06:14:48 DEBUG : Creating backend with remote "TestFileFabric:rclone-test-qoqevof4sovovoq8wihofop0" 2021/07/25 06:14:48 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2021/07/25 06:14:48 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: checkPathExists(map[path:rclone-test-qoqevof4sovovoq8wihofop0 pid:120673762]) options=[] 2021/07/25 06:14:49 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:14:49 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': 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/07/25 06:14:49 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:14:49 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doCreateNewFolder(map[fi_name:rclone-test-qoqevof4sovovoq8wihofop0 fi_pid:120673762]) options=[] 2021/07/25 06:14:54 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:14:54 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: getFolderContents(map[count:1000 fi_pid:121000277 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/07/25 06:14:56 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir 2021/07/25 06:14:56 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: getFolderContents(map[count:1000 fi_pid:121000277 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/07/25 06:14:56 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsPutFiles 2021/07/25 06:14:56 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:text/plain; charset=utf-8 fi_filename:file name.txt fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:file name.txt fi_pid:121000277 fi_size:100 responsetype:json]) options=[] 2021/07/25 06:14:57 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:14:58 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doCompleteUpload(map[fi_size:100 remotetime:2001-02-03 04:05:06 uploadcode:4b439eaddc6301a3cb9ecab44db683d5]) options=[] 2021/07/25 06:15:00 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:15:00 DEBUG : file name.txt: Correcting mime type from "text/plain" to "text/plain; charset=utf-8" 2021/07/25 06:15:00 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doModifyFile(map[data:fi_contenttype=text/plain; charset=utf-8 fi_id:121000278]) options=[] 2021/07/25 06:15:01 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:15:01 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: checkPathExists(map[path:file name.txt pid:121000277]) options=[] 2021/07/25 06:15:01 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:15:01 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: getFolderContents(map[count:1000 fi_pid:121000277 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/07/25 06:15:03 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:15:03 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doCreateNewFolder(map[fi_name:hello? sausage fi_pid:121000277]) options=[] 2021/07/25 06:15:07 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:15:07 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: getFolderContents(map[count:1000 fi_pid:121000279 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/07/25 06:15:09 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:15:09 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doCreateNewFolder(map[fi_name:êé fi_pid:121000279]) options=[] 2021/07/25 06:15:14 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:15:14 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: getFolderContents(map[count:1000 fi_pid:121000280 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/07/25 06:15:16 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:15:16 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doCreateNewFolder(map[fi_name:Hello, 世界 fi_pid:121000280]) options=[] 2021/07/25 06:15:20 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:15:20 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: getFolderContents(map[count:1000 fi_pid:121000281 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/07/25 06:15:21 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:15:21 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doCreateNewFolder(map[fi_name: " ' @ < > & ? + ≠ fi_pid:121000281]) options=[] 2021/07/25 06:15:27 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:15:27 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:text/plain; charset=utf-8 fi_filename:z.txt fi_localtime:2001-02-03 04:05:10 fi_modified:2001-02-03 04:05:10 fi_name:z.txt fi_pid:121000283 fi_size:100 responsetype:json]) options=[] 2021/07/25 06:15:28 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:15:29 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doCompleteUpload(map[fi_size:100 remotetime:2001-02-03 04:05:10 uploadcode:e0f20bf9c9ab1c445e47cf87d4751b14]) options=[] 2021/07/25 06:15:31 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:15:31 DEBUG : hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt: Correcting mime type from "text/plain" to "text/plain; charset=utf-8" 2021/07/25 06:15:31 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doModifyFile(map[data:fi_contenttype=text/plain; charset=utf-8 fi_id:121000284]) options=[] 2021/07/25 06:15:32 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:15:32 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: checkPathExists(map[path:hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt pid:121000277]) options=[] 2021/07/25 06:15:32 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:15:32 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:text/csv fi_filename:file name.txt fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:file name.txt fi_pid:121000277 fi_size:100 responsetype:json]) options=[] 2021/07/25 06:15:33 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:15:35 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doCompleteUpload(map[fi_size:100 remotetime:2001-02-03 04:05:06 uploadcode:8af0e98cf5d421312f3739afeac678a8]) options=[] 2021/07/25 06:16:04 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:16:04 DEBUG : file name.txt: Correcting mime type from "text/plain" to "text/csv" 2021/07/25 06:16:04 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doModifyFile(map[data:fi_contenttype=text/csv fi_id:121000278]) options=[] 2021/07/25 06:16:04 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:16:04 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: checkPathExists(map[path:file name.txt pid:121000277]) options=[] 2021/07/25 06:16:05 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsPutFiles/FsDirMove 2021/07/25 06:16:05 DEBUG : Creating backend with remote "TestFileFabric:rclone-test-jegatin3hawizog4zubuhoh7" 2021/07/25 06:16:05 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: checkPathExists(map[path:rclone-test-jegatin3hawizog4zubuhoh7 pid:120673762]) options=[] 2021/07/25 06:16:05 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:16:05 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': 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/07/25 06:16:06 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:16:06 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: doCreateNewFolder(map[fi_name:rclone-test-jegatin3hawizog4zubuhoh7 fi_pid:120673762]) options=[] 2021/07/25 06:16:10 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:16:10 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getFolderContents(map[count:1000 fi_pid:121000288 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/07/25 06:16:12 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:16:12 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: doCreateNewFolder(map[fi_name:new_name fi_pid:121000288]) options=[] 2021/07/25 06:16:16 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:16:16 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getFolderContents(map[count:1000 fi_pid:121000289 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/07/25 06:16:18 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:16:18 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: doRenameFolder(map[fi_id:121000277 fi_name:sub_new_name.sodiruw9]) options=[] 2021/07/25 06:16:34 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:16:34 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:16:35 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:16:35 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 1.378048099s already 2021/07/25 06:16:36 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:16:38 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:16:38 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 3.832716795s already 2021/07/25 06:16:39 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:16:40 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:16:40 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 6.319903554s already 2021/07/25 06:16:41 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:16:43 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:16:43 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 9.233492508s already 2021/07/25 06:16:44 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:16:46 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:16:46 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 11.792906081s already 2021/07/25 06:16:47 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:16:50 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:16:50 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 15.562992775s already 2021/07/25 06:16:51 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:16:52 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:16:52 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 18.05886305s already 2021/07/25 06:16:53 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:16:54 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:16:54 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 20.329115292s already 2021/07/25 06:16:55 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:16:58 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:16:58 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 23.711654966s already 2021/07/25 06:16:59 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:17:01 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:17:01 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 26.761335984s already 2021/07/25 06:17:02 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:17:04 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:17:04 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 30.013214925s already 2021/07/25 06:17:05 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:17:06 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:17:06 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 32.313995031s already 2021/07/25 06:17:07 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:17:09 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:17:09 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 34.816253703s already 2021/07/25 06:17:10 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:17:12 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:17:12 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 37.730523853s already 2021/07/25 06:17:13 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:17:14 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:17:14 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 40.321126009s already 2021/07/25 06:17:15 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:17:17 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:17:17 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 42.885613109s already 2021/07/25 06:17:18 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:17:19 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:17:19 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 45.253652787s already 2021/07/25 06:17:20 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:17:22 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:17:22 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 47.545862949s already 2021/07/25 06:17:23 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:17:24 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:17:24 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 49.998712364s already 2021/07/25 06:17:25 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:17:27 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:17:27 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Waiting for task ID 1277167: Rename folder 'S3 Storage/smestoragencw/sub_new_name.sodiruw9': to completed for 1s - waited 52.984654707s already 2021/07/25 06:17:28 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: getUserBackgroundTasks(map[taskid:1277167]) options=[] 2021/07/25 06:17:29 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= 2021/07/25 06:17:29 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: doMoveFolders(map[dir_id:121000289 fi_ids:121000277]) options=[] 2021/07/25 06:17:40 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Succcess. (ok), err= 2021/07/25 06:17:40 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: doRenameFolder(map[fi_id:121000277 fi_name:sub_new_name]) options=[] 2021/07/25 06:17:46 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:17:52 DEBUG : pacer: low level retry 1/10 (error Can not rename folder now. We are not able to complete the requested operation. We are processing move folder in parent folder. Please try again later. (error_background)) 2021/07/25 06:17:52 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2021/07/25 06:17:56 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:18:02 DEBUG : pacer: low level retry 2/10 (error Can not rename folder now. We are not able to complete the requested operation. We are processing move folder in parent folder. Please try again later. (error_background)) 2021/07/25 06:18:02 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2021/07/25 06:18:06 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:18:12 DEBUG : pacer: low level retry 3/10 (error Can not rename folder now. We are not able to complete the requested operation. We are processing move folder in parent folder. Please try again later. (error_background)) 2021/07/25 06:18:12 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2021/07/25 06:18:19 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:18:25 DEBUG : pacer: low level retry 4/10 (error Can not rename folder now. We are not able to complete the requested operation. We are processing move folder in parent folder. Please try again later. (error_background)) 2021/07/25 06:18:25 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2021/07/25 06:18:30 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:18:36 DEBUG : pacer: low level retry 5/10 (error Can not rename folder now. We are not able to complete the requested operation. We are processing move folder in parent folder. Please try again later. (error_background)) 2021/07/25 06:18:36 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2021/07/25 06:18:42 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:18:48 DEBUG : pacer: low level retry 6/10 (error Can not rename folder now. We are not able to complete the requested operation. We are processing move folder in parent folder. Please try again later. (error_background)) 2021/07/25 06:18:48 DEBUG : pacer: Rate limited, increasing sleep to 1.28s 2021/07/25 06:18:52 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:18:58 DEBUG : pacer: low level retry 7/10 (error Can not rename folder now. We are not able to complete the requested operation. We are processing move folder in parent folder. Please try again later. (error_background)) 2021/07/25 06:18:58 DEBUG : pacer: Rate limited, increasing sleep to 2.56s 2021/07/25 06:19:01 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:19:07 DEBUG : pacer: low level retry 8/10 (error Can not rename folder now. We are not able to complete the requested operation. We are processing move folder in parent folder. Please try again later. (error_background)) 2021/07/25 06:19:07 DEBUG : pacer: Rate limited, increasing sleep to 5.12s 2021/07/25 06:19:12 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:19:18 DEBUG : pacer: low level retry 9/10 (error Can not rename folder now. We are not able to complete the requested operation. We are processing move folder in parent folder. Please try again later. (error_background)) 2021/07/25 06:19:18 DEBUG : pacer: Rate limited, increasing sleep to 10s 2021/07/25 06:19:21 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:19:27 DEBUG : pacer: low level retry 10/10 (error Can not rename folder now. We are not able to complete the requested operation. We are processing move folder in parent folder. Please try again later. (error_background)) 2021/07/25 06:19:27 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Can not rename folder now. We are not able to complete the requested operation. We are processing move folder in parent folder. Please try again later. (error_background), err=Can not rename folder now. We are not able to complete the requested operation. We are processing move folder in parent folder. Please try again later. (error_background) fstests.go:1220: Error Trace: fstests.go:1220 Error: Received unexpected error: Can not rename folder now. We are not able to complete the requested operation. We are processing move folder in parent folder. Please try again later. (error_background) failed to rename leaf github.com/rclone/rclone/backend/filefabric.(*Fs).renameLeaf /home/rclone/go/src/github.com/rclone/rclone/backend/filefabric/filefabric.go:888 github.com/rclone/rclone/backend/filefabric.(*Fs).move /home/rclone/go/src/github.com/rclone/rclone/backend/filefabric/filefabric.go:943 github.com/rclone/rclone/backend/filefabric.(*Fs).DirMove /home/rclone/go/src/github.com/rclone/rclone/backend/filefabric/filefabric.go:1022 github.com/rclone/rclone/fstest/fstests.Run.func13.13.19 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:1219 testing.tRunner /usr/local/go/src/testing/testing.go:1123 runtime.goexit /usr/local/go/src/runtime/asm_amd64.s:1374 Test: TestIntegration/FsMkdir/FsPutFiles/FsDirMove 2021/07/25 06:19:27 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Purge remote 2021/07/25 06:19:27 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': rpc: doDeleteFolder(map[fi_id:121000288]) options=[] 2021/07/25 06:19:28 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:19:34 DEBUG : pacer: low level retry 1/10 (error We are not able to complete the requested operation. We are processing move folder in parent folder. Please try again later. (error_background)) 2021/07/25 06:19:38 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:19:44 DEBUG : pacer: low level retry 2/10 (error We are not able to complete the requested operation. We are processing move folder in parent folder. Please try again later. (error_background)) 2021/07/25 06:19:52 DEBUG : pacer: Reducing sleep to 7.5s 2021/07/25 06:19:52 DEBUG : filefabric root 'rclone-test-jegatin3hawizog4zubuhoh7': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsPutFiles/ObjectMimeType 2021/07/25 06:19:52 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: checkPathExists(map[path:file name.txt pid:121000277]) options=[] 2021/07/25 06:19:52 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= fstests.go:1342: Error Trace: fstests.go:1342 Error: Not equal: expected: "text/csv" actual : "text/plain" Diff: --- Expected +++ Actual @@ -1 +1 @@ -text/csv +text/plain Test: TestIntegration/FsMkdir/FsPutFiles/ObjectMimeType Messages: can read and write mime types but failed === RUN TestIntegration/FsMkdir/FsPutFiles/ObjectUpdate 2021/07/25 06:19:52 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: checkPathExists(map[path:file name.txt pid:121000277]) options=[] 2021/07/25 06:19:52 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:19:52 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:text/plain; charset=utf-8 fi_filename:file name.txt fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:file name.txt fi_pid:121000277 fi_size:200 responsetype:json]) options=[] 2021/07/25 06:19:53 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Can not upload file now. We are not able to complete the requested operation. We are processing delete in parent folder. Please try again later. (error_locked), err=Can not upload file now. We are not able to complete the requested operation. We are processing delete in parent folder. Please try again later. (error_locked) fstests.go:1432: Error Trace: fstests.go:1432 Error: Received unexpected error: Can not upload file now. We are not able to complete the requested operation. We are processing delete in parent folder. Please try again later. (error_locked) failed to initialize upload github.com/rclone/rclone/backend/filefabric.(*Object).Update /home/rclone/go/src/github.com/rclone/rclone/backend/filefabric/filefabric.go:1245 github.com/rclone/rclone/fstest/fstests.Run.func13.13.34 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:1431 testing.tRunner /usr/local/go/src/testing/testing.go:1123 runtime.goexit /usr/local/go/src/runtime/asm_amd64.s:1374 Test: TestIntegration/FsMkdir/FsPutFiles/ObjectUpdate === RUN TestIntegration/FsMkdir/FsPutFiles/FsIsFile 2021/07/25 06:19:53 DEBUG : Creating backend with remote "TestFileFabric:rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ \" ' @ < > & ? + ≠/z.txt" 2021/07/25 06:19:53 DEBUG : Config file has changed externaly - reloading 2021/07/25 06:19:53 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt': rpc: checkPathExists(map[path:rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt pid:120673762]) options=[] 2021/07/25 06:19:53 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt': >rpc: result=Success (ok), err= fstests.go:1463: Error Trace: fstests.go:1463 Error: Not equal: expected: *errors.fundamental(is a file not a directory) actual : () Test: TestIntegration/FsMkdir/FsPutFiles/FsIsFile 2021/07/25 06:19:53 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt': 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/07/25 06:19:54 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt': >rpc: result=Success (ok), err= 2021/07/25 06:19:54 ERROR : : error listing: directory not found fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache 2021/07/25 06:19:55 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt': 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/07/25 06:19:56 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt': >rpc: result=Success (ok), err= 2021/07/25 06:19:56 ERROR : : error listing: directory not found fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache 2021/07/25 06:19:58 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt': 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/07/25 06:19:58 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt': >rpc: result=Success (ok), err= 2021/07/25 06:19:58 ERROR : : error listing: directory not found fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:345 fstests.go:1470 Error: Should be true Test: TestIntegration/FsMkdir/FsPutFiles/FsIsFile Messages: listing wrong, want z.txt (100) got fstest.go:204: Not found "z.txt" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:345 fstests.go:1470 Error: Not equal: expected: 0 actual : 1 Test: TestIntegration/FsMkdir/FsPutFiles/FsIsFile Messages: 1 objects not found === RUN TestIntegration/FsMkdir/FsPutFiles/FromRoot fstests.go:1496: Opening root remote "TestFileFabric:" path "rclone-test-qoqevof4sovovoq8wihofop0" from "TestFileFabric:rclone-test-qoqevof4sovovoq8wihofop0" 2021/07/25 06:20:02 DEBUG : Creating backend with remote "TestFileFabric:" === RUN TestIntegration/FsMkdir/FsPutFiles/FromRoot/List 2021/07/25 06:20:02 DEBUG : filefabric root '': 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/07/25 06:20:02 DEBUG : filefabric root '': >rpc: result=Success (ok), err= 2021/07/25 06:20:02 ERROR : rclone-test-qoqevof4sovovoq8wihofop0: error listing: directory not found fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache 2021/07/25 06:20:03 DEBUG : filefabric root '': 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/07/25 06:20:04 DEBUG : filefabric root '': >rpc: result=Success (ok), err= 2021/07/25 06:20:04 ERROR : rclone-test-qoqevof4sovovoq8wihofop0: error listing: directory not found fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache 2021/07/25 06:20:06 DEBUG : filefabric root '': 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/07/25 06:20:06 DEBUG : filefabric root '': >rpc: result=Success (ok), err= 2021/07/25 06:20:06 ERROR : rclone-test-qoqevof4sovovoq8wihofop0: error listing: directory not found fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstests.go:1516 Error: Should be true Test: TestIntegration/FsMkdir/FsPutFiles/FromRoot/List Messages: listing wrong, want rclone-test-qoqevof4sovovoq8wihofop0/file name.txt (200), rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt (100) got fstest.go:204: Not found "rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ \" ' @ < > & ? + ≠/z.txt" fstest.go:204: Not found "rclone-test-qoqevof4sovovoq8wihofop0/file name.txt" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstests.go:1516 Error: Not equal: expected: 0 actual : 2 Test: TestIntegration/FsMkdir/FsPutFiles/FromRoot/List Messages: 2 objects not found fstest.go:328: Error Trace: fstest.go:328 fstests.go:1516 Error: Not equal: expected: []string{"rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage", "rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé", "rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界", "rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ \" ' @ < > & ? + ≠"} actual : []string{} Diff: --- Expected +++ Actual @@ -1,6 +1,2 @@ -([]string) (len=4) { - (string) (len=51) "rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage", - (string) (len=56) "rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé", - (string) (len=70) "rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界", - (string) (len=91) "rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ \" ' @ < > & ? + ≠" +([]string) { } Test: TestIntegration/FsMkdir/FsPutFiles/FromRoot/List Messages: directories === RUN TestIntegration/FsMkdir/FsPutFiles/FromRoot/ListEntries 2021/07/25 06:20:10 DEBUG : filefabric root '': 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/07/25 06:20:10 DEBUG : filefabric root '': >rpc: result=Success (ok), err= fstests.go:1522: Error Trace: fstests.go:1522 Error: Received unexpected error: directory not found github.com/rclone/rclone/fs.init /home/rclone/go/src/github.com/rclone/rclone/fs/fs.go:34 runtime.doInit /usr/local/go/src/runtime/proc.go:5625 runtime.doInit /usr/local/go/src/runtime/proc.go:5620 runtime.doInit /usr/local/go/src/runtime/proc.go:5620 runtime.doInit /usr/local/go/src/runtime/proc.go:5620 runtime.main /usr/local/go/src/runtime/proc.go:191 runtime.goexit /usr/local/go/src/runtime/asm_amd64.s:1374 Test: TestIntegration/FsMkdir/FsPutFiles/FromRoot/ListEntries === RUN TestIntegration/FsMkdir/FsPutFiles/FromRoot/Put 2021/07/25 06:20:10 DEBUG : filefabric root '': 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/07/25 06:20:11 DEBUG : filefabric root '': >rpc: result=Success (ok), err= 2021/07/25 06:20:11 DEBUG : filefabric root '': rpc: doCreateNewFolder(map[fi_name:rclone-test-qoqevof4sovovoq8wihofop0 fi_pid:120673762]) options=[] 2021/07/25 06:20:15 DEBUG : filefabric root '': >rpc: result=Success (ok), err= 2021/07/25 06:20:15 DEBUG : filefabric root '': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:text/plain; charset=utf-8 fi_filename:created from root.txt fi_localtime:2021-07-25 06:20:10 fi_modified:2021-07-25 06:20:10 fi_name:created from root.txt fi_pid:121000307 fi_size:100 responsetype:json]) options=[] 2021/07/25 06:20:16 DEBUG : filefabric root '': >rpc: result=Success (ok), err= 2021/07/25 06:20:17 DEBUG : filefabric root '': rpc: doCompleteUpload(map[fi_size:100 remotetime:2021-07-25 06:20:10 uploadcode:fd7aa900a36ae13ddc6bcf422ce5e19c]) options=[] 2021/07/25 06:20:19 DEBUG : filefabric root '': >rpc: result=Success (ok), err= 2021/07/25 06:20:19 DEBUG : rclone-test-qoqevof4sovovoq8wihofop0/created from root.txt: Correcting mime type from "text/plain" to "text/plain; charset=utf-8" 2021/07/25 06:20:19 DEBUG : filefabric root '': rpc: doModifyFile(map[data:fi_contenttype=text/plain; charset=utf-8 fi_id:121000308]) options=[] 2021/07/25 06:20:20 DEBUG : filefabric root '': >rpc: result=Success (ok), err= 2021/07/25 06:20:20 DEBUG : filefabric root '': rpc: checkPathExists(map[path:rclone-test-qoqevof4sovovoq8wihofop0/created from root.txt pid:120673762]) options=[] 2021/07/25 06:20:20 DEBUG : filefabric root '': >rpc: result=Success (ok), err= 2021/07/25 06:20:20 DEBUG : filefabric root '': rpc: getFolderContents(map[count:1000 fi_pid:121000307 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/07/25 06:20:22 DEBUG : filefabric root '': >rpc: result=Success (ok), err= fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache 2021/07/25 06:20:23 DEBUG : filefabric root '': 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/07/25 06:20:23 DEBUG : filefabric root '': >rpc: result=Success (ok), err= 2021/07/25 06:20:23 DEBUG : filefabric root '': rpc: getFolderContents(map[count:1000 fi_pid:121000307 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/07/25 06:20:23 DEBUG : filefabric root '': >rpc: result=Success (ok), err= fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache 2021/07/25 06:20:25 DEBUG : filefabric root '': 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/07/25 06:20:25 DEBUG : filefabric root '': >rpc: result=Success (ok), err= 2021/07/25 06:20:25 DEBUG : filefabric root '': rpc: getFolderContents(map[count:1000 fi_pid:121000307 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/07/25 06:20:27 DEBUG : filefabric root '': >rpc: result=Success (ok), err= fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstests.go:1572 Error: Should be true Test: TestIntegration/FsMkdir/FsPutFiles/FromRoot/Put Messages: listing wrong, want rclone-test-qoqevof4sovovoq8wihofop0/created from root.txt (100), rclone-test-qoqevof4sovovoq8wihofop0/file name.txt (200), rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt (100) got rclone-test-qoqevof4sovovoq8wihofop0/created from root.txt (100) fstest.go:204: Not found "rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ \" ' @ < > & ? + ≠/z.txt" fstest.go:204: Not found "rclone-test-qoqevof4sovovoq8wihofop0/file name.txt" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstests.go:1572 Error: Not equal: expected: 0 actual : 2 Test: TestIntegration/FsMkdir/FsPutFiles/FromRoot/Put Messages: 2 objects not found === RUN TestIntegration/FsMkdir/FsPutFiles/FromRoot/Put/Remove 2021/07/25 06:20:31 DEBUG : filefabric root '': rpc: doDeleteFile(map[completedeletion:n fi_id:121000308]) options=[] 2021/07/25 06:20:43 DEBUG : filefabric root '': >rpc: result=Success (ok), err= 2021/07/25 06:20:43 DEBUG : filefabric root '': 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/07/25 06:20:43 DEBUG : filefabric root '': >rpc: result=Success (ok), err= 2021/07/25 06:20:43 DEBUG : filefabric root '': rpc: getFolderContents(map[count:1000 fi_pid:121000307 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/07/25 06:20:45 DEBUG : filefabric root '': >rpc: result=Success (ok), err= fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache 2021/07/25 06:20:46 DEBUG : filefabric root '': 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/07/25 06:20:46 DEBUG : filefabric root '': >rpc: result=Success (ok), err= 2021/07/25 06:20:46 DEBUG : filefabric root '': rpc: getFolderContents(map[count:1000 fi_pid:121000307 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/07/25 06:20:47 DEBUG : filefabric root '': >rpc: result=Success (ok), err= fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache 2021/07/25 06:20:49 DEBUG : filefabric root '': 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/07/25 06:20:49 DEBUG : filefabric root '': >rpc: result=Success (ok), err= 2021/07/25 06:20:49 DEBUG : filefabric root '': rpc: getFolderContents(map[count:1000 fi_pid:121000307 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2021/07/25 06:20:49 DEBUG : filefabric root '': >rpc: result=Success (ok), err= fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstests.go:1577 Error: Should be true Test: TestIntegration/FsMkdir/FsPutFiles/FromRoot/Put/Remove Messages: listing wrong, want rclone-test-qoqevof4sovovoq8wihofop0/file name.txt (200), rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt (100) got fstest.go:204: Not found "rclone-test-qoqevof4sovovoq8wihofop0/file name.txt" fstest.go:204: Not found "rclone-test-qoqevof4sovovoq8wihofop0/hello? sausage/êé/Hello, 世界/ \" ' @ < > & ? + ≠/z.txt" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstests.go:1577 Error: Not equal: expected: 0 actual : 2 Test: TestIntegration/FsMkdir/FsPutFiles/FromRoot/Put/Remove Messages: 2 objects not found === RUN TestIntegration/FsMkdir/FsPutFiles/ObjectRemove 2021/07/25 06:20:53 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: checkPathExists(map[path:file name.txt pid:121000277]) options=[] 2021/07/25 06:20:53 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:20:53 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doDeleteFile(map[completedeletion:n fi_id:121000278]) options=[] 2021/07/25 06:20:54 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:21:00 DEBUG : pacer: low level retry 1/10 (error We are not able to complete the requested operation. We are processing delete in parent folder. Please try again later. (error_background)) 2021/07/25 06:21:00 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2021/07/25 06:21:00 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:21:06 DEBUG : pacer: low level retry 2/10 (error We are not able to complete the requested operation. We are processing delete in parent folder. Please try again later. (error_background)) 2021/07/25 06:21:06 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2021/07/25 06:21:07 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:21:13 DEBUG : pacer: low level retry 3/10 (error We are not able to complete the requested operation. We are processing delete in parent folder. Please try again later. (error_background)) 2021/07/25 06:21:13 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2021/07/25 06:21:13 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:21:19 DEBUG : pacer: low level retry 4/10 (error We are not able to complete the requested operation. We are processing delete in parent folder. Please try again later. (error_background)) 2021/07/25 06:21:19 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2021/07/25 06:21:19 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:21:25 DEBUG : pacer: low level retry 5/10 (error We are not able to complete the requested operation. We are processing delete in parent folder. Please try again later. (error_background)) 2021/07/25 06:21:25 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2021/07/25 06:21:26 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:21:32 DEBUG : pacer: low level retry 6/10 (error We are not able to complete the requested operation. We are processing delete in parent folder. Please try again later. (error_background)) 2021/07/25 06:21:32 DEBUG : pacer: Rate limited, increasing sleep to 1.28s 2021/07/25 06:21:32 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:21:38 DEBUG : pacer: low level retry 7/10 (error We are not able to complete the requested operation. We are processing delete in parent folder. Please try again later. (error_background)) 2021/07/25 06:21:38 DEBUG : pacer: Rate limited, increasing sleep to 2.56s 2021/07/25 06:21:38 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': Sleeping for 6s to wait for "error_background" error to clear 2021/07/25 06:21:44 DEBUG : pacer: low level retry 8/10 (error We are not able to complete the requested operation. We are processing delete in parent folder. Please try again later. (error_background)) 2021/07/25 06:21:44 DEBUG : pacer: Rate limited, increasing sleep to 5.12s 2021/07/25 06:21:47 DEBUG : pacer: Reducing sleep to 3.84s 2021/07/25 06:21:47 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=File file name.txt is already in trash. To delete it permanently use the DeleteFromTrash function. (file_error), err=File file name.txt is already in trash. To delete it permanently use the DeleteFromTrash function. (file_error) fstests.go:1691: Error Trace: fstests.go:1691 Error: Received unexpected error: File file name.txt is already in trash. To delete it permanently use the DeleteFromTrash function. (file_error) failed to delete file github.com/rclone/rclone/backend/filefabric.(*Fs).deleteObject /home/rclone/go/src/github.com/rclone/rclone/backend/filefabric/filefabric.go:724 github.com/rclone/rclone/backend/filefabric.(*Object).Remove /home/rclone/go/src/github.com/rclone/rclone/backend/filefabric/filefabric.go:1326 github.com/rclone/rclone/fstest/fstests.Run.func13.13.42 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:1690 testing.tRunner /usr/local/go/src/testing/testing.go:1123 runtime.goexit /usr/local/go/src/runtime/asm_amd64.s:1374 Test: TestIntegration/FsMkdir/FsPutFiles/ObjectRemove === RUN TestIntegration/FsMkdir/FsUploadUnknownSize === RUN TestIntegration/FsMkdir/FsUploadUnknownSize/FsUpdateUnknownSize 2021/07/25 06:21:47 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:text/plain; charset=utf-8 fi_filename:unknown-size-update.txt fi_localtime:2002-02-03 04:05:06 fi_modified:2002-02-03 04:05:06 fi_name:unknown-size-update.txt fi_pid:121000277 fi_size:100 responsetype:json]) options=[] 2021/07/25 06:21:51 DEBUG : pacer: Reducing sleep to 2.88s 2021/07/25 06:21:51 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:21:55 DEBUG : pacer: Reducing sleep to 2.16s 2021/07/25 06:21:55 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doCompleteUpload(map[fi_size:100 remotetime:2002-02-03 04:05:06 uploadcode:a469c1bc0c84824de781f85b25792b33]) options=[] 2021/07/25 06:21:59 DEBUG : pacer: Reducing sleep to 1.62s 2021/07/25 06:21:59 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:21:59 DEBUG : unknown-size-update.txt: Correcting mime type from "text/plain" to "text/plain; charset=utf-8" 2021/07/25 06:21:59 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doModifyFile(map[data:fi_contenttype=text/plain; charset=utf-8 fi_id:121000316]) options=[] 2021/07/25 06:21:59 DEBUG : pacer: Reducing sleep to 1.215s 2021/07/25 06:21:59 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:21:59 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: checkPathExists(map[path:unknown-size-update.txt pid:121000277]) options=[] 2021/07/25 06:22:01 DEBUG : pacer: Reducing sleep to 911.25ms 2021/07/25 06:22:01 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:22:01 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: checkPathExists(map[path:unknown-size-update.txt pid:121000277]) options=[] 2021/07/25 06:22:02 DEBUG : pacer: Reducing sleep to 683.4375ms 2021/07/25 06:22:02 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:22:02 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:text/plain; charset=utf-8 fi_filename:unknown-size-update.txt fi_localtime:2002-02-03 04:05:06 fi_modified:2002-02-03 04:05:06 fi_name:unknown-size-update.txt fi_pid:121000277 responsetype:json]) options=[] 2021/07/25 06:22:04 DEBUG : pacer: Reducing sleep to 512.578125ms 2021/07/25 06:22:04 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:22:05 DEBUG : pacer: Reducing sleep to 384.433593ms 2021/07/25 06:22:05 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doCompleteUpload(map[fi_size:200 remotetime:2002-02-03 04:05:06 uploadcode:4eb0c55f3b7452f7e4ed2aaa475674ea]) options=[] 2021/07/25 06:22:26 DEBUG : pacer: Reducing sleep to 288.325194ms 2021/07/25 06:22:26 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:22:26 DEBUG : unknown-size-update.txt: Correcting mime type from "text/plain" to "text/plain; charset=utf-8" 2021/07/25 06:22:26 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doModifyFile(map[data:fi_contenttype=text/plain; charset=utf-8 fi_id:121000316]) options=[] 2021/07/25 06:22:26 DEBUG : pacer: Reducing sleep to 216.243895ms 2021/07/25 06:22:26 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:22:26 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doDeleteFile(map[completedeletion:n fi_id:121000316]) options=[] 2021/07/25 06:22:29 DEBUG : pacer: Reducing sleep to 162.182921ms 2021/07/25 06:22:29 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=File unknown-size-update.txt is already in trash. To delete it permanently use the DeleteFromTrash function. (file_error), err=File unknown-size-update.txt is already in trash. To delete it permanently use the DeleteFromTrash function. (file_error) fstests.go:1923: Error Trace: fstests.go:1923 Error: Received unexpected error: File unknown-size-update.txt is already in trash. To delete it permanently use the DeleteFromTrash function. (file_error) failed to delete file github.com/rclone/rclone/backend/filefabric.(*Fs).deleteObject /home/rclone/go/src/github.com/rclone/rclone/backend/filefabric/filefabric.go:724 github.com/rclone/rclone/backend/filefabric.(*Object).Remove /home/rclone/go/src/github.com/rclone/rclone/backend/filefabric/filefabric.go:1326 github.com/rclone/rclone/fstest/fstests.Run.func13.15.2 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:1923 testing.tRunner /usr/local/go/src/testing/testing.go:1123 runtime.goexit /usr/local/go/src/runtime/asm_amd64.s:1374 Test: TestIntegration/FsMkdir/FsUploadUnknownSize/FsUpdateUnknownSize Messages: successfully updated object with unknown-sized source but failed to remove 2021/07/25 06:22:29 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doDeleteFolder(map[fi_id:121000277]) options=[] 2021/07/25 06:22:32 DEBUG : pacer: Reducing sleep to 121.63719ms 2021/07/25 06:22:32 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Folder sub_new_name.sodiruw9 is already in trash. To delete it permanently use the DeleteFromTrash function. (file_error), err=Folder sub_new_name.sodiruw9 is already in trash. To delete it permanently use the DeleteFromTrash function. (file_error) === CONT TestIntegration/FsMkdir fstests.go:1954: Error Trace: fstests.go:1954 Error: Received unexpected error: failed to remove directory: Folder sub_new_name.sodiruw9 is already in trash. To delete it permanently use the DeleteFromTrash function. (file_error) Test: TestIntegration/FsMkdir 2021/07/25 06:22:32 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': 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/07/25 06:22:34 DEBUG : pacer: Reducing sleep to 91.227892ms 2021/07/25 06:22:34 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= 2021/07/25 06:22:34 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': rpc: doDeleteFolder(map[fi_id:121000307]) options=[] 2021/07/25 06:22:37 DEBUG : pacer: Reducing sleep to 68.420919ms 2021/07/25 06:22:37 DEBUG : filefabric root 'rclone-test-qoqevof4sovovoq8wihofop0': >rpc: result=Success (ok), err= --- FAIL: TestIntegration (468.41s) --- FAIL: TestIntegration/FsMkdir (456.19s) --- FAIL: TestIntegration/FsMkdir/FsPutFiles (411.19s) --- FAIL: TestIntegration/FsMkdir/FsPutFiles/FsDirMove (227.34s) --- FAIL: TestIntegration/FsMkdir/FsPutFiles/ObjectMimeType (0.23s) --- FAIL: TestIntegration/FsMkdir/FsPutFiles/ObjectUpdate (0.97s) --- FAIL: TestIntegration/FsMkdir/FsPutFiles/FsIsFile (8.72s) --- FAIL: TestIntegration/FsMkdir/FsPutFiles/FromRoot (51.28s) --- FAIL: TestIntegration/FsMkdir/FsPutFiles/FromRoot/List (8.02s) --- FAIL: TestIntegration/FsMkdir/FsPutFiles/FromRoot/ListEntries (0.42s) --- FAIL: TestIntegration/FsMkdir/FsPutFiles/FromRoot/Put (42.84s) --- FAIL: TestIntegration/FsMkdir/FsPutFiles/FromRoot/Put/Remove (21.87s) --- FAIL: TestIntegration/FsMkdir/FsPutFiles/ObjectRemove (54.22s) --- FAIL: TestIntegration/FsMkdir/FsUploadUnknownSize (42.00s) --- FAIL: TestIntegration/FsMkdir/FsUploadUnknownSize/FsUpdateUnknownSize (42.00s) FAIL exit status 1 FAIL github.com/rclone/rclone/backend/filefabric 468.419s "go test -v -timeout 1h0m0s -remote TestFileFabric: -verbose -test.run '^TestIntegration$/^FsMkdir$/^(FsPutFiles|FsUploadUnknownSize)$/^(FromRoot|FsDirMove|FsIsFile|FsUpdateUnknownSize|ObjectMimeType|ObjectRemove|ObjectUpdate)$/^(List|ListEntries|Put)$/^Remove$'" - Finished ERROR in 7m50.256866962s (try 3/5): exit status 1: Failed [TestIntegration/FsMkdir/FsPutFiles/FsDirMove TestIntegration/FsMkdir/FsPutFiles/ObjectMimeType TestIntegration/FsMkdir/FsPutFiles/ObjectUpdate TestIntegration/FsMkdir/FsPutFiles/FsIsFile TestIntegration/FsMkdir/FsPutFiles/FromRoot/List TestIntegration/FsMkdir/FsPutFiles/FromRoot/ListEntries TestIntegration/FsMkdir/FsPutFiles/FromRoot/Put/Remove TestIntegration/FsMkdir/FsPutFiles/ObjectRemove TestIntegration/FsMkdir/FsUploadUnknownSize/FsUpdateUnknownSize]