"./bisync.test -test.v -test.timeout 1h0m0s -remote TestUlozto: -verbose" - Starting (try 4/5) 2025/09/17 06:13:25 DEBUG : Creating backend with remote "TestUlozto:rclone-test-hawiqal7huru" 2025/09/17 06:13:25 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/09/17 06:13:27 DEBUG : Creating backend with remote "/tmp/rclone124268924" === RUN TestBisyncRemoteLocal 2025/09/17 06:13:27 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu" 2025/09/17 06:13:30 NOTICE: remote: TestUlozto:rclone-test-bexobab3hohu === RUN TestBisyncRemoteLocal/all_changed 2025/09/17 06:13:30 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba" 2025/09/17 06:13:32 INFO : path1: Making directory 2025/09/17 06:13:34 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1" 2025/09/17 06:13:37 DEBUG : Creating backend with remote "/tmp/061330ba" 2025/09/17 06:13:37 DEBUG : Creating backend with remote "/tmp/061330ba/all_changed/path2" 2025/09/17 06:13:37 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_all_changed/initial" 2025/09/17 06:13:37 DEBUG : Creating backend with remote "/tmp/061330ba/initdir/test_all_changed-sevuraq2" 2025/09/17 06:13:37 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 06:13:37 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:37 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:37 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:37 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:37 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:37 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:37 DEBUG : subdir: Making directory with metadata 2025/09/17 06:13:37 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/17 06:13:37 DEBUG : Added delayed dir = "subdir", newDst=subdir 2025/09/17 06:13:37 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:37 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 06:13:37 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:37 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:37 DEBUG : Local file system at /tmp/061330ba/initdir/test_all_changed-sevuraq2: Waiting for checks to finish 2025/09/17 06:13:37 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2025/09/17 06:13:37 INFO : RCLONE_TEST: Copied (new) 2025/09/17 06:13:37 DEBUG : Local file system at /tmp/061330ba/initdir/test_all_changed-sevuraq2: Waiting for transfers to finish 2025/09/17 06:13:37 DEBUG : file1.copy1.txt.21b8fa2b.partial: renamed to: file1.copy1.txt 2025/09/17 06:13:37 INFO : file1.copy1.txt: Copied (new) 2025/09/17 06:13:37 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:37 DEBUG : file1.copy3.txt.d0285540.partial: renamed to: file1.copy3.txt 2025/09/17 06:13:37 INFO : file1.copy3.txt: Copied (new) 2025/09/17 06:13:37 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:37 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:37 DEBUG : file1.copy2.txt.455881d5.partial: renamed to: file1.copy2.txt 2025/09/17 06:13:37 INFO : file1.copy2.txt: Copied (new) 2025/09/17 06:13:37 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2025/09/17 06:13:37 INFO : file1.txt: Copied (new) 2025/09/17 06:13:37 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:37 DEBUG : file1.copy4.txt.8c987629.partial: renamed to: file1.copy4.txt 2025/09/17 06:13:37 INFO : file1.copy4.txt: Copied (new) 2025/09/17 06:13:37 DEBUG : file1.copy5.txt.19e8a2bc.partial: renamed to: file1.copy5.txt 2025/09/17 06:13:37 INFO : file1.copy5.txt: Copied (new) 2025/09/17 06:13:37 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:37 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2025/09/17 06:13:37 INFO : subdir/file20.txt: Copied (new) 2025/09/17 06:13:37 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 06:13:37 DEBUG : Waiting for deletions to finish 2025/09/17 06:13:37 ERROR : error listing: directory not found 2025/09/17 06:13:37 ERROR : uloz.to root 'rclone-test-bexobab3hohu/061330ba/all_changed/path1': Failed to list "": directory not found 2025/09/17 06:13:37 DEBUG : removing 1 level 0 directories 2025/09/17 06:13:37 INFO : uloz.to root 'rclone-test-bexobab3hohu/061330ba/all_changed/path1': Removing directory 2025/09/17 06:13:37 ERROR : Failed to rmdir: directory not found 2025/09/17 06:13:37 DEBUG : Waiting for deletions to finish 2025/09/17 06:13:37 ERROR : error listing: directory not found 2025/09/17 06:13:37 ERROR : Local file system at /tmp/061330ba/all_changed/path2: Failed to list "": directory not found 2025/09/17 06:13:37 DEBUG : removing 1 level 0 directories 2025/09/17 06:13:37 INFO : Local file system at /tmp/061330ba/all_changed/path2: Removing directory 2025/09/17 06:13:37 ERROR : Failed to rmdir: stat /tmp/061330ba/all_changed/path2: no such file or directory 2025/09/17 06:13:38 ERROR : error listing: directory not found 2025/09/17 06:13:38 ERROR : error listing: directory not found 2025/09/17 06:13:38 NOTICE: checking initFs Local file system at /tmp/061330ba/initdir/test_all_changed-sevuraq2 2025/09/17 06:13:38 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 06:13:38 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:38 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:38 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:38 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:38 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:38 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:38 INFO : subdir: Making directory 2025/09/17 06:13:39 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:39 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/all_changed/path1': Waiting for checks to finish 2025/09/17 06:13:39 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/all_changed/path1': Waiting for transfers to finish 2025/09/17 06:13:41 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:41 INFO : file1.copy1.txt: Copied (new) 2025/09/17 06:13:41 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:41 INFO : file1.copy2.txt: Copied (new) 2025/09/17 06:13:42 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:42 INFO : file1.copy3.txt: Copied (new) 2025/09/17 06:13:42 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 06:13:42 INFO : RCLONE_TEST: Copied (new) 2025/09/17 06:13:42 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:42 INFO : file1.copy5.txt: Copied (new) 2025/09/17 06:13:43 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:43 INFO : file1.txt: Copied (new) 2025/09/17 06:13:43 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:43 INFO : subdir/file20.txt: Copied (new) 2025/09/17 06:13:43 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:43 INFO : file1.copy4.txt: Copied (new) 2025/09/17 06:13:43 NOTICE: checking Path1 uloz.to root 'rclone-test-bexobab3hohu/061330ba/all_changed/path1' 2025/09/17 06:13:44 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 06:13:44 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:44 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:44 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:44 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:44 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:44 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:44 DEBUG : subdir: Making directory with metadata 2025/09/17 06:13:44 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:44 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/17 06:13:44 DEBUG : Added delayed dir = "subdir", newDst=subdir 2025/09/17 06:13:44 DEBUG : file1.copy1.txt.21b8fa2b.partial: renamed to: file1.copy1.txt 2025/09/17 06:13:44 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:44 INFO : file1.copy1.txt: Copied (new) 2025/09/17 06:13:44 DEBUG : file1.copy2.txt.455881d5.partial: renamed to: file1.copy2.txt 2025/09/17 06:13:44 INFO : file1.copy2.txt: Copied (new) 2025/09/17 06:13:44 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/09/17 06:13:44 DEBUG : Local file system at /tmp/061330ba/all_changed/path2: Waiting for checks to finish 2025/09/17 06:13:44 DEBUG : Local file system at /tmp/061330ba/all_changed/path2: Waiting for transfers to finish 2025/09/17 06:13:44 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:44 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:44 DEBUG : file1.copy3.txt.d0285540.partial: renamed to: file1.copy3.txt 2025/09/17 06:13:44 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:44 DEBUG : file1.copy4.txt.8c987629.partial: renamed to: file1.copy4.txt 2025/09/17 06:13:44 INFO : file1.copy4.txt: Copied (new) 2025/09/17 06:13:44 DEBUG : file1.copy5.txt.19e8a2bc.partial: renamed to: file1.copy5.txt 2025/09/17 06:13:44 INFO : file1.copy5.txt: Copied (new) 2025/09/17 06:13:44 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 06:13:44 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2025/09/17 06:13:44 INFO : RCLONE_TEST: Copied (new) 2025/09/17 06:13:44 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:44 INFO : file1.copy3.txt: Copied (new) 2025/09/17 06:13:44 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2025/09/17 06:13:44 INFO : file1.txt: Copied (new) 2025/09/17 06:13:44 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:13:44 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2025/09/17 06:13:44 INFO : subdir/file20.txt: Copied (new) 2025/09/17 06:13:44 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 06:13:44 NOTICE: checking path2 Local file system at /tmp/061330ba/all_changed/path2 2025/09/17 06:13:44 NOTICE: (01) : test all-changed 2025/09/17 06:13:44 NOTICE: (02) : test initial bisync 2025/09/17 06:13:44 NOTICE: (03) : bisync resync 2025/09/17 06:13:47 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/all_changed/path1': Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/17 06:13:47 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 06:13:47 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/17 06:13:47 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/09/17 06:13:47 INFO : Synching Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1/" with Path2 "/tmp/061330ba/all_changed/path2/" 2025/09/17 06:13:47 INFO : Copying Path2 files to Path1 2025/09/17 06:13:47 INFO : - Path2 Resync is copying files to - Path1 2025/09/17 06:13:47 INFO : There was nothing to transfer 2025/09/17 06:13:47 INFO : - Path1 Resync is copying files to - Path2 2025/09/17 06:13:48 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 06:13:48 INFO : There was nothing to transfer 2025/09/17 06:13:48 INFO : Resync updating listings 2025/09/17 06:13:48 INFO : Validating listings for Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1/" vs Path2 "/tmp/061330ba/all_changed/path2/" 2025/09/17 06:13:48 INFO : Bisync successful 2025/09/17 06:13:48 NOTICE: (04) : test change timestamp on all files except RCLONE_TEST 2025/09/17 06:13:48 NOTICE: (05) : touch-glob 2005-01-02 TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1/ file* 2025/09/17 06:13:48 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1/" 2025/09/17 06:13:51 DEBUG : fs cache: renaming cache item "TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1/" to be canonical "TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1" 2025/09/17 06:13:51 DEBUG : file1.copy1.txt: Set modification time 2005-01-02 2025/09/17 06:13:51 DEBUG : file1.copy2.txt: Set modification time 2005-01-02 2025/09/17 06:13:51 DEBUG : file1.copy3.txt: Set modification time 2005-01-02 2025/09/17 06:13:51 DEBUG : file1.copy4.txt: Set modification time 2005-01-02 2025/09/17 06:13:51 DEBUG : file1.copy5.txt: Set modification time 2005-01-02 2025/09/17 06:13:52 DEBUG : file1.txt: Set modification time 2005-01-02 2025/09/17 06:13:52 NOTICE: (06) : touch-glob 2005-01-02 TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1/subdir file* 2025/09/17 06:13:52 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1/subdir" 2025/09/17 06:13:55 DEBUG : file20.txt: Set modification time 2005-01-02 2025/09/17 06:13:55 NOTICE: (07) : test sync should pass 2025/09/17 06:13:55 NOTICE: (08) : bisync 2025/09/17 06:13:58 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/all_changed/path1': Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/17 06:13:58 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 06:13:58 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/17 06:13:58 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/09/17 06:13:58 INFO : Synching Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1/" with Path2 "/tmp/061330ba/all_changed/path2/" 2025/09/17 06:13:58 INFO : Building Path1 and Path2 listings 2025/09/17 06:13:59 INFO : Path1 checking for diffs 2025/09/17 06:13:59 INFO : - Path1 File changed: time (newer) - file1.copy1.txt 2025/09/17 06:13:59 INFO : - Path1 File changed: time (newer) - file1.copy2.txt 2025/09/17 06:13:59 INFO : - Path1 File changed: time (newer) - file1.copy3.txt 2025/09/17 06:13:59 INFO : - Path1 File changed: time (newer) - file1.copy4.txt 2025/09/17 06:13:59 INFO : - Path1 File changed: time (newer) - file1.copy5.txt 2025/09/17 06:13:59 INFO : - Path1 File changed: time (newer) - file1.txt 2025/09/17 06:13:59 INFO : - Path1 File changed: time (newer) - subdir/file20.txt 2025/09/17 06:13:59 INFO : Path1: 7 changes:  0 new,  7 modified,  0 deleted 2025/09/17 06:13:59 INFO : (Modified:  7 newer,  0 older) 2025/09/17 06:13:59 INFO : Path2 checking for diffs 2025/09/17 06:13:59 INFO : Applying changes 2025/09/17 06:13:59 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/all_changed/path2/file1.copy1.txt 2025/09/17 06:13:59 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/all_changed/path2/file1.copy2.txt 2025/09/17 06:13:59 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/all_changed/path2/file1.copy3.txt 2025/09/17 06:13:59 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/all_changed/path2/file1.copy4.txt 2025/09/17 06:13:59 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/all_changed/path2/file1.copy5.txt 2025/09/17 06:13:59 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/all_changed/path2/file1.txt 2025/09/17 06:13:59 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/all_changed/path2/subdir/file20.txt 2025/09/17 06:13:59 INFO : - Path1 Do queued copies to - Path2 2025/09/17 06:13:59 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 06:13:59 INFO : file1.copy1.txt: Updated modification time in destination 2025/09/17 06:13:59 INFO : file1.copy2.txt: Updated modification time in destination 2025/09/17 06:13:59 INFO : file1.copy3.txt: Updated modification time in destination 2025/09/17 06:13:59 INFO : file1.copy4.txt: Updated modification time in destination 2025/09/17 06:13:59 INFO : file1.copy5.txt: Updated modification time in destination 2025/09/17 06:13:59 INFO : file1.txt: Updated modification time in destination 2025/09/17 06:13:59 INFO : subdir/file20.txt: Updated modification time in destination 2025/09/17 06:13:59 INFO : There was nothing to transfer 2025/09/17 06:13:59 INFO : Updating listings 2025/09/17 06:13:59 INFO : Validating listings for Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1/" vs Path2 "/tmp/061330ba/all_changed/path2/" 2025/09/17 06:13:59 INFO : Bisync successful 2025/09/17 06:13:59 NOTICE: (09) : test change timestamp on all files including RCLONE_TEST 2025/09/17 06:13:59 NOTICE: (10) : touch-glob 2004-01-02 TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1/ * 2025/09/17 06:13:59 DEBUG : fs cache: switching user supplied name "TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1/" for canonical name "TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1" 2025/09/17 06:13:59 DEBUG : file1.copy1.txt: Set modification time 2004-01-02 2025/09/17 06:14:00 DEBUG : file1.copy2.txt: Set modification time 2004-01-02 2025/09/17 06:14:00 DEBUG : file1.copy3.txt: Set modification time 2004-01-02 2025/09/17 06:14:00 DEBUG : file1.copy4.txt: Set modification time 2004-01-02 2025/09/17 06:14:00 DEBUG : file1.copy5.txt: Set modification time 2004-01-02 2025/09/17 06:14:00 DEBUG : file1.txt: Set modification time 2004-01-02 2025/09/17 06:14:00 DEBUG : RCLONE_TEST: Set modification time 2004-01-02 2025/09/17 06:14:00 NOTICE: (11) : touch-glob 2004-01-02 TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1/subdir * 2025/09/17 06:14:01 DEBUG : file20.txt: Set modification time 2004-01-02 2025/09/17 06:14:01 NOTICE: (12) : test sync should fail 2025/09/17 06:14:01 NOTICE: (13) : bisync 2025/09/17 06:14:04 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/all_changed/path1': Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/17 06:14:04 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 06:14:04 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/17 06:14:04 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/09/17 06:14:04 INFO : Synching Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1/" with Path2 "/tmp/061330ba/all_changed/path2/" 2025/09/17 06:14:04 INFO : Building Path1 and Path2 listings 2025/09/17 06:14:04 INFO : Path1 checking for diffs 2025/09/17 06:14:04 INFO : - Path1 File changed: time (newer) - RCLONE_TEST 2025/09/17 06:14:04 INFO : - Path1 File changed: time (older) - file1.copy1.txt 2025/09/17 06:14:04 INFO : - Path1 File changed: time (older) - file1.copy2.txt 2025/09/17 06:14:04 INFO : - Path1 File changed: time (older) - file1.copy3.txt 2025/09/17 06:14:04 INFO : - Path1 File changed: time (older) - file1.copy4.txt 2025/09/17 06:14:04 INFO : - Path1 File changed: time (older) - file1.copy5.txt 2025/09/17 06:14:04 INFO : - Path1 File changed: time (older) - file1.txt 2025/09/17 06:14:04 INFO : - Path1 File changed: time (older) - subdir/file20.txt 2025/09/17 06:14:04 INFO : Path1: 8 changes:  0 new,  8 modified,  0 deleted 2025/09/17 06:14:04 INFO : (Modified:  1 newer,  7 older) 2025/09/17 06:14:04 INFO : Path2 checking for diffs 2025/09/17 06:14:04 ERROR : Safety abort: all files were changed on Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1/". Run with --force if desired. 2025/09/17 06:14:04 NOTICE: Bisync aborted. Please try again. 2025/09/17 06:14:04 NOTICE: Bisync error: all files were changed 2025/09/17 06:14:04 NOTICE: (14) : test sync with force should pass 2025/09/17 06:14:04 NOTICE: (15) : bisync force 2025/09/17 06:14:08 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/all_changed/path1': Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/17 06:14:08 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 06:14:08 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/17 06:14:08 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/09/17 06:14:08 INFO : Synching Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1/" with Path2 "/tmp/061330ba/all_changed/path2/" 2025/09/17 06:14:08 INFO : Building Path1 and Path2 listings 2025/09/17 06:14:08 INFO : Path1 checking for diffs 2025/09/17 06:14:08 INFO : - Path1 File changed: time (newer) - RCLONE_TEST 2025/09/17 06:14:08 INFO : - Path1 File changed: time (older) - file1.copy1.txt 2025/09/17 06:14:08 INFO : - Path1 File changed: time (older) - file1.copy2.txt 2025/09/17 06:14:08 INFO : - Path1 File changed: time (older) - file1.copy3.txt 2025/09/17 06:14:08 INFO : - Path1 File changed: time (older) - file1.copy4.txt 2025/09/17 06:14:08 INFO : - Path1 File changed: time (older) - file1.copy5.txt 2025/09/17 06:14:08 INFO : - Path1 File changed: time (older) - file1.txt 2025/09/17 06:14:08 INFO : - Path1 File changed: time (older) - subdir/file20.txt 2025/09/17 06:14:08 INFO : Path1: 8 changes:  0 new,  8 modified,  0 deleted 2025/09/17 06:14:08 INFO : (Modified:  1 newer,  7 older) 2025/09/17 06:14:08 INFO : Path2 checking for diffs 2025/09/17 06:14:08 INFO : Applying changes 2025/09/17 06:14:08 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/all_changed/path2/RCLONE_TEST 2025/09/17 06:14:08 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/all_changed/path2/file1.copy1.txt 2025/09/17 06:14:08 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/all_changed/path2/file1.copy2.txt 2025/09/17 06:14:08 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/all_changed/path2/file1.copy3.txt 2025/09/17 06:14:08 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/all_changed/path2/file1.copy4.txt 2025/09/17 06:14:08 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/all_changed/path2/file1.copy5.txt 2025/09/17 06:14:08 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/all_changed/path2/file1.txt 2025/09/17 06:14:08 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/all_changed/path2/subdir/file20.txt 2025/09/17 06:14:08 INFO : - Path1 Do queued copies to - Path2 2025/09/17 06:14:08 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 06:14:08 INFO : file1.copy2.txt: Updated modification time in destination 2025/09/17 06:14:08 INFO : file1.copy1.txt: Updated modification time in destination 2025/09/17 06:14:08 INFO : file1.copy3.txt: Updated modification time in destination 2025/09/17 06:14:08 INFO : file1.copy5.txt: Updated modification time in destination 2025/09/17 06:14:08 INFO : file1.txt: Updated modification time in destination 2025/09/17 06:14:08 INFO : file1.copy4.txt: Updated modification time in destination 2025/09/17 06:14:08 INFO : RCLONE_TEST: Updated modification time in destination 2025/09/17 06:14:09 INFO : subdir/file20.txt: Updated modification time in destination 2025/09/17 06:14:09 INFO : There was nothing to transfer 2025/09/17 06:14:09 INFO : Updating listings 2025/09/17 06:14:09 INFO : Validating listings for Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/all_changed/path1/" vs Path2 "/tmp/061330ba/all_changed/path2/" 2025/09/17 06:14:09 INFO : Bisync successful 2025/09/17 06:14:09 DEBUG : Waiting for deletions to finish 2025/09/17 06:14:09 INFO : file1.copy2.txt: Deleted 2025/09/17 06:14:09 INFO : file1.copy1.txt: Deleted 2025/09/17 06:14:09 INFO : RCLONE_TEST: Deleted 2025/09/17 06:14:09 INFO : file1.copy3.txt: Deleted 2025/09/17 06:14:09 INFO : file1.txt: Deleted 2025/09/17 06:14:09 INFO : file1.copy5.txt: Deleted 2025/09/17 06:14:09 INFO : file1.copy4.txt: Deleted 2025/09/17 06:14:09 INFO : subdir/file20.txt: Deleted 2025/09/17 06:14:10 DEBUG : removing 1 level 1 directories 2025/09/17 06:14:10 INFO : subdir: Removing directory 2025/09/17 06:14:10 DEBUG : removing 1 level 0 directories 2025/09/17 06:14:10 INFO : uloz.to root 'rclone-test-bexobab3hohu/061330ba/all_changed/path1': Removing directory 2025/09/17 06:14:11 DEBUG : Waiting for deletions to finish 2025/09/17 06:14:11 INFO : file1.copy4.txt: Deleted 2025/09/17 06:14:11 INFO : file1.copy3.txt: Deleted 2025/09/17 06:14:11 INFO : file1.copy5.txt: Deleted 2025/09/17 06:14:11 INFO : file1.copy1.txt: Deleted 2025/09/17 06:14:11 INFO : file1.copy2.txt: Deleted 2025/09/17 06:14:11 INFO : file1.txt: Deleted 2025/09/17 06:14:11 INFO : RCLONE_TEST: Deleted 2025/09/17 06:14:11 INFO : subdir/file20.txt: Deleted 2025/09/17 06:14:11 DEBUG : removing 1 level 1 directories 2025/09/17 06:14:11 INFO : subdir: Removing directory 2025/09/17 06:14:11 DEBUG : removing 1 level 0 directories 2025/09/17 06:14:11 INFO : Local file system at /tmp/061330ba/all_changed/path2: Removing directory bisync_test.go:608: TEST all_changed PASSED === RUN TestBisyncRemoteLocal/backupdir 2025/09/17 06:14:11 INFO : path1: Making directory 2025/09/17 06:14:11 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba/backupdir/path1" 2025/09/17 06:14:13 DEBUG : Creating backend with remote "/tmp/061330ba/backupdir/path2" 2025/09/17 06:14:13 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_backupdir/initial" 2025/09/17 06:14:13 DEBUG : Creating backend with remote "/tmp/061330ba/initdir/test_backupdir-qolihef2" 2025/09/17 06:14:13 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : file3.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : file4.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : file5.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : file6.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : file7.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : file8.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:13 DEBUG : Local file system at /tmp/061330ba/initdir/test_backupdir-qolihef2: Waiting for checks to finish 2025/09/17 06:14:13 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 06:14:13 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2025/09/17 06:14:13 DEBUG : Local file system at /tmp/061330ba/initdir/test_backupdir-qolihef2: Waiting for transfers to finish 2025/09/17 06:14:13 INFO : file2.txt: Copied (new) 2025/09/17 06:14:13 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:13 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2025/09/17 06:14:13 INFO : RCLONE_TEST: Copied (new) 2025/09/17 06:14:13 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2025/09/17 06:14:13 INFO : file3.txt: Copied (new) 2025/09/17 06:14:13 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:13 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:13 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:13 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2025/09/17 06:14:13 INFO : file1.txt: Copied (new) 2025/09/17 06:14:13 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2025/09/17 06:14:13 INFO : file4.txt: Copied (new) 2025/09/17 06:14:13 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:13 DEBUG : file5.txt.6e808e0e.partial: renamed to: file5.txt 2025/09/17 06:14:13 INFO : file5.txt: Copied (new) 2025/09/17 06:14:13 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:13 DEBUG : file6.txt.0a60f5f0.partial: renamed to: file6.txt 2025/09/17 06:14:13 INFO : file6.txt: Copied (new) 2025/09/17 06:14:13 DEBUG : file7.txt.9f102165.partial: renamed to: file7.txt 2025/09/17 06:14:13 INFO : file7.txt: Copied (new) 2025/09/17 06:14:13 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:13 DEBUG : file8.txt.b300b322.partial: renamed to: file8.txt 2025/09/17 06:14:13 INFO : file8.txt: Copied (new) 2025/09/17 06:14:13 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_backupdir/modfiles" 2025/09/17 06:14:13 DEBUG : Creating backend with remote "/tmp/061330ba/datadir/test_backupdir-fepetoh0" 2025/09/17 06:14:13 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : file10.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : file11.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : file5L.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : file5R.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : file6.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : file7.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:13 DEBUG : Local file system at /tmp/061330ba/datadir/test_backupdir-fepetoh0: Waiting for checks to finish 2025/09/17 06:14:13 DEBUG : Local file system at /tmp/061330ba/datadir/test_backupdir-fepetoh0: Waiting for transfers to finish 2025/09/17 06:14:13 DEBUG : file2.txt: md5 = fb3ecfb2800400fb01b0bfd39903e9fb OK 2025/09/17 06:14:13 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:14:13 DEBUG : file11.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:14:13 DEBUG : file2.txt.4526d70e.partial: renamed to: file2.txt 2025/09/17 06:14:13 INFO : file2.txt: Copied (new) 2025/09/17 06:14:13 DEBUG : file1.txt.75b77f44.partial: renamed to: file1.txt 2025/09/17 06:14:13 INFO : file1.txt: Copied (new) 2025/09/17 06:14:13 DEBUG : file10.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:14:13 DEBUG : file11.txt.40d797d4.partial: renamed to: file11.txt 2025/09/17 06:14:13 INFO : file11.txt: Copied (new) 2025/09/17 06:14:13 DEBUG : file10.txt.c02780cb.partial: renamed to: file10.txt 2025/09/17 06:14:13 INFO : file10.txt: Copied (new) 2025/09/17 06:14:13 DEBUG : file5R.txt: md5 = 979a803b15d27df0c31ad7d29006d10b OK 2025/09/17 06:14:13 DEBUG : file5R.txt.ee3b9525.partial: renamed to: file5R.txt 2025/09/17 06:14:13 INFO : file5R.txt: Copied (new) 2025/09/17 06:14:13 DEBUG : file6.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:14:13 DEBUG : file5L.txt: md5 = 0860a03592626642f8fd6c8bfb447d2a OK 2025/09/17 06:14:13 DEBUG : file6.txt.4185169b.partial: renamed to: file6.txt 2025/09/17 06:14:13 INFO : file6.txt: Copied (new) 2025/09/17 06:14:13 DEBUG : file5L.txt.8dd6541a.partial: renamed to: file5L.txt 2025/09/17 06:14:13 INFO : file5L.txt: Copied (new) 2025/09/17 06:14:13 DEBUG : file7.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:14:13 DEBUG : file7.txt.c1750184.partial: renamed to: file7.txt 2025/09/17 06:14:13 INFO : file7.txt: Copied (new) 2025/09/17 06:14:13 DEBUG : Waiting for deletions to finish 2025/09/17 06:14:14 ERROR : error listing: directory not found 2025/09/17 06:14:14 ERROR : uloz.to root 'rclone-test-bexobab3hohu/061330ba/backupdir/path1': Failed to list "": directory not found 2025/09/17 06:14:14 DEBUG : removing 1 level 0 directories 2025/09/17 06:14:14 INFO : uloz.to root 'rclone-test-bexobab3hohu/061330ba/backupdir/path1': Removing directory 2025/09/17 06:14:14 ERROR : Failed to rmdir: directory not found 2025/09/17 06:14:14 DEBUG : Waiting for deletions to finish 2025/09/17 06:14:14 ERROR : error listing: directory not found 2025/09/17 06:14:14 ERROR : Local file system at /tmp/061330ba/backupdir/path2: Failed to list "": directory not found 2025/09/17 06:14:14 DEBUG : removing 1 level 0 directories 2025/09/17 06:14:14 INFO : Local file system at /tmp/061330ba/backupdir/path2: Removing directory 2025/09/17 06:14:14 ERROR : Failed to rmdir: stat /tmp/061330ba/backupdir/path2: no such file or directory 2025/09/17 06:14:14 ERROR : error listing: directory not found 2025/09/17 06:14:14 ERROR : error listing: directory not found 2025/09/17 06:14:14 NOTICE: checking initFs Local file system at /tmp/061330ba/initdir/test_backupdir-qolihef2 2025/09/17 06:14:14 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 06:14:14 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:14 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:14 DEBUG : file3.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:14 DEBUG : file4.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:14 DEBUG : file5.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:14 DEBUG : file6.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:14 DEBUG : file7.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:14 DEBUG : file8.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:14 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/backupdir/path1': Waiting for checks to finish 2025/09/17 06:14:14 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/backupdir/path1': Waiting for transfers to finish 2025/09/17 06:14:17 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:17 INFO : file2.txt: Copied (new) 2025/09/17 06:14:17 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 06:14:17 INFO : RCLONE_TEST: Copied (new) 2025/09/17 06:14:17 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:17 INFO : file1.txt: Copied (new) 2025/09/17 06:14:17 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:17 INFO : file3.txt: Copied (new) 2025/09/17 06:14:18 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:18 INFO : file6.txt: Copied (new) 2025/09/17 06:14:18 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:18 INFO : file5.txt: Copied (new) 2025/09/17 06:14:18 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:18 INFO : file4.txt: Copied (new) 2025/09/17 06:14:18 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:18 INFO : file7.txt: Copied (new) 2025/09/17 06:14:19 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:19 INFO : file8.txt: Copied (new) 2025/09/17 06:14:19 NOTICE: checking Path1 uloz.to root 'rclone-test-bexobab3hohu/061330ba/backupdir/path1' 2025/09/17 06:14:19 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 06:14:19 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:19 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:19 DEBUG : file3.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:19 DEBUG : file4.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:19 DEBUG : file5.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:19 DEBUG : file6.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:19 DEBUG : file7.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:19 DEBUG : file8.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:19 DEBUG : Local file system at /tmp/061330ba/backupdir/path2: Waiting for checks to finish 2025/09/17 06:14:19 DEBUG : Local file system at /tmp/061330ba/backupdir/path2: Waiting for transfers to finish 2025/09/17 06:14:19 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:19 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:19 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2025/09/17 06:14:19 INFO : file2.txt: Copied (new) 2025/09/17 06:14:19 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2025/09/17 06:14:19 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:19 INFO : file3.txt: Copied (new) 2025/09/17 06:14:19 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2025/09/17 06:14:19 INFO : file1.txt: Copied (new) 2025/09/17 06:14:19 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:19 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2025/09/17 06:14:19 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:19 INFO : file4.txt: Copied (new) 2025/09/17 06:14:19 DEBUG : file5.txt.6e808e0e.partial: renamed to: file5.txt 2025/09/17 06:14:19 INFO : file5.txt: Copied (new) 2025/09/17 06:14:19 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:19 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:19 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:19 DEBUG : file6.txt.0a60f5f0.partial: renamed to: file6.txt 2025/09/17 06:14:19 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 06:14:19 INFO : file6.txt: Copied (new) 2025/09/17 06:14:19 DEBUG : file8.txt.b300b322.partial: renamed to: file8.txt 2025/09/17 06:14:19 INFO : file8.txt: Copied (new) 2025/09/17 06:14:19 DEBUG : file7.txt.9f102165.partial: renamed to: file7.txt 2025/09/17 06:14:19 INFO : file7.txt: Copied (new) 2025/09/17 06:14:19 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2025/09/17 06:14:19 INFO : RCLONE_TEST: Copied (new) 2025/09/17 06:14:19 NOTICE: checking path2 Local file system at /tmp/061330ba/backupdir/path2 2025/09/17 06:14:19 NOTICE: (01) : test backupdir 2025/09/17 06:14:19 NOTICE: (02) : test initial bisync 2025/09/17 06:14:19 NOTICE: (03) : bisync resync backupdir1=/tmp/061330ba/workdir/backupdirs/backupdir1 backupdir2=/tmp/061330ba/workdir/backupdirs/backupdir2 bisync_test.go:975: backupdir test currently only works on local (it uses the workdir) === RUN TestBisyncRemoteLocal/basic 2025/09/17 06:14:19 INFO : path1: Making directory 2025/09/17 06:14:19 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba/basic/path1" 2025/09/17 06:14:22 DEBUG : Creating backend with remote "/tmp/061330ba/basic/path2" 2025/09/17 06:14:22 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_basic/initial" 2025/09/17 06:14:22 DEBUG : Creating backend with remote "/tmp/061330ba/initdir/test_basic-cazeqod5" 2025/09/17 06:14:22 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 06:14:22 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:22 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:22 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:22 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:22 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:22 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:22 DEBUG : subdir: Making directory with metadata 2025/09/17 06:14:22 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/17 06:14:22 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:22 DEBUG : Added delayed dir = "subdir", newDst=subdir 2025/09/17 06:14:22 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:22 DEBUG : file1.copy2.txt.455881d5.partial: renamed to: file1.copy2.txt 2025/09/17 06:14:22 DEBUG : file1.copy1.txt.21b8fa2b.partial: renamed to: file1.copy1.txt 2025/09/17 06:14:22 INFO : file1.copy1.txt: Copied (new) 2025/09/17 06:14:22 INFO : file1.copy2.txt: Copied (new) 2025/09/17 06:14:22 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:22 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 06:14:22 DEBUG : file1.copy3.txt.d0285540.partial: renamed to: file1.copy3.txt 2025/09/17 06:14:22 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:22 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2025/09/17 06:14:22 INFO : file1.copy3.txt: Copied (new) 2025/09/17 06:14:22 INFO : RCLONE_TEST: Copied (new) 2025/09/17 06:14:22 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:22 DEBUG : file1.copy4.txt.8c987629.partial: renamed to: file1.copy4.txt 2025/09/17 06:14:22 INFO : file1.copy4.txt: Copied (new) 2025/09/17 06:14:22 DEBUG : Local file system at /tmp/061330ba/initdir/test_basic-cazeqod5: Waiting for checks to finish 2025/09/17 06:14:22 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:22 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:22 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:22 DEBUG : Local file system at /tmp/061330ba/initdir/test_basic-cazeqod5: Waiting for transfers to finish 2025/09/17 06:14:22 DEBUG : file1.copy5.txt.19e8a2bc.partial: renamed to: file1.copy5.txt 2025/09/17 06:14:22 INFO : file1.copy5.txt: Copied (new) 2025/09/17 06:14:22 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2025/09/17 06:14:22 INFO : file1.txt: Copied (new) 2025/09/17 06:14:22 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2025/09/17 06:14:22 INFO : subdir/file20.txt: Copied (new) 2025/09/17 06:14:22 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 06:14:22 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_basic/modfiles" 2025/09/17 06:14:22 DEBUG : Creating backend with remote "/tmp/061330ba/datadir/test_basic-hepocev9" 2025/09/17 06:14:22 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:22 DEBUG : Local file system at /tmp/061330ba/datadir/test_basic-hepocev9: Waiting for checks to finish 2025/09/17 06:14:22 DEBUG : Local file system at /tmp/061330ba/datadir/test_basic-hepocev9: Waiting for transfers to finish 2025/09/17 06:14:22 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:14:22 DEBUG : file1.txt.75b77f44.partial: renamed to: file1.txt 2025/09/17 06:14:22 INFO : file1.txt: Copied (new) 2025/09/17 06:14:22 DEBUG : Waiting for deletions to finish 2025/09/17 06:14:22 ERROR : error listing: directory not found 2025/09/17 06:14:22 ERROR : uloz.to root 'rclone-test-bexobab3hohu/061330ba/basic/path1': Failed to list "": directory not found 2025/09/17 06:14:22 DEBUG : removing 1 level 0 directories 2025/09/17 06:14:22 INFO : uloz.to root 'rclone-test-bexobab3hohu/061330ba/basic/path1': Removing directory 2025/09/17 06:14:22 ERROR : Failed to rmdir: directory not found 2025/09/17 06:14:22 DEBUG : Waiting for deletions to finish 2025/09/17 06:14:22 ERROR : error listing: directory not found 2025/09/17 06:14:22 ERROR : Local file system at /tmp/061330ba/basic/path2: Failed to list "": directory not found 2025/09/17 06:14:22 DEBUG : removing 1 level 0 directories 2025/09/17 06:14:22 INFO : Local file system at /tmp/061330ba/basic/path2: Removing directory 2025/09/17 06:14:22 ERROR : Failed to rmdir: stat /tmp/061330ba/basic/path2: no such file or directory 2025/09/17 06:14:23 ERROR : error listing: directory not found 2025/09/17 06:14:23 ERROR : error listing: directory not found 2025/09/17 06:14:23 NOTICE: checking initFs Local file system at /tmp/061330ba/initdir/test_basic-cazeqod5 2025/09/17 06:14:23 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 06:14:23 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:23 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:23 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:23 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:23 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:23 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:23 INFO : subdir: Making directory 2025/09/17 06:14:24 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:24 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/basic/path1': Waiting for checks to finish 2025/09/17 06:14:24 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/basic/path1': Waiting for transfers to finish 2025/09/17 06:14:25 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:25 INFO : file1.copy3.txt: Copied (new) 2025/09/17 06:14:25 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 06:14:25 INFO : RCLONE_TEST: Copied (new) 2025/09/17 06:14:25 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:25 INFO : file1.copy1.txt: Copied (new) 2025/09/17 06:14:25 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:25 INFO : file1.copy2.txt: Copied (new) 2025/09/17 06:14:26 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:26 INFO : file1.copy4.txt: Copied (new) 2025/09/17 06:14:26 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:26 INFO : file1.copy5.txt: Copied (new) 2025/09/17 06:14:26 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:26 INFO : file1.txt: Copied (new) 2025/09/17 06:14:26 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:26 INFO : subdir/file20.txt: Copied (new) 2025/09/17 06:14:26 NOTICE: checking Path1 uloz.to root 'rclone-test-bexobab3hohu/061330ba/basic/path1' 2025/09/17 06:14:26 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 06:14:26 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:26 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:26 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:26 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:26 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:26 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:26 DEBUG : subdir: Making directory with metadata 2025/09/17 06:14:26 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:26 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/17 06:14:26 DEBUG : Added delayed dir = "subdir", newDst=subdir 2025/09/17 06:14:26 DEBUG : file1.copy1.txt.21b8fa2b.partial: renamed to: file1.copy1.txt 2025/09/17 06:14:26 INFO : file1.copy1.txt: Copied (new) 2025/09/17 06:14:26 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:26 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:26 DEBUG : file1.copy3.txt.d0285540.partial: renamed to: file1.copy3.txt 2025/09/17 06:14:26 INFO : file1.copy3.txt: Copied (new) 2025/09/17 06:14:26 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:26 DEBUG : file1.copy2.txt.455881d5.partial: renamed to: file1.copy2.txt 2025/09/17 06:14:26 INFO : file1.copy2.txt: Copied (new) 2025/09/17 06:14:26 DEBUG : file1.copy4.txt.8c987629.partial: renamed to: file1.copy4.txt 2025/09/17 06:14:26 INFO : file1.copy4.txt: Copied (new) 2025/09/17 06:14:26 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:26 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:26 DEBUG : file1.copy5.txt.19e8a2bc.partial: renamed to: file1.copy5.txt 2025/09/17 06:14:26 INFO : file1.copy5.txt: Copied (new) 2025/09/17 06:14:26 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/09/17 06:14:26 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2025/09/17 06:14:26 INFO : file1.txt: Copied (new) 2025/09/17 06:14:26 DEBUG : Local file system at /tmp/061330ba/basic/path2: Waiting for checks to finish 2025/09/17 06:14:26 DEBUG : Local file system at /tmp/061330ba/basic/path2: Waiting for transfers to finish 2025/09/17 06:14:26 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:14:26 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2025/09/17 06:14:26 INFO : subdir/file20.txt: Copied (new) 2025/09/17 06:14:26 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 06:14:26 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2025/09/17 06:14:26 INFO : RCLONE_TEST: Copied (new) 2025/09/17 06:14:26 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 06:14:26 NOTICE: checking path2 Local file system at /tmp/061330ba/basic/path2 2025/09/17 06:14:26 NOTICE: (01) : test basic 2025/09/17 06:14:26 NOTICE: (02) : test initial bisync 2025/09/17 06:14:26 NOTICE: (03) : bisync resync 2025/09/17 06:14:30 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/basic/path1': Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/17 06:14:30 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 06:14:30 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/17 06:14:30 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/09/17 06:14:30 INFO : Synching Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/basic/path1/" with Path2 "/tmp/061330ba/basic/path2/" 2025/09/17 06:14:30 INFO : Copying Path2 files to Path1 2025/09/17 06:14:30 INFO : - Path2 Resync is copying files to - Path1 2025/09/17 06:14:30 INFO : There was nothing to transfer 2025/09/17 06:14:30 INFO : - Path1 Resync is copying files to - Path2 2025/09/17 06:14:30 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 06:14:31 INFO : There was nothing to transfer 2025/09/17 06:14:31 INFO : Resync updating listings 2025/09/17 06:14:31 INFO : Validating listings for Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/basic/path1/" vs Path2 "/tmp/061330ba/basic/path2/" 2025/09/17 06:14:31 INFO : Bisync successful 2025/09/17 06:14:31 NOTICE: (04) : test place newer files on both paths 2025/09/17 06:14:31 NOTICE: (05) : touch-copy 2001-01-02 /tmp/061330ba/datadir/test_basic-hepocev9/file1.txt /tmp/061330ba/basic/path2/ 2025/09/17 06:14:31 DEBUG : Creating backend with remote "/tmp/061330ba/datadir/test_basic-hepocev9/" 2025/09/17 06:14:31 DEBUG : fs cache: renaming cache item "/tmp/061330ba/datadir/test_basic-hepocev9/" to be canonical "/tmp/061330ba/datadir/test_basic-hepocev9" 2025/09/17 06:14:31 DEBUG : file1.txt: Set modification time 2001-01-02 2025/09/17 06:14:31 DEBUG : copyFile "/tmp/061330ba/datadir/test_basic-hepocev9/file1.txt" to "/tmp/061330ba/basic/path2/" as "" 2025/09/17 06:14:31 DEBUG : Creating backend with remote "/tmp/061330ba/datadir/test_basic-hepocev9/file1.txt" 2025/09/17 06:14:31 DEBUG : Creating backend with remote "/tmp/061330ba/basic/path2/" 2025/09/17 06:14:31 DEBUG : operations.CopyFile "file1.txt" to "Local file system at /tmp/061330ba/basic/path2" as "file1.txt" 2025/09/17 06:14:31 DEBUG : file1.txt: Sizes differ (src 19 vs dst 0) 2025/09/17 06:14:31 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:14:31 DEBUG : file1.txt.75b77f44.partial: renamed to: file1.txt 2025/09/17 06:14:31 INFO : file1.txt: Copied (replaced existing) 2025/09/17 06:14:31 NOTICE: (06) : copy-as /tmp/061330ba/datadir/test_basic-hepocev9/file1.txt TestUlozto:rclone-test-bexobab3hohu/061330ba/basic/path1/subdir file20.txt 2025/09/17 06:14:31 DEBUG : copyFile "/tmp/061330ba/datadir/test_basic-hepocev9/file1.txt" to "TestUlozto:rclone-test-bexobab3hohu/061330ba/basic/path1/subdir" as "file20.txt" 2025/09/17 06:14:31 DEBUG : Creating backend with remote "/tmp/061330ba/datadir/test_basic-hepocev9/file1.txt" 2025/09/17 06:14:31 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba/basic/path1/subdir" 2025/09/17 06:14:33 DEBUG : operations.CopyFile "file1.txt" to "uloz.to root 'rclone-test-bexobab3hohu/061330ba/basic/path1/subdir'" as "file20.txt" 2025/09/17 06:14:34 DEBUG : file1.txt: Sizes differ (src 19 vs dst 0) 2025/09/17 06:14:34 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:14:34 INFO : file1.txt: Copied (replaced existing) to: file20.txt 2025/09/17 06:14:34 NOTICE: (07) : test bisync run 2025/09/17 06:14:34 NOTICE: (08) : bisync 2025/09/17 06:14:38 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/basic/path1': Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/17 06:14:38 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 06:14:38 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/17 06:14:38 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/09/17 06:14:38 INFO : Synching Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/basic/path1/" with Path2 "/tmp/061330ba/basic/path2/" 2025/09/17 06:14:38 INFO : Building Path1 and Path2 listings 2025/09/17 06:14:38 INFO : Path1 checking for diffs 2025/09/17 06:14:38 INFO : - Path1 File changed: size (larger), time (newer) - subdir/file20.txt 2025/09/17 06:14:38 INFO : Path1: 1 changes:  0 new,  1 modified,  0 deleted 2025/09/17 06:14:38 INFO : (Modified:  1 newer,  0 older,  1 larger,  0 smaller) 2025/09/17 06:14:38 INFO : Path2 checking for diffs 2025/09/17 06:14:38 INFO : - Path2 File changed: size (larger), time (newer) - file1.txt 2025/09/17 06:14:38 INFO : Path2: 1 changes:  0 new,  1 modified,  0 deleted 2025/09/17 06:14:38 INFO : (Modified:  1 newer,  0 older,  1 larger,  0 smaller) 2025/09/17 06:14:38 INFO : Applying changes 2025/09/17 06:14:38 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/basic/path2/subdir/file20.txt 2025/09/17 06:14:38 INFO : - Path2 Queue copy to Path1 - TestUlozto:rclone-test-bexobab3hohu/061330ba/basic/path1/file1.txt 2025/09/17 06:14:38 INFO : - Path2 Do queued copies to - Path1 2025/09/17 06:14:39 INFO : file1.txt: Copied (replaced existing) 2025/09/17 06:14:39 INFO : - Path1 Do queued copies to - Path2 2025/09/17 06:14:40 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 06:25:17 ERROR : subdir/file20.txt: Failed to copy: failed to open source object: HTTP error 400 (400 Bad Request) returned body: "\n\n\n \n Ulož.to Disk - Platnost odkazu na stránku vypršela\n \n \n \n \n\n\n\n
\n
\n \n \n \n \n \n \n \n \n \n
\n
\n\n
\n
\n\t\n\t

