"./bisync.test -test.v -test.timeout 1h0m0s -remote TestB2: -list-retries 5 -verbose -test.run '^TestBisyncLocalRemote$/^check_access_filters$|^TestBisyncRemoteRemote$/^resync$'" - Starting (try 3/5) 2025/09/18 05:46:53 DEBUG : Creating backend with remote "TestB2:rclone-test-davirix9toyu" 2025/09/18 05:46:53 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/09/18 05:46:53 DEBUG : Creating backend with remote "/tmp/rclone3048277901" === RUN TestBisyncLocalRemote 2025/09/18 05:46:53 DEBUG : Creating backend with remote "TestB2:rclone-test-jikujah1rova" 2025/09/18 05:46:54 NOTICE: remote: TestB2:rclone-test-jikujah1rova === RUN TestBisyncLocalRemote/check_access_filters 2025/09/18 05:46:54 DEBUG : Creating backend with remote "/tmp/054654pu" 2025/09/18 05:46:54 DEBUG : Creating backend with remote "/tmp/054654pu/check_access_filters/path1" 2025/09/18 05:46:54 DEBUG : Creating backend with remote "TestB2:rclone-test-jikujah1rova/054654pu" 2025/09/18 05:46:55 INFO : path2: Making directory 2025/09/18 05:46:56 DEBUG : Creating backend with remote "TestB2:rclone-test-jikujah1rova/054654pu/check_access_filters/path2" 2025/09/18 05:46:57 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access_filters/initial" 2025/09/18 05:46:57 DEBUG : Creating backend with remote "/tmp/054654pu/initdir/test_check_access_filters-fevukub5" 2025/09/18 05:46:57 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : file3.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : file4.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : subdir-not: Making directory with metadata 2025/09/18 05:46:57 INFO : subdir-not: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/18 05:46:57 DEBUG : Added delayed dir = "subdir-not", newDst=subdir-not 2025/09/18 05:46:57 DEBUG : subdir: Making directory with metadata 2025/09/18 05:46:57 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/18 05:46:57 DEBUG : Added delayed dir = "subdir", newDst=subdir 2025/09/18 05:46:57 DEBUG : subdirX: Making directory with metadata 2025/09/18 05:46:57 INFO : subdirX: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/18 05:46:57 DEBUG : Added delayed dir = "subdirX", newDst=subdirX 2025/09/18 05:46:57 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:57 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:57 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : subdirX/subdirX1: Making directory with metadata 2025/09/18 05:46:57 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2025/09/18 05:46:57 INFO : file1.txt: Copied (new) 2025/09/18 05:46:57 INFO : subdirX/subdirX1: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/18 05:46:57 DEBUG : Added delayed dir = "subdirX/subdirX1", newDst=subdirX/subdirX1 2025/09/18 05:46:57 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2025/09/18 05:46:57 INFO : file2.txt: Copied (new) 2025/09/18 05:46:57 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:57 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2025/09/18 05:46:57 INFO : file3.txt: Copied (new) 2025/09/18 05:46:57 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : subdir-not/subdir-not2: Making directory with metadata 2025/09/18 05:46:57 INFO : subdir-not/subdir-not2: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/18 05:46:57 DEBUG : Added delayed dir = "subdir-not/subdir-not2", newDst=subdir-not/subdir-not2 2025/09/18 05:46:57 DEBUG : subdirX/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:57 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:57 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2025/09/18 05:46:57 INFO : file4.txt: Copied (new) 2025/09/18 05:46:57 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : subdir/subdirA: Making directory with metadata 2025/09/18 05:46:57 DEBUG : subdirX/file20.txt.0c4add8a.partial: renamed to: subdirX/file20.txt 2025/09/18 05:46:57 INFO : subdirX/file20.txt: Copied (new) 2025/09/18 05:46:57 INFO : subdir/subdirA: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/18 05:46:57 DEBUG : Added delayed dir = "subdir/subdirA", newDst=subdir/subdirA 2025/09/18 05:46:57 DEBUG : subdir/subdirB: Making directory with metadata 2025/09/18 05:46:57 INFO : subdir/subdirB: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/18 05:46:57 DEBUG : Added delayed dir = "subdir/subdirB", newDst=subdir/subdirB 2025/09/18 05:46:57 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : Local file system at /tmp/054654pu/initdir/test_check_access_filters-fevukub5: Waiting for checks to finish 2025/09/18 05:46:57 DEBUG : Local file system at /tmp/054654pu/initdir/test_check_access_filters-fevukub5: Waiting for transfers to finish 2025/09/18 05:46:57 DEBUG : subdirX/subdirX1/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:57 DEBUG : subdirX/subdirX1/file30.txt.0106cff7.partial: renamed to: subdirX/subdirX1/file30.txt 2025/09/18 05:46:57 INFO : subdirX/subdirX1/file30.txt: Copied (new) 2025/09/18 05:46:57 DEBUG : subdirX/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:46:57 DEBUG : subdirX/RCLONE_TEST.fd5b40a2.partial: renamed to: subdirX/RCLONE_TEST 2025/09/18 05:46:57 INFO : subdirX/RCLONE_TEST: Copied (new) 2025/09/18 05:46:57 DEBUG : subdir-not/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:57 DEBUG : subdir-not/file20.txt.e2b8d4dd.partial: renamed to: subdir-not/file20.txt 2025/09/18 05:46:57 INFO : subdir-not/file20.txt: Copied (new) 2025/09/18 05:46:57 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:46:57 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.51791ac5.partial: renamed to: subdir-not/subdir-not2/RCLONE_TEST 2025/09/18 05:46:57 INFO : subdir-not/subdir-not2/RCLONE_TEST: Copied (new) 2025/09/18 05:46:57 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:46:57 DEBUG : subdir-not/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:46:57 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2025/09/18 05:46:57 INFO : RCLONE_TEST: Copied (new) 2025/09/18 05:46:57 DEBUG : subdir-not/subdir-not2/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:57 DEBUG : subdir-not/RCLONE_TEST.16d95000.partial: renamed to: subdir-not/RCLONE_TEST 2025/09/18 05:46:57 INFO : subdir-not/RCLONE_TEST: Copied (new) 2025/09/18 05:46:57 DEBUG : subdir-not/subdir-not2/file30.txt.e99a79ee.partial: renamed to: subdir-not/subdir-not2/file30.txt 2025/09/18 05:46:57 INFO : subdir-not/subdir-not2/file30.txt: Copied (new) 2025/09/18 05:46:57 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:57 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2025/09/18 05:46:57 INFO : subdir/file20.txt: Copied (new) 2025/09/18 05:46:57 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:46:57 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: renamed to: subdir/RCLONE_TEST 2025/09/18 05:46:57 INFO : subdir/RCLONE_TEST: Copied (new) 2025/09/18 05:46:57 DEBUG : subdir/subdirB/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:46:57 DEBUG : subdir/subdirB/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:57 DEBUG : subdir/subdirB/RCLONE_TEST.37da2e99.partial: renamed to: subdir/subdirB/RCLONE_TEST 2025/09/18 05:46:57 INFO : subdir/subdirB/RCLONE_TEST: Copied (new) 2025/09/18 05:46:57 DEBUG : subdirX/subdirX1/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:46:57 DEBUG : subdirX/subdirX1/RCLONE_TEST.09a85483.partial: renamed to: subdirX/subdirX1/RCLONE_TEST 2025/09/18 05:46:57 INFO : subdirX/subdirX1/RCLONE_TEST: Copied (new) 2025/09/18 05:46:57 DEBUG : subdir/subdirB/file30.txt.ca7c4d29.partial: renamed to: subdir/subdirB/file30.txt 2025/09/18 05:46:57 DEBUG : subdir/subdirA/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:46:57 INFO : subdir/subdirB/file30.txt: Copied (new) 2025/09/18 05:46:57 DEBUG : subdir/subdirA/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:57 DEBUG : subdir/subdirA/RCLONE_TEST.b780822c.partial: renamed to: subdir/subdirA/RCLONE_TEST 2025/09/18 05:46:57 INFO : subdir/subdirA/RCLONE_TEST: Copied (new) 2025/09/18 05:46:57 DEBUG : subdir/subdirA/file30.txt.03485624.partial: renamed to: subdir/subdirA/file30.txt 2025/09/18 05:46:57 INFO : subdir/subdirA/file30.txt: Copied (new) 2025/09/18 05:46:57 INFO : subdir/subdirB: Set directory modification time (using SetModTime) 2025/09/18 05:46:57 INFO : subdir-not/subdir-not2: Set directory modification time (using SetModTime) 2025/09/18 05:46:57 INFO : subdirX/subdirX1: Set directory modification time (using SetModTime) 2025/09/18 05:46:57 INFO : subdir/subdirA: Set directory modification time (using SetModTime) 2025/09/18 05:46:57 INFO : subdirX: Set directory modification time (using SetModTime) 2025/09/18 05:46:57 INFO : subdir-not: Set directory modification time (using SetModTime) 2025/09/18 05:46:57 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/18 05:46:57 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access_filters/modfiles" 2025/09/18 05:46:57 DEBUG : Creating backend with remote "/tmp/054654pu/datadir/test_check_access_filters-hexutel0" 2025/09/18 05:46:57 DEBUG : exclude-other-filtersfile.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : include-other-filtersfile.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:57 DEBUG : Local file system at /tmp/054654pu/datadir/test_check_access_filters-hexutel0: Waiting for checks to finish 2025/09/18 05:46:57 DEBUG : Local file system at /tmp/054654pu/datadir/test_check_access_filters-hexutel0: Waiting for transfers to finish 2025/09/18 05:46:57 DEBUG : exclude-other-filtersfile.txt: md5 = 5fcc6205d7df1c2e9ed3a15a1356b345 OK 2025/09/18 05:46:57 DEBUG : exclude-other-filtersfile.txt.955454a7.partial: renamed to: exclude-other-filtersfile.txt 2025/09/18 05:46:57 INFO : exclude-other-filtersfile.txt: Copied (new) 2025/09/18 05:46:57 DEBUG : include-other-filtersfile.txt: md5 = 2ec13b2813141ed088e5978ef5a47b0e OK 2025/09/18 05:46:57 DEBUG : include-other-filtersfile.txt.8126a844.partial: renamed to: include-other-filtersfile.txt 2025/09/18 05:46:57 INFO : include-other-filtersfile.txt: Copied (new) 2025/09/18 05:46:57 DEBUG : Waiting for deletions to finish 2025/09/18 05:46:57 ERROR : error listing: directory not found 2025/09/18 05:46:57 ERROR : Local file system at /tmp/054654pu/check_access_filters/path1: Failed to list "": directory not found 2025/09/18 05:46:57 DEBUG : removing 1 level 0 directories 2025/09/18 05:46:57 INFO : Local file system at /tmp/054654pu/check_access_filters/path1: Removing directory 2025/09/18 05:46:57 ERROR : Failed to rmdir: stat /tmp/054654pu/check_access_filters/path1: no such file or directory 2025/09/18 05:46:57 INFO : B2 bucket rclone-test-jikujah1rova path 054654pu/check_access_filters/path2: cleaning bucket "rclone-test-jikujah1rova" of all files 2025/09/18 05:46:58 ERROR : error listing: directory not found 2025/09/18 05:46:58 NOTICE: checking initFs Local file system at /tmp/054654pu/initdir/test_check_access_filters-fevukub5 2025/09/18 05:46:58 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : file3.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : file4.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdir-not: Making directory with metadata 2025/09/18 05:46:58 INFO : subdir-not: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/18 05:46:58 DEBUG : Added delayed dir = "subdir-not", newDst=subdir-not 2025/09/18 05:46:58 DEBUG : subdir: Making directory with metadata 2025/09/18 05:46:58 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/18 05:46:58 DEBUG : Added delayed dir = "subdir", newDst=subdir 2025/09/18 05:46:58 DEBUG : subdirX: Making directory with metadata 2025/09/18 05:46:58 INFO : subdirX: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/18 05:46:58 DEBUG : Added delayed dir = "subdirX", newDst=subdirX 2025/09/18 05:46:58 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdirX/subdirX1: Making directory with metadata 2025/09/18 05:46:58 INFO : subdirX/subdirX1: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/18 05:46:58 DEBUG : Added delayed dir = "subdirX/subdirX1", newDst=subdirX/subdirX1 2025/09/18 05:46:58 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:58 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdir-not/subdir-not2: Making directory with metadata 2025/09/18 05:46:58 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdir/subdirA: Making directory with metadata 2025/09/18 05:46:58 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2025/09/18 05:46:58 INFO : file3.txt: Copied (new) 2025/09/18 05:46:58 INFO : subdir-not/subdir-not2: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/18 05:46:58 INFO : subdir/subdirA: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/18 05:46:58 DEBUG : Added delayed dir = "subdir/subdirA", newDst=subdir/subdirA 2025/09/18 05:46:58 DEBUG : subdir/subdirB: Making directory with metadata 2025/09/18 05:46:58 DEBUG : Added delayed dir = "subdir-not/subdir-not2", newDst=subdir-not/subdir-not2 2025/09/18 05:46:58 INFO : subdir/subdirB: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/09/18 05:46:58 DEBUG : Added delayed dir = "subdir/subdirB", newDst=subdir/subdirB 2025/09/18 05:46:58 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:58 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:46:58 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2025/09/18 05:46:58 INFO : file2.txt: Copied (new) 2025/09/18 05:46:58 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:58 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2025/09/18 05:46:58 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2025/09/18 05:46:58 INFO : file1.txt: Copied (new) 2025/09/18 05:46:58 INFO : RCLONE_TEST: Copied (new) 2025/09/18 05:46:58 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdirX/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:58 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdirX/file20.txt.0c4add8a.partial: renamed to: subdirX/file20.txt 2025/09/18 05:46:58 INFO : subdirX/file20.txt: Copied (new) 2025/09/18 05:46:58 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:58 DEBUG : Local file system at /tmp/054654pu/check_access_filters/path1: Waiting for checks to finish 2025/09/18 05:46:58 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2025/09/18 05:46:58 INFO : file4.txt: Copied (new) 2025/09/18 05:46:58 DEBUG : Local file system at /tmp/054654pu/check_access_filters/path1: Waiting for transfers to finish 2025/09/18 05:46:58 DEBUG : subdirX/subdirX1/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:46:58 DEBUG : subdirX/subdirX1/RCLONE_TEST.09a85483.partial: renamed to: subdirX/subdirX1/RCLONE_TEST 2025/09/18 05:46:58 DEBUG : subdirX/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:46:58 INFO : subdirX/subdirX1/RCLONE_TEST: Copied (new) 2025/09/18 05:46:58 DEBUG : subdirX/subdirX1/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:58 DEBUG : subdirX/RCLONE_TEST.fd5b40a2.partial: renamed to: subdirX/RCLONE_TEST 2025/09/18 05:46:58 INFO : subdirX/RCLONE_TEST: Copied (new) 2025/09/18 05:46:58 DEBUG : subdirX/subdirX1/file30.txt.0106cff7.partial: renamed to: subdirX/subdirX1/file30.txt 2025/09/18 05:46:58 INFO : subdirX/subdirX1/file30.txt: Copied (new) 2025/09/18 05:46:58 DEBUG : subdir-not/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:58 DEBUG : subdir-not/file20.txt.e2b8d4dd.partial: renamed to: subdir-not/file20.txt 2025/09/18 05:46:58 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:58 INFO : subdir-not/file20.txt: Copied (new) 2025/09/18 05:46:58 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2025/09/18 05:46:58 INFO : subdir/file20.txt: Copied (new) 2025/09/18 05:46:58 DEBUG : subdir-not/subdir-not2/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:58 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:46:58 DEBUG : subdir-not/subdir-not2/file30.txt.e99a79ee.partial: renamed to: subdir-not/subdir-not2/file30.txt 2025/09/18 05:46:58 INFO : subdir-not/subdir-not2/file30.txt: Copied (new) 2025/09/18 05:46:58 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: renamed to: subdir/RCLONE_TEST 2025/09/18 05:46:58 INFO : subdir/RCLONE_TEST: Copied (new) 2025/09/18 05:46:58 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:46:58 DEBUG : subdir-not/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:46:58 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.51791ac5.partial: renamed to: subdir-not/subdir-not2/RCLONE_TEST 2025/09/18 05:46:58 INFO : subdir-not/subdir-not2/RCLONE_TEST: Copied (new) 2025/09/18 05:46:58 DEBUG : subdir/subdirB/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:58 DEBUG : subdir-not/RCLONE_TEST.16d95000.partial: renamed to: subdir-not/RCLONE_TEST 2025/09/18 05:46:58 INFO : subdir-not/RCLONE_TEST: Copied (new) 2025/09/18 05:46:58 DEBUG : subdir/subdirB/file30.txt.ca7c4d29.partial: renamed to: subdir/subdirB/file30.txt 2025/09/18 05:46:58 INFO : subdir/subdirB/file30.txt: Copied (new) 2025/09/18 05:46:58 DEBUG : subdir/subdirA/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:46:58 DEBUG : subdir/subdirA/file30.txt.03485624.partial: renamed to: subdir/subdirA/file30.txt 2025/09/18 05:46:58 INFO : subdir/subdirA/file30.txt: Copied (new) 2025/09/18 05:46:58 DEBUG : subdir/subdirB/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:46:58 DEBUG : subdir/subdirA/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:46:58 DEBUG : subdir/subdirB/RCLONE_TEST.37da2e99.partial: renamed to: subdir/subdirB/RCLONE_TEST 2025/09/18 05:46:58 DEBUG : subdir/subdirA/RCLONE_TEST.b780822c.partial: renamed to: subdir/subdirA/RCLONE_TEST 2025/09/18 05:46:58 INFO : subdir/subdirB/RCLONE_TEST: Copied (new) 2025/09/18 05:46:58 INFO : subdir/subdirA/RCLONE_TEST: Copied (new) 2025/09/18 05:46:58 INFO : subdir/subdirB: Set directory modification time (using SetModTime) 2025/09/18 05:46:58 INFO : subdirX/subdirX1: Set directory modification time (using SetModTime) 2025/09/18 05:46:58 INFO : subdir/subdirA: Set directory modification time (using SetModTime) 2025/09/18 05:46:58 INFO : subdir-not/subdir-not2: Set directory modification time (using SetModTime) 2025/09/18 05:46:58 INFO : subdirX: Set directory modification time (using SetModTime) 2025/09/18 05:46:58 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/18 05:46:58 INFO : subdir-not: Set directory modification time (using SetModTime) 2025/09/18 05:46:58 NOTICE: checking Path1 Local file system at /tmp/054654pu/check_access_filters/path1 2025/09/18 05:46:58 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : file3.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : file4.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 INFO : subdir-not: Making directory 2025/09/18 05:46:58 INFO : subdir: Making directory 2025/09/18 05:46:58 INFO : subdirX: Making directory 2025/09/18 05:46:58 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 INFO : subdirX/subdirX1: Making directory 2025/09/18 05:46:58 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 INFO : subdir-not/subdir-not2: Making directory 2025/09/18 05:46:58 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 INFO : subdir/subdirA: Making directory 2025/09/18 05:46:58 INFO : subdir/subdirB: Making directory 2025/09/18 05:46:58 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination 2025/09/18 05:46:58 DEBUG : B2 bucket rclone-test-jikujah1rova path 054654pu/check_access_filters/path2: Waiting for checks to finish 2025/09/18 05:46:58 DEBUG : B2 bucket rclone-test-jikujah1rova path 054654pu/check_access_filters/path2: Waiting for transfers to finish 2025/09/18 05:46:59 DEBUG : file1.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:46:59 INFO : file1.txt: Copied (new) 2025/09/18 05:46:59 DEBUG : file4.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:46:59 INFO : file4.txt: Copied (new) 2025/09/18 05:46:59 DEBUG : file2.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:46:59 INFO : file2.txt: Copied (new) 2025/09/18 05:46:59 DEBUG : subdirX/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2025/09/18 05:46:59 INFO : subdirX/RCLONE_TEST: Copied (new) 2025/09/18 05:46:59 DEBUG : file3.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:46:59 INFO : file3.txt: Copied (new) 2025/09/18 05:46:59 DEBUG : RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2025/09/18 05:46:59 INFO : RCLONE_TEST: Copied (new) 2025/09/18 05:46:59 DEBUG : subdirX/file20.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:46:59 INFO : subdirX/file20.txt: Copied (new) 2025/09/18 05:47:00 DEBUG : subdirX/subdirX1/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2025/09/18 05:47:00 INFO : subdirX/subdirX1/RCLONE_TEST: Copied (new) 2025/09/18 05:47:00 DEBUG : subdir-not/file20.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:00 INFO : subdir-not/file20.txt: Copied (new) 2025/09/18 05:47:00 DEBUG : subdir-not/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2025/09/18 05:47:00 INFO : subdir-not/RCLONE_TEST: Copied (new) 2025/09/18 05:47:00 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2025/09/18 05:47:00 INFO : subdir-not/subdir-not2/RCLONE_TEST: Copied (new) 2025/09/18 05:47:00 DEBUG : subdirX/subdirX1/file30.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:00 INFO : subdirX/subdirX1/file30.txt: Copied (new) 2025/09/18 05:47:00 DEBUG : subdir/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2025/09/18 05:47:00 INFO : subdir/RCLONE_TEST: Copied (new) 2025/09/18 05:47:00 DEBUG : subdir/file20.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:00 INFO : subdir/file20.txt: Copied (new) 2025/09/18 05:47:00 DEBUG : subdir-not/subdir-not2/file30.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:00 INFO : subdir-not/subdir-not2/file30.txt: Copied (new) 2025/09/18 05:47:00 DEBUG : subdir/subdirB/file30.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:00 INFO : subdir/subdirB/file30.txt: Copied (new) 2025/09/18 05:47:00 DEBUG : subdir/subdirA/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2025/09/18 05:47:00 INFO : subdir/subdirA/RCLONE_TEST: Copied (new) 2025/09/18 05:47:00 DEBUG : subdir/subdirB/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2025/09/18 05:47:00 INFO : subdir/subdirB/RCLONE_TEST: Copied (new) 2025/09/18 05:47:00 DEBUG : subdir/subdirA/file30.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:00 INFO : subdir/subdirA/file30.txt: Copied (new) 2025/09/18 05:47:00 NOTICE: checking path2 B2 bucket rclone-test-jikujah1rova path 054654pu/check_access_filters/path2 2025/09/18 05:47:01 NOTICE: (01) : test check-access-filters 2025/09/18 05:47:01 NOTICE: (02) : test EXCLUDE - OTHER TESTS 2025/09/18 05:47:01 NOTICE: (03) : copy-file /tmp/054654pu/datadir/test_check_access_filters-hexutel0/exclude-other-filtersfile.txt /tmp/054654pu/workdir/ 2025/09/18 05:47:01 DEBUG : copyFile "/tmp/054654pu/datadir/test_check_access_filters-hexutel0/exclude-other-filtersfile.txt" to "/tmp/054654pu/workdir/" as "" 2025/09/18 05:47:01 DEBUG : Creating backend with remote "/tmp/054654pu/datadir/test_check_access_filters-hexutel0/exclude-other-filtersfile.txt" 2025/09/18 05:47:01 DEBUG : Creating backend with remote "/tmp/054654pu/workdir/" 2025/09/18 05:47:01 DEBUG : operations.CopyFile "exclude-other-filtersfile.txt" to "Local file system at /tmp/054654pu/workdir" as "exclude-other-filtersfile.txt" 2025/09/18 05:47:01 DEBUG : exclude-other-filtersfile.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:01 DEBUG : exclude-other-filtersfile.txt: md5 = 5fcc6205d7df1c2e9ed3a15a1356b345 OK 2025/09/18 05:47:01 DEBUG : exclude-other-filtersfile.txt.955454a7.partial: renamed to: exclude-other-filtersfile.txt 2025/09/18 05:47:01 INFO : exclude-other-filtersfile.txt: Copied (new) 2025/09/18 05:47:01 NOTICE: (04) : test resync to get the filters file md5 built. 2025/09/18 05:47:01 NOTICE: (05) : bisync resync filters-file=/tmp/054654pu/workdir/exclude-other-filtersfile.txt 2025/09/18 05:47:04 INFO : subdir: Set directory modification time (using SetModTime) 2025/09/18 05:47:04 INFO : subdir-not: Set directory modification time (using SetModTime) 2025/09/18 05:47:04 INFO : subdirX: Set directory modification time (using SetModTime) 2025/09/18 05:47:04 INFO : subdirX/subdirX1: Set directory modification time (using SetModTime) 2025/09/18 05:47:04 INFO : subdir-not/subdir-not2: Set directory modification time (using SetModTime) 2025/09/18 05:47:04 INFO : subdir/subdirA: Set directory modification time (using SetModTime) 2025/09/18 05:47:04 INFO : subdir/subdirB: Set directory modification time (using SetModTime) 2025/09/18 05:47:04 DEBUG : B2 bucket rclone-test-jikujah1rova path 054654pu/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/18 05:47:04 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/18 05:47: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/18 05:47:04 INFO : Synching Path1 "/tmp/054654pu/check_access_filters/path1/" with Path2 "TestB2:rclone-test-jikujah1rova/054654pu/check_access_filters/path2/" 2025/09/18 05:47:04 INFO : Using filters file /tmp/054654pu/workdir/exclude-other-filtersfile.txt 2025/09/18 05:47:04 INFO : Storing filters file hash to /tmp/054654pu/workdir/exclude-other-filtersfile.txt.md5 2025/09/18 05:47:04 INFO : Copying Path2 files to Path1 2025/09/18 05:47:04 INFO : - Path2 Resync is copying files to - Path1 2025/09/18 05:47:04 INFO : There was nothing to transfer 2025/09/18 05:47:04 INFO : - Path1 Resync is copying files to - Path2 2025/09/18 05:47:05 INFO : There was nothing to transfer 2025/09/18 05:47:05 INFO : Resync updating listings 2025/09/18 05:47:05 INFO : Validating listings for Path1 "/tmp/054654pu/check_access_filters/path1/" vs Path2 "TestB2:rclone-test-jikujah1rova/054654pu/check_access_filters/path2/" 2025/09/18 05:47:05 INFO : Bisync successful 2025/09/18 05:47:05 NOTICE: (06) : test EXCLUDE - test filters for check access 2025/09/18 05:47:05 NOTICE: (07) : bisync check-access filters-file=/tmp/054654pu/workdir/exclude-other-filtersfile.txt 2025/09/18 05:47:05 DEBUG : modtime_write_test: Clearing upload URL because of error: Post "https://pod-000-1182-07.backblaze.com/b2api/v1/b2_upload_file/af228db350cd5bbb9f980e1b/c001_v0001182_t0005": EOF 2025/09/18 05:47:05 DEBUG : pacer: low level retry 1/1 (error Post "https://pod-000-1182-07.backblaze.com/b2api/v1/b2_upload_file/af228db350cd5bbb9f980e1b/c001_v0001182_t0005": EOF) 2025/09/18 05:47:05 DEBUG : pacer: Rate limited, increasing sleep to 20ms bisync_test.go:1025: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:1025 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:1046 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:1111 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:788 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:542 /usr/local/go/src/strings/iter.go:61 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:525 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:405 Error: Received unexpected error: Post "https://pod-000-1182-07.backblaze.com/b2api/v1/b2_upload_file/af228db350cd5bbb9f980e1b/c001_v0001182_t0005": EOF Test: TestBisyncLocalRemote/check_access_filters 2025/09/18 05:47:05 DEBUG : B2 bucket rclone-test-jikujah1rova: Purge remote 2025/09/18 05:47:05 INFO : B2 bucket rclone-test-jikujah1rova: cleaning bucket "rclone-test-jikujah1rova" of all files 2025/09/18 05:47:06 DEBUG : 054654pu/check_access_filters/path2/RCLONE_TEST: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f107a37bddbc78d4e_d20250918_m054659_c001_v0001182_t0044_u01758174419724") 2025/09/18 05:47:06 DEBUG : 054654pu/check_access_filters/path2/file1.txt: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f103db5fe435fcc79_d20250918_m054659_c001_v0001182_t0056_u01758174419156") 2025/09/18 05:47:06 DEBUG : 054654pu/check_access_filters/path2/file2.txt: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f103a0ca2b16ccc01_d20250918_m054659_c001_v0001154_t0003_u01758174419351") 2025/09/18 05:47:06 DEBUG : 054654pu/check_access_filters/path2/file3.txt: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f114807a0dc0a5f1a_d20250918_m054659_c001_v0001157_t0028_u01758174419529") 2025/09/18 05:47:06 DEBUG : 054654pu/check_access_filters/path2/file4.txt: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f103db5fe435fcc7b_d20250918_m054659_c001_v0001182_t0012_u01758174419384") 2025/09/18 05:47:06 DEBUG : 054654pu/check_access_filters/path2/modtime_write_test: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f419de83fdb433911_d20250918_m054704_c001_v7007000_t0000_u01758174424299") 2025/09/18 05:47:06 DEBUG : 054654pu/check_access_filters/path2/modtime_write_test: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f114bb71fbe654141_d20250918_m054702_c001_v0001098_t0008_u01758174422987") 2025/09/18 05:47:06 DEBUG : 054654pu/check_access_filters/path2/modtime_write_test: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f103db5fe435fcc9a_d20250918_m054701_c001_v0001182_t0053_u01758174421211") 2025/09/18 05:47:06 DEBUG : 054654pu/check_access_filters/path2/subdir-not/RCLONE_TEST: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f103db5fe435fcc81_d20250918_m054659_c001_v0001182_t0000_u01758174419808") 2025/09/18 05:47:06 DEBUG : 054654pu/check_access_filters/path2/subdir-not/file20.txt: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f114807a0dc0a5f1c_d20250918_m054659_c001_v0001157_t0031_u01758174419865") 2025/09/18 05:47:06 DEBUG : 054654pu/check_access_filters/path2/subdir-not/subdir-not2/RCLONE_TEST: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f107a37bddbc78d54_d20250918_m054700_c001_v0001182_t0035_u01758174420121") 2025/09/18 05:47:07 DEBUG : 054654pu/check_access_filters/path2/subdir-not/subdir-not2/file30.txt: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f114807a0dc0a5f20_d20250918_m054700_c001_v0001157_t0054_u01758174420172") 2025/09/18 05:47:07 DEBUG : 054654pu/check_access_filters/path2/subdir/RCLONE_TEST: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f103db5fe435fcc89_d20250918_m054700_c001_v0001182_t0047_u01758174420221") 2025/09/18 05:47:07 DEBUG : 054654pu/check_access_filters/path2/subdir/file20.txt: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f107a37bddbc78d58_d20250918_m054700_c001_v0001182_t0012_u01758174420339") 2025/09/18 05:47:07 DEBUG : 054654pu/check_access_filters/path2/subdir/subdirA/RCLONE_TEST: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f107a37bddbc78d5c_d20250918_m054700_c001_v0001182_t0005_u01758174420535") 2025/09/18 05:47:07 DEBUG : 054654pu/check_access_filters/path2/subdir/subdirA/file30.txt: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f114807a0dc0a5f24_d20250918_m054700_c001_v0001157_t0001_u01758174420583") 2025/09/18 05:47:07 DEBUG : 054654pu/check_access_filters/path2/subdir/subdirB/RCLONE_TEST: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f103a0ca2b16ccc07_d20250918_m054700_c001_v0001154_t0018_u01758174420367") 2025/09/18 05:47:07 DEBUG : 054654pu/check_access_filters/path2/subdir/subdirB/file30.txt: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f103db5fe435fcc8d_d20250918_m054700_c001_v0001182_t0018_u01758174420444") 2025/09/18 05:47:07 DEBUG : 054654pu/check_access_filters/path2/subdirX/RCLONE_TEST: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f103db5fe435fcc7d_d20250918_m054659_c001_v0001182_t0050_u01758174419590") 2025/09/18 05:47:07 DEBUG : 054654pu/check_access_filters/path2/subdirX/file20.txt: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f103a0ca2b16ccc03_d20250918_m054659_c001_v0001154_t0019_u01758174419710") 2025/09/18 05:47:07 DEBUG : 054654pu/check_access_filters/path2/subdirX/subdirX1/RCLONE_TEST: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f107a37bddbc78d50_d20250918_m054659_c001_v0001182_t0043_u01758174419924") 2025/09/18 05:47:07 DEBUG : 054654pu/check_access_filters/path2/subdirX/subdirX1/file30.txt: Deleting (id "4_zaf228db350cd5bbb9f980e1b_f103a0ca2b16ccc05_d20250918_m054700_c001_v0001154_t0023_u01758174420030") --- FAIL: TestBisyncLocalRemote (14.66s) --- FAIL: TestBisyncLocalRemote/check_access_filters (11.45s) === RUN TestBisyncRemoteRemote 2025/09/18 05:47:08 DEBUG : Creating backend with remote "TestB2:rclone-test-tijuviy0tawu" 2025/09/18 05:47:08 NOTICE: remote: TestB2:rclone-test-tijuviy0tawu === RUN TestBisyncRemoteRemote/resync 2025/09/18 05:47:08 DEBUG : Creating backend with remote "TestB2:rclone-test-tijuviy0tawu/054708bu" 2025/09/18 05:47:09 INFO : path1: Making directory 2025/09/18 05:47:10 DEBUG : Creating backend with remote "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1" 2025/09/18 05:47:11 INFO : path2: Making directory 2025/09/18 05:47:11 DEBUG : Creating backend with remote "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2" 2025/09/18 05:47:12 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_resync/initial" 2025/09/18 05:47:12 DEBUG : Creating backend with remote "/tmp/054708bu/initdir/test_resync-yobomuh9" 2025/09/18 05:47:12 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:47:12 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:12 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:12 DEBUG : file3.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:12 DEBUG : file4.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:12 DEBUG : file5.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:12 DEBUG : file6.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:12 DEBUG : file7.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:12 DEBUG : Local file system at /tmp/054708bu/initdir/test_resync-yobomuh9: Waiting for checks to finish 2025/09/18 05:47:12 DEBUG : Local file system at /tmp/054708bu/initdir/test_resync-yobomuh9: Waiting for transfers to finish 2025/09/18 05:47:12 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:47:12 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:47:12 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2025/09/18 05:47:12 INFO : file1.txt: Copied (new) 2025/09/18 05:47:12 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2025/09/18 05:47:12 INFO : file2.txt: Copied (new) 2025/09/18 05:47:12 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:47:12 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:47:12 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2025/09/18 05:47:12 INFO : file3.txt: Copied (new) 2025/09/18 05:47:12 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2025/09/18 05:47:12 INFO : file4.txt: Copied (new) 2025/09/18 05:47:12 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:47:12 DEBUG : file5.txt.6e808e0e.partial: renamed to: file5.txt 2025/09/18 05:47:12 INFO : file5.txt: Copied (new) 2025/09/18 05:47:12 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:47:12 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/09/18 05:47:12 DEBUG : file6.txt.0a60f5f0.partial: renamed to: file6.txt 2025/09/18 05:47:12 INFO : file6.txt: Copied (new) 2025/09/18 05:47:12 DEBUG : file7.txt.9f102165.partial: renamed to: file7.txt 2025/09/18 05:47:12 INFO : file7.txt: Copied (new) 2025/09/18 05:47:12 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/09/18 05:47:12 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2025/09/18 05:47:12 INFO : RCLONE_TEST: Copied (new) 2025/09/18 05:47:12 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_resync/modfiles" 2025/09/18 05:47:12 DEBUG : Creating backend with remote "/tmp/054708bu/datadir/test_resync-nitegaq3" 2025/09/18 05:47:12 DEBUG : fileA.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:12 DEBUG : fileB.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:12 DEBUG : Local file system at /tmp/054708bu/datadir/test_resync-nitegaq3: Waiting for checks to finish 2025/09/18 05:47:12 DEBUG : Local file system at /tmp/054708bu/datadir/test_resync-nitegaq3: Waiting for transfers to finish 2025/09/18 05:47:12 DEBUG : fileA.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/18 05:47:12 DEBUG : fileB.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2025/09/18 05:47:12 DEBUG : fileA.txt.04c13af3.partial: renamed to: fileA.txt 2025/09/18 05:47:12 INFO : fileA.txt: Copied (new) 2025/09/18 05:47:12 DEBUG : fileB.txt.b8ec97e6.partial: renamed to: fileB.txt 2025/09/18 05:47:12 INFO : fileB.txt: Copied (new) 2025/09/18 05:47:12 INFO : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path1: cleaning bucket "rclone-test-tijuviy0tawu" of all files 2025/09/18 05:47:13 INFO : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path2: cleaning bucket "rclone-test-tijuviy0tawu" of all files 2025/09/18 05:47:14 NOTICE: checking initFs Local file system at /tmp/054708bu/initdir/test_resync-yobomuh9 2025/09/18 05:47:14 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:47:14 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:14 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:14 DEBUG : file3.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:14 DEBUG : file4.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:14 DEBUG : file5.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:14 DEBUG : file6.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:14 DEBUG : file7.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:14 DEBUG : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path1: Waiting for checks to finish 2025/09/18 05:47:14 DEBUG : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path1: Waiting for transfers to finish 2025/09/18 05:47:15 DEBUG : file2.txt: Clearing upload URL because of error: CPU too busy (503 service_unavailable): trying again in 1s 2025/09/18 05:47:15 DEBUG : pacer: low level retry 1/1 (error CPU too busy (503 service_unavailable): trying again in 1s) 2025/09/18 05:47:15 DEBUG : pacer: Rate limited, increasing sleep to 1s 2025/09/18 05:47:15 DEBUG : file2.txt: Received error: CPU too busy (503 service_unavailable): trying again in 1s - low level retry 0/10 2025/09/18 05:47:16 DEBUG : pacer: Reducing sleep to 500ms 2025/09/18 05:47:16 DEBUG : pacer: Reducing sleep to 250ms 2025/09/18 05:47:16 DEBUG : file1.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:16 INFO : file1.txt: Copied (new) 2025/09/18 05:47:16 DEBUG : pacer: Reducing sleep to 125ms 2025/09/18 05:47:16 DEBUG : RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2025/09/18 05:47:16 INFO : RCLONE_TEST: Copied (new) 2025/09/18 05:47:16 DEBUG : pacer: Reducing sleep to 62.5ms 2025/09/18 05:47:16 DEBUG : file3.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:16 INFO : file3.txt: Copied (new) 2025/09/18 05:47:17 DEBUG : pacer: Reducing sleep to 31.25ms 2025/09/18 05:47:17 DEBUG : file5.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:17 INFO : file5.txt: Copied (new) 2025/09/18 05:47:17 DEBUG : pacer: Reducing sleep to 15.625ms 2025/09/18 05:47:17 DEBUG : file4.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:17 INFO : file4.txt: Copied (new) 2025/09/18 05:47:17 DEBUG : pacer: Reducing sleep to 10ms 2025/09/18 05:47:17 DEBUG : file7.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:17 INFO : file7.txt: Copied (new) 2025/09/18 05:47:17 DEBUG : file6.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:17 INFO : file6.txt: Copied (new) 2025/09/18 05:47:17 DEBUG : file2.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:17 INFO : file2.txt: Copied (new) 2025/09/18 05:47:17 NOTICE: checking Path1 B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path1 2025/09/18 05:47:17 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/09/18 05:47:17 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:17 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:17 DEBUG : file3.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:17 DEBUG : file4.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:17 DEBUG : file5.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:17 DEBUG : file6.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:17 DEBUG : file7.txt: Need to transfer - File not found at Destination 2025/09/18 05:47:17 DEBUG : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path2: Waiting for checks to finish 2025/09/18 05:47:17 DEBUG : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path2: Waiting for transfers to finish 2025/09/18 05:47:18 DEBUG : file3.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:18 INFO : file3.txt: Copied (new) 2025/09/18 05:47:19 DEBUG : file2.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:19 INFO : file2.txt: Copied (new) 2025/09/18 05:47:19 DEBUG : file1.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:19 INFO : file1.txt: Copied (new) 2025/09/18 05:47:19 DEBUG : RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2025/09/18 05:47:19 INFO : RCLONE_TEST: Copied (new) 2025/09/18 05:47:19 DEBUG : file4.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:19 INFO : file4.txt: Copied (new) 2025/09/18 05:47:19 DEBUG : file7.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:19 INFO : file7.txt: Copied (new) 2025/09/18 05:47:19 DEBUG : file5.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:19 INFO : file5.txt: Copied (new) 2025/09/18 05:47:19 DEBUG : file6.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2025/09/18 05:47:19 INFO : file6.txt: Copied (new) 2025/09/18 05:47:19 NOTICE: checking path2 B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path2 2025/09/18 05:47:19 NOTICE: (01) : test resync 2025/09/18 05:47:19 NOTICE: (02) : test 1. resync with empty path1, resulting in copying all content from path2. 2025/09/18 05:47:19 NOTICE: (03) : purge-children TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/ 2025/09/18 05:47:19 DEBUG : RCLONE_TEST: Remove file 2025/09/18 05:47:20 DEBUG : file1.txt: Remove file 2025/09/18 05:47:20 DEBUG : file2.txt: Remove file 2025/09/18 05:47:20 DEBUG : file3.txt: Remove file 2025/09/18 05:47:20 DEBUG : file4.txt: Remove file 2025/09/18 05:47:20 DEBUG : file5.txt: Remove file 2025/09/18 05:47:21 DEBUG : file6.txt: Remove file 2025/09/18 05:47:21 DEBUG : file7.txt: Remove file 2025/09/18 05:47:21 NOTICE: (04) : bisync resync 2025/09/18 05:47:29 DEBUG : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/18 05:47:29 DEBUG : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/18 05:47:29 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/18 05:47:29 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2025/09/18 05:47:29 INFO : Synching Path1 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/" with Path2 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" 2025/09/18 05:47:29 INFO : Copying Path2 files to Path1 2025/09/18 05:47:29 INFO : - Path2 Resync is copying files to - Path1 2025/09/18 05:47:29 INFO : RCLONE_TEST: Copied (server-side copy) 2025/09/18 05:47:30 INFO : file1.txt: Copied (server-side copy) 2025/09/18 05:47:30 INFO : file4.txt: Copied (server-side copy) 2025/09/18 05:47:30 INFO : file3.txt: Copied (server-side copy) 2025/09/18 05:47:30 INFO : file7.txt: Copied (server-side copy) 2025/09/18 05:47:30 INFO : file2.txt: Copied (server-side copy) 2025/09/18 05:47:30 INFO : file6.txt: Copied (server-side copy) 2025/09/18 05:47:30 INFO : file5.txt: Copied (server-side copy) 2025/09/18 05:47:30 INFO : - Path1 Resync is copying files to - Path2 2025/09/18 05:47:30 INFO : Resync updating listings 2025/09/18 05:47:30 INFO : Validating listings for Path1 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/" vs Path2 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" 2025/09/18 05:47:30 INFO : Bisync successful 2025/09/18 05:47:30 NOTICE: (05) : move-listings empty-path1 2025/09/18 05:47:30 NOTICE: (06) : test 2. resync with empty path2, resulting in syncing all content to path2. 2025/09/18 05:47:30 NOTICE: (07) : purge-children TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/ 2025/09/18 05:47:31 DEBUG : RCLONE_TEST: Remove file 2025/09/18 05:47:31 DEBUG : file1.txt: Remove file 2025/09/18 05:47:31 DEBUG : file2.txt: Remove file 2025/09/18 05:47:31 DEBUG : file3.txt: Remove file 2025/09/18 05:47:31 DEBUG : file4.txt: Remove file 2025/09/18 05:47:32 DEBUG : file5.txt: Remove file 2025/09/18 05:47:32 DEBUG : file6.txt: Remove file 2025/09/18 05:47:32 DEBUG : file7.txt: Remove file 2025/09/18 05:47:32 NOTICE: (08) : bisync resync 2025/09/18 05:47:40 DEBUG : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/18 05:47:40 DEBUG : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/18 05:47:40 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/18 05:47:40 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2025/09/18 05:47:40 INFO : Synching Path1 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/" with Path2 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" 2025/09/18 05:47:40 INFO : Copying Path2 files to Path1 2025/09/18 05:47:40 INFO : - Path2 Resync is copying files to - Path1 2025/09/18 05:47:40 INFO : There was nothing to transfer 2025/09/18 05:47:40 INFO : - Path1 Resync is copying files to - Path2 2025/09/18 05:47:40 INFO : RCLONE_TEST: Copied (server-side copy) 2025/09/18 05:47:41 INFO : file1.txt: Copied (server-side copy) 2025/09/18 05:47:41 INFO : file2.txt: Copied (server-side copy) 2025/09/18 05:47:41 INFO : file3.txt: Copied (server-side copy) 2025/09/18 05:47:41 INFO : file4.txt: Copied (server-side copy) 2025/09/18 05:47:41 INFO : file7.txt: Copied (server-side copy) 2025/09/18 05:47:41 INFO : file5.txt: Copied (server-side copy) 2025/09/18 05:47:43 INFO : file6.txt: Copied (server-side copy) 2025/09/18 05:47:43 INFO : Resync updating listings 2025/09/18 05:47:43 INFO : Validating listings for Path1 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/" vs Path2 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" 2025/09/18 05:47:43 INFO : Bisync successful 2025/09/18 05:47:43 NOTICE: (09) : move-listings empty-path2 2025/09/18 05:47:43 NOTICE: (10) : test 3. exercise all of the various file difference scenarios during a resync. 2025/09/18 05:47:43 NOTICE: (11) : touch-glob 2002-02-02 /tmp/054708bu/datadir/test_resync-nitegaq3/ fileA.txt 2025/09/18 05:47:43 DEBUG : Creating backend with remote "/tmp/054708bu/datadir/test_resync-nitegaq3/" 2025/09/18 05:47:43 DEBUG : fs cache: renaming cache item "/tmp/054708bu/datadir/test_resync-nitegaq3/" to be canonical "/tmp/054708bu/datadir/test_resync-nitegaq3" 2025/09/18 05:47:43 DEBUG : fileA.txt: Set modification time 2002-02-02 2025/09/18 05:47:43 NOTICE: (12) : touch-glob 1999-09-09 /tmp/054708bu/datadir/test_resync-nitegaq3/ fileB.txt 2025/09/18 05:47:43 DEBUG : fs cache: switching user supplied name "/tmp/054708bu/datadir/test_resync-nitegaq3/" for canonical name "/tmp/054708bu/datadir/test_resync-nitegaq3" 2025/09/18 05:47:43 DEBUG : fileB.txt: Set modification time 1999-09-09 2025/09/18 05:47:43 NOTICE: (13) : test = file - path1 - path2 - expected action - who wins 2025/09/18 05:47:43 NOTICE: (14) : test - file1.txt - exists - missing - sync path1 > path2 - path1 2025/09/18 05:47:43 NOTICE: (15) : delete-file TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/file1.txt 2025/09/18 05:47:43 DEBUG : Creating backend with remote "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" 2025/09/18 05:47:44 DEBUG : fs cache: renaming cache item "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" to be canonical "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2" 2025/09/18 05:47:45 INFO : file1.txt: Deleted 2025/09/18 05:47:45 NOTICE: (16) : test - file2.txt - missing - exists - copy path2 > path1 - path2 2025/09/18 05:47:45 NOTICE: (17) : delete-file TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/file2.txt 2025/09/18 05:47:45 DEBUG : Creating backend with remote "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/" 2025/09/18 05:47:46 DEBUG : fs cache: renaming cache item "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/" to be canonical "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1" 2025/09/18 05:47:47 INFO : file2.txt: Deleted 2025/09/18 05:47:47 NOTICE: (18) : test - file3.txt - exists - newer date - sync path1 > path2 - path1 2025/09/18 05:47:47 NOTICE: (19) : copy-as /tmp/054708bu/datadir/test_resync-nitegaq3/fileA.txt TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/ file3.txt 2025/09/18 05:47:47 DEBUG : copyFile "/tmp/054708bu/datadir/test_resync-nitegaq3/fileA.txt" to "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" as "file3.txt" 2025/09/18 05:47:47 DEBUG : Creating backend with remote "/tmp/054708bu/datadir/test_resync-nitegaq3/fileA.txt" 2025/09/18 05:47:47 DEBUG : Creating backend with remote "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" 2025/09/18 05:47:48 DEBUG : operations.CopyFile "fileA.txt" to "B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path2" as "file3.txt" 2025/09/18 05:47:49 DEBUG : fileA.txt: Sizes differ (src 19 vs dst 0) 2025/09/18 05:47:50 DEBUG : fileA.txt: sha1 = be91a3d4ae9841cfe52de8379de8d1d248201b9c OK 2025/09/18 05:47:50 INFO : fileA.txt: Copied (replaced existing) to: file3.txt 2025/09/18 05:47:50 NOTICE: (20) : test - file4.txt - missing - newer date - copy path2 > path1 - path2 2025/09/18 05:47:50 NOTICE: (21) : delete-file TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/file4.txt 2025/09/18 05:47:50 DEBUG : fs cache: switching user supplied name "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/" for canonical name "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1" 2025/09/18 05:47:51 INFO : file4.txt: Deleted 2025/09/18 05:47:51 NOTICE: (22) : copy-as /tmp/054708bu/datadir/test_resync-nitegaq3/fileA.txt TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/ file4.txt 2025/09/18 05:47:51 DEBUG : copyFile "/tmp/054708bu/datadir/test_resync-nitegaq3/fileA.txt" to "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" as "file4.txt" 2025/09/18 05:47:51 DEBUG : Creating backend with remote "/tmp/054708bu/datadir/test_resync-nitegaq3/fileA.txt" 2025/09/18 05:47:51 DEBUG : Creating backend with remote "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" 2025/09/18 05:47:52 DEBUG : operations.CopyFile "fileA.txt" to "B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path2" as "file4.txt" 2025/09/18 05:47:52 DEBUG : fileA.txt: Sizes differ (src 19 vs dst 0) 2025/09/18 05:47:54 DEBUG : fileA.txt: sha1 = be91a3d4ae9841cfe52de8379de8d1d248201b9c OK 2025/09/18 05:47:54 INFO : fileA.txt: Copied (replaced existing) to: file4.txt 2025/09/18 05:47:54 NOTICE: (23) : test - file5.txt - exists - older date - sync path1 > path2 - path1 2025/09/18 05:47:54 NOTICE: (24) : copy-as /tmp/054708bu/datadir/test_resync-nitegaq3/fileB.txt TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/ file5.txt 2025/09/18 05:47:54 DEBUG : copyFile "/tmp/054708bu/datadir/test_resync-nitegaq3/fileB.txt" to "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" as "file5.txt" 2025/09/18 05:47:54 DEBUG : Creating backend with remote "/tmp/054708bu/datadir/test_resync-nitegaq3/fileB.txt" 2025/09/18 05:47:54 DEBUG : Creating backend with remote "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" 2025/09/18 05:47:55 DEBUG : operations.CopyFile "fileB.txt" to "B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path2" as "file5.txt" 2025/09/18 05:47:55 DEBUG : fileB.txt: Sizes differ (src 19 vs dst 0) 2025/09/18 05:47:57 DEBUG : fileB.txt: sha1 = be91a3d4ae9841cfe52de8379de8d1d248201b9c OK 2025/09/18 05:47:57 INFO : fileB.txt: Copied (replaced existing) to: file5.txt 2025/09/18 05:47:57 NOTICE: (25) : test - file6.txt - older date - newer date - sync path1 > path2 - path1 2025/09/18 05:47:57 NOTICE: (26) : copy-as /tmp/054708bu/datadir/test_resync-nitegaq3/fileB.txt TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/ file6.txt 2025/09/18 05:47:57 DEBUG : copyFile "/tmp/054708bu/datadir/test_resync-nitegaq3/fileB.txt" to "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/" as "file6.txt" 2025/09/18 05:47:57 DEBUG : Creating backend with remote "/tmp/054708bu/datadir/test_resync-nitegaq3/fileB.txt" 2025/09/18 05:47:57 DEBUG : Creating backend with remote "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/" 2025/09/18 05:47:58 DEBUG : operations.CopyFile "fileB.txt" to "B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path1" as "file6.txt" 2025/09/18 05:47:58 DEBUG : fileB.txt: Sizes differ (src 19 vs dst 0) 2025/09/18 05:48:00 DEBUG : fileB.txt: sha1 = be91a3d4ae9841cfe52de8379de8d1d248201b9c OK 2025/09/18 05:48:00 INFO : fileB.txt: Copied (replaced existing) to: file6.txt 2025/09/18 05:48:00 NOTICE: (27) : copy-as /tmp/054708bu/datadir/test_resync-nitegaq3/fileA.txt TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/ file6.txt 2025/09/18 05:48:00 DEBUG : copyFile "/tmp/054708bu/datadir/test_resync-nitegaq3/fileA.txt" to "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" as "file6.txt" 2025/09/18 05:48:00 DEBUG : Creating backend with remote "/tmp/054708bu/datadir/test_resync-nitegaq3/fileA.txt" 2025/09/18 05:48:00 DEBUG : Creating backend with remote "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" 2025/09/18 05:48:01 DEBUG : operations.CopyFile "fileA.txt" to "B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path2" as "file6.txt" 2025/09/18 05:48:01 DEBUG : fileA.txt: Sizes differ (src 19 vs dst 0) 2025/09/18 05:48:03 DEBUG : fileA.txt: sha1 = be91a3d4ae9841cfe52de8379de8d1d248201b9c OK 2025/09/18 05:48:03 INFO : fileA.txt: Copied (replaced existing) to: file6.txt 2025/09/18 05:48:03 NOTICE: (28) : test - file7.txt - exists - exists (same) - none - same 2025/09/18 05:48:03 NOTICE: (29) : test run bisync with resync 2025/09/18 05:48:03 NOTICE: (30) : bisync resync 2025/09/18 05:48:11 DEBUG : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/18 05:48:11 DEBUG : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/18 05:48:11 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/18 05:48:11 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2025/09/18 05:48:11 INFO : Synching Path1 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/" with Path2 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" 2025/09/18 05:48:11 INFO : Copying Path2 files to Path1 2025/09/18 05:48:11 INFO : - Path2 Resync is copying files to - Path1 2025/09/18 05:48:12 INFO : file2.txt: Copied (server-side copy) 2025/09/18 05:48:12 INFO : file4.txt: Copied (server-side copy) 2025/09/18 05:48:12 INFO : - Path1 Resync is copying files to - Path2 2025/09/18 05:48:13 INFO : file1.txt: Copied (server-side copy) 2025/09/18 05:48:13 INFO : file6.txt: Updated modification time in destination 2025/09/18 05:48:13 INFO : file3.txt: Copied (server-side copy) 2025/09/18 05:48:14 INFO : file5.txt: Copied (server-side copy) 2025/09/18 05:48:14 INFO : Resync updating listings 2025/09/18 05:48:14 INFO : Validating listings for Path1 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/" vs Path2 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" 2025/09/18 05:48:14 INFO : Bisync successful 2025/09/18 05:48:14 NOTICE: (31) : copy-listings mixed-diffs 2025/09/18 05:48:14 NOTICE: (32) : test run normal bisync 2025/09/18 05:48:14 NOTICE: (33) : bisync 2025/09/18 05:48:22 DEBUG : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/18 05:48:22 DEBUG : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/18 05:48:22 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/18 05:48:22 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2025/09/18 05:48:22 INFO : Synching Path1 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/" with Path2 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" 2025/09/18 05:48:22 INFO : Building Path1 and Path2 listings 2025/09/18 05:48:22 INFO : Path1 checking for diffs 2025/09/18 05:48:22 INFO : Path2 checking for diffs 2025/09/18 05:48:22 INFO : No changes found 2025/09/18 05:48:22 INFO : Updating listings 2025/09/18 05:48:22 INFO : Validating listings for Path1 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/" vs Path2 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" 2025/09/18 05:48:22 INFO : Bisync successful 2025/09/18 05:48:22 NOTICE: (34) : test 4. confirm critical error on normal sync of empty path. 2025/09/18 05:48:22 NOTICE: (35) : purge-children TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/ 2025/09/18 05:48:22 DEBUG : RCLONE_TEST: Remove file 2025/09/18 05:48:22 DEBUG : file1.txt: Remove file 2025/09/18 05:48:22 DEBUG : file2.txt: Remove file 2025/09/18 05:48:23 DEBUG : file3.txt: Remove file 2025/09/18 05:48:23 DEBUG : file4.txt: Remove file 2025/09/18 05:48:23 DEBUG : file5.txt: Remove file 2025/09/18 05:48:23 DEBUG : file6.txt: Remove file 2025/09/18 05:48:23 DEBUG : file7.txt: Remove file 2025/09/18 05:48:24 NOTICE: (36) : bisync 2025/09/18 05:48:32 DEBUG : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/18 05:48:32 DEBUG : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2025/09/18 05:48:32 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2025/09/18 05:48:32 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2025/09/18 05:48:32 INFO : Synching Path1 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path1/" with Path2 "TestB2:rclone-test-tijuviy0tawu/054708bu/resync/path2/" 2025/09/18 05:48:32 INFO : Building Path1 and Path2 listings 2025/09/18 05:48:32 INFO : Path1 checking for diffs 2025/09/18 05:48:32 INFO : Path2 checking for diffs 2025/09/18 05:48:32 ERROR : Empty current Path2 listing. Cannot sync to an empty directory: /tmp/054708bu/workdir/TestB2_rclone-test-tijuviy0tawu_054708bu_resync_path1..TestB2_rclone-test-tijuviy0tawu_054708bu_resync_path2.path2.lst-new 2025/09/18 05:48:32 ERROR : Bisync critical error: empty current Path2 listing: /tmp/054708bu/workdir/TestB2_rclone-test-tijuviy0tawu_054708bu_resync_path1..TestB2_rclone-test-tijuviy0tawu_054708bu_resync_path2.path2.lst-new 2025/09/18 05:48:32 ERROR : Bisync aborted. Must run --resync to recover. 2025/09/18 05:48:32 NOTICE: Bisync error: bisync aborted 2025/09/18 05:48:32 INFO : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path1: cleaning bucket "rclone-test-tijuviy0tawu" of all files 2025/09/18 05:48:32 DEBUG : RCLONE_TEST: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1010b5d3154f1b43_d20250918_m054729_c001_v0001182_t0059_u01758174449383") 2025/09/18 05:48:32 DEBUG : RCLONE_TEST: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff0588e_d20250918_m054720_c001_v7007000_t0000_u01758174440042") 2025/09/18 05:48:32 DEBUG : RCLONE_TEST: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f112d4b5d891f5777_d20250918_m054716_c001_v0001184_t0041_u01758174436153") 2025/09/18 05:48:32 DEBUG : file1.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1113b5880f7ffdee_d20250918_m054729_c001_v0001091_t0058_u01758174449599") 2025/09/18 05:48:32 DEBUG : file1.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff0588f_d20250918_m054720_c001_v7007000_t0000_u01758174440225") 2025/09/18 05:48:32 DEBUG : file1.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1072b927defcd69b_d20250918_m054715_c001_v0001134_t0059_u01758174435598") 2025/09/18 05:48:32 DEBUG : file2.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1003ee25c595c82b_d20250918_m054811_c001_v0001102_t0043_u01758174491947") 2025/09/18 05:48:32 DEBUG : file2.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f418a9cce027c435e_d20250918_m054747_c001_v7007000_t0000_u01758174467743") 2025/09/18 05:48:32 DEBUG : file2.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f109c3c1001b61f2f_d20250918_m054729_c001_v0001106_t0057_u01758174449758") 2025/09/18 05:48:33 DEBUG : file2.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff05891_d20250918_m054720_c001_v7007000_t0000_u01758174440406") 2025/09/18 05:48:33 DEBUG : file2.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f102d2a982b700abe_d20250918_m054717_c001_v0001113_t0032_u01758174437334") 2025/09/18 05:48:33 DEBUG : file3.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f11335f356ee8179e_d20250918_m054729_c001_v0001098_t0059_u01758174449763") 2025/09/18 05:48:33 DEBUG : file3.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff05892_d20250918_m054720_c001_v7007000_t0000_u01758174440587") 2025/09/18 05:48:33 DEBUG : file3.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f112d0f870e0de4dc_d20250918_m054715_c001_v0001109_t0007_u01758174435969") 2025/09/18 05:48:33 DEBUG : file4.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f110be686e942cecb_d20250918_m054812_c001_v0001106_t0025_u01758174492324") 2025/09/18 05:48:33 DEBUG : file4.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f418a9cce027c4385_d20250918_m054751_c001_v7007000_t0000_u01758174471034") 2025/09/18 05:48:33 DEBUG : file4.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f116ab6ba310f04cb_d20250918_m054729_c001_v0001146_t0006_u01758174449775") 2025/09/18 05:48:33 DEBUG : file4.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff05893_d20250918_m054720_c001_v7007000_t0000_u01758174440770") 2025/09/18 05:48:33 DEBUG : file4.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1072b927defcd6a5_d20250918_m054717_c001_v0001134_t0007_u01758174437033") 2025/09/18 05:48:33 DEBUG : file5.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f11178e6936d05683_d20250918_m054730_c001_v0001144_t0020_u01758174450151") 2025/09/18 05:48:33 DEBUG : file5.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff05894_d20250918_m054720_c001_v7007000_t0000_u01758174440952") 2025/09/18 05:48:33 DEBUG : file5.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f112d4b5d891f577f_d20250918_m054717_c001_v0001184_t0018_u01758174437094") 2025/09/18 05:48:33 DEBUG : file6.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f112b58d6cb64cdf9_d20250918_m054800_c001_v0001172_t0047_u01758174480171") 2025/09/18 05:48:33 DEBUG : file6.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1026c040c238c107_d20250918_m054730_c001_v0001144_t0035_u01758174450166") 2025/09/18 05:48:34 DEBUG : file6.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff05895_d20250918_m054721_c001_v7007000_t0000_u01758174441134") 2025/09/18 05:48:34 DEBUG : file6.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f112d0f870e0de4e0_d20250918_m054717_c001_v0001109_t0008_u01758174437157") 2025/09/18 05:48:34 DEBUG : file7.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1152cfd8fc3f5d96_d20250918_m054730_c001_v0001179_t0006_u01758174450241") 2025/09/18 05:48:34 DEBUG : file7.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff05896_d20250918_m054721_c001_v7007000_t0000_u01758174441315") 2025/09/18 05:48:34 DEBUG : file7.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f112d4b5d891f5785_d20250918_m054717_c001_v0001184_t0044_u01758174437287") 2025/09/18 05:48:34 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f416fe87503f6fb99_d20250918_m054828_c001_v7007000_t0000_u01758174508011") 2025/09/18 05:48:34 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1021465b4b8dd0e4_d20250918_m054826_c001_v0001041_t0051_u01758174506569") 2025/09/18 05:48:34 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1072b927defcd78b_d20250918_m054824_c001_v0001134_t0047_u01758174504575") 2025/09/18 05:48:34 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f416fe87503f6fb62_d20250918_m054817_c001_v7007000_t0000_u01758174497971") 2025/09/18 05:48:34 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1158e1b5ae918e08_d20250918_m054816_c001_v0001145_t0056_u01758174496490") 2025/09/18 05:48:34 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f102d2a982b700b74_d20250918_m054814_c001_v0001113_t0013_u01758174494488") 2025/09/18 05:48:34 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4033424b34dda7eb_d20250918_m054807_c001_v7007000_t0000_u01758174487500") 2025/09/18 05:48:34 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1109a1af27270fce_d20250918_m054806_c001_v0001182_t0002_u01758174486284") 2025/09/18 05:48:34 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f112d0f870e0de512_d20250918_m054803_c001_v0001109_t0053_u01758174483817") 2025/09/18 05:48:34 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff058df_d20250918_m054736_c001_v7007000_t0000_u01758174456192") 2025/09/18 05:48:34 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f11841857ceb78c82_d20250918_m054734_c001_v0001113_t0004_u01758174454861") 2025/09/18 05:48:34 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f112d4b5d891f584d_d20250918_m054733_c001_v0001184_t0009_u01758174453101") 2025/09/18 05:48:34 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff0589e_d20250918_m054724_c001_v7007000_t0000_u01758174444905") 2025/09/18 05:48:34 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f104664151f7489c7_d20250918_m054723_c001_v0001037_t0022_u01758174443533") 2025/09/18 05:48:34 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1072b927defcd6b5_d20250918_m054721_c001_v0001134_t0054_u01758174441498") 2025/09/18 05:48:35 INFO : B2 bucket rclone-test-tijuviy0tawu path 054708bu/resync/path2: cleaning bucket "rclone-test-tijuviy0tawu" of all files 2025/09/18 05:48:35 DEBUG : RCLONE_TEST: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff059c0_d20250918_m054822_c001_v7007000_t0000_u01758174502638") 2025/09/18 05:48:35 DEBUG : RCLONE_TEST: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f100c6978d1b3a8fc_d20250918_m054740_c001_v0001136_t0051_u01758174460666") 2025/09/18 05:48:35 DEBUG : RCLONE_TEST: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f420ff6e9f6c7e2c7_d20250918_m054731_c001_v7007000_t0000_u01758174451268") 2025/09/18 05:48:35 DEBUG : RCLONE_TEST: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f116bd87a78ee13c9_d20250918_m054719_c001_v0001180_t0026_u01758174439179") 2025/09/18 05:48:35 DEBUG : file1.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff059c4_d20250918_m054822_c001_v7007000_t0000_u01758174502824") 2025/09/18 05:48:35 DEBUG : file1.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f116f7a69fed44541_d20250918_m054813_c001_v0001102_t0010_u01758174493185") 2025/09/18 05:48:35 DEBUG : file1.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4027163b1d88c029_d20250918_m054745_c001_v7007000_t0000_u01758174465231") 2025/09/18 05:48:35 DEBUG : file1.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1001aca1fb5cf461_d20250918_m054741_c001_v0001182_t0048_u01758174461041") 2025/09/18 05:48:35 DEBUG : file1.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f420ff6e9f6c7e2c8_d20250918_m054731_c001_v7007000_t0000_u01758174451451") 2025/09/18 05:48:35 DEBUG : file1.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f103f8fde4f004423_d20250918_m054718_c001_v0001099_t0050_u01758174438980") 2025/09/18 05:48:36 DEBUG : file2.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff059c5_d20250918_m054823_c001_v7007000_t0000_u01758174503007") 2025/09/18 05:48:36 DEBUG : file2.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1125fe01519f5dc5_d20250918_m054741_c001_v0001136_t0028_u01758174461058") 2025/09/18 05:48:36 DEBUG : file2.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f420ff6e9f6c7e2c9_d20250918_m054731_c001_v7007000_t0000_u01758174451632") 2025/09/18 05:48:36 DEBUG : file2.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f101e0954016f2862_d20250918_m054718_c001_v0001042_t0043_u01758174438804") 2025/09/18 05:48:36 DEBUG : file3.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff059c6_d20250918_m054823_c001_v7007000_t0000_u01758174503188") 2025/09/18 05:48:36 DEBUG : file3.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1014fa623b31cbe4_d20250918_m054813_c001_v0001109_t0009_u01758174493490") 2025/09/18 05:48:36 DEBUG : file3.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f11139eb6d6677c67_d20250918_m054750_c001_v0001184_t0010_u01758174470563") 2025/09/18 05:48:36 DEBUG : file3.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f11571d63ea5ec9f4_d20250918_m054741_c001_v0001101_t0024_u01758174461049") 2025/09/18 05:48:36 DEBUG : file3.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f420ff6e9f6c7e2ca_d20250918_m054731_c001_v7007000_t0000_u01758174451815") 2025/09/18 05:48:36 DEBUG : file3.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f100b780bc68597aa_d20250918_m054718_c001_v0001131_t0045_u01758174438609") 2025/09/18 05:48:36 DEBUG : file4.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff059c9_d20250918_m054823_c001_v7007000_t0000_u01758174503371") 2025/09/18 05:48:36 DEBUG : file4.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1175717531c0c724_d20250918_m054754_c001_v0001130_t0059_u01758174474192") 2025/09/18 05:48:36 DEBUG : file4.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f11825123dd7071f3_d20250918_m054741_c001_v0001134_t0006_u01758174461071") 2025/09/18 05:48:36 DEBUG : file4.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f420ff6e9f6c7e2cb_d20250918_m054731_c001_v7007000_t0000_u01758174451998") 2025/09/18 05:48:36 DEBUG : file4.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f100b780bc68597ac_d20250918_m054718_c001_v0001131_t0056_u01758174438990") 2025/09/18 05:48:36 DEBUG : file5.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff059cd_d20250918_m054823_c001_v7007000_t0000_u01758174503554") 2025/09/18 05:48:36 DEBUG : file5.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f118eac60c2940e00_d20250918_m054813_c001_v0001130_t0042_u01758174493563") 2025/09/18 05:48:36 DEBUG : file5.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f109556d64da9d9c7_d20250918_m054757_c001_v0001100_t0053_u01758174477214") 2025/09/18 05:48:36 DEBUG : file5.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f104b076eae891536_d20250918_m054741_c001_v0001106_t0029_u01758174461276") 2025/09/18 05:48:37 DEBUG : file5.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f420ff6e9f6c7e2cc_d20250918_m054732_c001_v7007000_t0000_u01758174452185") 2025/09/18 05:48:37 DEBUG : file5.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f101e0954016f2864_d20250918_m054719_c001_v0001042_t0027_u01758174439299") 2025/09/18 05:48:37 DEBUG : file6.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff059ce_d20250918_m054823_c001_v7007000_t0000_u01758174503736") 2025/09/18 05:48:37 DEBUG : file6.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f114fea312dc5d05f_d20250918_m054813_c001_v0001165_t0044_u01758174493587") 2025/09/18 05:48:37 DEBUG : file6.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f118af13e177d647a_d20250918_m054803_c001_v0001092_t0008_u01758174483144") 2025/09/18 05:48:37 DEBUG : file6.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f104c93643f4b21bf_d20250918_m054743_c001_v0001176_t0018_u01758174463377") 2025/09/18 05:48:37 DEBUG : file6.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f420ff6e9f6c7e2cd_d20250918_m054732_c001_v7007000_t0000_u01758174452367") 2025/09/18 05:48:37 DEBUG : file6.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f103f8fde4f004427_d20250918_m054719_c001_v0001099_t0020_u01758174439343") 2025/09/18 05:48:37 DEBUG : file7.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff059cf_d20250918_m054824_c001_v7007000_t0000_u01758174504022") 2025/09/18 05:48:37 DEBUG : file7.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f1000bb12d8bd0d60_d20250918_m054741_c001_v0001178_t0049_u01758174461380") 2025/09/18 05:48:37 DEBUG : file7.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f420ff6e9f6c7e2ce_d20250918_m054732_c001_v7007000_t0000_u01758174452552") 2025/09/18 05:48:37 DEBUG : file7.txt: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f116bd87a78ee13cb_d20250918_m054719_c001_v0001180_t0015_u01758174439381") 2025/09/18 05:48:37 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f40056f63f8c6bf87_d20250918_m054832_c001_v7007000_t0000_u01758174512262") 2025/09/18 05:48:37 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f107fcf4e3057bf32_d20250918_m054830_c001_v0001090_t0020_u01758174510863") 2025/09/18 05:48:37 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f100b780bc68598e3_d20250918_m054828_c001_v0001131_t0059_u01758174508561") 2025/09/18 05:48:37 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f4146187dcff059b8_d20250918_m054822_c001_v7007000_t0000_u01758174502073") 2025/09/18 05:48:37 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f111877dccc89cf13_d20250918_m054820_c001_v0001115_t0055_u01758174500424") 2025/09/18 05:48:37 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f103f8fde4f00450b_d20250918_m054818_c001_v0001099_t0011_u01758174498520") 2025/09/18 05:48:37 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f423fb2df74d6bf75_d20250918_m054811_c001_v7007000_t0000_u01758174491555") 2025/09/18 05:48:37 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f109ed470a6add171_d20250918_m054810_c001_v0001115_t0008_u01758174490085") 2025/09/18 05:48:37 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f101e0954016f2898_d20250918_m054808_c001_v0001042_t0032_u01758174488048") 2025/09/18 05:48:37 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f416fe87503f6fa79_d20250918_m054740_c001_v7007000_t0000_u01758174460087") 2025/09/18 05:48:38 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f108c70805087aa38_d20250918_m054738_c001_v0001179_t0035_u01758174458868") 2025/09/18 05:48:38 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f116bd87a78ee13f7_d20250918_m054736_c001_v0001180_t0046_u01758174456730") 2025/09/18 05:48:38 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f420ff6e9f6c7e2c6_d20250918_m054729_c001_v7007000_t0000_u01758174449000") 2025/09/18 05:48:38 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f102ce8b9a936a621_d20250918_m054727_c001_v0001102_t0005_u01758174447691") 2025/09/18 05:48:38 DEBUG : modtime_write_test: Deleting (id "4_zbf52cd4350cd5bbb9f980e1b_f100b780bc68597ce_d20250918_m054725_c001_v0001131_t0020_u01758174445448") bisync_test.go:608: TEST resync PASSED 2025/09/18 05:48:38 DEBUG : B2 bucket rclone-test-tijuviy0tawu: Purge remote 2025/09/18 05:48:38 INFO : B2 bucket rclone-test-tijuviy0tawu: cleaning bucket "rclone-test-tijuviy0tawu" of all files --- PASS: TestBisyncRemoteRemote (91.63s) --- PASS: TestBisyncRemoteRemote/resync (89.89s) FAIL 2025/09/18 05:48:39 DEBUG : B2 bucket rclone-test-davirix9toyu: Purge remote 2025/09/18 05:48:39 INFO : B2 bucket rclone-test-davirix9toyu: cleaning bucket "rclone-test-davirix9toyu" of all files 2025/09/18 05:48:40 NOTICE: purge failed: directory not found "./bisync.test -test.v -test.timeout 1h0m0s -remote TestB2: -list-retries 5 -verbose -test.run '^TestBisyncLocalRemote$/^check_access_filters$|^TestBisyncRemoteRemote$/^resync$'" - Finished ERROR in 1m47.688504935s (try 3/5): exit status 1: Failed [TestBisyncLocalRemote/check_access_filters]