"./operations.test -test.v -test.timeout 2h0m0s -remote TestFileFabric: -verbose -test.run '^(TestCheckDownload|TestCheckSizeOnly|TestCheckSumDownload|TestParseSumFile)$'" - Starting (try 3/5) 2022/03/15 09:34:50 DEBUG : Creating backend with remote "TestFileFabric:rclone-test-cegomab6nazopop9neyojaj6" 2022/03/15 09:34:50 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2022/03/15 09:34:50 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: checkPathExists(map[path:rclone-test-cegomab6nazopop9neyojaj6 pid:120673762]) options=[] 2022/03/15 09:34:51 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:34:51 DEBUG : Creating backend with remote "/tmp/rclone3373798547" === RUN TestCheckDownload run.go:181: Remote "filefabric root 'rclone-test-cegomab6nazopop9neyojaj6'", Local "Local file system at /tmp/rclone3373798547", Modify Window "1s" 2022/03/15 09:34:51 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': 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/15 09:34:52 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:34:52 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCreateNewFolder(map[fi_name:rclone-test-cegomab6nazopop9neyojaj6 fi_pid:120673762]) options=[] 2022/03/15 09:35:06 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:35:06 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:rutabaga fi_localtime:2011-12-30 12:59:59 fi_modified:2011-12-30 12:59:59 fi_name:rutabaga fi_pid:121409261 fi_size:8 responsetype:json]) options=[] 2022/03/15 09:35:07 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:35:09 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:8 remotetime:2011-12-30 12:59:59 uploadcode:3747198e1b8589cf17f05c4a9abec079]) options=[] 2022/03/15 09:35:14 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:35:14 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:35:23 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= === RUN TestCheckDownload/1 === RUN TestCheckDownload/2 2022/03/15 09:35:38 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:empty space fi_localtime:2011-12-25 12:59:59 fi_modified:2011-12-25 12:59:59 fi_name:empty space fi_pid:121409261 fi_size:1 responsetype:json]) options=[] 2022/03/15 09:35:39 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:35:41 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:1 remotetime:2011-12-25 12:59:59 uploadcode:1383c31fa248cec2346badb1cedffcee]) options=[] 2022/03/15 09:35:46 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:35:46 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:35:56 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= === RUN TestCheckDownload/3 2022/03/15 09:36:00 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:potato2 fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:potato2 fi_pid:121409261 fi_size:60 responsetype:json]) options=[] 2022/03/15 09:36:01 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:36:03 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:60 remotetime:2001-02-03 04:05:06 uploadcode:f874b21630d9b6dc2211e3c42688e649]) options=[] 2022/03/15 09:36:09 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:36:09 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:36:18 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= === RUN TestCheckDownload/4 === RUN TestCheckDownload/5 2022/03/15 09:36:34 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:remotepotato fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:remotepotato fi_pid:121409261 fi_size:60 responsetype:json]) options=[] 2022/03/15 09:36:35 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:36:37 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:60 remotetime:2001-02-03 04:05:06 uploadcode:929c56381d070c5981837f2806f60c86]) options=[] 2022/03/15 09:36:42 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:36:42 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:36:52 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= === RUN TestCheckDownload/6 === RUN TestCheckDownload/7 2022/03/15 09:37:00 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:37:00 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:37:00 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doDeleteFile(map[completedeletion:n fi_id:121409263]) options=[] 2022/03/15 09:37:41 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:37:41 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doDeleteFile(map[completedeletion:n fi_id:121409265]) options=[] 2022/03/15 09:38:26 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:38:26 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doDeleteFile(map[completedeletion:n fi_id:121409267]) options=[] 2022/03/15 09:39:02 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:39:02 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doDeleteFile(map[completedeletion:n fi_id:121409262]) options=[] 2022/03/15 09:39:31 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:39:31 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:39:39 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= --- PASS: TestCheckDownload (288.80s) --- PASS: TestCheckDownload/1 (3.56s) --- PASS: TestCheckDownload/2 (11.65s) --- PASS: TestCheckDownload/3 (3.63s) --- PASS: TestCheckDownload/4 (3.85s) --- PASS: TestCheckDownload/5 (11.98s) --- PASS: TestCheckDownload/6 (3.67s) --- PASS: TestCheckDownload/7 (3.55s) === RUN TestCheckSizeOnly run.go:181: Remote "filefabric root 'rclone-test-cegomab6nazopop9neyojaj6'", Local "Local file system at /tmp/rclone3373798547", Modify Window "1s" 2022/03/15 09:39:39 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:rutabaga fi_localtime:2011-12-30 12:59:59 fi_modified:2011-12-30 12:59:59 fi_name:rutabaga fi_pid:121409261 fi_size:8 responsetype:json]) options=[] 2022/03/15 09:39:41 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:39:42 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:8 remotetime:2011-12-30 12:59:59 uploadcode:d8a30067f5aa91f9425f9d82ac360339]) options=[] 2022/03/15 09:39:48 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:39:48 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:40:01 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= === RUN TestCheckSizeOnly/1 === RUN TestCheckSizeOnly/2 2022/03/15 09:40:02 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:empty space fi_localtime:2011-12-25 12:59:59 fi_modified:2011-12-25 12:59:59 fi_name:empty space fi_pid:121409261 fi_size:1 responsetype:json]) options=[] 2022/03/15 09:40:06 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:40:08 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:1 remotetime:2011-12-25 12:59:59 uploadcode:317078f86c9676c7ea117078582875a9]) options=[] 2022/03/15 09:40:18 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:40:18 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:40:31 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= === RUN TestCheckSizeOnly/3 2022/03/15 09:40:31 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:potato2 fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:potato2 fi_pid:121409261 fi_size:60 responsetype:json]) options=[] 2022/03/15 09:40:36 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:40:38 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:60 remotetime:2001-02-03 04:05:06 uploadcode:49e29af89c5694999245784b517b4165]) options=[] 2022/03/15 09:40:44 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:40:44 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:40:56 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= === RUN TestCheckSizeOnly/4 === RUN TestCheckSizeOnly/5 2022/03/15 09:40:58 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:remotepotato fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:remotepotato fi_pid:121409261 fi_size:60 responsetype:json]) options=[] 2022/03/15 09:41:01 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:41:03 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:60 remotetime:2001-02-03 04:05:06 uploadcode:2c34e9d16821e14bd8f04241c49cda29]) options=[] 2022/03/15 09:41:13 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:41:13 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:41:26 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= === RUN TestCheckSizeOnly/6 === RUN TestCheckSizeOnly/7 2022/03/15 09:41:27 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:41:28 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:41:28 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doDeleteFile(map[completedeletion:n fi_id:121409278]) options=[] 2022/03/15 09:42:04 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:42:04 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doDeleteFile(map[completedeletion:n fi_id:121409280]) options=[] 2022/03/15 09:42:34 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:42:34 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doDeleteFile(map[completedeletion:n fi_id:121409282]) options=[] 2022/03/15 09:43:12 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:43:12 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doDeleteFile(map[completedeletion:n fi_id:121409277]) options=[] 2022/03/15 09:43:43 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:43:43 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:43:59 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= --- PASS: TestCheckSizeOnly (259.48s) --- PASS: TestCheckSizeOnly/1 (0.60s) --- PASS: TestCheckSizeOnly/2 (0.58s) --- PASS: TestCheckSizeOnly/3 (0.61s) --- PASS: TestCheckSizeOnly/4 (0.59s) --- PASS: TestCheckSizeOnly/5 (0.59s) --- PASS: TestCheckSizeOnly/6 (0.58s) --- PASS: TestCheckSizeOnly/7 (0.59s) === RUN TestParseSumFile run.go:181: Remote "filefabric root 'rclone-test-cegomab6nazopop9neyojaj6'", Local "Local file system at /tmp/rclone3373798547", Modify Window "1s" 2022/03/15 09:43:59 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:test.sum fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:test.sum fi_pid:121409261 fi_size:81 responsetype:json]) options=[] 2022/03/15 09:44:04 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:44:05 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:81 remotetime:2001-02-03 04:05:06 uploadcode:f78a5181dcdafc4ea472f7bb0e4931da]) options=[] 2022/03/15 09:44:19 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:44:19 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: checkPathExists(map[path:test.sum pid:121409261]) options=[] 2022/03/15 09:44:19 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:44:19 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFile(map[fi_id:121409286]) options=[] 2022/03/15 09:44:22 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=, err= 2022/03/15 09:44:22 NOTICE: test.sum: improperly formatted checksum line 4 2022/03/15 09:44:22 NOTICE: test.sum: improperly formatted checksum line 5 2022/03/15 09:44:22 NOTICE: test.sum: improperly formatted checksum line 6 2022/03/15 09:44:22 NOTICE: test.sum: 2 warning(s) suppressed... 2022/03/15 09:44:22 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:test.sum fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:test.sum fi_pid:121409261 fi_size:90 responsetype:json]) options=[] 2022/03/15 09:44:24 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:44:25 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:90 remotetime:2001-02-03 04:05:06 uploadcode:bae63d30310fc5d2cdc5fe187908e39c]) options=[] 2022/03/15 09:45:37 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:45:37 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: checkPathExists(map[path:test.sum pid:121409261]) options=[] 2022/03/15 09:45:37 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': Token expired - refreshing 2022/03/15 09:45:37 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getTokenByAuthToken(map[authtoken:622506e6346e7ad6-c48bf9558d23a2ae token:*]) options=[] 2022/03/15 09:45:37 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:45:37 DEBUG : Saving config "token" in section "TestFileFabric" of the config file 2022/03/15 09:45:37 DEBUG : Config file has changed externaly - reloading 2022/03/15 09:45:37 DEBUG : Saving config "token_expiry" in section "TestFileFabric" of the config file 2022/03/15 09:45:37 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getApplianceInfo(map[token:*]) options=[] 2022/03/15 09:45:38 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:45:38 DEBUG : Saving config "version" in section "TestFileFabric" of the config file 2022/03/15 09:45:38 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:45:38 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFile(map[fi_id:121409286]) options=[] 2022/03/15 09:45:41 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=, err= 2022/03/15 09:45:41 NOTICE: test.sum: improperly formatted checksum line 4 2022/03/15 09:45:41 NOTICE: test.sum: improperly formatted checksum line 5 2022/03/15 09:45:41 NOTICE: test.sum: improperly formatted checksum line 6 2022/03/15 09:45:41 NOTICE: test.sum: 2 warning(s) suppressed... 2022/03/15 09:45:41 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:45:54 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:45:54 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doDeleteFile(map[completedeletion:n fi_id:121409286]) options=[] 2022/03/15 09:46:27 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:46:27 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:46:36 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= --- PASS: TestParseSumFile (156.72s) === RUN TestCheckSumDownload run.go:181: Remote "filefabric root 'rclone-test-cegomab6nazopop9neyojaj6'", Local "Local file system at /tmp/rclone3373798547", Modify Window "1s" 2022/03/15 09:46:36 DEBUG : Creating backend with remote "TestFileFabric:rclone-test-cegomab6nazopop9neyojaj6/data" 2022/03/15 09:46:36 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6/data': rpc: checkPathExists(map[path:rclone-test-cegomab6nazopop9neyojaj6/data pid:120673762]) options=[] 2022/03/15 09:46:36 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6/data': >rpc: result=Success (ok), err= 2022/03/15 09:46:36 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:46:37 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:46:37 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCreateNewFolder(map[fi_name:data fi_pid:121409261]) options=[] 2022/03/15 09:46:57 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:46:57 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:banana fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:banana fi_pid:121409292 fi_size:13 responsetype:json]) options=[] 2022/03/15 09:46:59 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:47:00 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:13 remotetime:2001-02-03 04:05:06 uploadcode:5a507cc44d86796ca2dc2effd62fd50a]) options=[] 2022/03/15 09:47:06 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:47:06 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:test.sum fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:test.sum fi_pid:121409261 fi_size:41 responsetype:json]) options=[] 2022/03/15 09:47:07 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:47:09 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:41 remotetime:2001-02-03 04:05:06 uploadcode:0437c12ca17d5da941b298c9d2e248c9]) options=[] 2022/03/15 09:47:19 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:47:19 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:47:31 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:47:31 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409292 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/15 09:47:47 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= === RUN TestCheckSumDownload/subtest1 2022/03/15 09:48:03 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:potato fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:potato fi_pid:121409292 fi_size:15 responsetype:json]) options=[] 2022/03/15 09:48:07 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:48:08 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:15 remotetime:2001-02-03 04:05:06 uploadcode:3e49a8465a3b02db5bd627dc0548060b]) options=[] 2022/03/15 09:48:14 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:48:14 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:test.sum fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:test.sum fi_pid:121409261 fi_size:41 responsetype:json]) options=[] 2022/03/15 09:48:16 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:48:17 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:41 remotetime:2001-02-03 04:05:06 uploadcode:5ba3d5f97fd33d76d3d835803faad1a0]) options=[] 2022/03/15 09:49:54 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:49:54 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:50:10 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:50:10 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409292 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/15 09:50:26 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= === RUN TestCheckSumDownload/subtest2 2022/03/15 09:50:33 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:test.sum fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:test.sum fi_pid:121409261 fi_size:82 responsetype:json]) options=[] 2022/03/15 09:50:36 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:50:38 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:82 remotetime:2001-02-03 04:05:06 uploadcode:0ec35f6896d392ed8d534d254f7a5253]) options=[] 2022/03/15 09:52:08 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:52:08 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:52:23 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:52:23 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409292 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/15 09:52:24 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= === RUN TestCheckSumDownload/subtest3 2022/03/15 09:52:31 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:test.sum fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:test.sum fi_pid:121409261 fi_size:82 responsetype:json]) options=[] 2022/03/15 09:52:32 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:52:34 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:82 remotetime:2001-02-03 04:05:06 uploadcode:1bfb0faa5d4efec563ba6dadb761f367]) options=[] 2022/03/15 09:53:53 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:53:53 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:54:02 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:54:02 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409292 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/15 09:54:02 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= === RUN TestCheckSumDownload/subtest4 2022/03/15 09:54:09 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:test.sum fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:test.sum fi_pid:121409261 fi_size:123 responsetype:json]) options=[] 2022/03/15 09:54:11 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:54:13 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:123 remotetime:2001-02-03 04:05:06 uploadcode:ec8171bcd3e188967503194e9aed7770]) options=[] 2022/03/15 09:55:25 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:55:25 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:55:38 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:55:38 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409292 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/15 09:55:38 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= === RUN TestCheckSumDownload/subtest5 2022/03/15 09:55:45 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:test.sum fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:test.sum fi_pid:121409261 fi_size:123 responsetype:json]) options=[] 2022/03/15 09:55:47 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:55:48 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:123 remotetime:2001-02-03 04:05:06 uploadcode:48004bdd638d224028d033b1f20a6e42]) options=[] 2022/03/15 09:57:09 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:57:09 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 09:57:18 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:57:18 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409292 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/15 09:57:19 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= === RUN TestCheckSumDownload/subtest6 2022/03/15 09:57:26 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:banana fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:banana fi_pid:121409292 fi_size:13 responsetype:json]) options=[] 2022/03/15 09:57:28 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:57:29 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:13 remotetime:2001-02-03 04:05:06 uploadcode:658aeac9750cd70d9aa5e4e369c47e0a]) options=[] 2022/03/15 09:59:07 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:59:07 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:potato fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:potato fi_pid:121409292 fi_size:15 responsetype:json]) options=[] 2022/03/15 09:59:08 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 09:59:10 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:15 remotetime:2001-02-03 04:05:06 uploadcode:263ef7501538ccdd2dbeed3204722cf1]) options=[] 2022/03/15 10:00:18 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 10:00:18 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doInitUpload(map[directuploadsupport:n fi_contenttype:application/octet-stream fi_filename:test.sum fi_localtime:2001-02-03 04:05:06 fi_modified:2001-02-03 04:05:06 fi_name:test.sum fi_pid:121409261 fi_size:82 responsetype:json]) options=[] 2022/03/15 10:00:23 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 10:00:25 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doCompleteUpload(map[fi_size:82 remotetime:2001-02-03 04:05:06 uploadcode:de14785b5538a56760312ac9818ca490]) options=[] 2022/03/15 10:01:44 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 10:01:44 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 10:02:04 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 10:02:04 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409292 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/15 10:02:17 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= === RUN TestCheckSumDownload/subtest7 2022/03/15 10:02:24 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 10:02:24 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 10:02:24 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doDeleteFile(map[completedeletion:n fi_id:121409298]) options=[] 2022/03/15 10:03:02 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 10:03:02 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409292 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/15 10:03:03 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 10:03:03 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doDeleteFile(map[completedeletion:n fi_id:121409297]) options=[] 2022/03/15 10:03:47 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 10:03:47 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doDeleteFile(map[completedeletion:n fi_id:121409300]) options=[] 2022/03/15 10:04:21 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 10:04:21 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409292 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/15 10:04:41 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 10:04:41 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doDeleteFolder(map[fi_id:121409292]) options=[] 2022/03/15 10:04:50 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= 2022/03/15 10:04:50 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: getFolderContents(map[count:1000 fi_pid:121409261 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/15 10:04:51 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= --- PASS: TestCheckSumDownload (1094.93s) --- PASS: TestCheckSumDownload/subtest1 (16.20s) --- PASS: TestCheckSumDownload/subtest2 (7.01s) --- PASS: TestCheckSumDownload/subtest3 (7.02s) --- PASS: TestCheckSumDownload/subtest4 (6.96s) --- PASS: TestCheckSumDownload/subtest5 (6.92s) --- PASS: TestCheckSumDownload/subtest6 (7.07s) --- PASS: TestCheckSumDownload/subtest7 (7.02s) PASS 2022/03/15 10:04:51 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': Purge remote 2022/03/15 10:04:51 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': rpc: doDeleteFolder(map[fi_id:121409261]) options=[] 2022/03/15 10:04:51 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': Sleeping for 1s to wait for "error_background" error to clear 2022/03/15 10:04:52 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/15 10:04:52 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2022/03/15 10:04:53 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': Sleeping for 2s to wait for "error_background" error to clear 2022/03/15 10:04:55 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/15 10:04:55 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2022/03/15 10:04:55 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': Sleeping for 4s to wait for "error_background" error to clear 2022/03/15 10:04:59 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/15 10:04:59 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2022/03/15 10:05:00 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': Sleeping for 8s to wait for "error_background" error to clear 2022/03/15 10:05:08 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/15 10:05:08 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2022/03/15 10:05:09 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': Sleeping for 16s to wait for "error_background" error to clear 2022/03/15 10:05:25 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/15 10:05:25 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2022/03/15 10:05:27 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': Sleeping for 32s to wait for "error_background" error to clear 2022/03/15 10:05:59 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/15 10:05:59 DEBUG : pacer: Rate limited, increasing sleep to 1.28s 2022/03/15 10:06:00 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': Sleeping for 1m4s to wait for "error_background" error to clear 2022/03/15 10:07:04 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/15 10:07:04 DEBUG : pacer: Rate limited, increasing sleep to 2.56s 2022/03/15 10:07:24 DEBUG : pacer: Reducing sleep to 1.92s 2022/03/15 10:07:24 DEBUG : filefabric root 'rclone-test-cegomab6nazopop9neyojaj6': >rpc: result=Success (ok), err= "./operations.test -test.v -test.timeout 2h0m0s -remote TestFileFabric: -verbose -test.run '^(TestCheckDownload|TestCheckSizeOnly|TestCheckSumDownload|TestParseSumFile)$'" - Finished OK in 32m33.407858245s (try 3/5)