Platnost odkazu na stránku vypršela

\n

\n

Link to the page has expired

\n\t\n
\n
\n\n \n\n\n\n\n\n" 2025/09/17 06:25:17 ERROR : Local file system at /tmp/061330ba/basic/path2: not deleting files as there were IO errors 2025/09/17 06:25:17 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 06:25:17 ERROR : Local file system at /tmp/061330ba/basic/path2: not deleting directories as there were IO errors 2025/09/17 06:25:17 ERROR : Bisync critical error: failed to open source object: HTTP error 400 (400 Bad Request) returned body: "\n\n\n \n Ulož.to Disk - Platnost odkazu na stránku vypršela\n \n \n \n \n\n\n\n
\n
\n \n \n \n \n \n \n \n \n \n
\n
\n\n
\n
\n\t\n\t

Platnost odkazu na stránku vypršela

\n

\n

Link to the page has expired

\n\t\n
\n
\n\n \n\n\n\n\n\n" 2025/09/17 06:25:17 ERROR : Bisync aborted. Must run --resync to recover. 2025/09/17 06:25:17 NOTICE: Bisync error: bisync aborted 2025/09/17 06:25:17 NOTICE: ---------------------------------------------------------- 2025/09/17 06:25:17 NOTICE: MISCOMPARE - Number of Golden and Results files do not match: 2025/09/17 06:25:17 NOTICE: Golden count: 9 2025/09/17 06:25:17 NOTICE: Result count: 7 2025/09/17 06:25:17 NOTICE: Golden files: _testdir_path1.._testdir_path2.copy1to2.que, _testdir_path1.._testdir_path2.copy2to1.que, _testdir_path1.._testdir_path2.path1.lst, _testdir_path1.._testdir_path2.path1.lst-new, _testdir_path1.._testdir_path2.path1.lst-old, _testdir_path1.._testdir_path2.path2.lst, _testdir_path1.._testdir_path2.path2.lst-new, _testdir_path1.._testdir_path2.path2.lst-old, test.log 2025/09/17 06:25:17 NOTICE: Result files: _testdir_path1.._testdir_path2.copy1to2.que, _testdir_path1.._testdir_path2.copy2to1.que, _testdir_path1.._testdir_path2.path1.lst-err, _testdir_path1.._testdir_path2.path1.lst-new, _testdir_path1.._testdir_path2.path2.lst-err, _testdir_path1.._testdir_path2.path2.lst-new, test.log 2025/09/17 06:25:17 NOTICE: File found in Golden but not in Results: _testdir_path1.._testdir_path2.path1.lst 2025/09/17 06:25:17 NOTICE: File found in Golden but not in Results: _testdir_path1.._testdir_path2.path1.lst-old 2025/09/17 06:25:17 NOTICE: File found in Golden but not in Results: _testdir_path1.._testdir_path2.path2.lst 2025/09/17 06:25:17 NOTICE: File found in Golden but not in Results: _testdir_path1.._testdir_path2.path2.lst-old 2025/09/17 06:25:17 NOTICE: File found in Results but not in Golden: _testdir_path1.._testdir_path2.path1.lst-err 2025/09/17 06:25:17 NOTICE: File found in Results but not in Golden: _testdir_path1.._testdir_path2.path2.lst-err 2025/09/17 06:25:17 NOTICE: ---------------------------------------------------------- 2025/09/17 06:25:17 NOTICE: | MISCOMPARE -Golden vs +Results for test.log 2025/09/17 06:25:17 NOTICE: | @@ -53,3 +53,6 @@ 2025/09/17 06:25:17 NOTICE: | -INFO : Updating listings 2025/09/17 06:25:17 NOTICE: | -INFO : Validating listings for Path1 "{path1/}" vs Path2 "{path2/}" 2025/09/17 06:25:17 NOTICE: | -INFO : Bisync successful 2025/09/17 06:25:17 NOTICE: | +ERROR : subdir/file20.txt: Failed to copy: failed to open source object: HTTP error 400 (400 Bad Request) returned body: "\n\n\n \n Ulož.to Disk - Platnost odkazu na stránku vypršela\n \n \n \n \n\n\n\n
\n
\n \n \n \n \n \n \n \n \n \n
\n
\n\n
\n
\n\t\n\t

