"go test -v -timeout 2h0m0s -remote TestFileFabric: -verbose" - Starting (try 1/5) === RUN TestIntegration fstests.go:418: Using remote "TestFileFabric:" 2022/03/02 05:43:26 DEBUG : Creating backend with remote "TestFileFabric:rclone-test-bugebiz6zobayoj2lozifix5" 2022/03/02 05:43:26 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2022/03/02 05:43:26 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:rclone-test-bugebiz6zobayoj2lozifix5 pid:120673762]) options=[] 2022/03/02 05:43:27 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsCheckWrap fstests.go:459: Not a wrapping Fs === RUN TestIntegration/FsCommand fstests.go:487: No commands in this remote === RUN TestIntegration/FsRmdirNotFound 2022/03/02 05:43:27 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': 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=[] 2022/03/02 05:44:00 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:44:00 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': 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=[] 2022/03/02 05:44:01 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:44:01 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:rclone-test-bugebiz6zobayoj2lozifix5 fi_pid:120673762]) options=[] 2022/03/02 05:44:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:44:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389004 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:45:18 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsString === RUN TestIntegration/FsName === RUN TestIntegration/FsRoot === RUN TestIntegration/FsRmdirEmpty 2022/03/02 05:45:18 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389004 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:45:19 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:45:19 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389004]) options=[] 2022/03/02 05:45:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir 2022/03/02 05:45:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': 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=[] 2022/03/02 05:46:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:46:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:rclone-test-bugebiz6zobayoj2lozifix5 fi_pid:120673762]) options=[] 2022/03/02 05:46:09 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': Sleeping for 1s to wait for "error_background" error to clear 2022/03/02 05:46:10 DEBUG : pacer: low level retry 1/10 (error Can not create folder now. We are not able to complete the requested operation with such name. We are processing delete in that folder. Please try again later or use another name. (error_background)) 2022/03/02 05:46:10 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2022/03/02 05:46:18 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': Sleeping for 2s to wait for "error_background" error to clear 2022/03/02 05:46:20 DEBUG : pacer: low level retry 2/10 (error Can not create folder now. We are not able to complete the requested operation with such name. We are processing delete in that folder. Please try again later or use another name. (error_background)) 2022/03/02 05:46:20 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2022/03/02 05:46:23 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': Sleeping for 4s to wait for "error_background" error to clear 2022/03/02 05:46:27 DEBUG : pacer: low level retry 3/10 (error Can not create folder now. We are not able to complete the requested operation with such name. We are processing delete in that folder. Please try again later or use another name. (error_background)) 2022/03/02 05:46:27 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2022/03/02 05:46:28 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': Sleeping for 8s to wait for "error_background" error to clear 2022/03/02 05:46:36 DEBUG : pacer: low level retry 4/10 (error Can not create folder now. We are not able to complete the requested operation with such name. We are processing delete in that folder. Please try again later or use another name. (error_background)) 2022/03/02 05:46:36 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2022/03/02 05:46:39 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': Sleeping for 16s to wait for "error_background" error to clear 2022/03/02 05:46:55 DEBUG : pacer: low level retry 5/10 (error Can not create folder now. We are not able to complete the requested operation with such name. We are processing delete in that folder. Please try again later or use another name. (error_background)) 2022/03/02 05:46:55 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2022/03/02 05:47:01 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': Sleeping for 32s to wait for "error_background" error to clear 2022/03/02 05:47:33 DEBUG : pacer: low level retry 6/10 (error Can not create folder now. We are not able to complete the requested operation with such name. We are processing delete in that folder. Please try again later or use another name. (error_background)) 2022/03/02 05:47:33 DEBUG : pacer: Rate limited, increasing sleep to 1.28s 2022/03/02 05:48:21 DEBUG : pacer: Reducing sleep to 960ms 2022/03/02 05:48:21 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:48:21 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:48:52 DEBUG : pacer: Reducing sleep to 720ms 2022/03/02 05:48:52 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsMkdirRmdirSubdir 2022/03/02 05:48:52 DEBUG : dir/subdir: Making directory 2022/03/02 05:48:52 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:48:53 DEBUG : pacer: Reducing sleep to 540ms 2022/03/02 05:48:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:48:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:dir fi_pid:121389008]) options=[] 2022/03/02 05:49:38 DEBUG : pacer: Reducing sleep to 405ms 2022/03/02 05:49:38 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:49:38 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389009 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:50:06 DEBUG : pacer: Reducing sleep to 303.75ms 2022/03/02 05:50:06 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:50:06 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:subdir fi_pid:121389009]) options=[] 2022/03/02 05:51:03 DEBUG : pacer: Reducing sleep to 227.8125ms 2022/03/02 05:51:03 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:51:03 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:51:34 DEBUG : pacer: Reducing sleep to 170.859375ms 2022/03/02 05:51:34 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:51:34 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389009 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:52:13 DEBUG : pacer: Reducing sleep to 128.144531ms 2022/03/02 05:52:13 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:52:13 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389010 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:52:44 DEBUG : pacer: Reducing sleep to 96.108398ms 2022/03/02 05:52:44 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:52:44 INFO : dir/subdir: Removing directory 2022/03/02 05:52:44 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389010 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:52:44 DEBUG : pacer: Reducing sleep to 72.081298ms 2022/03/02 05:52:44 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:52:44 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389010]) options=[] 2022/03/02 05:53:25 DEBUG : pacer: Reducing sleep to 54.060973ms 2022/03/02 05:53:25 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:53:25 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:53:26 DEBUG : pacer: Reducing sleep to 40.545729ms 2022/03/02 05:53:26 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:53:26 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389009 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:53:31 DEBUG : pacer: Reducing sleep to 30.409296ms 2022/03/02 05:53:31 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:53:31 INFO : dir: Removing directory 2022/03/02 05:53:31 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389009 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:53:32 DEBUG : pacer: Reducing sleep to 22.806972ms 2022/03/02 05:53:32 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:53:32 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389009]) options=[] 2022/03/02 05:53:37 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': Sleeping for 1s to wait for "error_background" error to clear 2022/03/02 05:53:38 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)) 2022/03/02 05:53:38 DEBUG : pacer: Rate limited, increasing sleep to 45.613944ms 2022/03/02 05:53:43 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': Sleeping for 2s to wait for "error_background" error to clear 2022/03/02 05:53:45 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)) 2022/03/02 05:53:45 DEBUG : pacer: Rate limited, increasing sleep to 91.227888ms 2022/03/02 05:53:52 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': Sleeping for 4s to wait for "error_background" error to clear 2022/03/02 05:53:56 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)) 2022/03/02 05:53:56 DEBUG : pacer: Rate limited, increasing sleep to 182.455776ms 2022/03/02 05:54:02 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': Sleeping for 8s to wait for "error_background" error to clear 2022/03/02 05:54:10 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)) 2022/03/02 05:54:10 DEBUG : pacer: Rate limited, increasing sleep to 364.911552ms 2022/03/02 05:54:17 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': Sleeping for 16s to wait for "error_background" error to clear 2022/03/02 05:54:33 DEBUG : pacer: low level retry 5/10 (error The requested operation cannot be completed. A delete operation is already being processed in this folder. Please try again later. (error_background)) 2022/03/02 05:54:33 DEBUG : pacer: Rate limited, increasing sleep to 729.823104ms 2022/03/02 05:54:34 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': Sleeping for 32s to wait for "error_background" error to clear 2022/03/02 05:55:06 DEBUG : pacer: low level retry 6/10 (error The requested operation cannot be completed. A delete operation is already being processed in this folder. Please try again later. (error_background)) 2022/03/02 05:55:06 DEBUG : pacer: Rate limited, increasing sleep to 1.459646208s 2022/03/02 05:55:15 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': Sleeping for 1m4s to wait for "error_background" error to clear 2022/03/02 05:56:19 DEBUG : pacer: low level retry 7/10 (error The requested operation cannot be completed. A delete operation is already being processed in this folder. Please try again later. (error_background)) 2022/03/02 05:56:19 DEBUG : pacer: Rate limited, increasing sleep to 2.919292416s 2022/03/02 05:56:55 DEBUG : pacer: Reducing sleep to 2.189469312s 2022/03/02 05:56:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:56:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:57:01 DEBUG : pacer: Reducing sleep to 1.642101984s 2022/03/02 05:57:01 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsListEmpty 2022/03/02 05:57:01 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:57:02 DEBUG : pacer: Reducing sleep to 1.231576488s 2022/03/02 05:57:02 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsListDirEmpty 2022/03/02 05:57:02 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:57:03 DEBUG : pacer: Reducing sleep to 923.682366ms 2022/03/02 05:57:03 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsListRDirEmpty fstests.go:378: FS has no ListR interface === RUN TestIntegration/FsMkdir/FsListDirNotFound 2022/03/02 05:57:03 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:57:05 DEBUG : pacer: Reducing sleep to 692.761774ms 2022/03/02 05:57:05 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:57:05 ERROR : does not exist: error listing: directory not found === RUN TestIntegration/FsMkdir/FsListRDirNotFound fstests.go:378: FS has no ListR interface === RUN TestIntegration/FsMkdir/FsEncoding 2022/03/02 05:57:05 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:57:06 DEBUG : pacer: Reducing sleep to 519.57133ms 2022/03/02 05:57:06 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/control_chars fstests.go:674: testing "␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡" 2022/03/02 05:57:06 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:57:06 DEBUG : pacer: Reducing sleep to 389.678497ms 2022/03/02 05:57:06 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:57:06 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡ fi_pid:121389008]) options=[] 2022/03/02 05:57:38 DEBUG : pacer: Reducing sleep to 292.258872ms 2022/03/02 05:57:38 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:57:38 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡ fi_localtime:2022-03-02 05:57:38 fi_modified:2022-03-02 05:57:38 fi_name:␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡ fi_pid:121389016 fi_size:100 responsetype:json]) options=[] 2022/03/02 05:57:45 DEBUG : pacer: Reducing sleep to 219.194154ms 2022/03/02 05:57:45 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:57:47 DEBUG : pacer: Reducing sleep to 164.395615ms 2022/03/02 05:57:47 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 05:57:38 uploadcode:92f0138541f6c19e827d0ef03fde1a15]) options=[] 2022/03/02 05:58:20 DEBUG : pacer: Reducing sleep to 123.296711ms 2022/03/02 05:58:20 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:58:20 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡/␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡ pid:121389008]) options=[] 2022/03/02 05:58:21 DEBUG : pacer: Reducing sleep to 92.472533ms 2022/03/02 05:58:21 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:58:21 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:58:26 DEBUG : pacer: Reducing sleep to 69.354399ms 2022/03/02 05:58:26 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:58:26 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389016 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 05:59:04 DEBUG : pacer: Reducing sleep to 52.015799ms 2022/03/02 05:59:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 05:59:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389018]) options=[] 2022/03/02 06:01:28 DEBUG : pacer: Reducing sleep to 39.011849ms 2022/03/02 06:01:28 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:01:28 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389016 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:02:04 DEBUG : pacer: Reducing sleep to 29.258886ms 2022/03/02 06:02:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:02:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389016]) options=[] 2022/03/02 06:02:42 DEBUG : pacer: Reducing sleep to 21.944164ms 2022/03/02 06:02:42 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:02:42 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:02:48 DEBUG : pacer: Reducing sleep to 20ms 2022/03/02 06:02:48 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/dot fstests.go:674: testing "．" 2022/03/02 06:02:48 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:02:49 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:02:49 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:． fi_pid:121389008]) options=[] 2022/03/02 06:03:20 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:03:20 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:． fi_localtime:2022-03-02 06:03:20 fi_modified:2022-03-02 06:03:20 fi_name:． fi_pid:121389020 fi_size:100 responsetype:json]) options=[] 2022/03/02 06:03:27 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:03:28 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 06:03:20 uploadcode:8b624a3b42c62eca8aa9980e0c4ba9ed]) options=[] 2022/03/02 06:03:59 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:03:59 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:．/． pid:121389008]) options=[] 2022/03/02 06:03:59 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:03:59 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:04:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:04:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389020 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:04:34 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:04:34 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389021]) options=[] 2022/03/02 06:06:59 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:06:59 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389020 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:07:33 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:07:33 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389020]) options=[] 2022/03/02 06:08:11 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:08:11 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:08:20 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/dot_dot fstests.go:674: testing "．．" 2022/03/02 06:08:20 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:08:21 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:08:21 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:．． fi_pid:121389008]) options=[] 2022/03/02 06:09:14 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:09:14 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:．． fi_localtime:2022-03-02 06:09:14 fi_modified:2022-03-02 06:09:14 fi_name:．． fi_pid:121389024 fi_size:100 responsetype:json]) options=[] 2022/03/02 06:09:26 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:09:28 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 06:09:14 uploadcode:e9b9c9292361f8441f10fed9d0289005]) options=[] 2022/03/02 06:10:03 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:10:03 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:．．/．． pid:121389008]) options=[] 2022/03/02 06:10:03 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:10:03 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:10:37 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:10:37 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389024 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:11:11 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:11:11 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389025]) options=[] 2022/03/02 06:13:07 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:13:07 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389024 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:13:44 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:13:44 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389024]) options=[] 2022/03/02 06:14:28 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:14:28 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:14:33 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/punctuation fstests.go:674: testing "!\"#$%&'()*+,-.／:;<=>?@[\\]^_`{|}~" 2022/03/02 06:14:33 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:14:34 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:14:34 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:!"#$%&'()*+,-.／:;<=>?@[\]^_`{|}~ fi_pid:121389008]) options=[] 2022/03/02 06:15:12 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:15:12 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:!"#$%&'()*+,-.／:;<=>?@[\]^_`{|}~ fi_localtime:2022-03-02 06:15:12 fi_modified:2022-03-02 06:15:12 fi_name:!"#$%&'()*+,-.／:;<=>?@[\]^_`{|}~ fi_pid:121389031 fi_size:100 responsetype:json]) options=[] 2022/03/02 06:15:20 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:15:21 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 06:15:12 uploadcode:7f651b780cdf10a356d132e6fa1ce474]) options=[] 2022/03/02 06:15:54 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:15:54 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:!"#$%&'()*+,-.／:;<=>?@[\]^_`{|}~/!"#$%&'()*+,-.／:;<=>?@[\]^_`{|}~ pid:121389008]) options=[] 2022/03/02 06:15:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:15:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:16:00 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:16:00 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389031 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:16:49 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:16:49 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389032]) options=[] 2022/03/02 06:19:19 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:19:19 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389031 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:19:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:19:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389031]) options=[] 2022/03/02 06:20:42 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:20:42 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:20:52 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/leading_space fstests.go:674: testing " leading space" 2022/03/02 06:20:52 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:20:52 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:20:52 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name: leading space fi_pid:121389008]) options=[] 2022/03/02 06:21:48 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:21:48 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename: leading space fi_localtime:2022-03-02 06:21:48 fi_modified:2022-03-02 06:21:48 fi_name: leading space fi_pid:121389038 fi_size:100 responsetype:json]) options=[] 2022/03/02 06:21:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:21:57 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 06:21:48 uploadcode:2b2ee63d97a9d738e297e9168b07aecd]) options=[] 2022/03/02 06:22:32 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:22:32 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path: leading space/ leading space pid:121389008]) options=[] 2022/03/02 06:22:33 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:22:33 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:23:21 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:23:21 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389038 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:23:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:23:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389039]) options=[] 2022/03/02 06:25:36 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:25:36 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389038 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:26:21 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:26:21 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389038]) options=[] 2022/03/02 06:26:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:26:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:26:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': Token expired - refreshing 2022/03/02 06:26:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getTokenByAuthToken(map[authtoken:622506e6346e7ad6-c48bf9558d23a2ae token:*]) options=[] 2022/03/02 06:26:56 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:26:56 DEBUG : Saving config "token" in section "TestFileFabric" of the config file 2022/03/02 06:26:56 DEBUG : Config file has changed externaly - reloading 2022/03/02 06:26:56 DEBUG : Saving config "token_expiry" in section "TestFileFabric" of the config file 2022/03/02 06:26:56 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getApplianceInfo(map[token:*]) options=[] 2022/03/02 06:26:56 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:26:56 DEBUG : Saving config "version" in section "TestFileFabric" of the config file 2022/03/02 06:27:01 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/leading_tilde fstests.go:674: testing "~leading tilde" 2022/03/02 06:27:01 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:27:02 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:27:02 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:~leading tilde fi_pid:121389008]) options=[] 2022/03/02 06:27:57 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:27:57 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:~leading tilde fi_localtime:2022-03-02 06:27:57 fi_modified:2022-03-02 06:27:57 fi_name:~leading tilde fi_pid:121389043 fi_size:100 responsetype:json]) options=[] 2022/03/02 06:28:07 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:28:09 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 06:27:57 uploadcode:9eadbeac2612b9860e9aa8b7e112c9a6]) options=[] 2022/03/02 06:28:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:28:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:~leading tilde/~leading tilde pid:121389008]) options=[] 2022/03/02 06:28:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:28:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:28:56 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:28:56 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389043 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:29:33 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:29:33 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389044]) options=[] 2022/03/02 06:32:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:32:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389043 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:32:39 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:32:39 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389043]) options=[] 2022/03/02 06:33:20 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:33:20 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:33:26 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/leading_CR fstests.go:674: testing "␍leading CR" 2022/03/02 06:33:26 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:33:27 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:33:27 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:␍leading CR fi_pid:121389008]) options=[] 2022/03/02 06:34:19 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:34:19 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:␍leading CR fi_localtime:2022-03-02 06:34:19 fi_modified:2022-03-02 06:34:19 fi_name:␍leading CR fi_pid:121389054 fi_size:100 responsetype:json]) options=[] 2022/03/02 06:34:29 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:34:31 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 06:34:19 uploadcode:f61920c9fa8cfe1fa3d6c225f2cd56c5]) options=[] 2022/03/02 06:35:06 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:35:06 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:␍leading CR/␍leading CR pid:121389008]) options=[] 2022/03/02 06:35:07 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:35:07 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:35:11 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:35:11 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389054 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:35:47 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:35:47 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389055]) options=[] 2022/03/02 06:38:29 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:38:29 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389054 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:39:05 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:39:05 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389054]) options=[] 2022/03/02 06:39:47 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:39:47 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:39:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/leading_LF fstests.go:674: testing "␊leading LF" 2022/03/02 06:39:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:39:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:39:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:␊leading LF fi_pid:121389008]) options=[] 2022/03/02 06:40:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:40:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:␊leading LF fi_localtime:2022-03-02 06:40:53 fi_modified:2022-03-02 06:40:53 fi_name:␊leading LF fi_pid:121389060 fi_size:100 responsetype:json]) options=[] 2022/03/02 06:40:59 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:41:00 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 06:40:53 uploadcode:105054018b9c9295f0173cf7cb2d1262]) options=[] 2022/03/02 06:41:40 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:41:40 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:␊leading LF/␊leading LF pid:121389008]) options=[] 2022/03/02 06:41:41 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:41:41 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:41:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:41:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389060 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:42:32 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:42:32 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389062]) options=[] 2022/03/02 06:45:08 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:45:08 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389060 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:45:36 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:45:36 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389060]) options=[] 2022/03/02 06:46:14 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:46:14 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:46:23 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/leading_HT fstests.go:674: testing "␉leading HT" 2022/03/02 06:46:23 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:46:24 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:46:24 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:␉leading HT fi_pid:121389008]) options=[] 2022/03/02 06:47:12 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:47:12 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:␉leading HT fi_localtime:2022-03-02 06:47:12 fi_modified:2022-03-02 06:47:12 fi_name:␉leading HT fi_pid:121389070 fi_size:100 responsetype:json]) options=[] 2022/03/02 06:47:22 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:47:24 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 06:47:12 uploadcode:54a9cd7977b5ad0c128c813adcd89734]) options=[] 2022/03/02 06:47:58 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:47:58 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:␉leading HT/␉leading HT pid:121389008]) options=[] 2022/03/02 06:47:59 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:47:59 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:48:08 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:48:08 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389070 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:48:48 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:48:48 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389071]) options=[] 2022/03/02 06:50:40 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:50:40 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389070 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:51:08 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:51:08 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389070]) options=[] 2022/03/02 06:51:44 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:51:44 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:51:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/leading_VT fstests.go:674: testing "␋leading VT" 2022/03/02 06:51:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:51:54 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:51:54 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:␋leading VT fi_pid:121389008]) options=[] 2022/03/02 06:52:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:52:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:␋leading VT fi_localtime:2022-03-02 06:52:46 fi_modified:2022-03-02 06:52:46 fi_name:␋leading VT fi_pid:121389074 fi_size:100 responsetype:json]) options=[] 2022/03/02 06:52:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:52:54 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 06:52:46 uploadcode:5e483fe5965b09813732c5cdd5bc0a13]) options=[] 2022/03/02 06:53:28 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:53:28 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:␋leading VT/␋leading VT pid:121389008]) options=[] 2022/03/02 06:53:29 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:53:29 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:53:33 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:53:33 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389074 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:54:10 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:54:10 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389075]) options=[] 2022/03/02 06:55:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:55:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389074 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:56:25 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:56:25 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389074]) options=[] 2022/03/02 06:57:06 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:57:06 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:57:16 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/leading_dot fstests.go:674: testing ".leading dot" 2022/03/02 06:57:16 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:57:17 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:57:17 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:.leading dot fi_pid:121389008]) options=[] 2022/03/02 06:58:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:58:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:.leading dot fi_localtime:2022-03-02 06:58:04 fi_modified:2022-03-02 06:58:04 fi_name:.leading dot fi_pid:121389078 fi_size:100 responsetype:json]) options=[] 2022/03/02 06:58:15 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:58:17 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 06:58:04 uploadcode:d916f603b8d437010d392554328a4844]) options=[] 2022/03/02 06:58:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:58:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:.leading dot/.leading dot pid:121389008]) options=[] 2022/03/02 06:58:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:58:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:59:03 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:59:03 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389078 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 06:59:31 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 06:59:31 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389079]) options=[] 2022/03/02 07:01:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:01:53 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389078 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:02:31 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:02:31 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389078]) options=[] 2022/03/02 07:03:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:03:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:03:09 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/trailing_space fstests.go:674: testing "trailing space " 2022/03/02 07:03:09 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:03:10 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:03:10 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:trailing space fi_pid:121389008]) options=[] 2022/03/02 07:03:58 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:03:58 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:trailing space fi_localtime:2022-03-02 07:03:58 fi_modified:2022-03-02 07:03:58 fi_name:trailing space fi_pid:121389085 fi_size:100 responsetype:json]) options=[] 2022/03/02 07:04:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:04:06 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 07:03:58 uploadcode:38c0667fad95a059f32e1245c7c76eed]) options=[] 2022/03/02 07:04:31 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:04:31 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:trailing space /trailing space pid:121389008]) options=[] 2022/03/02 07:04:32 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:04:32 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:04:36 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:04:36 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389085 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:05:07 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:05:07 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389086]) options=[] 2022/03/02 07:07:19 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:07:19 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389085 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:07:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:07:55 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389085]) options=[] 2022/03/02 07:08:39 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:08:39 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:08:48 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/trailing_CR fstests.go:674: testing "trailing CR␍" 2022/03/02 07:08:48 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:08:48 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:08:48 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:trailing CR␍ fi_pid:121389008]) options=[] 2022/03/02 07:09:35 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:09:35 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:trailing CR␍ fi_localtime:2022-03-02 07:09:35 fi_modified:2022-03-02 07:09:35 fi_name:trailing CR␍ fi_pid:121389091 fi_size:100 responsetype:json]) options=[] 2022/03/02 07:09:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:09:47 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 07:09:35 uploadcode:2010deecef36a0077c4ee1cbd9585e63]) options=[] 2022/03/02 07:10:18 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:10:18 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:trailing CR␍/trailing CR␍ pid:121389008]) options=[] 2022/03/02 07:10:18 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:10:18 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:10:23 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:10:23 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389091 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:11:03 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:11:03 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389093]) options=[] 2022/03/02 07:13:25 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:13:25 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389091 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:14:05 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:14:05 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389091]) options=[] 2022/03/02 07:14:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:14:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:14:51 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/trailing_LF fstests.go:674: testing "trailing LF␊" 2022/03/02 07:14:51 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:14:52 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:14:52 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:trailing LF␊ fi_pid:121389008]) options=[] 2022/03/02 07:15:43 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:15:43 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:trailing LF␊ fi_localtime:2022-03-02 07:15:43 fi_modified:2022-03-02 07:15:43 fi_name:trailing LF␊ fi_pid:121389095 fi_size:100 responsetype:json]) options=[] 2022/03/02 07:15:49 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:15:51 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 07:15:43 uploadcode:74f749f178ef5c2d823daa287b79ca56]) options=[] 2022/03/02 07:16:25 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:16:25 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:trailing LF␊/trailing LF␊ pid:121389008]) options=[] 2022/03/02 07:16:26 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:16:26 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:16:34 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:16:34 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389095 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:17:03 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:17:03 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389096]) options=[] 2022/03/02 07:19:07 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:19:07 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389095 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:19:42 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:19:42 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389095]) options=[] 2022/03/02 07:20:19 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:20:19 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:20:25 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/trailing_HT fstests.go:674: testing "trailing HT␉" 2022/03/02 07:20:25 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:20:25 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:20:25 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:trailing HT␉ fi_pid:121389008]) options=[] 2022/03/02 07:21:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:21:04 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:trailing HT␉ fi_localtime:2022-03-02 07:21:04 fi_modified:2022-03-02 07:21:04 fi_name:trailing HT␉ fi_pid:121389099 fi_size:100 responsetype:json]) options=[] 2022/03/02 07:21:10 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:21:11 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 07:21:04 uploadcode:56af371167d4b528b1ccaaf0345e9ff3]) options=[] 2022/03/02 07:21:37 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:21:37 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:trailing HT␉/trailing HT␉ pid:121389008]) options=[] 2022/03/02 07:21:38 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:21:38 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:21:43 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:21:43 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389099 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:22:19 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:22:19 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389101]) options=[] 2022/03/02 07:22:19 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': Token expired - refreshing 2022/03/02 07:22:19 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getTokenByAuthToken(map[authtoken:622506e6346e7ad6-c48bf9558d23a2ae token:*]) options=[] 2022/03/02 07:22:19 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:22:19 DEBUG : Saving config "token" in section "TestFileFabric" of the config file 2022/03/02 07:22:19 DEBUG : Config file has changed externaly - reloading 2022/03/02 07:22:19 DEBUG : Saving config "token_expiry" in section "TestFileFabric" of the config file 2022/03/02 07:22:19 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getApplianceInfo(map[token:*]) options=[] 2022/03/02 07:22:20 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:22:20 DEBUG : Saving config "version" in section "TestFileFabric" of the config file 2022/03/02 07:24:36 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:24:36 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389099 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:25:12 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:25:12 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389099]) options=[] 2022/03/02 07:25:50 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:25:50 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:25:59 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/trailing_VT fstests.go:674: testing "trailing VT␋" 2022/03/02 07:25:59 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:26:00 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:26:00 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:trailing VT␋ fi_pid:121389008]) options=[] 2022/03/02 07:26:32 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:26:32 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:trailing VT␋ fi_localtime:2022-03-02 07:26:32 fi_modified:2022-03-02 07:26:32 fi_name:trailing VT␋ fi_pid:121389111 fi_size:100 responsetype:json]) options=[] 2022/03/02 07:26:42 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:26:44 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 07:26:32 uploadcode:c76959c88bc4bd7f23771f132c67ce48]) options=[] 2022/03/02 07:27:23 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:27:23 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:trailing VT␋/trailing VT␋ pid:121389008]) options=[] 2022/03/02 07:27:24 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:27:24 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:27:32 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:27:32 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389111 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:28:01 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:28:01 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389112]) options=[] 2022/03/02 07:30:38 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:30:38 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389111 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:31:11 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:31:11 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389111]) options=[] 2022/03/02 07:31:48 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:31:48 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:31:54 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/trailing_dot fstests.go:674: testing "trailing dot." 2022/03/02 07:31:54 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:31:54 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:31:54 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:trailing dot. fi_pid:121389008]) options=[] 2022/03/02 07:32:44 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:32:44 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:trailing dot. fi_localtime:2022-03-02 07:32:44 fi_modified:2022-03-02 07:32:44 fi_name:trailing dot. fi_pid:121389117 fi_size:100 responsetype:json]) options=[] 2022/03/02 07:32:51 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:32:52 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 07:32:44 uploadcode:586e7f17254ded5b729446957a2eda63]) options=[] 2022/03/02 07:33:09 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:33:09 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:trailing dot./trailing dot. pid:121389008]) options=[] 2022/03/02 07:33:09 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:33:09 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:33:14 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:33:14 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389117 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:33:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:33:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389118]) options=[] 2022/03/02 07:35:24 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:35:24 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389117 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:36:00 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:36:00 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389117]) options=[] 2022/03/02 07:36:37 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:36:37 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:36:42 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/invalid_UTF-8 fstests.go:674: testing "invalid utf-8\xfe" 2022/03/02 07:36:42 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:36:43 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:36:43 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:invalid utf-8‛FE fi_pid:121389008]) options=[] 2022/03/02 07:37:28 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:37:28 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:invalid utf-8‛FE fi_localtime:2022-03-02 07:37:28 fi_modified:2022-03-02 07:37:28 fi_name:invalid utf-8‛FE fi_pid:121389123 fi_size:100 responsetype:json]) options=[] 2022/03/02 07:37:37 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:37:39 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 07:37:28 uploadcode:7f6ce7c9257fd03d962bad55f8ee5208]) options=[] 2022/03/02 07:38:09 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:38:09 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: checkPathExists(map[path:invalid utf-8‛FE/invalid utf-8‛FE pid:121389008]) options=[] 2022/03/02 07:38:10 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:38:10 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:38:14 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:38:14 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389123 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:38:49 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:38:49 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFile(map[completedeletion:n fi_id:121389124]) options=[] 2022/03/02 07:41:15 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:41:15 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389123 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:41:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:41:46 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doDeleteFolder(map[fi_id:121389123]) options=[] 2022/03/02 07:42:25 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:42:25 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:42:30 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= === RUN TestIntegration/FsMkdir/FsEncoding/URL_encoding fstests.go:674: testing "test%46.txt" 2022/03/02 07:42:30 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: getFolderContents(map[count:1000 fi_pid:121389008 options:filelist|fi_id|fi_pid|fi_name|fi_type|fi_size|fi_contenttype|fi_modified|fi_localtime|trash|subfolders subfolders:y]) options=[] 2022/03/02 07:42:31 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:42:31 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCreateNewFolder(map[fi_name:test%46.txt fi_pid:121389008]) options=[] 2022/03/02 07:43:06 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:43:06 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:text/plain; charset=utf-8 fi_filename:test%46.txt fi_localtime:2022-03-02 07:43:06 fi_modified:2022-03-02 07:43:06 fi_name:test%46.txt fi_pid:121389129 fi_size:100 responsetype:json]) options=[] 2022/03/02 07:43:15 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': >rpc: result=Success (ok), err= 2022/03/02 07:43:17 DEBUG : filefabric root 'rclone-test-bugebiz6zobayoj2lozifix5': rpc: doCompleteUpload(map[fi_size:100 remotetime:2022-03-02 07:43:06 uploadcode:c15a9384bb572e0ec97c57c14de7c608]) options=[] panic: test timed out after 2h0m0s goroutine 2496 [running]: testing.(*M).startAlarm.func1() /usr/local/go/src/testing/testing.go:1788 +0x8e created by time.goFunc /usr/local/go/src/time/sleep.go:180 +0x31 goroutine 1 [chan receive, 119 minutes]: testing.(*T).Run(0xc000082b60, {0x9f85a6, 0x46d293}, 0xa30a00) /usr/local/go/src/testing/testing.go:1307 +0x375 testing.runTests.func1(0xc00009cc60) /usr/local/go/src/testing/testing.go:1598 +0x6e testing.tRunner(0xc000082b60, 0xc000237d18) /usr/local/go/src/testing/testing.go:1259 +0x102 testing.runTests(0xc0000a2300, {0xe79560, 0x1, 0x1}, {0x48af4d, 0x9f80fa, 0xe8dee0}) /usr/local/go/src/testing/testing.go:1596 +0x43f testing.(*M).Run(0xc0000a2300) /usr/local/go/src/testing/testing.go:1504 +0x51d main.main() _testmain.go:45 +0x14b goroutine 19 [chan receive, 119 minutes]: testing.(*T).Run(0xc000082d00, {0x9f3a65, 0xc00038c600}, 0xc0000e0210) /usr/local/go/src/testing/testing.go:1307 +0x375 github.com/rclone/rclone/fstest/fstests.Run(0xc000082d00, 0xc0000c60b0) /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:554 +0x1109 github.com/rclone/rclone/backend/filefabric_test.TestIntegration(0x407b99) /home/rclone/go/src/github.com/rclone/rclone/backend/filefabric/filefabric_test.go:13 +0x57 testing.tRunner(0xc000082d00, 0xa30a00) /usr/local/go/src/testing/testing.go:1259 +0x102 created by testing.(*T).Run /usr/local/go/src/testing/testing.go:1306 +0x35a goroutine 70 [chan receive, 107 minutes]: testing.(*T).Run(0xc00016e340, {0x9f54f8, 0x0}, 0xc0005688d0) /usr/local/go/src/testing/testing.go:1307 +0x375 github.com/rclone/rclone/fstest/fstests.Run.func13(0xc00016e340) /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:633 +0x65a testing.tRunner(0xc00016e340, 0xc0000e0210) /usr/local/go/src/testing/testing.go:1259 +0x102 created by testing.(*T).Run /usr/local/go/src/testing/testing.go:1306 +0x35a goroutine 379 [chan receive]: testing.(*T).Run(0xc0002f01a0, {0x9f6abc, 0x0}, 0xc000588060) /usr/local/go/src/testing/testing.go:1307 +0x375 github.com/rclone/rclone/fstest/fstests.Run.func13.7(0xc0002f01a0) /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:667 +0x2bc testing.tRunner(0xc0002f01a0, 0xc0005688d0) /usr/local/go/src/testing/testing.go:1259 +0x102 created by testing.(*T).Run /usr/local/go/src/testing/testing.go:1306 +0x35a goroutine 460 [chan receive, 107 minutes]: github.com/rclone/rclone/lib/atexit.Register.func1.1() /home/rclone/go/src/github.com/rclone/rclone/lib/atexit/atexit.go:45 +0x2f created by github.com/rclone/rclone/lib/atexit.Register.func1 /home/rclone/go/src/github.com/rclone/rclone/lib/atexit/atexit.go:44 +0x6d goroutine 444 [syscall, 107 minutes]: os/signal.signal_recv() /usr/local/go/src/runtime/sigqueue.go:169 +0x98 os/signal.loop() /usr/local/go/src/os/signal/signal_unix.go:24 +0x19 created by os/signal.Notify.func1.1 /usr/local/go/src/os/signal/signal.go:151 +0x2c goroutine 2523 [select]: net/http.(*persistConn).roundTrip(0xc000517c20, 0xc0003ca880) /usr/local/go/src/net/http/transport.go:2614 +0x97d net/http.(*Transport).roundTrip(0xc0000e4c80, 0xc0000fa300) /usr/local/go/src/net/http/transport.go:594 +0x7d1 net/http.(*Transport).RoundTrip(...) /usr/local/go/src/net/http/roundtrip.go:18 github.com/rclone/rclone/fs/fshttp.(*Transport).RoundTrip(0xc0000aebe0, 0xc0000fa300) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:274 +0x4c8 net/http.send(0xc0000fa300, {0xabace0, 0xc0000aebe0}, {0x9deca0, 0x1, 0x0}) /usr/local/go/src/net/http/client.go:252 +0x5d8 net/http.(*Client).send(0xc00009df20, 0xc0000fa300, {0xc00017b170, 0x2f, 0x0}) /usr/local/go/src/net/http/client.go:176 +0x9b net/http.(*Client).do(0xc00009df20, 0xc0000fa300) /usr/local/go/src/net/http/client.go:725 +0x908 net/http.(*Client).Do(...) /usr/local/go/src/net/http/client.go:593 github.com/rclone/rclone/lib/rest.(*Client).Call(0xc0000aec30, {0xac8450, 0xc000024058}, 0xc000517b00) /home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:284 +0xc05 github.com/rclone/rclone/lib/rest.(*Client).callCodec(0xe1ca20, {0xac8450, 0xc000024058}, 0xc00007c1e0, {0x0, 0x0}, {0x96cea0, 0xc0002c20f0}, 0xc00007c1e0, 0xa30c50, ...) /home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:481 +0x485 github.com/rclone/rclone/lib/rest.(*Client).CallJSON(...) /home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:424 github.com/rclone/rclone/backend/filefabric.(*Fs).rpc.func1() /home/rclone/go/src/github.com/rclone/rclone/backend/filefabric/filefabric.go:411 +0x17b github.com/rclone/rclone/fs.pacerInvoker(0xc0000ac660, 0xc00040f3f8, 0x100000000452b89) /home/rclone/go/src/github.com/rclone/rclone/fs/pacer.go:88 +0x38 github.com/rclone/rclone/lib/pacer.(*Pacer).call(0xc0000ac660, 0xc00040f440, 0xa) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:197 +0x85 github.com/rclone/rclone/lib/pacer.(*Pacer).Call(0xc0000ac660, 0xc00017b110) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:216 +0x90 github.com/rclone/rclone/backend/filefabric.(*Fs).rpc(0xc00038c600, {0xac8450, 0xc000024058}, {0x9f904e, 0xc000584f40}, 0xc00017b080, {0xac4948, 0xc0002c20f0}, {0x0, 0x0, ...}) /home/rclone/go/src/github.com/rclone/rclone/backend/filefabric/filefabric.go:407 +0x91c github.com/rclone/rclone/backend/filefabric.(*Object).Update(0xc0002e74a0, {0xac8450, 0xc000024058}, {0xabb2a0, 0xc0002cc5e0}, {0xacf200, 0xc0000af310}, {0x0, 0x0, 0x0}) /home/rclone/go/src/github.com/rclone/rclone/backend/filefabric/filefabric.go:1309 +0xfa5 github.com/rclone/rclone/backend/filefabric.(*Fs).Put(0x17, {0xac8450, 0xc000024058}, {0xabb2a0, 0xc0002cc5e0}, {0xacf200, 0xc0000af310}, {0x0, 0x0, 0x0}) /home/rclone/go/src/github.com/rclone/rclone/backend/filefabric/filefabric.go:712 +0x165 github.com/rclone/rclone/fstest/fstests.putTestContentsMimeType.func1() /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:197 +0x2d3 github.com/rclone/rclone/fstest/fstests.retry(0xc0002e1860, {0x9f2182, 0x3}, 0xc00040fd48) /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:145 +0x119 github.com/rclone/rclone/fstest/fstests.putTestContentsMimeType({0xac8450, 0xc000024058}, 0xc00031ddf8, {0xad4398, 0xc00038c600}, 0xc00040ff28, {0xc00002c5b0, 0x64}, 0x1, {0x0, ...}) /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:187 +0x151 github.com/rclone/rclone/fstest/fstests.PutTestContents(...) /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:212 github.com/rclone/rclone/fstest/fstests.testPut({0xac8450, 0xc000024058}, 0x0, {0xad4398, 0xc00038c600}, 0x9f65c6) /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:217 +0x8d github.com/rclone/rclone/fstest/fstests.Run.func13.7.1(0xc0002e1860) /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:680 +0x289 testing.tRunner(0xc0002e1860, 0xc000588060) /usr/local/go/src/testing/testing.go:1259 +0x102 created by testing.(*T).Run /usr/local/go/src/testing/testing.go:1306 +0x35a goroutine 2565 [IO wait]: internal/poll.runtime_pollWait(0x7f041c8ab018, 0x72) /usr/local/go/src/runtime/netpoll.go:234 +0x89 internal/poll.(*pollDesc).wait(0xc0000a2400, 0xc0001f1500, 0x0) /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x32 internal/poll.(*pollDesc).waitRead(...) /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Read(0xc0000a2400, {0xc0001f1500, 0x1484, 0x1484}) /usr/local/go/src/internal/poll/fd_unix.go:167 +0x25a net.(*netFD).Read(0xc0000a2400, {0xc0001f1500, 0x4f8318, 0x61}) /usr/local/go/src/net/fd_posix.go:56 +0x29 net.(*conn).Read(0xc000308098, {0xc0001f1500, 0x628be5, 0xc0002e9500}) /usr/local/go/src/net/net.go:183 +0x45 github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc0004b0978, {0xc0001f1500, 0xc0005b0480, 0x100000000000000}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:104 +0x32 crypto/tls.(*atLeastReader).Read(0xc0004b0d98, {0xc0001f1500, 0x0, 0x40b98d}) /usr/local/go/src/crypto/tls/conn.go:777 +0x3d bytes.(*Buffer).ReadFrom(0xc0002e9778, {0xaba800, 0xc0004b0d98}) /usr/local/go/src/bytes/buffer.go:204 +0x98 crypto/tls.(*Conn).readFromUntil(0xc0002e9500, {0x7f041c069858, 0xc0004b0978}, 0x10100c0001a3908) /usr/local/go/src/crypto/tls/conn.go:799 +0xe5 crypto/tls.(*Conn).readRecordOrCCS(0xc0002e9500, 0x0) /usr/local/go/src/crypto/tls/conn.go:606 +0x112 crypto/tls.(*Conn).readRecord(...) /usr/local/go/src/crypto/tls/conn.go:574 crypto/tls.(*Conn).Read(0xc0002e9500, {0xc000410000, 0x1000, 0x101000000203000}) /usr/local/go/src/crypto/tls/conn.go:1277 +0x16f net/http.(*persistConn).Read(0xc000517c20, {0xc000410000, 0x406e5d, 0x60}) /usr/local/go/src/net/http/transport.go:1926 +0x4e bufio.(*Reader).fill(0xc0005b1200) /usr/local/go/src/bufio/bufio.go:101 +0x103 bufio.(*Reader).Peek(0xc0005b1200, 0x1) /usr/local/go/src/bufio/bufio.go:139 +0x5d net/http.(*persistConn).readLoop(0xc000517c20) /usr/local/go/src/net/http/transport.go:2087 +0x1ac created by net/http.(*Transport).dialConn /usr/local/go/src/net/http/transport.go:1747 +0x1e05 goroutine 2566 [select]: net/http.(*persistConn).writeLoop(0xc000517c20) /usr/local/go/src/net/http/transport.go:2386 +0xfb created by net/http.(*Transport).dialConn /usr/local/go/src/net/http/transport.go:1748 +0x1e65 exit status 2 FAIL github.com/rclone/rclone/backend/filefabric 7200.023s "go test -v -timeout 2h0m0s -remote TestFileFabric: -verbose" - Finished ERROR in 2h0m0.750960157s (try 1/5): exit status 1: Failed []