Platnost odkazu na stránku vypršela

\n

\n

Link to the page has expired

\n\t\n
\n
\n\n \n\n\n\n\n\n" 2025/09/17 06:25:17 NOTICE: | +ERROR : {path2String}: not deleting files as there were IO errors 2025/09/17 06:25:17 NOTICE: | +ERROR : {path2String}: not deleting directories as there were IO errors 2025/09/17 06:25:17 NOTICE: | +ERROR : Bisync critical error: failed to open source object: HTTP error 400 (400 Bad Request) returned body: "\n\n\n \n Ulož.to Disk - Platnost odkazu na stránku vypršela\n \n \n \n \n\n\n\n
\n
\n \n \n \n \n \n \n \n \n \n
\n
\n\n
\n
\n\t\n\t

Platnost odkazu na stránku vypršela

\n

\n

Link to the page has expired

\n\t\n
\n
\n\n \n\n\n\n\n\n" 2025/09/17 06:25:17 NOTICE: | +ERROR : Bisync aborted. Must run --resync to recover. 2025/09/17 06:25:17 NOTICE: | +Bisync error: bisync aborted 2025/09/17 06:25:17 NOTICE: ---------------------------------------------------------- 2025/09/17 06:25:17 DEBUG : Waiting for deletions to finish 2025/09/17 06:25:18 DEBUG : pacer: Reducing sleep to 360ms 2025/09/17 06:25:18 DEBUG : pacer: Reducing sleep to 270ms 2025/09/17 06:25:18 DEBUG : pacer: Reducing sleep to 202.5ms 2025/09/17 06:25:19 DEBUG : pacer: Reducing sleep to 151.875ms 2025/09/17 06:25:19 DEBUG : pacer: Reducing sleep to 113.90625ms 2025/09/17 06:25:19 DEBUG : pacer: Reducing sleep to 85.429687ms 2025/09/17 06:25:19 DEBUG : pacer: Reducing sleep to 64.072265ms 2025/09/17 06:25:19 DEBUG : pacer: Reducing sleep to 48.054198ms 2025/09/17 06:25:19 DEBUG : pacer: Reducing sleep to 36.040648ms 2025/09/17 06:25:19 DEBUG : pacer: Reducing sleep to 27.030486ms 2025/09/17 06:25:19 DEBUG : pacer: Reducing sleep to 20.272864ms 2025/09/17 06:25:19 DEBUG : pacer: Reducing sleep to 15.204648ms 2025/09/17 06:25:19 INFO : file1.copy3.txt: Deleted 2025/09/17 06:25:19 DEBUG : pacer: Reducing sleep to 11.403486ms 2025/09/17 06:25:19 INFO : file1.copy2.txt: Deleted 2025/09/17 06:25:20 DEBUG : pacer: Reducing sleep to 10ms 2025/09/17 06:25:20 INFO : file1.copy1.txt: Deleted 2025/09/17 06:25:20 INFO : file1.copy5.txt: Deleted 2025/09/17 06:25:20 INFO : file1.copy4.txt: Deleted 2025/09/17 06:25:20 INFO : RCLONE_TEST: Deleted 2025/09/17 06:25:20 INFO : file1.txt: Deleted 2025/09/17 06:25:20 INFO : subdir/file20.txt: Deleted 2025/09/17 06:25:20 DEBUG : removing 1 level 1 directories 2025/09/17 06:25:20 INFO : subdir: Removing directory 2025/09/17 06:25:21 DEBUG : removing 1 level 0 directories 2025/09/17 06:25:21 INFO : uloz.to root 'rclone-test-bexobab3hohu/061330ba/basic/path1': Removing directory 2025/09/17 06:25:21 DEBUG : Waiting for deletions to finish 2025/09/17 06:25:21 INFO : file1.copy3.txt: Deleted 2025/09/17 06:25:21 INFO : file1.copy4.txt: Deleted 2025/09/17 06:25:21 INFO : file1.copy1.txt: Deleted 2025/09/17 06:25:21 INFO : file1.copy5.txt: Deleted 2025/09/17 06:25:21 INFO : RCLONE_TEST: Deleted 2025/09/17 06:25:21 INFO : file1.copy2.txt: Deleted 2025/09/17 06:25:21 INFO : subdir/file20.txt: Deleted 2025/09/17 06:25:21 INFO : file1.txt: Deleted 2025/09/17 06:25:21 DEBUG : removing 1 level 1 directories 2025/09/17 06:25:21 INFO : subdir: Removing directory 2025/09/17 06:25:21 DEBUG : removing 1 level 0 directories 2025/09/17 06:25:21 INFO : Local file system at /tmp/061330ba/basic/path2: Removing directory bisync_test.go:608: TEST basic FAILED - 7 MISCOMPARED FILES === RUN TestBisyncRemoteLocal/changes 2025/09/17 06:25:21 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba" 2025/09/17 06:25:23 INFO : path1: Making directory 2025/09/17 06:25:24 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1" 2025/09/17 06:25:26 DEBUG : Creating backend with remote "/tmp/061330ba" 2025/09/17 06:25:26 DEBUG : Creating backend with remote "/tmp/061330ba/changes/path2" 2025/09/17 06:25:26 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_changes/initial" 2025/09/17 06:25:26 DEBUG : Creating backend with remote "/tmp/061330ba/initdir/test_changes-hetatuv5" 2025/09/17 06:25:26 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : file3.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : file4.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : file5.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : file6.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : file7.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : file8.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : Local file system at /tmp/061330ba/initdir/test_changes-hetatuv5: Waiting for checks to finish 2025/09/17 06:25:26 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:26 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2025/09/17 06:25:26 INFO : file1.txt: Copied (new) 2025/09/17 06:25:26 DEBUG : Local file system at /tmp/061330ba/initdir/test_changes-hetatuv5: Waiting for transfers to finish 2025/09/17 06:25:26 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:26 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:26 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2025/09/17 06:25:26 INFO : file2.txt: Copied (new) 2025/09/17 06:25:26 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2025/09/17 06:25:26 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:26 INFO : file3.txt: Copied (new) 2025/09/17 06:25:26 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 06:25:26 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2025/09/17 06:25:26 INFO : RCLONE_TEST: Copied (new) 2025/09/17 06:25:26 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:26 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:26 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:26 DEBUG : file7.txt.9f102165.partial: renamed to: file7.txt 2025/09/17 06:25:26 DEBUG : file6.txt.0a60f5f0.partial: renamed to: file6.txt 2025/09/17 06:25:26 INFO : file7.txt: Copied (new) 2025/09/17 06:25:26 DEBUG : file5.txt.6e808e0e.partial: renamed to: file5.txt 2025/09/17 06:25:26 INFO : file5.txt: Copied (new) 2025/09/17 06:25:26 INFO : file6.txt: Copied (new) 2025/09/17 06:25:26 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2025/09/17 06:25:26 INFO : file4.txt: Copied (new) 2025/09/17 06:25:26 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:26 DEBUG : file8.txt.b300b322.partial: renamed to: file8.txt 2025/09/17 06:25:26 INFO : file8.txt: Copied (new) 2025/09/17 06:25:26 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_changes/modfiles" 2025/09/17 06:25:26 DEBUG : Creating backend with remote "/tmp/061330ba/datadir/test_changes-veyizek3" 2025/09/17 06:25:26 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : file10.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : file11.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : file5L.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : file5R.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : file6.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : file7.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:26 DEBUG : Local file system at /tmp/061330ba/datadir/test_changes-veyizek3: Waiting for checks to finish 2025/09/17 06:25:26 DEBUG : Local file system at /tmp/061330ba/datadir/test_changes-veyizek3: Waiting for transfers to finish 2025/09/17 06:25:26 DEBUG : file2.txt: md5 = fb3ecfb2800400fb01b0bfd39903e9fb OK 2025/09/17 06:25:26 DEBUG : file11.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:25:26 DEBUG : file2.txt.4526d70e.partial: renamed to: file2.txt 2025/09/17 06:25:26 INFO : file2.txt: Copied (new) 2025/09/17 06:25:26 DEBUG : file10.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:25:26 DEBUG : file10.txt.c02780cb.partial: renamed to: file10.txt 2025/09/17 06:25:26 INFO : file10.txt: Copied (new) 2025/09/17 06:25:26 DEBUG : file11.txt.40d797d4.partial: renamed to: file11.txt 2025/09/17 06:25:26 INFO : file11.txt: Copied (new) 2025/09/17 06:25:26 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:25:26 DEBUG : file1.txt.75b77f44.partial: renamed to: file1.txt 2025/09/17 06:25:26 INFO : file1.txt: Copied (new) 2025/09/17 06:25:26 DEBUG : file5L.txt: md5 = 0860a03592626642f8fd6c8bfb447d2a OK 2025/09/17 06:25:26 DEBUG : file5L.txt.8dd6541a.partial: renamed to: file5L.txt 2025/09/17 06:25:26 DEBUG : file5R.txt: md5 = 979a803b15d27df0c31ad7d29006d10b OK 2025/09/17 06:25:26 INFO : file5L.txt: Copied (new) 2025/09/17 06:25:26 DEBUG : file6.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:25:26 DEBUG : file5R.txt.ee3b9525.partial: renamed to: file5R.txt 2025/09/17 06:25:26 INFO : file5R.txt: Copied (new) 2025/09/17 06:25:26 DEBUG : file6.txt.4185169b.partial: renamed to: file6.txt 2025/09/17 06:25:26 INFO : file6.txt: Copied (new) 2025/09/17 06:25:26 DEBUG : file7.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:25:26 DEBUG : file7.txt.c1750184.partial: renamed to: file7.txt 2025/09/17 06:25:26 INFO : file7.txt: Copied (new) 2025/09/17 06:25:26 DEBUG : Waiting for deletions to finish 2025/09/17 06:25:26 ERROR : error listing: directory not found 2025/09/17 06:25:27 ERROR : uloz.to root 'rclone-test-bexobab3hohu/061330ba/changes/path1': Failed to list "": directory not found 2025/09/17 06:25:27 DEBUG : removing 1 level 0 directories 2025/09/17 06:25:27 INFO : uloz.to root 'rclone-test-bexobab3hohu/061330ba/changes/path1': Removing directory 2025/09/17 06:25:27 ERROR : Failed to rmdir: directory not found 2025/09/17 06:25:27 DEBUG : Waiting for deletions to finish 2025/09/17 06:25:27 ERROR : error listing: directory not found 2025/09/17 06:25:27 ERROR : Local file system at /tmp/061330ba/changes/path2: Failed to list "": directory not found 2025/09/17 06:25:27 DEBUG : removing 1 level 0 directories 2025/09/17 06:25:27 INFO : Local file system at /tmp/061330ba/changes/path2: Removing directory 2025/09/17 06:25:27 ERROR : Failed to rmdir: stat /tmp/061330ba/changes/path2: no such file or directory 2025/09/17 06:25:27 ERROR : error listing: directory not found 2025/09/17 06:25:27 ERROR : error listing: directory not found 2025/09/17 06:25:27 NOTICE: checking initFs Local file system at /tmp/061330ba/initdir/test_changes-hetatuv5 2025/09/17 06:25:27 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 06:25:27 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:27 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:27 DEBUG : file3.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:27 DEBUG : file4.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:27 DEBUG : file5.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:27 DEBUG : file6.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:27 DEBUG : file7.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:27 DEBUG : file8.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:27 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/changes/path1': Waiting for checks to finish 2025/09/17 06:25:27 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/changes/path1': Waiting for transfers to finish 2025/09/17 06:25:31 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 06:25:31 INFO : RCLONE_TEST: Copied (new) 2025/09/17 06:25:31 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:31 INFO : file1.txt: Copied (new) 2025/09/17 06:25:31 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:31 INFO : file2.txt: Copied (new) 2025/09/17 06:25:31 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:31 INFO : file3.txt: Copied (new) 2025/09/17 06:25:32 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:32 INFO : file4.txt: Copied (new) 2025/09/17 06:25:32 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:32 INFO : file5.txt: Copied (new) 2025/09/17 06:25:32 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:32 INFO : file6.txt: Copied (new) 2025/09/17 06:25:32 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:32 INFO : file7.txt: Copied (new) 2025/09/17 06:25:33 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:33 INFO : file8.txt: Copied (new) 2025/09/17 06:25:33 NOTICE: checking Path1 uloz.to root 'rclone-test-bexobab3hohu/061330ba/changes/path1' 2025/09/17 06:25:33 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 06:25:33 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:33 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:33 DEBUG : file3.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:33 DEBUG : file4.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:33 DEBUG : file5.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:33 DEBUG : file6.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:33 DEBUG : file7.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:33 DEBUG : file8.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:33 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:33 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2025/09/17 06:25:33 INFO : file3.txt: Copied (new) 2025/09/17 06:25:33 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:33 DEBUG : Local file system at /tmp/061330ba/changes/path2: Waiting for checks to finish 2025/09/17 06:25:33 DEBUG : Local file system at /tmp/061330ba/changes/path2: Waiting for transfers to finish 2025/09/17 06:25:33 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2025/09/17 06:25:33 INFO : file2.txt: Copied (new) 2025/09/17 06:25:33 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:33 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:33 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:33 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2025/09/17 06:25:33 INFO : file4.txt: Copied (new) 2025/09/17 06:25:33 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 06:25:33 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2025/09/17 06:25:33 INFO : file1.txt: Copied (new) 2025/09/17 06:25:33 DEBUG : file5.txt.6e808e0e.partial: renamed to: file5.txt 2025/09/17 06:25:33 INFO : file5.txt: Copied (new) 2025/09/17 06:25:33 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:33 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:33 DEBUG : file6.txt.0a60f5f0.partial: renamed to: file6.txt 2025/09/17 06:25:33 INFO : file6.txt: Copied (new) 2025/09/17 06:25:33 DEBUG : file7.txt.9f102165.partial: renamed to: file7.txt 2025/09/17 06:25:33 INFO : file7.txt: Copied (new) 2025/09/17 06:25:33 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2025/09/17 06:25:33 INFO : RCLONE_TEST: Copied (new) 2025/09/17 06:25:33 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 06:25:33 DEBUG : file8.txt.b300b322.partial: renamed to: file8.txt 2025/09/17 06:25:33 INFO : file8.txt: Copied (new) 2025/09/17 06:25:33 NOTICE: checking path2 Local file system at /tmp/061330ba/changes/path2 2025/09/17 06:25:33 NOTICE: (01) : test changes 2025/09/17 06:25:33 NOTICE: (02) : test initial bisync 2025/09/17 06:25:33 NOTICE: (03) : bisync resync 2025/09/17 06:25:36 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/changes/path1': Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/17 06:25:36 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/17 06:25:36 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/09/17 06:25:36 INFO : Synching Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/" with Path2 "/tmp/061330ba/changes/path2/" 2025/09/17 06:25:36 INFO : Copying Path2 files to Path1 2025/09/17 06:25:36 INFO : - Path2 Resync is copying files to - Path1 2025/09/17 06:25:36 INFO : There was nothing to transfer 2025/09/17 06:25:36 INFO : - Path1 Resync is copying files to - Path2 2025/09/17 06:25:37 INFO : There was nothing to transfer 2025/09/17 06:25:37 INFO : Resync updating listings 2025/09/17 06:25:37 INFO : Validating listings for Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/" vs Path2 "/tmp/061330ba/changes/path2/" 2025/09/17 06:25:37 INFO : Bisync successful 2025/09/17 06:25:37 NOTICE: (04) : test make modifications on both paths 2025/09/17 06:25:37 NOTICE: (05) : test new on path2 - file10 2025/09/17 06:25:37 NOTICE: (06) : touch-copy 2001-01-02 /tmp/061330ba/datadir/test_changes-veyizek3/file10.txt /tmp/061330ba/changes/path2/ 2025/09/17 06:25:37 DEBUG : Creating backend with remote "/tmp/061330ba/datadir/test_changes-veyizek3/" 2025/09/17 06:25:37 DEBUG : fs cache: renaming cache item "/tmp/061330ba/datadir/test_changes-veyizek3/" to be canonical "/tmp/061330ba/datadir/test_changes-veyizek3" 2025/09/17 06:25:37 DEBUG : file10.txt: Set modification time 2001-01-02 2025/09/17 06:25:37 DEBUG : copyFile "/tmp/061330ba/datadir/test_changes-veyizek3/file10.txt" to "/tmp/061330ba/changes/path2/" as "" 2025/09/17 06:25:37 DEBUG : Creating backend with remote "/tmp/061330ba/datadir/test_changes-veyizek3/file10.txt" 2025/09/17 06:25:37 DEBUG : Creating backend with remote "/tmp/061330ba/changes/path2/" 2025/09/17 06:25:37 DEBUG : operations.CopyFile "file10.txt" to "Local file system at /tmp/061330ba/changes/path2" as "file10.txt" 2025/09/17 06:25:37 DEBUG : file10.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:37 DEBUG : file10.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:25:37 DEBUG : file10.txt.c02780cb.partial: renamed to: file10.txt 2025/09/17 06:25:37 INFO : file10.txt: Copied (new) 2025/09/17 06:25:37 NOTICE: (07) : test newer on path2 - file1 2025/09/17 06:25:37 NOTICE: (08) : touch-copy 2001-01-02 /tmp/061330ba/datadir/test_changes-veyizek3/file1.txt /tmp/061330ba/changes/path2/ 2025/09/17 06:25:37 DEBUG : fs cache: switching user supplied name "/tmp/061330ba/datadir/test_changes-veyizek3/" for canonical name "/tmp/061330ba/datadir/test_changes-veyizek3" 2025/09/17 06:25:37 DEBUG : file1.txt: Set modification time 2001-01-02 2025/09/17 06:25:37 DEBUG : copyFile "/tmp/061330ba/datadir/test_changes-veyizek3/file1.txt" to "/tmp/061330ba/changes/path2/" as "" 2025/09/17 06:25:37 DEBUG : Creating backend with remote "/tmp/061330ba/datadir/test_changes-veyizek3/file1.txt" 2025/09/17 06:25:37 DEBUG : Creating backend with remote "/tmp/061330ba/changes/path2/" 2025/09/17 06:25:37 DEBUG : operations.CopyFile "file1.txt" to "Local file system at /tmp/061330ba/changes/path2" as "file1.txt" 2025/09/17 06:25:37 DEBUG : file1.txt: Sizes differ (src 19 vs dst 0) 2025/09/17 06:25:37 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:25:37 DEBUG : file1.txt.75b77f44.partial: renamed to: file1.txt 2025/09/17 06:25:37 INFO : file1.txt: Copied (replaced existing) 2025/09/17 06:25:37 NOTICE: (09) : test new on path1 - file11 2025/09/17 06:25:37 NOTICE: (10) : touch-copy 2001-01-02 /tmp/061330ba/datadir/test_changes-veyizek3/file11.txt TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/ 2025/09/17 06:25:37 DEBUG : fs cache: switching user supplied name "/tmp/061330ba/datadir/test_changes-veyizek3/" for canonical name "/tmp/061330ba/datadir/test_changes-veyizek3" 2025/09/17 06:25:37 DEBUG : file11.txt: Set modification time 2001-01-02 2025/09/17 06:25:37 DEBUG : copyFile "/tmp/061330ba/datadir/test_changes-veyizek3/file11.txt" to "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/" as "" 2025/09/17 06:25:37 DEBUG : Creating backend with remote "/tmp/061330ba/datadir/test_changes-veyizek3/file11.txt" 2025/09/17 06:25:37 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/" 2025/09/17 06:25:39 DEBUG : operations.CopyFile "file11.txt" to "uloz.to root 'rclone-test-bexobab3hohu/061330ba/changes/path1'" as "file11.txt" 2025/09/17 06:25:40 DEBUG : file11.txt: Need to transfer - File not found at Destination 2025/09/17 06:25:42 DEBUG : file11.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:25:42 INFO : file11.txt: Copied (new) 2025/09/17 06:25:42 NOTICE: (11) : test newer on path1 - file2 2025/09/17 06:25:42 NOTICE: (12) : touch-copy 2001-01-02 /tmp/061330ba/datadir/test_changes-veyizek3/file2.txt TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/ 2025/09/17 06:25:42 DEBUG : fs cache: switching user supplied name "/tmp/061330ba/datadir/test_changes-veyizek3/" for canonical name "/tmp/061330ba/datadir/test_changes-veyizek3" 2025/09/17 06:25:42 DEBUG : file2.txt: Set modification time 2001-01-02 2025/09/17 06:25:42 DEBUG : copyFile "/tmp/061330ba/datadir/test_changes-veyizek3/file2.txt" to "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/" as "" 2025/09/17 06:25:42 DEBUG : Creating backend with remote "/tmp/061330ba/datadir/test_changes-veyizek3/file2.txt" 2025/09/17 06:25:42 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/" 2025/09/17 06:25:45 DEBUG : operations.CopyFile "file2.txt" to "uloz.to root 'rclone-test-bexobab3hohu/061330ba/changes/path1'" as "file2.txt" 2025/09/17 06:25:45 DEBUG : file2.txt: Sizes differ (src 13 vs dst 0) 2025/09/17 06:25:46 DEBUG : file2.txt: md5 = fb3ecfb2800400fb01b0bfd39903e9fb OK 2025/09/17 06:25:46 INFO : file2.txt: Copied (replaced existing) 2025/09/17 06:25:46 NOTICE: (13) : test deleted on path2 - file3 2025/09/17 06:25:46 NOTICE: (14) : delete-file /tmp/061330ba/changes/path2/file3.txt 2025/09/17 06:25:46 DEBUG : Creating backend with remote "/tmp/061330ba/changes/path2/" 2025/09/17 06:25:46 DEBUG : fs cache: renaming cache item "/tmp/061330ba/changes/path2/" to be canonical "/tmp/061330ba/changes/path2" 2025/09/17 06:25:46 INFO : file3.txt: Deleted 2025/09/17 06:25:46 NOTICE: (15) : test deleted on path1 - file4 2025/09/17 06:25:46 NOTICE: (16) : delete-file TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/file4.txt 2025/09/17 06:25:46 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/" 2025/09/17 06:25:48 DEBUG : fs cache: renaming cache item "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/" to be canonical "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1" 2025/09/17 06:25:49 INFO : file4.txt: Deleted 2025/09/17 06:25:49 NOTICE: (17) : test deleted on both paths - file8 2025/09/17 06:25:49 NOTICE: (18) : delete-file TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/file8.txt 2025/09/17 06:25:49 DEBUG : fs cache: switching user supplied name "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/" for canonical name "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1" 2025/09/17 06:25:49 INFO : file8.txt: Deleted 2025/09/17 06:25:49 NOTICE: (19) : delete-file /tmp/061330ba/changes/path2/file8.txt 2025/09/17 06:25:49 DEBUG : fs cache: switching user supplied name "/tmp/061330ba/changes/path2/" for canonical name "/tmp/061330ba/changes/path2" 2025/09/17 06:25:49 INFO : file8.txt: Deleted 2025/09/17 06:25:49 NOTICE: (20) : test changed on both paths - file5 (file5R, file5L) 2025/09/17 06:25:49 NOTICE: (21) : touch-glob 2001-01-02 /tmp/061330ba/datadir/test_changes-veyizek3/ file5R.txt 2025/09/17 06:25:49 DEBUG : fs cache: switching user supplied name "/tmp/061330ba/datadir/test_changes-veyizek3/" for canonical name "/tmp/061330ba/datadir/test_changes-veyizek3" 2025/09/17 06:25:49 DEBUG : file5R.txt: Set modification time 2001-01-02 2025/09/17 06:25:49 NOTICE: (22) : copy-as /tmp/061330ba/datadir/test_changes-veyizek3/file5R.txt /tmp/061330ba/changes/path2/ file5.txt 2025/09/17 06:25:49 DEBUG : copyFile "/tmp/061330ba/datadir/test_changes-veyizek3/file5R.txt" to "/tmp/061330ba/changes/path2/" as "file5.txt" 2025/09/17 06:25:49 DEBUG : Creating backend with remote "/tmp/061330ba/datadir/test_changes-veyizek3/file5R.txt" 2025/09/17 06:25:49 DEBUG : Creating backend with remote "/tmp/061330ba/changes/path2/" 2025/09/17 06:25:49 DEBUG : operations.CopyFile "file5R.txt" to "Local file system at /tmp/061330ba/changes/path2" as "file5.txt" 2025/09/17 06:25:49 DEBUG : file5R.txt: Sizes differ (src 39 vs dst 0) 2025/09/17 06:25:49 DEBUG : file5R.txt: md5 = 979a803b15d27df0c31ad7d29006d10b OK 2025/09/17 06:25:49 DEBUG : file5.txt.232124ee.partial: renamed to: file5.txt 2025/09/17 06:25:49 INFO : file5R.txt: Copied (replaced existing) to: file5.txt 2025/09/17 06:25:49 NOTICE: (23) : touch-glob 2001-03-04 /tmp/061330ba/datadir/test_changes-veyizek3/ file5L.txt 2025/09/17 06:25:49 DEBUG : fs cache: switching user supplied name "/tmp/061330ba/datadir/test_changes-veyizek3/" for canonical name "/tmp/061330ba/datadir/test_changes-veyizek3" 2025/09/17 06:25:49 DEBUG : file5L.txt: Set modification time 2001-03-04 2025/09/17 06:25:49 NOTICE: (24) : copy-as /tmp/061330ba/datadir/test_changes-veyizek3/file5L.txt TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/ file5.txt 2025/09/17 06:25:49 DEBUG : copyFile "/tmp/061330ba/datadir/test_changes-veyizek3/file5L.txt" to "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/" as "file5.txt" 2025/09/17 06:25:49 DEBUG : Creating backend with remote "/tmp/061330ba/datadir/test_changes-veyizek3/file5L.txt" 2025/09/17 06:25:49 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/" 2025/09/17 06:25:52 DEBUG : operations.CopyFile "file5L.txt" to "uloz.to root 'rclone-test-bexobab3hohu/061330ba/changes/path1'" as "file5.txt" 2025/09/17 06:25:52 DEBUG : file5L.txt: Sizes differ (src 39 vs dst 0) 2025/09/17 06:25:53 DEBUG : file5L.txt: md5 = 0860a03592626642f8fd6c8bfb447d2a OK 2025/09/17 06:25:53 INFO : file5L.txt: Copied (replaced existing) to: file5.txt 2025/09/17 06:25:53 NOTICE: (25) : test newer on path2 and deleted on path1 - file6 2025/09/17 06:25:53 NOTICE: (26) : touch-copy 2001-01-02 /tmp/061330ba/datadir/test_changes-veyizek3/file6.txt /tmp/061330ba/changes/path2/ 2025/09/17 06:25:53 DEBUG : fs cache: switching user supplied name "/tmp/061330ba/datadir/test_changes-veyizek3/" for canonical name "/tmp/061330ba/datadir/test_changes-veyizek3" 2025/09/17 06:25:53 DEBUG : file6.txt: Set modification time 2001-01-02 2025/09/17 06:25:53 DEBUG : copyFile "/tmp/061330ba/datadir/test_changes-veyizek3/file6.txt" to "/tmp/061330ba/changes/path2/" as "" 2025/09/17 06:25:53 DEBUG : Creating backend with remote "/tmp/061330ba/datadir/test_changes-veyizek3/file6.txt" 2025/09/17 06:25:53 DEBUG : Creating backend with remote "/tmp/061330ba/changes/path2/" 2025/09/17 06:25:53 DEBUG : operations.CopyFile "file6.txt" to "Local file system at /tmp/061330ba/changes/path2" as "file6.txt" 2025/09/17 06:25:53 DEBUG : file6.txt: Sizes differ (src 19 vs dst 0) 2025/09/17 06:25:53 DEBUG : file6.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:25:53 DEBUG : file6.txt.4185169b.partial: renamed to: file6.txt 2025/09/17 06:25:53 INFO : file6.txt: Copied (replaced existing) 2025/09/17 06:25:53 NOTICE: (27) : delete-file TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/file6.txt 2025/09/17 06:25:53 DEBUG : fs cache: switching user supplied name "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/" for canonical name "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1" 2025/09/17 06:25:53 INFO : file6.txt: Deleted 2025/09/17 06:25:53 NOTICE: (28) : test newer on path1 and deleted on path2 - file7 2025/09/17 06:25:53 NOTICE: (29) : touch-copy 2001-01-02 /tmp/061330ba/datadir/test_changes-veyizek3/file7.txt TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/ 2025/09/17 06:25:53 DEBUG : fs cache: switching user supplied name "/tmp/061330ba/datadir/test_changes-veyizek3/" for canonical name "/tmp/061330ba/datadir/test_changes-veyizek3" 2025/09/17 06:25:53 DEBUG : file7.txt: Set modification time 2001-01-02 2025/09/17 06:25:53 DEBUG : copyFile "/tmp/061330ba/datadir/test_changes-veyizek3/file7.txt" to "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/" as "" 2025/09/17 06:25:53 DEBUG : Creating backend with remote "/tmp/061330ba/datadir/test_changes-veyizek3/file7.txt" 2025/09/17 06:25:53 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/" 2025/09/17 06:25:56 DEBUG : operations.CopyFile "file7.txt" to "uloz.to root 'rclone-test-bexobab3hohu/061330ba/changes/path1'" as "file7.txt" 2025/09/17 06:25:56 DEBUG : file7.txt: Sizes differ (src 19 vs dst 0) 2025/09/17 06:25:57 DEBUG : file7.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/17 06:25:57 INFO : file7.txt: Copied (replaced existing) 2025/09/17 06:25:57 NOTICE: (30) : delete-file /tmp/061330ba/changes/path2/file7.txt 2025/09/17 06:25:57 DEBUG : fs cache: switching user supplied name "/tmp/061330ba/changes/path2/" for canonical name "/tmp/061330ba/changes/path2" 2025/09/17 06:25:57 INFO : file7.txt: Deleted 2025/09/17 06:25:57 NOTICE: (31) : test bisync run 2025/09/17 06:25:57 NOTICE: (32) : bisync 2025/09/17 06:26:00 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/changes/path1': Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/17 06:26:00 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/17 06:26:00 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/09/17 06:26:00 INFO : Synching Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/" with Path2 "/tmp/061330ba/changes/path2/" 2025/09/17 06:26:00 INFO : Building Path1 and Path2 listings 2025/09/17 06:26:01 INFO : Path1 checking for diffs 2025/09/17 06:26:01 INFO : - Path1 File changed: size (larger), time (newer) - file2.txt 2025/09/17 06:26:01 INFO : - Path1 File was deleted - file4.txt 2025/09/17 06:26:01 INFO : - Path1 File changed: size (larger), time (newer) - file5.txt 2025/09/17 06:26:01 INFO : - Path1 File was deleted - file6.txt 2025/09/17 06:26:01 INFO : - Path1 File changed: size (larger), time (newer) - file7.txt 2025/09/17 06:26:01 INFO : - Path1 File was deleted - file8.txt 2025/09/17 06:26:01 INFO : - Path1 File is new - file11.txt 2025/09/17 06:26:01 INFO : Path1: 7 changes:  1 new,  3 modified,  3 deleted 2025/09/17 06:26:01 INFO : (Modified:  3 newer,  0 older,  3 larger,  0 smaller) 2025/09/17 06:26:01 INFO : Path2 checking for diffs 2025/09/17 06:26:01 INFO : - Path2 File changed: size (larger), time (newer) - file1.txt 2025/09/17 06:26:01 INFO : - Path2 File was deleted - file3.txt 2025/09/17 06:26:01 INFO : - Path2 File changed: size (larger), time (newer) - file5.txt 2025/09/17 06:26:01 INFO : - Path2 File changed: size (larger), time (newer) - file6.txt 2025/09/17 06:26:01 INFO : - Path2 File was deleted - file7.txt 2025/09/17 06:26:01 INFO : - Path2 File was deleted - file8.txt 2025/09/17 06:26:01 INFO : - Path2 File is new - file10.txt 2025/09/17 06:26:01 INFO : Path2: 7 changes:  1 new,  3 modified,  3 deleted 2025/09/17 06:26:01 INFO : (Modified:  3 newer,  0 older,  3 larger,  0 smaller) 2025/09/17 06:26:01 INFO : Applying changes 2025/09/17 06:26:01 INFO : Checking potential conflicts... 2025/09/17 06:26:01 ERROR : file5.txt: md5 differ 2025/09/17 06:26:01 NOTICE: Local file system at /tmp/061330ba/changes/path2: 1 differences found 2025/09/17 06:26:01 NOTICE: Local file system at /tmp/061330ba/changes/path2: 1 errors while checking 2025/09/17 06:26:01 INFO : Finished checking the potential conflicts. 1 differences found 2025/09/17 06:26:01 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/changes/path2/file11.txt 2025/09/17 06:26:01 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/changes/path2/file2.txt 2025/09/17 06:26:01 INFO : - Path2 Queue delete - /tmp/061330ba/changes/path2/file4.txt 2025/09/17 06:26:01 NOTICE: - WARNING New or changed in both paths - file5.txt 2025/09/17 06:26:01 NOTICE: - Path1 Renaming Path1 copy - TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/file5.txt.conflict1 2025/09/17 06:26:02 INFO : file5.txt: Moved (server-side) to: file5.txt.conflict1 2025/09/17 06:26:02 NOTICE: - Path1 Queue copy to Path2 - /tmp/061330ba/changes/path2/file5.txt.conflict1 2025/09/17 06:26:02 NOTICE: - Path2 Renaming Path2 copy - /tmp/061330ba/changes/path2/file5.txt.conflict2 2025/09/17 06:26:02 INFO : file5.txt: Moved (server-side) to: file5.txt.conflict2 2025/09/17 06:26:02 NOTICE: - Path2 Queue copy to Path1 - TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/file5.txt.conflict2 2025/09/17 06:26:02 INFO : - Path2 Queue copy to Path1 - TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/file6.txt 2025/09/17 06:26:02 INFO : - Path1 Queue copy to Path2 - /tmp/061330ba/changes/path2/file7.txt 2025/09/17 06:26:02 INFO : - Path2 Queue copy to Path1 - TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/file1.txt 2025/09/17 06:26:02 INFO : - Path2 Queue copy to Path1 - TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/file10.txt 2025/09/17 06:26:02 INFO : - Path1 Queue delete - TestUlozto:rclone-test-bexobab3hohu/061330ba/changes/path1/file3.txt 2025/09/17 06:26:02 INFO : - Path2 Do queued copies to - Path1 2025/09/17 06:26:03 INFO : file1.txt: Copied (replaced existing) 2025/09/17 06:26:03 INFO : file5.txt.conflict2: Copied (new) 2025/09/17 06:26:03 INFO : file10.txt: Copied (new) 2025/09/17 06:26:03 INFO : file6.txt: Copied (new) 2025/09/17 06:26:03 INFO : file3.txt: Deleted 2025/09/17 06:26:03 INFO : - Path1 Do queued copies to - Path2 2025/09/17 06:26:05 INFO : file2.txt: Copied (replaced existing) 2025/09/17 06:36:12 ERROR : file11.txt: Failed to copy: failed to open source object: HTTP error 400 (400 Bad Request) returned body: "\n\n\n \n Ulož.to Disk - Platnost odkazu na stránku vypršela\n \n \n \n \n\n\n\n
\n
\n \n \n \n \n \n \n \n \n \n
\n
\n\n
\n
\n\t\n\t

Platnost odkazu na stránku vypršela

\n

\n

Link to the page has expired

\n\t\n
\n
\n\n \n\n\n\n\n\n" 2025/09/17 06:36:16 ERROR : file7.txt: Failed to copy: failed to open source object: HTTP error 400 (400 Bad Request) returned body: "\n\n\n \n Ulož.to Disk - Platnost odkazu na stránku vypršela\n \n \n \n \n\n\n\n
\n
\n \n \n \n \n \n \n \n \n \n
\n
\n\n
\n
\n\t\n\t

Platnost odkazu na stránku vypršela

\n

\n

Link to the page has expired

\n\t\n
\n
\n\n \n\n\n\n\n\n" 2025/09/17 07:12:39 INFO : file5.txt.conflict1: Copied (new) 2025/09/17 07:12:39 ERROR : Local file system at /tmp/061330ba/changes/path2: not deleting files as there were IO errors 2025/09/17 07:12:39 ERROR : Local file system at /tmp/061330ba/changes/path2: not deleting directories as there were IO errors 2025/09/17 07:12:39 ERROR : Bisync critical error: failed to open source object: HTTP error 400 (400 Bad Request) returned body: "\n\n\n \n Ulož.to Disk - Platnost odkazu na stránku vypršela\n \n \n \n \n\n\n\n
\n
\n \n \n \n \n \n \n \n \n \n
\n
\n\n
\n
\n\t\n\t

Platnost odkazu na stránku vypršela

\n

\n

Link to the page has expired

\n\t\n
\n
\n\n \n\n\n\n\n\n" 2025/09/17 07:12:39 ERROR : Bisync aborted. Must run --resync to recover. 2025/09/17 07:12:39 NOTICE: Bisync error: bisync aborted 2025/09/17 07:12:39 NOTICE: ---------------------------------------------------------- 2025/09/17 07:12:39 NOTICE: MISCOMPARE - Number of Golden and Results files do not match: 2025/09/17 07:12:39 NOTICE: Golden count: 11 2025/09/17 07:12:39 NOTICE: Result count: 7 2025/09/17 07:12:39 NOTICE: Golden files: _testdir_path1.._testdir_path2.copy1to2.que, _testdir_path1.._testdir_path2.copy2to1.que, _testdir_path1.._testdir_path2.delete1.que, _testdir_path1.._testdir_path2.delete2.que, _testdir_path1.._testdir_path2.path1.lst, _testdir_path1.._testdir_path2.path1.lst-new, _testdir_path1.._testdir_path2.path1.lst-old, _testdir_path1.._testdir_path2.path2.lst, _testdir_path1.._testdir_path2.path2.lst-new, _testdir_path1.._testdir_path2.path2.lst-old, test.log 2025/09/17 07:12:39 NOTICE: Result files: _testdir_path1.._testdir_path2.copy1to2.que, _testdir_path1.._testdir_path2.copy2to1.que, _testdir_path1.._testdir_path2.path1.lst-err, _testdir_path1.._testdir_path2.path1.lst-new, _testdir_path1.._testdir_path2.path2.lst-err, _testdir_path1.._testdir_path2.path2.lst-new, test.log 2025/09/17 07:12:39 NOTICE: File found in Golden but not in Results: _testdir_path1.._testdir_path2.delete1.que 2025/09/17 07:12:39 NOTICE: File found in Golden but not in Results: _testdir_path1.._testdir_path2.delete2.que 2025/09/17 07:12:39 NOTICE: File found in Golden but not in Results: _testdir_path1.._testdir_path2.path1.lst 2025/09/17 07:12:39 NOTICE: File found in Golden but not in Results: _testdir_path1.._testdir_path2.path1.lst-old 2025/09/17 07:12:39 NOTICE: File found in Golden but not in Results: _testdir_path1.._testdir_path2.path2.lst 2025/09/17 07:12:39 NOTICE: File found in Golden but not in Results: _testdir_path1.._testdir_path2.path2.lst-old 2025/09/17 07:12:39 NOTICE: File found in Results but not in Golden: _testdir_path1.._testdir_path2.path1.lst-err 2025/09/17 07:12:39 NOTICE: File found in Results but not in Golden: _testdir_path1.._testdir_path2.path2.lst-err 2025/09/17 07:12:39 NOTICE: ---------------------------------------------------------- 2025/09/17 07:12:39 NOTICE: | MISCOMPARE -Golden vs +Results for test.log 2025/09/17 07:12:39 NOTICE: | @@ -105,3 +105,7 @@ 2025/09/17 07:12:39 NOTICE: | -INFO : Updating listings 2025/09/17 07:12:39 NOTICE: | -INFO : Validating listings for Path1 "{path1/}" vs Path2 "{path2/}" 2025/09/17 07:12:39 NOTICE: | -INFO : Bisync successful 2025/09/17 07:12:39 NOTICE: | +ERROR : file11.txt: Failed to copy: failed to open source object: HTTP error 400 (400 Bad Request) returned body: "\n\n\n \n Ulož.to Disk - Platnost odkazu na stránku vypršela\n \n \n \n \n\n\n\n
\n
\n \n \n \n \n \n \n \n \n \n
\n
\n\n
\n
\n\t\n\t

Platnost odkazu na stránku vypršela

\n

\n

Link to the page has expired

\n\t\n
\n
\n\n \n\n\n\n\n\n" 2025/09/17 07:12:39 NOTICE: | +ERROR : file7.txt: Failed to copy: failed to open source object: HTTP error 400 (400 Bad Request) returned body: "\n\n\n \n Ulož.to Disk - Platnost odkazu na stránku vypršela\n \n \n \n \n\n\n\n
\n
\n \n \n \n \n \n \n \n \n \n
\n
\n\n
\n
\n\t\n\t

Platnost odkazu na stránku vypršela

\n

\n

Link to the page has expired

\n\t\n
\n
\n\n \n\n\n\n\n\n" 2025/09/17 07:12:39 NOTICE: | +ERROR : {path2String}: not deleting files as there were IO errors 2025/09/17 07:12:39 NOTICE: | +ERROR : {path2String}: not deleting directories as there were IO errors 2025/09/17 07:12:39 NOTICE: | +ERROR : Bisync critical error: failed to open source object: HTTP error 400 (400 Bad Request) returned body: "\n\n\n \n Ulož.to Disk - Platnost odkazu na stránku vypršela\n \n \n \n \n\n\n\n
\n
\n \n \n \n \n \n \n \n \n \n
\n
\n\n
\n
\n\t\n\t

Platnost odkazu na stránku vypršela

\n

\n

Link to the page has expired

\n\t\n
\n
\n\n \n\n\n\n\n\n" 2025/09/17 07:12:39 NOTICE: | +ERROR : Bisync aborted. Must run --resync to recover. 2025/09/17 07:12:39 NOTICE: | +Bisync error: bisync aborted 2025/09/17 07:12:39 NOTICE: ---------------------------------------------------------- 2025/09/17 07:12:39 DEBUG : Waiting for deletions to finish 2025/09/17 07:12:39 DEBUG : pacer: Reducing sleep to 1.125s 2025/09/17 07:12:41 DEBUG : pacer: Reducing sleep to 843.75ms 2025/09/17 07:12:42 DEBUG : pacer: Reducing sleep to 632.8125ms 2025/09/17 07:12:43 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/09/17 07:12:43 DEBUG : pacer: Reducing sleep to 355.957031ms 2025/09/17 07:12:44 DEBUG : pacer: Reducing sleep to 266.967773ms 2025/09/17 07:12:44 DEBUG : pacer: Reducing sleep to 200.225829ms 2025/09/17 07:12:44 DEBUG : pacer: Reducing sleep to 150.169371ms 2025/09/17 07:12:45 DEBUG : pacer: Reducing sleep to 112.627028ms 2025/09/17 07:12:45 DEBUG : pacer: Reducing sleep to 84.470271ms 2025/09/17 07:12:45 DEBUG : pacer: Reducing sleep to 63.352703ms 2025/09/17 07:12:45 INFO : file11.txt: Deleted 2025/09/17 07:12:45 DEBUG : pacer: Reducing sleep to 47.514527ms 2025/09/17 07:12:45 INFO : file6.txt: Deleted 2025/09/17 07:12:45 DEBUG : pacer: Reducing sleep to 35.635895ms 2025/09/17 07:12:45 INFO : RCLONE_TEST: Deleted 2025/09/17 07:12:45 DEBUG : pacer: Reducing sleep to 26.726921ms 2025/09/17 07:12:45 INFO : file2.txt: Deleted 2025/09/17 07:12:45 DEBUG : pacer: Reducing sleep to 20.04519ms 2025/09/17 07:12:45 INFO : file1.txt: Deleted 2025/09/17 07:12:45 DEBUG : pacer: Reducing sleep to 15.033892ms 2025/09/17 07:12:45 INFO : file5.txt.conflict1: Deleted 2025/09/17 07:12:45 DEBUG : pacer: Reducing sleep to 11.275419ms 2025/09/17 07:12:45 INFO : file10.txt: Deleted 2025/09/17 07:12:45 DEBUG : pacer: Reducing sleep to 10ms 2025/09/17 07:12:45 INFO : file5.txt.conflict2: Deleted 2025/09/17 07:12:45 INFO : file7.txt: Deleted 2025/09/17 07:12:46 DEBUG : removing 1 level 0 directories 2025/09/17 07:12:46 INFO : uloz.to root 'rclone-test-bexobab3hohu/061330ba/changes/path1': Removing directory 2025/09/17 07:12:46 DEBUG : Waiting for deletions to finish 2025/09/17 07:12:46 INFO : file4.txt: Deleted 2025/09/17 07:12:46 INFO : file2.txt: Deleted 2025/09/17 07:12:46 INFO : file5.txt.conflict1: Deleted 2025/09/17 07:12:46 INFO : file1.txt: Deleted 2025/09/17 07:12:46 INFO : file10.txt: Deleted 2025/09/17 07:12:46 INFO : file5.txt.conflict2: Deleted 2025/09/17 07:12:46 INFO : file6.txt: Deleted 2025/09/17 07:12:46 INFO : RCLONE_TEST: Deleted 2025/09/17 07:12:46 DEBUG : removing 1 level 0 directories 2025/09/17 07:12:46 INFO : Local file system at /tmp/061330ba/changes/path2: Removing directory bisync_test.go:608: TEST changes FAILED - 9 MISCOMPARED FILES === RUN TestBisyncRemoteLocal/check_access 2025/09/17 07:12:46 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba" 2025/09/17 07:12:46 DEBUG : Config file has changed externally - reloading 2025/09/17 07:12:48 INFO : path1: Making directory 2025/09/17 07:12:49 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba/check_access/path1" 2025/09/17 07:12:51 DEBUG : Creating backend with remote "/tmp/061330ba" 2025/09/17 07:12:51 DEBUG : Creating backend with remote "/tmp/061330ba/check_access/path2" 2025/09/17 07:12:51 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access/initial" 2025/09/17 07:12:51 DEBUG : Creating backend with remote "/tmp/061330ba/initdir/test_check_access-sidiyuw0" 2025/09/17 07:12:51 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 07:12:51 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 07:12:51 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/17 07:12:51 DEBUG : file3.txt: Need to transfer - File not found at Destination 2025/09/17 07:12:51 DEBUG : file4.txt: Need to transfer - File not found at Destination 2025/09/17 07:12:51 DEBUG : subdir: Making directory with metadata 2025/09/17 07:12:51 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/17 07:12:51 DEBUG : Added delayed dir = "subdir", newDst=subdir 2025/09/17 07:12:51 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 07:12:51 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/09/17 07:12:51 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 07:12:51 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 07:12:51 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 07:12:51 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2025/09/17 07:12:51 INFO : RCLONE_TEST: Copied (new) 2025/09/17 07:12:51 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2025/09/17 07:12:51 INFO : file1.txt: Copied (new) 2025/09/17 07:12:51 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2025/09/17 07:12:51 DEBUG : Local file system at /tmp/061330ba/initdir/test_check_access-sidiyuw0: Waiting for checks to finish 2025/09/17 07:12:51 INFO : file2.txt: Copied (new) 2025/09/17 07:12:51 DEBUG : Local file system at /tmp/061330ba/initdir/test_check_access-sidiyuw0: Waiting for transfers to finish 2025/09/17 07:12:51 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 07:12:51 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 07:12:51 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2025/09/17 07:12:51 INFO : file3.txt: Copied (new) 2025/09/17 07:12:51 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: renamed to: subdir/RCLONE_TEST 2025/09/17 07:12:51 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 07:12:51 INFO : subdir/RCLONE_TEST: Copied (new) 2025/09/17 07:12:51 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2025/09/17 07:12:51 INFO : file4.txt: Copied (new) 2025/09/17 07:12:51 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 07:12:51 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2025/09/17 07:12:51 INFO : subdir/file20.txt: Copied (new) 2025/09/17 07:12:51 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 07:12:51 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access/modfiles" 2025/09/17 07:12:51 DEBUG : Creating backend with remote "/tmp/061330ba/datadir/test_check_access-nafiqoy3" 2025/09/17 07:12:51 DEBUG : hold.txt: Need to transfer - File not found at Destination 2025/09/17 07:12:51 DEBUG : Local file system at /tmp/061330ba/datadir/test_check_access-nafiqoy3: Waiting for checks to finish 2025/09/17 07:12:51 DEBUG : Local file system at /tmp/061330ba/datadir/test_check_access-nafiqoy3: Waiting for transfers to finish 2025/09/17 07:12:51 DEBUG : hold.txt: md5 = 628c2241b6ba4e313ef08bdfcf1cd964 OK 2025/09/17 07:12:51 DEBUG : hold.txt.83686dab.partial: renamed to: hold.txt 2025/09/17 07:12:51 INFO : hold.txt: Copied (new) 2025/09/17 07:12:51 DEBUG : Waiting for deletions to finish 2025/09/17 07:12:51 ERROR : error listing: directory not found 2025/09/17 07:12:52 ERROR : uloz.to root 'rclone-test-bexobab3hohu/061330ba/check_access/path1': Failed to list "": directory not found 2025/09/17 07:12:52 DEBUG : removing 1 level 0 directories 2025/09/17 07:12:52 INFO : uloz.to root 'rclone-test-bexobab3hohu/061330ba/check_access/path1': Removing directory 2025/09/17 07:12:52 ERROR : Failed to rmdir: directory not found 2025/09/17 07:12:52 DEBUG : Waiting for deletions to finish 2025/09/17 07:12:52 ERROR : error listing: directory not found 2025/09/17 07:12:52 ERROR : Local file system at /tmp/061330ba/check_access/path2: Failed to list "": directory not found 2025/09/17 07:12:52 DEBUG : removing 1 level 0 directories 2025/09/17 07:12:52 INFO : Local file system at /tmp/061330ba/check_access/path2: Removing directory 2025/09/17 07:12:52 ERROR : Failed to rmdir: stat /tmp/061330ba/check_access/path2: no such file or directory 2025/09/17 07:12:52 ERROR : error listing: directory not found 2025/09/17 07:12:52 ERROR : error listing: directory not found 2025/09/17 07:12:52 NOTICE: checking initFs Local file system at /tmp/061330ba/initdir/test_check_access-sidiyuw0 2025/09/17 07:12:53 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 07:12:53 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 07:12:53 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/17 07:12:53 DEBUG : file3.txt: Need to transfer - File not found at Destination 2025/09/17 07:12:53 DEBUG : file4.txt: Need to transfer - File not found at Destination 2025/09/17 07:12:53 INFO : subdir: Making directory 2025/09/17 07:12:54 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 07:12:54 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/09/17 07:12:54 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/check_access/path1': Waiting for checks to finish 2025/09/17 07:12:54 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/check_access/path1': Waiting for transfers to finish 2025/09/17 07:12:54 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 07:12:54 INFO : RCLONE_TEST: Copied (new) 2025/09/17 07:12:55 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 07:12:55 INFO : file1.txt: Copied (new) 2025/09/17 07:12:55 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 07:12:55 INFO : file2.txt: Copied (new) 2025/09/17 07:12:55 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 07:12:55 INFO : subdir/file20.txt: Copied (new) 2025/09/17 07:12:55 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 07:12:55 INFO : subdir/RCLONE_TEST: Copied (new) 2025/09/17 07:12:56 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 07:12:56 INFO : file3.txt: Copied (new) 2025/09/17 07:12:56 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 07:12:56 INFO : file4.txt: Copied (new) 2025/09/17 07:12:56 NOTICE: checking Path1 uloz.to root 'rclone-test-bexobab3hohu/061330ba/check_access/path1' 2025/09/17 07:12:57 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 07:12:57 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/17 07:12:57 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/17 07:12:57 DEBUG : file3.txt: Need to transfer - File not found at Destination 2025/09/17 07:12:57 DEBUG : file4.txt: Need to transfer - File not found at Destination 2025/09/17 07:12:57 DEBUG : subdir: Making directory with metadata 2025/09/17 07:12:57 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 07:12:57 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 07:12:57 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2025/09/17 07:12:57 INFO : file1.txt: Copied (new) 2025/09/17 07:12:57 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/17 07:12:57 DEBUG : Added delayed dir = "subdir", newDst=subdir 2025/09/17 07:12:57 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2025/09/17 07:12:57 INFO : file2.txt: Copied (new) 2025/09/17 07:12:57 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 07:12:57 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2025/09/17 07:12:57 INFO : file3.txt: Copied (new) 2025/09/17 07:12:57 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/17 07:12:57 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/09/17 07:12:57 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 07:12:57 DEBUG : Local file system at /tmp/061330ba/check_access/path2: Waiting for checks to finish 2025/09/17 07:12:57 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/17 07:12:57 DEBUG : Local file system at /tmp/061330ba/check_access/path2: Waiting for transfers to finish 2025/09/17 07:12:57 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2025/09/17 07:12:57 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2025/09/17 07:12:57 INFO : subdir/file20.txt: Copied (new) 2025/09/17 07:12:57 INFO : file4.txt: Copied (new) 2025/09/17 07:12:57 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 07:12:57 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2025/09/17 07:12:57 INFO : RCLONE_TEST: Copied (new) 2025/09/17 07:12:57 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/17 07:12:57 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: renamed to: subdir/RCLONE_TEST 2025/09/17 07:12:57 INFO : subdir/RCLONE_TEST: Copied (new) 2025/09/17 07:12:57 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 07:12:57 NOTICE: checking path2 Local file system at /tmp/061330ba/check_access/path2 2025/09/17 07:12:57 NOTICE: (01) : test check-access 2025/09/17 07:12:57 NOTICE: (02) : test initial bisync 2025/09/17 07:12:57 NOTICE: (03) : bisync resync 2025/09/17 07:13:00 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/check_access/path1': Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/17 07:13:00 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 07:13:00 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/17 07:13:00 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/09/17 07:13:00 INFO : Synching Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/check_access/path1/" with Path2 "/tmp/061330ba/check_access/path2/" 2025/09/17 07:13:00 INFO : Copying Path2 files to Path1 2025/09/17 07:13:00 INFO : - Path2 Resync is copying files to - Path1 2025/09/17 07:13:02 INFO : There was nothing to transfer 2025/09/17 07:13:02 INFO : - Path1 Resync is copying files to - Path2 2025/09/17 07:13:02 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 07:13:02 INFO : There was nothing to transfer 2025/09/17 07:13:02 INFO : Resync updating listings 2025/09/17 07:13:02 INFO : Validating listings for Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/check_access/path1/" vs Path2 "/tmp/061330ba/check_access/path2/" 2025/09/17 07:13:02 INFO : Bisync successful 2025/09/17 07:13:02 NOTICE: (04) : test 1. see that check-access passes with the initial setup 2025/09/17 07:13:02 NOTICE: (05) : bisync check-access 2025/09/17 07:13:06 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/check_access/path1': Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/17 07:13:06 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 07:13:06 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/17 07:13:06 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/09/17 07:13:06 INFO : Synching Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/check_access/path1/" with Path2 "/tmp/061330ba/check_access/path2/" 2025/09/17 07:13:06 INFO : Building Path1 and Path2 listings 2025/09/17 07:13:07 INFO : Path1 checking for diffs 2025/09/17 07:13:07 INFO : Path2 checking for diffs 2025/09/17 07:13:07 INFO : Checking access health 2025/09/17 07:13:07 INFO : Found 2 matching "RCLONE_TEST" files on both paths 2025/09/17 07:13:07 INFO : No changes found 2025/09/17 07:13:07 INFO : Updating listings 2025/09/17 07:13:07 INFO : Validating listings for Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/check_access/path1/" vs Path2 "/tmp/061330ba/check_access/path2/" 2025/09/17 07:13:07 INFO : Bisync successful 2025/09/17 07:13:07 NOTICE: (06) : test 2. delete the path2 subdir RCLONE_TEST and run sync. should fail critical. 2025/09/17 07:13:07 NOTICE: (07) : delete-file /tmp/061330ba/check_access/path2/subdir/RCLONE_TEST 2025/09/17 07:13:07 DEBUG : Creating backend with remote "/tmp/061330ba/check_access/path2/subdir/" 2025/09/17 07:13:07 DEBUG : fs cache: renaming cache item "/tmp/061330ba/check_access/path2/subdir/" to be canonical "/tmp/061330ba/check_access/path2/subdir" 2025/09/17 07:13:07 INFO : RCLONE_TEST: Deleted 2025/09/17 07:13:07 NOTICE: (08) : bisync check-access 2025/09/17 07:13:10 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/check_access/path1': Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/17 07:13:10 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 07:13:10 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/17 07:13:10 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/09/17 07:13:10 INFO : Synching Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/check_access/path1/" with Path2 "/tmp/061330ba/check_access/path2/" 2025/09/17 07:13:10 INFO : Building Path1 and Path2 listings 2025/09/17 07:13:10 INFO : Path1 checking for diffs 2025/09/17 07:13:10 INFO : Path2 checking for diffs 2025/09/17 07:13:10 INFO : - Path2 File was deleted - subdir/RCLONE_TEST 2025/09/17 07:13:10 INFO : Path2: 1 changes:  0 new,  0 modified,  1 deleted 2025/09/17 07:13:10 INFO : Checking access health 2025/09/17 07:13:10 ERROR : Access test failed: Path1 count 2, Path2 count 1 - RCLONE_TEST 2025/09/17 07:13:10 ERROR : -  Access test failed: Path1 file not found in Path2 - subdir/RCLONE_TEST 2025/09/17 07:13:10 ERROR : Bisync critical error: check file check failed 2025/09/17 07:13:10 ERROR : Bisync aborted. Must run --resync to recover. 2025/09/17 07:13:10 NOTICE: Bisync error: bisync aborted 2025/09/17 07:13:10 NOTICE: (09) : copy-listings path2-missing 2025/09/17 07:13:10 NOTICE: (10) : test 3. put the path2 subdir RCLONE_TEST back, resync. 2025/09/17 07:13:10 NOTICE: (11) : copy-file TestUlozto:rclone-test-bexobab3hohu/061330ba/check_access/path1/subdir/RCLONE_TEST /tmp/061330ba/check_access/path2/ 2025/09/17 07:13:10 DEBUG : copyFile "TestUlozto:rclone-test-bexobab3hohu/061330ba/check_access/path1/subdir/RCLONE_TEST" to "/tmp/061330ba/check_access/path2/" as "" 2025/09/17 07:13:10 DEBUG : Creating backend with remote "TestUlozto:rclone-test-bexobab3hohu/061330ba/check_access/path1/subdir/RCLONE_TEST" 2025/09/17 07:13:15 DEBUG : Creating backend with remote "/tmp/061330ba/check_access/path2/" 2025/09/17 07:13:15 DEBUG : operations.CopyFile "RCLONE_TEST" to "Local file system at /tmp/061330ba/check_access/path2" as "RCLONE_TEST" 2025/09/17 07:13:15 DEBUG : RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1µs) 2025/09/17 07:13:15 DEBUG : RCLONE_TEST: Unchanged skipping 2025/09/17 07:13:15 NOTICE: (12) : bisync resync 2025/09/17 07:13:18 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/check_access/path1': Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/17 07:13:18 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 07:13:18 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/17 07:13:18 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/09/17 07:13:18 INFO : Synching Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/check_access/path1/" with Path2 "/tmp/061330ba/check_access/path2/" 2025/09/17 07:13:18 INFO : Copying Path2 files to Path1 2025/09/17 07:13:18 INFO : - Path2 Resync is copying files to - Path1 2025/09/17 07:13:19 INFO : There was nothing to transfer 2025/09/17 07:13:19 INFO : - Path1 Resync is copying files to - Path2 2025/09/17 07:13:19 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 07:13:24 INFO : subdir/RCLONE_TEST: Copied (new) 2025/09/17 07:13:24 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/17 07:13:24 INFO : Resync updating listings 2025/09/17 07:13:24 INFO : Validating listings for Path1 "TestUlozto:rclone-test-bexobab3hohu/061330ba/check_access/path1/" vs Path2 "/tmp/061330ba/check_access/path2/" 2025/09/17 07:13:24 INFO : Bisync successful 2025/09/17 07:13:24 NOTICE: (13) : test 4. run sync with check-access. should pass. 2025/09/17 07:13:24 NOTICE: (14) : bisync check-access 2025/09/17 07:13:27 DEBUG : uloz.to root 'rclone-test-bexobab3hohu/061330ba/check_access/path1': Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/17 07:13:27 INFO : subdir: Set directory modification time (using SetModTime) panic: test timed out after 1h0m0s running tests: TestBisyncRemoteLocal (1h0m0s) TestBisyncRemoteLocal/check_access (41s) goroutine 7162 [running]: testing.(*M).startAlarm.func1() /usr/local/go/src/testing/testing.go:2484 +0x394 created by time.goFunc /usr/local/go/src/time/sleep.go:215 +0x2d goroutine 1 [chan receive, 60 minutes]: testing.(*T).Run(0xc0000e7340, {0x27eb191?, 0xc0007936e0?}, 0x2916c78) /usr/local/go/src/testing/testing.go:1859 +0x431 testing.runTests.func1(0xc0000e7340) /usr/local/go/src/testing/testing.go:2279 +0x37 testing.tRunner(0xc0000e7340, 0xc000793820) /usr/local/go/src/testing/testing.go:1792 +0xf4 testing.runTests(0xc00080f770, {0x407c7c0, 0x4, 0x4}, {0xee05c4887?, 0x40baac0?, 0x40baac0?}) /usr/local/go/src/testing/testing.go:2277 +0x4b4 testing.(*M).Run(0xc00067d4a0) /usr/local/go/src/testing/testing.go:2142 +0x64a github.com/rclone/rclone/fstest.TestMain(0xc00067d4a0) /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:69 +0xa5 github.com/rclone/rclone/cmd/bisync_test.TestMain(0xc00067d4a0) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:243 +0xf2 main.main() _testmain.go:55 +0xa8 goroutine 21 [syscall, 60 minutes]: os/signal.signal_recv() /usr/local/go/src/runtime/sigqueue.go:152 +0x29 os/signal.loop() /usr/local/go/src/os/signal/signal_unix.go:23 +0x13 created by os/signal.Notify.func1.1 in goroutine 1 /usr/local/go/src/os/signal/signal.go:152 +0x1f goroutine 22 [chan receive, 60 minutes]: github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler.func1() /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:24 +0x27 created by github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler in goroutine 1 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:21 +0xa7 goroutine 23 [chan receive, 60 minutes]: github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler.func1() /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:24 +0x27 created by github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler in goroutine 1 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:21 +0xa7 goroutine 6433 [IO wait]: internal/poll.runtime_pollWait(0x715a605cc6f0, 0x72) /usr/local/go/src/runtime/netpoll.go:351 +0x85 internal/poll.(*pollDesc).wait(0xc0001e5100?, 0xc000488d80?, 0x0) /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 internal/poll.(*pollDesc).waitRead(...) /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Read(0xc0001e5100, {0xc000488d80, 0xd80, 0xd80}) /usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a net.(*netFD).Read(0xc0001e5100, {0xc000488d80?, 0x2000?, 0x0?}) /usr/local/go/src/net/fd_posix.go:55 +0x25 net.(*conn).Read(0xc0005e81e0, {0xc000488d80?, 0x0?, 0x40d98c0?}) /usr/local/go/src/net/net.go:194 +0x45 github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc000b16a08, {0xc000488d80?, 0x715a6023b918?, 0x715aa82c8108?}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29 crypto/tls.(*atLeastReader).Read(0xc00080e8d0, {0xc000488d80?, 0x40e0bc0?, 0xc0008719d0?}) /usr/local/go/src/crypto/tls/conn.go:809 +0x3b bytes.(*Buffer).ReadFrom(0xc000bd6638, {0x2c480a0, 0xc00080e8d0}) /usr/local/go/src/bytes/buffer.go:211 +0x98 crypto/tls.(*Conn).readFromUntil(0xc000bd6388, {0x715a60289000, 0xc000b16a08}, 0x4426d4?) /usr/local/go/src/crypto/tls/conn.go:831 +0xde crypto/tls.(*Conn).readRecordOrCCS(0xc000bd6388, 0x0) /usr/local/go/src/crypto/tls/conn.go:629 +0x3cf crypto/tls.(*Conn).readRecord(...) /usr/local/go/src/crypto/tls/conn.go:591 crypto/tls.(*Conn).Read(0xc000bd6388, {0xc00095b000, 0x1000, 0xc000365860?}) /usr/local/go/src/crypto/tls/conn.go:1385 +0x145 net/http.(*persistConn).Read(0xc00037b7a0, {0xc00095b000?, 0x8106e5?, 0x2c44b80?}) /usr/local/go/src/net/http/transport.go:2122 +0x47 bufio.(*Reader).fill(0xc0009c2a80) /usr/local/go/src/bufio/bufio.go:113 +0x103 bufio.(*Reader).Peek(0xc0009c2a80, 0x1) /usr/local/go/src/bufio/bufio.go:152 +0x53 net/http.(*persistConn).readLoop(0xc00037b7a0) /usr/local/go/src/net/http/transport.go:2275 +0x172 created by net/http.(*Transport).dialConn in goroutine 6470 /usr/local/go/src/net/http/transport.go:1944 +0x174f goroutine 7152 [select]: github.com/rclone/rclone/fs/march.(*March).Run.func1() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:208 +0x149 created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 6052 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:205 +0x172 goroutine 6052 [sync.WaitGroup.Wait]: sync.runtime_SemacquireWaitGroup(0xc000d48ec0?) /usr/local/go/src/runtime/sema.go:110 +0x25 sync.(*WaitGroup).Wait(0xc0008d2c60?) /usr/local/go/src/sync/waitgroup.go:118 +0x48 github.com/rclone/rclone/fs/march.(*March).Run(0xc0008d2c60, {0x2c6e188, 0xc0003f8420}) /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:262 +0x385 github.com/rclone/rclone/cmd/bisync.(*bisyncRun).makeMarchListing(0xc0003e9008, {0x2c6e188, 0xc0003f8420}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/march.go:44 +0x293 github.com/rclone/rclone/cmd/bisync.(*bisyncRun).runLocked(0xc0003e9008, {0x2c6e188, 0xc0003f8420}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/operations.go:311 +0xd6a github.com/rclone/rclone/cmd/bisync.Bisync({0x2c6e188, 0xc0003f8420}, {0x2c86d10, 0xc000a9ad20}, {0x2c85650, 0xc00097dc80}, 0xc00006d0c8) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/operations.go:180 +0xa58 github.com/rclone/rclone/cmd/bisync_test.(*bisyncTest).runBisync.func3() /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:1218 +0x38 github.com/rclone/rclone/cmd/bisync/bilib.CaptureOutput(0xc00006d1e0) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bilib/output.go:22 +0xd4 github.com/rclone/rclone/cmd/bisync_test.(*bisyncTest).runBisync(0xc000002000, {0x2c6e188?, 0xc0003b6e70?}, {0xc000d48430, 0x1, 0xc000bff770?}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:1217 +0x12c5 github.com/rclone/rclone/cmd/bisync_test.(*bisyncTest).runTestStep(0xc000002000, {0x2c6e188, 0xc0003c05a0}, {0xc000aba3d8, 0x13}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:788 +0x3af github.com/rclone/rclone/cmd/bisync_test.(*bisyncTest).runTestCase-range1({0xc000890fe7, 0x13}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:542 +0x1ed github.com/rclone/rclone/cmd/bisync_test.(*bisyncTest).runTestCase.SplitSeq.splitSeq.func3(0xc000acb900) /usr/local/go/src/strings/iter.go:61 +0x8a github.com/rclone/rclone/cmd/bisync_test.(*bisyncTest).runTestCase(0xc000002000, {0x2c6e188, 0xc00028f4d0}, 0xc00039a8c0, {0xc0007b40dd, 0xc}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:525 +0x165b github.com/rclone/rclone/cmd/bisync_test.testBisync.func4(0xc00039a8c0) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:405 +0x234 testing.tRunner(0xc00039a8c0, 0xc000d40360) /usr/local/go/src/testing/testing.go:1792 +0xf4 created by testing.(*T).Run in goroutine 51 /usr/local/go/src/testing/testing.go:1851 +0x413 goroutine 82 [chan receive, 60 minutes]: github.com/rclone/rclone/lib/atexit.Register.func1.1() /home/rclone/go/src/github.com/rclone/rclone/lib/atexit/atexit.go:45 +0x29 created by github.com/rclone/rclone/lib/atexit.Register.func1 in goroutine 51 /home/rclone/go/src/github.com/rclone/rclone/lib/atexit/atexit.go:44 +0x68 goroutine 51 [chan receive]: testing.(*T).Run(0xc0000e7500, {0xc0007b40dd?, 0x2c33678?}, 0xc000d40360) /usr/local/go/src/testing/testing.go:1859 +0x431 github.com/rclone/rclone/cmd/bisync_test.testBisync({0x2c6e188, 0xc00028f4d0}, 0xc0000e7500, {0xc000849350, 0x23}, {0x0, 0x0}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:398 +0x94f github.com/rclone/rclone/cmd/bisync_test.TestBisyncRemoteLocal(0xc0000e7500) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:256 +0x175 testing.tRunner(0xc0000e7500, 0x2916c78) /usr/local/go/src/testing/testing.go:1792 +0xf4 created by testing.(*T).Run in goroutine 1 /usr/local/go/src/testing/testing.go:1851 +0x413 goroutine 5905 [select, 1 minutes]: net/http.(*persistConn).writeLoop(0xc000abc6c0) /usr/local/go/src/net/http/transport.go:2590 +0xe7 created by net/http.(*Transport).dialConn in goroutine 5919 /usr/local/go/src/net/http/transport.go:1945 +0x17a5 goroutine 2954 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc000799c20, {0x2c6e1c0, 0xc000bcefa0}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 2953 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 6556 [select]: net/http.(*persistConn).writeLoop(0xc0004f47e0) /usr/local/go/src/net/http/transport.go:2590 +0xe7 created by net/http.(*Transport).dialConn in goroutine 6549 /usr/local/go/src/net/http/transport.go:1945 +0x17a5 goroutine 7149 [select]: github.com/rclone/rclone/fs/march.(*March).Run.func1() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:208 +0x149 created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 6052 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:205 +0x172 goroutine 1260 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc00073b680, {0x2c6e1c0, 0xc000a042d0}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 1294 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 1191 [chan receive (nil chan), 59 minutes]: github.com/rclone/rclone/fs/march.(*March).Run.func2() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:257 +0x3c created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 83 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:255 +0x378 goroutine 7077 [IO wait]: internal/poll.runtime_pollWait(0x715a605cb8b8, 0x72) /usr/local/go/src/runtime/netpoll.go:351 +0x85 internal/poll.(*pollDesc).wait(0xc0007b0580?, 0xc00048a880?, 0x0) /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 internal/poll.(*pollDesc).waitRead(...) /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Read(0xc0007b0580, {0xc00048a880, 0xd80, 0xd80}) /usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a net.(*netFD).Read(0xc0007b0580, {0xc00048a880?, 0x1100000d7b?, 0x0?}) /usr/local/go/src/net/fd_posix.go:55 +0x25 net.(*conn).Read(0xc00008cd00, {0xc00048a880?, 0x0?, 0x40da4c0?}) /usr/local/go/src/net/net.go:194 +0x45 github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc000c21260, {0xc00048a880?, 0x715a6023a838?, 0x715aa82c8108?}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29 crypto/tls.(*atLeastReader).Read(0xc00087ec78, {0xc00048a880?, 0x40e0bc0?, 0xc0009369c8?}) /usr/local/go/src/crypto/tls/conn.go:809 +0x3b bytes.(*Buffer).ReadFrom(0xc0009c1b38, {0x2c480a0, 0xc00087ec78}) /usr/local/go/src/bytes/buffer.go:211 +0x98 crypto/tls.(*Conn).readFromUntil(0xc0009c1888, {0x715a60289000, 0xc000c21260}, 0x4426d4?) /usr/local/go/src/crypto/tls/conn.go:831 +0xde crypto/tls.(*Conn).readRecordOrCCS(0xc0009c1888, 0x0) /usr/local/go/src/crypto/tls/conn.go:629 +0x3cf crypto/tls.(*Conn).readRecord(...) /usr/local/go/src/crypto/tls/conn.go:591 crypto/tls.(*Conn).Read(0xc0009c1888, {0xc000de2000, 0x1000, 0xc000365860?}) /usr/local/go/src/crypto/tls/conn.go:1385 +0x145 net/http.(*persistConn).Read(0xc00037bb00, {0xc000de2000?, 0x8106e5?, 0x2c44b80?}) /usr/local/go/src/net/http/transport.go:2122 +0x47 bufio.(*Reader).fill(0xc000dde300) /usr/local/go/src/bufio/bufio.go:113 +0x103 bufio.(*Reader).Peek(0xc000dde300, 0x1) /usr/local/go/src/bufio/bufio.go:152 +0x53 net/http.(*persistConn).readLoop(0xc00037bb00) /usr/local/go/src/net/http/transport.go:2275 +0x172 created by net/http.(*Transport).dialConn in goroutine 7122 /usr/local/go/src/net/http/transport.go:1944 +0x174f goroutine 6429 [IO wait]: internal/poll.runtime_pollWait(0x715a605cbf48, 0x72) /usr/local/go/src/runtime/netpoll.go:351 +0x85 internal/poll.(*pollDesc).wait(0xc0000c8280?, 0xc000488000?, 0x0) /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 internal/poll.(*pollDesc).waitRead(...) /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Read(0xc0000c8280, {0xc000488000, 0xd80, 0xd80}) /usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a net.(*netFD).Read(0xc0000c8280, {0xc000488000?, 0xd7b?, 0xc000696c80?}) /usr/local/go/src/net/fd_posix.go:55 +0x25 net.(*conn).Read(0xc000b12260, {0xc000488000?, 0xc000488000?, 0x5?}) /usr/local/go/src/net/net.go:194 +0x45 github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc000694a80, {0xc000488000?, 0x715a6023b918?, 0x715aa82c8108?}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29 crypto/tls.(*atLeastReader).Read(0xc00080e7b0, {0xc000488000?, 0xd7b?, 0xc0008b69d0?}) /usr/local/go/src/crypto/tls/conn.go:809 +0x3b bytes.(*Buffer).ReadFrom(0xc000554638, {0x2c480a0, 0xc00080e7b0}) /usr/local/go/src/bytes/buffer.go:211 +0x98 crypto/tls.(*Conn).readFromUntil(0xc000554388, {0x715a60289000, 0xc000694a80}, 0x4426d4?) /usr/local/go/src/crypto/tls/conn.go:831 +0xde crypto/tls.(*Conn).readRecordOrCCS(0xc000554388, 0x0) /usr/local/go/src/crypto/tls/conn.go:629 +0x3cf crypto/tls.(*Conn).readRecord(...) /usr/local/go/src/crypto/tls/conn.go:591 crypto/tls.(*Conn).Read(0xc000554388, {0xc000daf000, 0x1000, 0xc000365860?}) /usr/local/go/src/crypto/tls/conn.go:1385 +0x145 net/http.(*persistConn).Read(0xc00037b680, {0xc000daf000?, 0x8106e5?, 0x2c44b80?}) /usr/local/go/src/net/http/transport.go:2122 +0x47 bufio.(*Reader).fill(0xc000c08720) /usr/local/go/src/bufio/bufio.go:113 +0x103 bufio.(*Reader).Peek(0xc000c08720, 0x1) /usr/local/go/src/bufio/bufio.go:152 +0x53 net/http.(*persistConn).readLoop(0xc00037b680) /usr/local/go/src/net/http/transport.go:2275 +0x172 created by net/http.(*Transport).dialConn in goroutine 6462 /usr/local/go/src/net/http/transport.go:1944 +0x174f goroutine 6949 [chan receive (nil chan)]: github.com/rclone/rclone/fs/march.(*March).Run.func2() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:257 +0x3c created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 6052 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:255 +0x378 goroutine 6070 [IO wait]: internal/poll.runtime_pollWait(0x715a601f6190, 0x72) /usr/local/go/src/runtime/netpoll.go:351 +0x85 internal/poll.(*pollDesc).wait(0xc0004c3100?, 0xc000990000?, 0x0) /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 internal/poll.(*pollDesc).waitRead(...) /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Read(0xc0004c3100, {0xc000990000, 0x1300, 0x1300}) /usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a net.(*netFD).Read(0xc0004c3100, {0xc000990000?, 0xfb7?, 0xc00051f580?}) /usr/local/go/src/net/fd_posix.go:55 +0x25 net.(*conn).Read(0xc000148850, {0xc000990000?, 0xc000990344?, 0x5?}) /usr/local/go/src/net/net.go:194 +0x45 github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc00080e5d0, {0xc000990000?, 0x715a60293738?, 0x715aa82c8108?}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29 crypto/tls.(*atLeastReader).Read(0xc000a9ff50, {0xc000990000?, 0xfb7?, 0x25cbbc0?}) /usr/local/go/src/crypto/tls/conn.go:809 +0x3b bytes.(*Buffer).ReadFrom(0xc00018c2b8, {0x2c480a0, 0xc000a9ff50}) /usr/local/go/src/bytes/buffer.go:211 +0x98 crypto/tls.(*Conn).readFromUntil(0xc00018c008, {0x715a60289000, 0xc00080e5d0}, 0x4426d4?) /usr/local/go/src/crypto/tls/conn.go:831 +0xde crypto/tls.(*Conn).readRecordOrCCS(0xc00018c008, 0x0) /usr/local/go/src/crypto/tls/conn.go:629 +0x3cf crypto/tls.(*Conn).readRecord(...) /usr/local/go/src/crypto/tls/conn.go:591 crypto/tls.(*Conn).Read(0xc00018c008, {0xc0009ae000, 0x1000, 0xc00009bca0?}) /usr/local/go/src/crypto/tls/conn.go:1385 +0x145 bufio.(*Reader).Read(0xc0004814a0, {0xc00085ad60, 0x9, 0x4026210?}) /usr/local/go/src/bufio/bufio.go:245 +0x197 io.ReadAtLeast({0x2c44d60, 0xc0004814a0}, {0xc00085ad60, 0x9, 0x9}, 0x9) /usr/local/go/src/io/io.go:335 +0x91 io.ReadFull(...) /usr/local/go/src/io/io.go:354 net/http.http2readFrameHeader({0xc00085ad60, 0x9, 0xc0003f9770?}, {0x2c44d60?, 0xc0004814a0?}) /usr/local/go/src/net/http/h2_bundle.go:1805 +0x65 net/http.(*http2Framer).ReadFrame(0xc00085ad20) /usr/local/go/src/net/http/h2_bundle.go:2072 +0x7d net/http.(*http2clientConnReadLoop).run(0xc00009bfa8) /usr/local/go/src/net/http/h2_bundle.go:9933 +0xda net/http.(*http2ClientConn).readLoop(0xc000d54380) /usr/local/go/src/net/http/h2_bundle.go:9812 +0x79 created by net/http.(*http2Transport).newClientConn in goroutine 6069 /usr/local/go/src/net/http/h2_bundle.go:8334 +0xde5 goroutine 7078 [select]: net/http.(*persistConn).writeLoop(0xc00037bb00) /usr/local/go/src/net/http/transport.go:2590 +0xe7 created by net/http.(*Transport).dialConn in goroutine 7122 /usr/local/go/src/net/http/transport.go:1945 +0x17a5 goroutine 1146 [chan receive (nil chan), 59 minutes]: github.com/rclone/rclone/fs/march.(*March).Run.func2() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:257 +0x3c created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 83 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:255 +0x378 goroutine 7151 [select]: github.com/rclone/rclone/fs/march.(*March).Run.func1() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:208 +0x149 created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 6052 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:205 +0x172 goroutine 4567 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc000ca3a40, {0x2c6e1c0, 0xc0005059f0}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 3431 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 4508 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc0006da780, {0x2c6e1c0, 0xc000be8320}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 3431 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 4513 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc0006da960, {0x2c6e1c0, 0xc000be8410}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 3431 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 986 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc00073b2c0, {0x2c6e1c0, 0xc000bcf270}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 985 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 1136 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc00073b4a0, {0x2c6e1c0, 0xc00067f310}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 1135 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 7157 [chan receive (nil chan)]: github.com/rclone/rclone/fs/march.(*March).Run.func2() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:257 +0x3c created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 6052 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:255 +0x378 goroutine 996 [chan receive (nil chan), 59 minutes]: github.com/rclone/rclone/fs/march.(*March).Run.func2() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:257 +0x3c created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 83 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:255 +0x378 goroutine 6871 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc000ca34a0, {0x2c6e1c0, 0xc00067f400}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 6052 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 6975 [IO wait]: internal/poll.runtime_pollWait(0x715a601f6a50, 0x72) /usr/local/go/src/runtime/netpoll.go:351 +0x85 internal/poll.(*pollDesc).wait(0xc0000c8b00?, 0xc000993900?, 0x0) /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 internal/poll.(*pollDesc).waitRead(...) /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Read(0xc0000c8b00, {0xc000993900, 0x1300, 0x1300}) /usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a net.(*netFD).Read(0xc0000c8b00, {0xc000993900?, 0xe90?, 0xc0002edb40?}) /usr/local/go/src/net/fd_posix.go:55 +0x25 net.(*conn).Read(0xc000b12b30, {0xc000993900?, 0xc000993d6b?, 0x5?}) /usr/local/go/src/net/net.go:194 +0x45 github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc000b17b00, {0xc000993900?, 0x715a605d0518?, 0x715aa82c85c0?}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29 crypto/tls.(*atLeastReader).Read(0xc000694ba0, {0xc000993900?, 0xe90?, 0x25cbbc0?}) /usr/local/go/src/crypto/tls/conn.go:809 +0x3b bytes.(*Buffer).ReadFrom(0xc000bd7b38, {0x2c480a0, 0xc000694ba0}) /usr/local/go/src/bytes/buffer.go:211 +0x98 crypto/tls.(*Conn).readFromUntil(0xc000bd7888, {0x715a60289000, 0xc000b17b00}, 0x4426d4?) /usr/local/go/src/crypto/tls/conn.go:831 +0xde crypto/tls.(*Conn).readRecordOrCCS(0xc000bd7888, 0x0) /usr/local/go/src/crypto/tls/conn.go:629 +0x3cf crypto/tls.(*Conn).readRecord(...) /usr/local/go/src/crypto/tls/conn.go:591 crypto/tls.(*Conn).Read(0xc000bd7888, {0xc000850000, 0x1000, 0xc000a43ca0?}) /usr/local/go/src/crypto/tls/conn.go:1385 +0x145 bufio.(*Reader).Read(0xc000d41860, {0xc0009bd540, 0x9, 0x4026210?}) /usr/local/go/src/bufio/bufio.go:245 +0x197 io.ReadAtLeast({0x2c44d60, 0xc000d41860}, {0xc0009bd540, 0x9, 0x9}, 0x9) /usr/local/go/src/io/io.go:335 +0x91 io.ReadFull(...) /usr/local/go/src/io/io.go:354 net/http.http2readFrameHeader({0xc0009bd540, 0x9, 0xc0003c1bc0?}, {0x2c44d60?, 0xc000d41860?}) /usr/local/go/src/net/http/h2_bundle.go:1805 +0x65 net/http.(*http2Framer).ReadFrame(0xc0009bd500) /usr/local/go/src/net/http/h2_bundle.go:2072 +0x7d net/http.(*http2clientConnReadLoop).run(0xc000a43fa8) /usr/local/go/src/net/http/h2_bundle.go:9933 +0xda net/http.(*http2ClientConn).readLoop(0xc0006c7c00) /usr/local/go/src/net/http/h2_bundle.go:9812 +0x79 created by net/http.(*http2Transport).newClientConn in goroutine 6974 /usr/local/go/src/net/http/h2_bundle.go:8334 +0xde5 goroutine 7161 [select]: net/http.(*http2clientStream).writeRequest(0xc000366c00, 0xc000d0b540, 0x0) /usr/local/go/src/net/http/h2_bundle.go:9044 +0xc05 net/http.(*http2clientStream).doRequest(0xc000366c00, 0xc0006008b0?, 0xc000860fa8?) /usr/local/go/src/net/http/h2_bundle.go:8901 +0x56 created by net/http.(*http2ClientConn).roundTrip in goroutine 7025 /usr/local/go/src/net/http/h2_bundle.go:8806 +0x419 goroutine 7105 [IO wait]: internal/poll.runtime_pollWait(0x715a605cc3a8, 0x72) /usr/local/go/src/runtime/netpoll.go:351 +0x85 internal/poll.(*pollDesc).wait(0xc0001e5380?, 0xc000764880?, 0x0) /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 internal/poll.(*pollDesc).waitRead(...) /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Read(0xc0001e5380, {0xc000764880, 0xd80, 0xd80}) /usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a net.(*netFD).Read(0xc0001e5380, {0xc000764880?, 0x479fb3?, 0xc000938958?}) /usr/local/go/src/net/fd_posix.go:55 +0x25 net.(*conn).Read(0xc00008cca8, {0xc000764880?, 0x17?, 0x479699?}) /usr/local/go/src/net/net.go:194 +0x45 github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc000c20ff0, {0xc000764880?, 0x715a60235178?, 0x715aa82c8a78?}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29 crypto/tls.(*atLeastReader).Read(0xc000ca06f0, {0xc000764880?, 0x47ebde?, 0xc000d0a500?}) /usr/local/go/src/crypto/tls/conn.go:809 +0x3b bytes.(*Buffer).ReadFrom(0xc0009c17b8, {0x2c480a0, 0xc000ca06f0}) /usr/local/go/src/bytes/buffer.go:211 +0x98 crypto/tls.(*Conn).readFromUntil(0xc0009c1508, {0x715a60289000, 0xc000c20ff0}, 0x4426d4?) /usr/local/go/src/crypto/tls/conn.go:831 +0xde crypto/tls.(*Conn).readRecordOrCCS(0xc0009c1508, 0x0) /usr/local/go/src/crypto/tls/conn.go:629 +0x3cf crypto/tls.(*Conn).readRecord(...) /usr/local/go/src/crypto/tls/conn.go:591 crypto/tls.(*Conn).Read(0xc0009c1508, {0xc000e70000, 0x1000, 0x1b?}) /usr/local/go/src/crypto/tls/conn.go:1385 +0x145 bufio.(*Reader).Read(0xc0006b3740, {0xc000cb8820, 0x9, 0xc000487880?}) /usr/local/go/src/bufio/bufio.go:245 +0x197 io.ReadAtLeast({0x2c44d60, 0xc0006b3740}, {0xc000cb8820, 0x9, 0x9}, 0x9) /usr/local/go/src/io/io.go:335 +0x91 io.ReadFull(...) /usr/local/go/src/io/io.go:354 net/http.http2readFrameHeader({0xc000cb8820, 0x9, 0xc000324f30?}, {0x2c44d60?, 0xc0006b3740?}) /usr/local/go/src/net/http/h2_bundle.go:1805 +0x65 net/http.(*http2Framer).ReadFrame(0xc000cb87e0) /usr/local/go/src/net/http/h2_bundle.go:2072 +0x7d net/http.(*http2clientConnReadLoop).run(0xc000938fa8) /usr/local/go/src/net/http/h2_bundle.go:9933 +0xda net/http.(*http2ClientConn).readLoop(0xc0000e6fc0) /usr/local/go/src/net/http/h2_bundle.go:9812 +0x79 created by net/http.(*http2Transport).newClientConn in goroutine 7104 /usr/local/go/src/net/http/h2_bundle.go:8334 +0xde5 goroutine 6769 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc000ca2b40, {0x2c6e1c0, 0xc000bcfea0}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 6768 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 838 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc00073ab40, {0x2c6e1c0, 0xc000504d70}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 837 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 4478 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc000d26d20, {0x2c6e1c0, 0xc000a045a0}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 3431 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 4492 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc000ca32c0, {0x2c6e1c0, 0xc000504fa0}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 3431 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 7155 [select]: github.com/rclone/rclone/fs/march.(*March).Run.func1() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:208 +0x149 created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 6052 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:205 +0x172 goroutine 1181 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc000798d20, {0x2c6e1c0, 0xc000bcec30}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 1180 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 4706 [chan receive (nil chan), 47 minutes]: github.com/rclone/rclone/fs/march.(*March).Run.func2() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:257 +0x3c created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 3431 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:255 +0x378 goroutine 6899 [chan receive (nil chan)]: github.com/rclone/rclone/fs/march.(*March).Run.func2() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:257 +0x3c created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 6052 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:255 +0x378 goroutine 5958 [IO wait]: internal/poll.runtime_pollWait(0x715a605cbe30, 0x72) /usr/local/go/src/runtime/netpoll.go:351 +0x85 internal/poll.(*pollDesc).wait(0xc0000c8800?, 0xc0001b1300?, 0x0) /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 internal/poll.(*pollDesc).waitRead(...) /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Read(0xc0000c8800, {0xc0001b1300, 0x1300, 0x1300}) /usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a net.(*netFD).Read(0xc0000c8800, {0xc0001b1300?, 0x27?, 0xc00009d958?}) /usr/local/go/src/net/fd_posix.go:55 +0x25 net.(*conn).Read(0xc0005e8058, {0xc0001b1300?, 0x4?, 0x5?}) /usr/local/go/src/net/net.go:194 +0x45 github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc000b16000, {0xc0001b1300?, 0x715a6023b918?, 0x715aa82c8f30?}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29 crypto/tls.(*atLeastReader).Read(0xc00080e5a0, {0xc0001b1300?, 0x7?, 0x0?}) /usr/local/go/src/crypto/tls/conn.go:809 +0x3b bytes.(*Buffer).ReadFrom(0xc000bd62b8, {0x2c480a0, 0xc00080e5a0}) /usr/local/go/src/bytes/buffer.go:211 +0x98 crypto/tls.(*Conn).readFromUntil(0xc000bd6008, {0x715a60289000, 0xc000b16000}, 0x4426d4?) /usr/local/go/src/crypto/tls/conn.go:831 +0xde crypto/tls.(*Conn).readRecordOrCCS(0xc000bd6008, 0x0) /usr/local/go/src/crypto/tls/conn.go:629 +0x3cf crypto/tls.(*Conn).readRecord(...) /usr/local/go/src/crypto/tls/conn.go:591 crypto/tls.(*Conn).Read(0xc000bd6008, {0xc0007ab000, 0x1000, 0x7?}) /usr/local/go/src/crypto/tls/conn.go:1385 +0x145 bufio.(*Reader).Read(0xc000c096e0, {0xc000be6900, 0x9, 0xc0009756c0?}) /usr/local/go/src/bufio/bufio.go:245 +0x197 io.ReadAtLeast({0x2c44d60, 0xc000c096e0}, {0xc000be6900, 0x9, 0x9}, 0x9) /usr/local/go/src/io/io.go:335 +0x91 io.ReadFull(...) /usr/local/go/src/io/io.go:354 net/http.http2readFrameHeader({0xc000be6900, 0x9, 0xc000fc16b0?}, {0x2c44d60?, 0xc000c096e0?}) /usr/local/go/src/net/http/h2_bundle.go:1805 +0x65 net/http.(*http2Framer).ReadFrame(0xc000be68c0) /usr/local/go/src/net/http/h2_bundle.go:2072 +0x7d net/http.(*http2clientConnReadLoop).run(0xc00009dfa8) /usr/local/go/src/net/http/h2_bundle.go:9933 +0xda net/http.(*http2ClientConn).readLoop(0xc000c108c0) /usr/local/go/src/net/http/h2_bundle.go:9812 +0x79 created by net/http.(*http2Transport).newClientConn in goroutine 5957 /usr/local/go/src/net/http/h2_bundle.go:8334 +0xde5 goroutine 3130 [chan receive (nil chan), 59 minutes]: github.com/rclone/rclone/fs/march.(*March).Run.func2() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:257 +0x3c created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 2171 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:255 +0x378 goroutine 6482 [select]: net/http.(*persistConn).writeLoop(0xc00037b7a0) /usr/local/go/src/net/http/transport.go:2590 +0xe7 created by net/http.(*Transport).dialConn in goroutine 6470 /usr/local/go/src/net/http/transport.go:1945 +0x17a5 goroutine 5904 [IO wait, 1 minutes]: internal/poll.runtime_pollWait(0x715a605cbc00, 0x72) /usr/local/go/src/runtime/netpoll.go:351 +0x85 internal/poll.(*pollDesc).wait(0xc0000c8300?, 0xc000762000?, 0x0) /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 internal/poll.(*pollDesc).waitRead(...) /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Read(0xc0000c8300, {0xc000762000, 0xd80, 0xd80}) /usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a net.(*netFD).Read(0xc0000c8300, {0xc000762000?, 0x2000?, 0x0?}) /usr/local/go/src/net/fd_posix.go:55 +0x25 net.(*conn).Read(0xc000b12060, {0xc000762000?, 0x0?, 0x5?}) /usr/local/go/src/net/net.go:194 +0x45 github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc000a9e060, {0xc000762000?, 0x715a605d2db8?, 0x715aa82c8108?}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29 crypto/tls.(*atLeastReader).Read(0xc000b16390, {0xc000762000?, 0x40e0bc0?, 0xc00009a9c8?}) /usr/local/go/src/crypto/tls/conn.go:809 +0x3b bytes.(*Buffer).ReadFrom(0xc000856638, {0x2c480a0, 0xc000b16390}) /usr/local/go/src/bytes/buffer.go:211 +0x98 crypto/tls.(*Conn).readFromUntil(0xc000856388, {0x715a60289000, 0xc000a9e060}, 0x4426d4?) /usr/local/go/src/crypto/tls/conn.go:831 +0xde crypto/tls.(*Conn).readRecordOrCCS(0xc000856388, 0x0) /usr/local/go/src/crypto/tls/conn.go:629 +0x3cf crypto/tls.(*Conn).readRecord(...) /usr/local/go/src/crypto/tls/conn.go:591 crypto/tls.(*Conn).Read(0xc000856388, {0xc000561000, 0x1000, 0xc000300b10?}) /usr/local/go/src/crypto/tls/conn.go:1385 +0x145 net/http.(*persistConn).Read(0xc000abc6c0, {0xc000561000?, 0x8106e5?, 0x2c44b80?}) /usr/local/go/src/net/http/transport.go:2122 +0x47 bufio.(*Reader).fill(0xc000c08840) /usr/local/go/src/bufio/bufio.go:113 +0x103 bufio.(*Reader).Peek(0xc000c08840, 0x1) /usr/local/go/src/bufio/bufio.go:152 +0x53 net/http.(*persistConn).readLoop(0xc000abc6c0) /usr/local/go/src/net/http/transport.go:2275 +0x172 created by net/http.(*Transport).dialConn in goroutine 5919 /usr/local/go/src/net/http/transport.go:1944 +0x174f goroutine 7156 [select]: github.com/rclone/rclone/fs/march.(*March).Run.func1() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:208 +0x149 created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 6052 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:205 +0x172 goroutine 7153 [chan receive]: github.com/rclone/rclone/fs/march.(*March).matchListings(0xc0008d2c60, 0xc000423ab0, 0xc000423b20, 0xc0009f5de8, 0xc0009f5d98, 0xc0009f5d48) /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:316 +0x1af github.com/rclone/rclone/fs/march.(*March).processJob(0xc0008d2c60, {{0xc000a127c8, 0x6}, {0xc000a81480, 0x6}, 0x7ffffffd, 0x7ffffffd, 0x0, 0x0}) /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:493 +0x61b github.com/rclone/rclone/fs/march.(*March).Run.func1() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:215 +0x1e5 created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 6052 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:205 +0x172 goroutine 6080 [IO wait]: internal/poll.runtime_pollWait(0x715a605cc5d8, 0x72) /usr/local/go/src/runtime/netpoll.go:351 +0x85 internal/poll.(*pollDesc).wait(0xc0004c3500?, 0xc000992600?, 0x0) /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 internal/poll.(*pollDesc).waitRead(...) /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Read(0xc0004c3500, {0xc000992600, 0x1300, 0x1300}) /usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a net.(*netFD).Read(0xc0004c3500, {0xc000992600?, 0x12fb?, 0xc000438280?}) /usr/local/go/src/net/fd_posix.go:55 +0x25 net.(*conn).Read(0xc000148a48, {0xc000992600?, 0xc000992600?, 0x5?}) /usr/local/go/src/net/net.go:194 +0x45 github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc00080eac8, {0xc000992600?, 0x715a6023a838?, 0x715aa82c85c0?}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29 crypto/tls.(*atLeastReader).Read(0xc00087e528, {0xc000992600?, 0x12fb?, 0x41e9b1?}) /usr/local/go/src/crypto/tls/conn.go:809 +0x3b bytes.(*Buffer).ReadFrom(0xc0005542b8, {0x2c480a0, 0xc00087e528}) /usr/local/go/src/bytes/buffer.go:211 +0x98 crypto/tls.(*Conn).readFromUntil(0xc000554008, {0x715a60289000, 0xc00080eac8}, 0x4426d4?) /usr/local/go/src/crypto/tls/conn.go:831 +0xde crypto/tls.(*Conn).readRecordOrCCS(0xc000554008, 0x0) /usr/local/go/src/crypto/tls/conn.go:629 +0x3cf crypto/tls.(*Conn).readRecord(...) /usr/local/go/src/crypto/tls/conn.go:591 crypto/tls.(*Conn).Read(0xc000554008, {0xc0009e7000, 0x1000, 0xc0008e3ca0?}) /usr/local/go/src/crypto/tls/conn.go:1385 +0x145 bufio.(*Reader).Read(0xc000b097a0, {0xc00085b540, 0x9, 0x4026210?}) /usr/local/go/src/bufio/bufio.go:245 +0x197 io.ReadAtLeast({0x2c44d60, 0xc000b097a0}, {0xc00085b540, 0x9, 0x9}, 0x9) /usr/local/go/src/io/io.go:335 +0x91 io.ReadFull(...) /usr/local/go/src/io/io.go:354 net/http.http2readFrameHeader({0xc00085b540, 0x9, 0xc00028fa40?}, {0x2c44d60?, 0xc000b097a0?}) /usr/local/go/src/net/http/h2_bundle.go:1805 +0x65 net/http.(*http2Framer).ReadFrame(0xc00085b500) /usr/local/go/src/net/http/h2_bundle.go:2072 +0x7d net/http.(*http2clientConnReadLoop).run(0xc0008e3fa8) /usr/local/go/src/net/http/h2_bundle.go:9933 +0xda net/http.(*http2ClientConn).readLoop(0xc000d54540) /usr/local/go/src/net/http/h2_bundle.go:9812 +0x79 created by net/http.(*http2Transport).newClientConn in goroutine 6079 /usr/local/go/src/net/http/h2_bundle.go:8334 +0xde5 goroutine 7025 [select]: net/http.(*http2ClientConn).roundTrip(0xc000d54540, 0xc000d0b540, 0x0) /usr/local/go/src/net/http/h2_bundle.go:8870 +0x4d3 net/http.(*http2ClientConn).RoundTrip(...) /usr/local/go/src/net/http/h2_bundle.go:8767 net/http.(*http2Transport).RoundTripOpt(0xc000a9adc0, 0xc000d0b540, {0xa0?, 0x3e?}) /usr/local/go/src/net/http/h2_bundle.go:8063 +0x1ec net/http.(*http2Transport).RoundTrip(...) /usr/local/go/src/net/http/h2_bundle.go:8014 net/http.http2noDialH2RoundTripper.RoundTrip({0xc000b2f040?}, 0xc000d0b540?) /usr/local/go/src/net/http/h2_bundle.go:10872 +0x1c net/http.(*Transport).roundTrip(0xc000b2f040, 0xc000d0b540) /usr/local/go/src/net/http/transport.go:615 +0x497 net/http.(*Transport).RoundTrip(...) /usr/local/go/src/net/http/roundtrip.go:30 github.com/rclone/rclone/fs/fshttp.(*Transport).RoundTrip(0xc0000b4cc0, 0xc000d0b540) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:496 +0x345 net/http.send(0xc000d0b540, {0x2c469a0, 0xc0000b4cc0}, {0x6fe101?, 0x41d41e?, 0x0?}) /usr/local/go/src/net/http/client.go:259 +0x5e2 net/http.(*Client).send(0xc0003650e0, 0xc000d0b540, {0x715aa82c8108?, 0xa?, 0x0?}) /usr/local/go/src/net/http/client.go:180 +0x91 net/http.(*Client).do(0xc0003650e0, 0xc000d0b540) /usr/local/go/src/net/http/client.go:728 +0x989 net/http.(*Client).Do(...) /usr/local/go/src/net/http/client.go:587 github.com/rclone/rclone/lib/rest.(*Client).Call(0xc000be8d70, {0x2c6e188, 0xc0003f8420}, 0xc000d0b400) /home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:353 +0xd67 github.com/rclone/rclone/lib/rest.(*Client).callCodec(0xc000be8d70, {0x2c6e188, 0xc0003f8420}, 0xc000d0b400?, {0x0?, 0x0?}, {0x21a94e0, 0xc000b123c0}, 0x2918400?, 0x2918428, ...) /home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:550 +0x3f2 github.com/rclone/rclone/lib/rest.(*Client).CallJSON(...) /home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:493 github.com/rclone/rclone/backend/ulozto.(*Fs).fetchListFolderPage.func1() /home/rclone/go/src/github.com/rclone/rclone/backend/ulozto/ulozto.go:1160 +0x71 github.com/rclone/rclone/fs.pacerInvoker(0x1, 0xa, 0xc00008f808?) /home/rclone/go/src/github.com/rclone/rclone/fs/pacer.go:86 +0x32 github.com/rclone/rclone/lib/pacer.(*Pacer).call(0xc0000b5200, 0xc0003f9740, 0xa) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:199 +0x7c github.com/rclone/rclone/lib/pacer.(*Pacer).Call(0xc0000b5200, 0xc0003f9740) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:218 +0x93 github.com/rclone/rclone/backend/ulozto.(*Fs).fetchListFolderPage(0xc000a9ad20, {0x2c6e188, 0xc0003f8420}, {0xc000a12740, 0xc}, {0x0, 0x0}, 0x1f4, 0x0) /home/rclone/go/src/github.com/rclone/rclone/backend/ulozto/ulozto.go:1159 +0x5a9 github.com/rclone/rclone/backend/ulozto.(*Fs).listFolders(0xc000a9ad20, {0x2c6e188, 0xc0003f8420}, {0xc000a12740, 0xc}, {0x0, 0x0}) /home/rclone/go/src/github.com/rclone/rclone/backend/ulozto/ulozto.go:1185 +0x135 github.com/rclone/rclone/backend/ulozto.(*Fs).List(0xc000a9ad20, {0x2c6e188, 0xc0003f8420}, {0xc000a127c8, 0x6}) /home/rclone/go/src/github.com/rclone/rclone/backend/ulozto/ulozto.go:1106 +0x8f github.com/rclone/rclone/fs/list.listP({0x2c6e188, 0xc0003f8420}, {0x2c86d10, 0xc000a9ad20}, {0xc000a127c8, 0x6}, 0xc0008f8600) /home/rclone/go/src/github.com/rclone/rclone/fs/list/list.go:48 +0x6e github.com/rclone/rclone/fs/list.DirSortedFn({0x2c6e188, 0xc0003f8420}, {0x2c86d10, 0xc000a9ad20}, 0x0, {0xc000a127c8, 0x6}, 0xc000600a40, 0xc000600800) /home/rclone/go/src/github.com/rclone/rclone/fs/list/list.go:75 +0x257 github.com/rclone/rclone/fs/march.(*March).makeListDir.func1({0xc000a127c8, 0x6}, 0xc000600a40) /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:126 +0xb6 github.com/rclone/rclone/fs/march.(*March).processJob.func1() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:395 +0xbb created by github.com/rclone/rclone/fs/march.(*March).processJob in goroutine 7153 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:393 +0x20f goroutine 6430 [select]: net/http.(*persistConn).writeLoop(0xc00037b680) /usr/local/go/src/net/http/transport.go:2590 +0xe7 created by net/http.(*Transport).dialConn in goroutine 6462 /usr/local/go/src/net/http/transport.go:1945 +0x17a5 goroutine 7160 [sleep]: time.Sleep(0x989680) /usr/local/go/src/runtime/time.go:338 +0x165 github.com/rclone/rclone/lib/pacer.(*Pacer).beginCall.func1(0xc000a3e7a8?) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:169 +0x1c created by github.com/rclone/rclone/lib/pacer.(*Pacer).beginCall in goroutine 7025 /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:168 +0xef goroutine 6889 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc000ca30e0, {0x2c6e1c0, 0xc00067e500}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 6888 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 6446 [IO wait]: internal/poll.runtime_pollWait(0x715a605cc4c0, 0x72) /usr/local/go/src/runtime/netpoll.go:351 +0x85 internal/poll.(*pollDesc).wait(0xc0000c8600?, 0xc000762d80?, 0x0) /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 internal/poll.(*pollDesc).waitRead(...) /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Read(0xc0000c8600, {0xc000762d80, 0xd80, 0xd80}) /usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a net.(*netFD).Read(0xc0000c8600, {0xc000762d80?, 0xd7b?, 0xc000d49060?}) /usr/local/go/src/net/fd_posix.go:55 +0x25 net.(*conn).Read(0xc00008c3f0, {0xc000762d80?, 0xc000762d80?, 0x5?}) /usr/local/go/src/net/net.go:194 +0x45 github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc0008947e0, {0xc000762d80?, 0x715a60420628?, 0x715aa82c8a78?}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29 crypto/tls.(*atLeastReader).Read(0xc000a141f8, {0xc000762d80?, 0xd7b?, 0xc000a449d0?}) /usr/local/go/src/crypto/tls/conn.go:809 +0x3b bytes.(*Buffer).ReadFrom(0xc0008569b8, {0x2c480a0, 0xc000a141f8}) /usr/local/go/src/bytes/buffer.go:211 +0x98 crypto/tls.(*Conn).readFromUntil(0xc000856708, {0x715a60289000, 0xc0008947e0}, 0x4426d4?) /usr/local/go/src/crypto/tls/conn.go:831 +0xde crypto/tls.(*Conn).readRecordOrCCS(0xc000856708, 0x0) /usr/local/go/src/crypto/tls/conn.go:629 +0x3cf crypto/tls.(*Conn).readRecord(...) /usr/local/go/src/crypto/tls/conn.go:591 crypto/tls.(*Conn).Read(0xc000856708, {0xc0007b9000, 0x1000, 0xc000365860?}) /usr/local/go/src/crypto/tls/conn.go:1385 +0x145 net/http.(*persistConn).Read(0xc00037b8c0, {0xc0007b9000?, 0x8106e5?, 0x2c44b80?}) /usr/local/go/src/net/http/transport.go:2122 +0x47 bufio.(*Reader).fill(0xc0000b4960) /usr/local/go/src/bufio/bufio.go:113 +0x103 bufio.(*Reader).Peek(0xc0000b4960, 0x1) /usr/local/go/src/bufio/bufio.go:152 +0x53 net/http.(*persistConn).readLoop(0xc00037b8c0) /usr/local/go/src/net/http/transport.go:2275 +0x172 created by net/http.(*Transport).dialConn in goroutine 6479 /usr/local/go/src/net/http/transport.go:1944 +0x174f goroutine 3395 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc000ca21e0, {0x2c6e1c0, 0xc000bce410}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 3380 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 7150 [select]: github.com/rclone/rclone/fs/march.(*March).Run.func1() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:208 +0x149 created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 6052 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:205 +0x172 goroutine 4693 [chan receive (nil chan), 47 minutes]: github.com/rclone/rclone/fs/march.(*March).Run.func2() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:257 +0x3c created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 3431 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:255 +0x378 goroutine 5960 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc000ca25a0, {0x2c6e1c0, 0xc000be8730}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 5971 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 6447 [select]: net/http.(*persistConn).writeLoop(0xc00037b8c0) /usr/local/go/src/net/http/transport.go:2590 +0xe7 created by net/http.(*Transport).dialConn in goroutine 6479 /usr/local/go/src/net/http/transport.go:1945 +0x17a5 goroutine 6939 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc000ca3680, {0x2c6e1c0, 0xc00067f9f0}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 6938 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 7147 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc0007990e0, {0x2c6e1c0, 0xc000fd18b0}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 7146 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 4344 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc0002e1c20, {0x2c6e1c0, 0xc000fd1e00}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 4343 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 4641 [select]: github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc0006db2c0, {0x2c6e1c0, 0xc000be8460}) /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145 created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 3431 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a goroutine 6555 [IO wait]: internal/poll.runtime_pollWait(0x715a601f62a8, 0x72) /usr/local/go/src/runtime/netpoll.go:351 +0x85 internal/poll.(*pollDesc).wait(0xc0007b0780?, 0xc000763b00?, 0x0) /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27 internal/poll.(*pollDesc).waitRead(...) /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 internal/poll.(*FD).Read(0xc0007b0780, {0xc000763b00, 0xd80, 0xd80}) /usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a net.(*netFD).Read(0xc0007b0780, {0xc000763b00?, 0xd7b?, 0xc0002ec4e0?}) /usr/local/go/src/net/fd_posix.go:55 +0x25 net.(*conn).Read(0xc0005e8390, {0xc000763b00?, 0xc000763b00?, 0x5?}) /usr/local/go/src/net/net.go:194 +0x45 github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc000b17680, {0xc000763b00?, 0x715a602341d8?, 0x715aa82c8f30?}) /home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29 crypto/tls.(*atLeastReader).Read(0xc000895980, {0xc000763b00?, 0xd7b?, 0xc0008dc9d0?}) /usr/local/go/src/crypto/tls/conn.go:809 +0x3b bytes.(*Buffer).ReadFrom(0xc000bd69b8, {0x2c480a0, 0xc000895980}) /usr/local/go/src/bytes/buffer.go:211 +0x98 crypto/tls.(*Conn).readFromUntil(0xc000bd6708, {0x715a60289000, 0xc000b17680}, 0x4426d4?) /usr/local/go/src/crypto/tls/conn.go:831 +0xde crypto/tls.(*Conn).readRecordOrCCS(0xc000bd6708, 0x0) /usr/local/go/src/crypto/tls/conn.go:629 +0x3cf crypto/tls.(*Conn).readRecord(...) /usr/local/go/src/crypto/tls/conn.go:591 crypto/tls.(*Conn).Read(0xc000bd6708, {0xc000e4e000, 0x1000, 0xc000365860?}) /usr/local/go/src/crypto/tls/conn.go:1385 +0x145 net/http.(*persistConn).Read(0xc0004f47e0, {0xc000e4e000?, 0x8106e5?, 0x2c44b80?}) /usr/local/go/src/net/http/transport.go:2122 +0x47 bufio.(*Reader).fill(0xc0007b6540) /usr/local/go/src/bufio/bufio.go:113 +0x103 bufio.(*Reader).Peek(0xc0007b6540, 0x1) /usr/local/go/src/bufio/bufio.go:152 +0x53 net/http.(*persistConn).readLoop(0xc0004f47e0) /usr/local/go/src/net/http/transport.go:2275 +0x172 created by net/http.(*Transport).dialConn in goroutine 6549 /usr/local/go/src/net/http/transport.go:1944 +0x174f goroutine 7154 [select]: github.com/rclone/rclone/fs/march.(*March).Run.func1() /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:208 +0x149 created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 6052 /home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:205 +0x172 "./bisync.test -test.v -test.timeout 1h0m0s -remote TestUlozto: -verbose" - Finished ERROR in 1h0m2.493291388s (try 4/5): exit status 2: Failed []