"./bisync.test -test.v -test.timeout 1h0m0s -remote TestB2: -list-retries 5 -verbose -test.run '^TestBisyncLocalRemote$/^check_access_filters$|^TestBisyncRemoteRemote$/^check_sync$'" - Starting (try 3/5)
2025/11/12 03:48:01 DEBUG : Creating backend with remote "TestB2:rclone-test-foyidik9mobu"
2025/11/12 03:48:01 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/11/12 03:48:01 DEBUG : Creating backend with remote "/tmp/rclone2672513667"
=== RUN   TestBisyncLocalRemote
2025/11/12 03:48:01 DEBUG : Creating backend with remote "TestB2:rclone-test-bapahet9fubo"
2025/11/12 03:48:02 NOTICE: remote: TestB2:rclone-test-bapahet9fubo
=== RUN   TestBisyncLocalRemote/check_access_filters
2025/11/12 03:48:02 DEBUG : Creating backend with remote "/tmp/034802go"
2025/11/12 03:48:02 DEBUG : Creating backend with remote "/tmp/034802go/check_access_filters/path1"
2025/11/12 03:48:02 DEBUG : Creating backend with remote "TestB2:rclone-test-bapahet9fubo/034802go"
2025/11/12 03:48:03 INFO  : path2: Making directory
2025/11/12 03:48:04 DEBUG : Creating backend with remote "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2"
2025/11/12 03:48:05 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access_filters/initial"
2025/11/12 03:48:05 DEBUG : Creating backend with remote "/tmp/034802go/initdir/test_check_access_filters-cowabit8"
2025/11/12 03:48:05 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : subdir-not: Making directory with metadata
2025/11/12 03:48:05 INFO  : subdir-not: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/11/12 03:48:05 DEBUG : Added delayed dir = "subdir-not", newDst=subdir-not
2025/11/12 03:48:05 DEBUG : subdir: Making directory with metadata
2025/11/12 03:48:05 INFO  : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/11/12 03:48:05 DEBUG : Added delayed dir = "subdir", newDst=subdir
2025/11/12 03:48:05 DEBUG : subdirX: Making directory with metadata
2025/11/12 03:48:05 INFO  : subdirX: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/11/12 03:48:05 DEBUG : Added delayed dir = "subdirX", newDst=subdirX
2025/11/12 03:48:05 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : file1.txt.56d0d699.partial: size = 0 OK
2025/11/12 03:48:05 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:05 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : subdir-not/subdir-not2: Making directory with metadata
2025/11/12 03:48:05 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK
2025/11/12 03:48:05 DEBUG : file2.txt.3230ad67.partial: size = 0 OK
2025/11/12 03:48:05 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:05 INFO  : subdir-not/subdir-not2: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/11/12 03:48:05 DEBUG : Added delayed dir = "subdir-not/subdir-not2", newDst=subdir-not/subdir-not2
2025/11/12 03:48:05 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : subdirX/subdirX1: Making directory with metadata
2025/11/12 03:48:05 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:05 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : subdir/subdirA: Making directory with metadata
2025/11/12 03:48:05 INFO  : subdir/subdirA: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/11/12 03:48:05 DEBUG : Added delayed dir = "subdir/subdirA", newDst=subdir/subdirA
2025/11/12 03:48:05 INFO  : subdirX/subdirX1: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/11/12 03:48:05 DEBUG : subdir/subdirB: Making directory with metadata
2025/11/12 03:48:05 DEBUG : Added delayed dir = "subdirX/subdirX1", newDst=subdirX/subdirX1
2025/11/12 03:48:05 INFO  : subdir/subdirB: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/11/12 03:48:05 DEBUG : Added delayed dir = "subdir/subdirB", newDst=subdir/subdirB
2025/11/12 03:48:05 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : Local file system at /tmp/034802go/initdir/test_check_access_filters-cowabit8: Waiting for checks to finish
2025/11/12 03:48:05 DEBUG : Local file system at /tmp/034802go/initdir/test_check_access_filters-cowabit8: Waiting for transfers to finish
2025/11/12 03:48:05 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST
2025/11/12 03:48:05 INFO  : RCLONE_TEST: Copied (new)
2025/11/12 03:48:05 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt
2025/11/12 03:48:05 INFO  : file2.txt: Copied (new)
2025/11/12 03:48:05 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt
2025/11/12 03:48:05 INFO  : file1.txt: Copied (new)
2025/11/12 03:48:05 DEBUG : file4.txt.fbf05a9b.partial: size = 0 OK
2025/11/12 03:48:05 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:05 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt
2025/11/12 03:48:05 INFO  : file4.txt: Copied (new)
2025/11/12 03:48:05 DEBUG : subdir-not/file20.txt.e2b8d4dd.partial: size = 0 OK
2025/11/12 03:48:05 DEBUG : subdir-not/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:05 DEBUG : subdir-not/file20.txt.e2b8d4dd.partial: renamed to: subdir-not/file20.txt
2025/11/12 03:48:05 INFO  : subdir-not/file20.txt: Copied (new)
2025/11/12 03:48:05 DEBUG : subdir-not/RCLONE_TEST.16d95000.partial: size = 109 OK
2025/11/12 03:48:05 DEBUG : subdir-not/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:05 DEBUG : subdirX/RCLONE_TEST.fd5b40a2.partial: size = 109 OK
2025/11/12 03:48:05 DEBUG : subdirX/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:05 DEBUG : subdir-not/RCLONE_TEST.16d95000.partial: renamed to: subdir-not/RCLONE_TEST
2025/11/12 03:48:05 DEBUG : subdirX/RCLONE_TEST.fd5b40a2.partial: renamed to: subdirX/RCLONE_TEST
2025/11/12 03:48:05 INFO  : subdirX/RCLONE_TEST: Copied (new)
2025/11/12 03:48:05 INFO  : subdir-not/RCLONE_TEST: Copied (new)
2025/11/12 03:48:05 DEBUG : file3.txt.a74079f2.partial: size = 0 OK
2025/11/12 03:48:05 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:05 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt
2025/11/12 03:48:05 DEBUG : subdir-not/subdir-not2/file30.txt.e99a79ee.partial: size = 0 OK
2025/11/12 03:48:05 INFO  : file3.txt: Copied (new)
2025/11/12 03:48:05 DEBUG : subdir-not/subdir-not2/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:05 DEBUG : subdir-not/subdir-not2/file30.txt.e99a79ee.partial: renamed to: subdir-not/subdir-not2/file30.txt
2025/11/12 03:48:05 INFO  : subdir-not/subdir-not2/file30.txt: Copied (new)
2025/11/12 03:48:05 DEBUG : subdirX/file20.txt.0c4add8a.partial: size = 0 OK
2025/11/12 03:48:05 DEBUG : subdirX/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:05 DEBUG : subdirX/file20.txt.0c4add8a.partial: renamed to: subdirX/file20.txt
2025/11/12 03:48:05 INFO  : subdirX/file20.txt: Copied (new)
2025/11/12 03:48:05 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.51791ac5.partial: size = 109 OK
2025/11/12 03:48:05 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: size = 109 OK
2025/11/12 03:48:05 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK
2025/11/12 03:48:05 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:05 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:05 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: renamed to: subdir/RCLONE_TEST
2025/11/12 03:48:05 INFO  : subdir/RCLONE_TEST: Copied (new)
2025/11/12 03:48:05 DEBUG : subdir/subdirB/RCLONE_TEST.37da2e99.partial: size = 109 OK
2025/11/12 03:48:05 DEBUG : subdir/subdirB/file30.txt.ca7c4d29.partial: size = 0 OK
2025/11/12 03:48:05 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:05 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt
2025/11/12 03:48:05 INFO  : subdir/file20.txt: Copied (new)
2025/11/12 03:48:05 DEBUG : subdir/subdirB/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:05 DEBUG : subdir/subdirB/file30.txt.ca7c4d29.partial: renamed to: subdir/subdirB/file30.txt
2025/11/12 03:48:05 INFO  : subdir/subdirB/file30.txt: Copied (new)
2025/11/12 03:48:05 DEBUG : subdir/subdirB/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:05 DEBUG : subdir/subdirB/RCLONE_TEST.37da2e99.partial: renamed to: subdir/subdirB/RCLONE_TEST
2025/11/12 03:48:05 INFO  : subdir/subdirB/RCLONE_TEST: Copied (new)
2025/11/12 03:48:05 DEBUG : subdirX/subdirX1/file30.txt.0106cff7.partial: size = 0 OK
2025/11/12 03:48:05 DEBUG : subdirX/subdirX1/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:05 DEBUG : subdirX/subdirX1/file30.txt.0106cff7.partial: renamed to: subdirX/subdirX1/file30.txt
2025/11/12 03:48:05 INFO  : subdirX/subdirX1/file30.txt: Copied (new)
2025/11/12 03:48:05 DEBUG : subdir/subdirA/file30.txt.03485624.partial: size = 0 OK
2025/11/12 03:48:05 DEBUG : subdir/subdirA/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:05 DEBUG : subdir/subdirA/file30.txt.03485624.partial: renamed to: subdir/subdirA/file30.txt
2025/11/12 03:48:05 INFO  : subdir/subdirA/file30.txt: Copied (new)
2025/11/12 03:48:05 DEBUG : subdirX/subdirX1/RCLONE_TEST.09a85483.partial: size = 109 OK
2025/11/12 03:48:05 DEBUG : subdirX/subdirX1/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:05 DEBUG : subdirX/subdirX1/RCLONE_TEST.09a85483.partial: renamed to: subdirX/subdirX1/RCLONE_TEST
2025/11/12 03:48:05 INFO  : subdirX/subdirX1/RCLONE_TEST: Copied (new)
2025/11/12 03:48:05 DEBUG : subdir/subdirA/RCLONE_TEST.b780822c.partial: size = 109 OK
2025/11/12 03:48:05 DEBUG : subdir/subdirA/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:05 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.51791ac5.partial: renamed to: subdir-not/subdir-not2/RCLONE_TEST
2025/11/12 03:48:05 DEBUG : subdir/subdirA/RCLONE_TEST.b780822c.partial: renamed to: subdir/subdirA/RCLONE_TEST
2025/11/12 03:48:05 INFO  : subdir/subdirA/RCLONE_TEST: Copied (new)
2025/11/12 03:48:05 INFO  : subdir-not/subdir-not2/RCLONE_TEST: Copied (new)
2025/11/12 03:48:05 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/11/12 03:48:05 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/11/12 03:48:05 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/11/12 03:48:05 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/11/12 03:48:05 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/11/12 03:48:05 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/11/12 03:48:05 INFO  : subdir: Set directory modification time (using SetModTime)
2025/11/12 03:48:05 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access_filters/modfiles"
2025/11/12 03:48:05 DEBUG : Creating backend with remote "/tmp/034802go/datadir/test_check_access_filters-piyojel3"
2025/11/12 03:48:05 DEBUG : exclude-other-filtersfile.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : include-other-filtersfile.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:05 DEBUG : Local file system at /tmp/034802go/datadir/test_check_access_filters-piyojel3: Waiting for checks to finish
2025/11/12 03:48:05 DEBUG : Local file system at /tmp/034802go/datadir/test_check_access_filters-piyojel3: Waiting for transfers to finish
2025/11/12 03:48:05 DEBUG : include-other-filtersfile.txt.8126a844.partial: size = 178 OK
2025/11/12 03:48:05 DEBUG : exclude-other-filtersfile.txt.955454a7.partial: size = 173 OK
2025/11/12 03:48:05 DEBUG : include-other-filtersfile.txt: md5 = 2ec13b2813141ed088e5978ef5a47b0e OK
2025/11/12 03:48:05 DEBUG : exclude-other-filtersfile.txt: md5 = 5fcc6205d7df1c2e9ed3a15a1356b345 OK
2025/11/12 03:48:05 DEBUG : include-other-filtersfile.txt.8126a844.partial: renamed to: include-other-filtersfile.txt
2025/11/12 03:48:05 INFO  : include-other-filtersfile.txt: Copied (new)
2025/11/12 03:48:05 DEBUG : exclude-other-filtersfile.txt.955454a7.partial: renamed to: exclude-other-filtersfile.txt
2025/11/12 03:48:05 INFO  : exclude-other-filtersfile.txt: Copied (new)
2025/11/12 03:48:05 DEBUG : Waiting for deletions to finish
2025/11/12 03:48:05 ERROR : error listing: directory not found
2025/11/12 03:48:05 ERROR : Local file system at /tmp/034802go/check_access_filters/path1: Failed to list "": directory not found
2025/11/12 03:48:05 DEBUG : removing 1 level 0 directories
2025/11/12 03:48:05 INFO  : Local file system at /tmp/034802go/check_access_filters/path1: Removing directory
2025/11/12 03:48:05 ERROR : Failed to rmdir: stat /tmp/034802go/check_access_filters/path1: no such file or directory
2025/11/12 03:48:05 INFO  : B2 bucket rclone-test-bapahet9fubo path 034802go/check_access_filters/path2: cleaning bucket "rclone-test-bapahet9fubo" of all files
2025/11/12 03:48:06 ERROR : error listing: directory not found
2025/11/12 03:48:06 NOTICE: checking initFs Local file system at /tmp/034802go/initdir/test_check_access_filters-cowabit8
2025/11/12 03:48:06 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : subdir-not: Making directory with metadata
2025/11/12 03:48:06 INFO  : subdir-not: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/11/12 03:48:06 DEBUG : Added delayed dir = "subdir-not", newDst=subdir-not
2025/11/12 03:48:06 DEBUG : subdir: Making directory with metadata
2025/11/12 03:48:06 INFO  : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/11/12 03:48:06 DEBUG : Added delayed dir = "subdir", newDst=subdir
2025/11/12 03:48:06 DEBUG : subdirX: Making directory with metadata
2025/11/12 03:48:06 INFO  : subdirX: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/11/12 03:48:06 DEBUG : Added delayed dir = "subdirX", newDst=subdirX
2025/11/12 03:48:06 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : subdirX/subdirX1: Making directory with metadata
2025/11/12 03:48:06 INFO  : subdirX/subdirX1: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/11/12 03:48:06 DEBUG : Added delayed dir = "subdirX/subdirX1", newDst=subdirX/subdirX1
2025/11/12 03:48:06 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : subdir-not/subdir-not2: Making directory with metadata
2025/11/12 03:48:06 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:06 INFO  : subdir-not/subdir-not2: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/11/12 03:48:06 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : Added delayed dir = "subdir-not/subdir-not2", newDst=subdir-not/subdir-not2
2025/11/12 03:48:06 DEBUG : subdir/subdirA: Making directory with metadata
2025/11/12 03:48:06 INFO  : subdir/subdirA: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/11/12 03:48:06 DEBUG : Added delayed dir = "subdir/subdirA", newDst=subdir/subdirA
2025/11/12 03:48:06 DEBUG : subdir/subdirB: Making directory with metadata
2025/11/12 03:48:06 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:06 INFO  : subdir/subdirB: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/11/12 03:48:06 DEBUG : Added delayed dir = "subdir/subdirB", newDst=subdir/subdirB
2025/11/12 03:48:06 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:06 DEBUG : Local file system at /tmp/034802go/check_access_filters/path1: Waiting for checks to finish
2025/11/12 03:48:06 DEBUG : Local file system at /tmp/034802go/check_access_filters/path1: Waiting for transfers to finish
2025/11/12 03:48:06 DEBUG : file2.txt.3230ad67.partial: size = 0 OK
2025/11/12 03:48:06 DEBUG : file1.txt.56d0d699.partial: size = 0 OK
2025/11/12 03:48:06 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:06 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt
2025/11/12 03:48:06 INFO  : file2.txt: Copied (new)
2025/11/12 03:48:06 DEBUG : file3.txt.a74079f2.partial: size = 0 OK
2025/11/12 03:48:06 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:06 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt
2025/11/12 03:48:06 INFO  : file1.txt: Copied (new)
2025/11/12 03:48:06 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:06 DEBUG : file4.txt.fbf05a9b.partial: size = 0 OK
2025/11/12 03:48:06 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt
2025/11/12 03:48:06 INFO  : file3.txt: Copied (new)
2025/11/12 03:48:06 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:06 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt
2025/11/12 03:48:06 INFO  : file4.txt: Copied (new)
2025/11/12 03:48:06 DEBUG : subdirX/file20.txt.0c4add8a.partial: size = 0 OK
2025/11/12 03:48:06 DEBUG : subdirX/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:06 DEBUG : subdirX/file20.txt.0c4add8a.partial: renamed to: subdirX/file20.txt
2025/11/12 03:48:06 INFO  : subdirX/file20.txt: Copied (new)
2025/11/12 03:48:06 DEBUG : subdirX/subdirX1/file30.txt.0106cff7.partial: size = 0 OK
2025/11/12 03:48:06 DEBUG : subdirX/subdirX1/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:06 DEBUG : subdirX/subdirX1/file30.txt.0106cff7.partial: renamed to: subdirX/subdirX1/file30.txt
2025/11/12 03:48:06 INFO  : subdirX/subdirX1/file30.txt: Copied (new)
2025/11/12 03:48:06 DEBUG : subdirX/subdirX1/RCLONE_TEST.09a85483.partial: size = 109 OK
2025/11/12 03:48:06 DEBUG : subdirX/subdirX1/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:06 DEBUG : subdirX/subdirX1/RCLONE_TEST.09a85483.partial: renamed to: subdirX/subdirX1/RCLONE_TEST
2025/11/12 03:48:06 DEBUG : subdirX/RCLONE_TEST.fd5b40a2.partial: size = 109 OK
2025/11/12 03:48:06 INFO  : subdirX/subdirX1/RCLONE_TEST: Copied (new)
2025/11/12 03:48:06 DEBUG : subdirX/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:06 DEBUG : subdir-not/file20.txt.e2b8d4dd.partial: size = 0 OK
2025/11/12 03:48:06 DEBUG : subdir-not/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:06 DEBUG : subdirX/RCLONE_TEST.fd5b40a2.partial: renamed to: subdirX/RCLONE_TEST
2025/11/12 03:48:06 INFO  : subdirX/RCLONE_TEST: Copied (new)
2025/11/12 03:48:06 DEBUG : subdir-not/file20.txt.e2b8d4dd.partial: renamed to: subdir-not/file20.txt
2025/11/12 03:48:06 INFO  : subdir-not/file20.txt: Copied (new)
2025/11/12 03:48:06 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK
2025/11/12 03:48:06 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:06 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST
2025/11/12 03:48:06 INFO  : RCLONE_TEST: Copied (new)
2025/11/12 03:48:06 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK
2025/11/12 03:48:06 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: size = 109 OK
2025/11/12 03:48:06 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:06 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: renamed to: subdir/RCLONE_TEST
2025/11/12 03:48:06 INFO  : subdir/RCLONE_TEST: Copied (new)
2025/11/12 03:48:06 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:06 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt
2025/11/12 03:48:06 INFO  : subdir/file20.txt: Copied (new)
2025/11/12 03:48:06 DEBUG : subdir-not/subdir-not2/file30.txt.e99a79ee.partial: size = 0 OK
2025/11/12 03:48:06 DEBUG : subdir-not/subdir-not2/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:06 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.51791ac5.partial: size = 109 OK
2025/11/12 03:48:06 DEBUG : subdir-not/RCLONE_TEST.16d95000.partial: size = 109 OK
2025/11/12 03:48:06 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:06 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.51791ac5.partial: renamed to: subdir-not/subdir-not2/RCLONE_TEST
2025/11/12 03:48:06 INFO  : subdir-not/subdir-not2/RCLONE_TEST: Copied (new)
2025/11/12 03:48:06 DEBUG : subdir-not/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:06 DEBUG : subdir-not/RCLONE_TEST.16d95000.partial: renamed to: subdir-not/RCLONE_TEST
2025/11/12 03:48:06 INFO  : subdir-not/RCLONE_TEST: Copied (new)
2025/11/12 03:48:06 DEBUG : subdir/subdirB/file30.txt.ca7c4d29.partial: size = 0 OK
2025/11/12 03:48:06 DEBUG : subdir/subdirB/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:06 DEBUG : subdir/subdirB/file30.txt.ca7c4d29.partial: renamed to: subdir/subdirB/file30.txt
2025/11/12 03:48:06 INFO  : subdir/subdirB/file30.txt: Copied (new)
2025/11/12 03:48:06 DEBUG : subdir-not/subdir-not2/file30.txt.e99a79ee.partial: renamed to: subdir-not/subdir-not2/file30.txt
2025/11/12 03:48:06 INFO  : subdir-not/subdir-not2/file30.txt: Copied (new)
2025/11/12 03:48:06 DEBUG : subdir/subdirB/RCLONE_TEST.37da2e99.partial: size = 109 OK
2025/11/12 03:48:06 DEBUG : subdir/subdirB/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:06 DEBUG : subdir/subdirB/RCLONE_TEST.37da2e99.partial: renamed to: subdir/subdirB/RCLONE_TEST
2025/11/12 03:48:06 INFO  : subdir/subdirB/RCLONE_TEST: Copied (new)
2025/11/12 03:48:06 DEBUG : subdir/subdirA/RCLONE_TEST.b780822c.partial: size = 109 OK
2025/11/12 03:48:06 DEBUG : subdir/subdirA/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:06 DEBUG : subdir/subdirA/file30.txt.03485624.partial: size = 0 OK
2025/11/12 03:48:06 DEBUG : subdir/subdirA/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:48:06 DEBUG : subdir/subdirA/RCLONE_TEST.b780822c.partial: renamed to: subdir/subdirA/RCLONE_TEST
2025/11/12 03:48:06 INFO  : subdir/subdirA/RCLONE_TEST: Copied (new)
2025/11/12 03:48:06 DEBUG : subdir/subdirA/file30.txt.03485624.partial: renamed to: subdir/subdirA/file30.txt
2025/11/12 03:48:06 INFO  : subdir/subdirA/file30.txt: Copied (new)
2025/11/12 03:48:06 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/11/12 03:48:06 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/11/12 03:48:06 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/11/12 03:48:06 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/11/12 03:48:06 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/11/12 03:48:06 INFO  : subdir: Set directory modification time (using SetModTime)
2025/11/12 03:48:06 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/11/12 03:48:06 NOTICE: checking Path1 Local file system at /tmp/034802go/check_access_filters/path1
2025/11/12 03:48:07 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:07 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:07 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:07 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:07 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:07 INFO  : subdir-not: Making directory
2025/11/12 03:48:07 INFO  : subdir: Making directory
2025/11/12 03:48:07 INFO  : subdirX: Making directory
2025/11/12 03:48:07 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:07 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:07 INFO  : subdirX/subdirX1: Making directory
2025/11/12 03:48:07 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:07 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:07 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:07 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:07 INFO  : subdir-not/subdir-not2: Making directory
2025/11/12 03:48:07 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:07 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:07 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:07 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:07 INFO  : subdir/subdirA: Making directory
2025/11/12 03:48:07 INFO  : subdir/subdirB: Making directory
2025/11/12 03:48:07 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:07 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:07 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:07 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:07 DEBUG : B2 bucket rclone-test-bapahet9fubo path 034802go/check_access_filters/path2: Waiting for checks to finish
2025/11/12 03:48:07 DEBUG : B2 bucket rclone-test-bapahet9fubo path 034802go/check_access_filters/path2: Waiting for transfers to finish
2025/11/12 03:48:07 DEBUG : file2.txt: Clearing upload URL because of error: no tomes available (503 service_unavailable): trying again in 1s
2025/11/12 03:48:07 DEBUG : pacer: low level retry 1/1 (error no tomes available (503 service_unavailable): trying again in 1s)
2025/11/12 03:48:07 DEBUG : pacer: Rate limited, increasing sleep to 1s
2025/11/12 03:48:07 DEBUG : file2.txt: Received error: no tomes available (503 service_unavailable): trying again in 1s - low level retry 0/10
2025/11/12 03:48:07 DEBUG : pacer: Reducing sleep to 500ms
2025/11/12 03:48:08 DEBUG : pacer: Reducing sleep to 250ms
2025/11/12 03:48:08 DEBUG : pacer: Reducing sleep to 125ms
2025/11/12 03:48:08 DEBUG : pacer: Reducing sleep to 62.5ms
2025/11/12 03:48:08 DEBUG : file3.txt: size = 0 OK
2025/11/12 03:48:08 DEBUG : file1.txt: size = 0 OK
2025/11/12 03:48:08 DEBUG : file3.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:48:08 INFO  : file3.txt: Copied (new)
2025/11/12 03:48:08 DEBUG : file1.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:48:08 INFO  : file1.txt: Copied (new)
2025/11/12 03:48:08 DEBUG : pacer: Reducing sleep to 31.25ms
2025/11/12 03:48:08 DEBUG : RCLONE_TEST: size = 109 OK
2025/11/12 03:48:08 DEBUG : RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK
2025/11/12 03:48:08 INFO  : RCLONE_TEST: Copied (new)
2025/11/12 03:48:08 DEBUG : pacer: Reducing sleep to 15.625ms
2025/11/12 03:48:08 DEBUG : file4.txt: size = 0 OK
2025/11/12 03:48:08 DEBUG : file4.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:48:08 INFO  : file4.txt: Copied (new)
2025/11/12 03:48:09 DEBUG : pacer: Reducing sleep to 10ms
2025/11/12 03:48:09 DEBUG : subdirX/file20.txt: size = 0 OK
2025/11/12 03:48:09 DEBUG : subdirX/file20.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:48:09 INFO  : subdirX/file20.txt: Copied (new)
2025/11/12 03:48:09 DEBUG : subdirX/subdirX1/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:09 DEBUG : subdirX/subdirX1/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK
2025/11/12 03:48:09 INFO  : subdirX/subdirX1/RCLONE_TEST: Copied (new)
2025/11/12 03:48:09 DEBUG : subdir-not/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:09 DEBUG : subdir-not/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK
2025/11/12 03:48:09 INFO  : subdir-not/RCLONE_TEST: Copied (new)
2025/11/12 03:48:09 DEBUG : subdirX/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:09 DEBUG : subdirX/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK
2025/11/12 03:48:09 INFO  : subdirX/RCLONE_TEST: Copied (new)
2025/11/12 03:48:09 DEBUG : subdir-not/file20.txt: size = 0 OK
2025/11/12 03:48:09 DEBUG : subdir-not/file20.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:48:09 INFO  : subdir-not/file20.txt: Copied (new)
2025/11/12 03:48:09 DEBUG : file2.txt: size = 0 OK
2025/11/12 03:48:09 DEBUG : file2.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:48:09 INFO  : file2.txt: Copied (new)
2025/11/12 03:48:09 DEBUG : subdir-not/subdir-not2/file30.txt: size = 0 OK
2025/11/12 03:48:09 DEBUG : subdir-not/subdir-not2/file30.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:48:09 INFO  : subdir-not/subdir-not2/file30.txt: Copied (new)
2025/11/12 03:48:09 DEBUG : subdirX/subdirX1/file30.txt: size = 0 OK
2025/11/12 03:48:09 DEBUG : subdirX/subdirX1/file30.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:48:09 INFO  : subdirX/subdirX1/file30.txt: Copied (new)
2025/11/12 03:48:10 DEBUG : subdir/file20.txt: size = 0 OK
2025/11/12 03:48:10 DEBUG : subdir/file20.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:48:10 INFO  : subdir/file20.txt: Copied (new)
2025/11/12 03:48:10 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:10 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK
2025/11/12 03:48:10 INFO  : subdir-not/subdir-not2/RCLONE_TEST: Copied (new)
2025/11/12 03:48:10 DEBUG : subdir/subdirB/file30.txt: size = 0 OK
2025/11/12 03:48:10 DEBUG : subdir/subdirB/file30.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:48:10 INFO  : subdir/subdirB/file30.txt: Copied (new)
2025/11/12 03:48:10 DEBUG : subdir/subdirB/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:10 DEBUG : subdir/subdirB/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK
2025/11/12 03:48:10 INFO  : subdir/subdirB/RCLONE_TEST: Copied (new)
2025/11/12 03:48:10 DEBUG : subdir/subdirA/file30.txt: size = 0 OK
2025/11/12 03:48:10 DEBUG : subdir/subdirA/file30.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:48:10 INFO  : subdir/subdirA/file30.txt: Copied (new)
2025/11/12 03:48:10 DEBUG : subdir/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:10 DEBUG : subdir/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK
2025/11/12 03:48:10 INFO  : subdir/RCLONE_TEST: Copied (new)
2025/11/12 03:48:10 DEBUG : subdir/subdirA/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:10 DEBUG : subdir/subdirA/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK
2025/11/12 03:48:10 INFO  : subdir/subdirA/RCLONE_TEST: Copied (new)
2025/11/12 03:48:10 NOTICE: checking path2 B2 bucket rclone-test-bapahet9fubo path 034802go/check_access_filters/path2
2025/11/12 03:48:11 NOTICE: (01)  : test check-access-filters
2025/11/12 03:48:11 NOTICE: (02)  : test EXCLUDE - OTHER TESTS
2025/11/12 03:48:11 NOTICE: (03)  : copy-file /tmp/034802go/datadir/test_check_access_filters-piyojel3/exclude-other-filtersfile.txt /tmp/034802go/workdir/
2025/11/12 03:48:11 DEBUG : copyFile "/tmp/034802go/datadir/test_check_access_filters-piyojel3/exclude-other-filtersfile.txt" to "/tmp/034802go/workdir/" as ""
2025/11/12 03:48:11 DEBUG : Creating backend with remote "/tmp/034802go/datadir/test_check_access_filters-piyojel3/exclude-other-filtersfile.txt"
2025/11/12 03:48:11 DEBUG : Creating backend with remote "/tmp/034802go/workdir/"
2025/11/12 03:48:11 DEBUG : operations.CopyFile "exclude-other-filtersfile.txt" to "Local file system at /tmp/034802go/workdir" as "exclude-other-filtersfile.txt"
2025/11/12 03:48:11 DEBUG : exclude-other-filtersfile.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:11 DEBUG : exclude-other-filtersfile.txt.955454a7.partial: size = 173 OK
2025/11/12 03:48:11 DEBUG : exclude-other-filtersfile.txt: md5 = 5fcc6205d7df1c2e9ed3a15a1356b345 OK
2025/11/12 03:48:11 DEBUG : exclude-other-filtersfile.txt.955454a7.partial: renamed to: exclude-other-filtersfile.txt
2025/11/12 03:48:11 INFO  : exclude-other-filtersfile.txt: Copied (new)
2025/11/12 03:48:11 NOTICE: (04)  : test resync to get the filters file md5 built.
2025/11/12 03:48:11 NOTICE: (05)  : bisync resync filters-file=/tmp/034802go/workdir/exclude-other-filtersfile.txt
2025/11/12 03:48:15 INFO  : subdir: Set directory modification time (using SetModTime)
2025/11/12 03:48:15 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/11/12 03:48:15 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/11/12 03:48:15 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/11/12 03:48:15 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/11/12 03:48:15 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/11/12 03:48:15 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/11/12 03:48:15 DEBUG : B2 bucket rclone-test-bapahet9fubo path 034802go/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:48:15 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/11/12 03:48:15 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/11/12 03:48:15 INFO  : Synching Path1 "/tmp/034802go/check_access_filters/path1/" with Path2 "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/"
2025/11/12 03:48:15 INFO  : Using filters file /tmp/034802go/workdir/exclude-other-filtersfile.txt
2025/11/12 03:48:15 INFO  : Storing filters file hash to /tmp/034802go/workdir/exclude-other-filtersfile.txt.md5
2025/11/12 03:48:15 INFO  : Copying Path2 files to Path1
2025/11/12 03:48:15 INFO  : - Path2    Resync is copying files to         - Path1
2025/11/12 03:48:15 INFO  : There was nothing to transfer
2025/11/12 03:48:15 INFO  : - Path1    Resync is copying files to         - Path2
2025/11/12 03:48:16 INFO  : There was nothing to transfer
2025/11/12 03:48:16 INFO  : Resync updating listings
2025/11/12 03:48:16 INFO  : Validating listings for Path1 "/tmp/034802go/check_access_filters/path1/" vs Path2 "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/"
2025/11/12 03:48:16 INFO  : Bisync successful
2025/11/12 03:48:16 NOTICE: (06)  : test EXCLUDE - test filters for check access
2025/11/12 03:48:16 NOTICE: (07)  : bisync check-access filters-file=/tmp/034802go/workdir/exclude-other-filtersfile.txt
2025/11/12 03:48:19 INFO  : subdir: Set directory modification time (using SetModTime)
2025/11/12 03:48:19 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/11/12 03:48:19 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/11/12 03:48:19 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/11/12 03:48:19 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/11/12 03:48:19 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/11/12 03:48:19 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/11/12 03:48:19 DEBUG : B2 bucket rclone-test-bapahet9fubo path 034802go/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:48:19 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/11/12 03:48:19 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/11/12 03:48:19 INFO  : Synching Path1 "/tmp/034802go/check_access_filters/path1/" with Path2 "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/"
2025/11/12 03:48:19 INFO  : Using filters file /tmp/034802go/workdir/exclude-other-filtersfile.txt
2025/11/12 03:48:19 INFO  : Building Path1 and Path2 listings
2025/11/12 03:48:20 INFO  : Path1 checking for diffs
2025/11/12 03:48:20 INFO  : Path2 checking for diffs
2025/11/12 03:48:20 INFO  : Checking access health
2025/11/12 03:48:20 INFO  : Found 3 matching "RCLONE_TEST" files on both paths
2025/11/12 03:48:20 INFO  : No changes found
2025/11/12 03:48:20 INFO  : Updating listings
2025/11/12 03:48:20 INFO  : Validating listings for Path1 "/tmp/034802go/check_access_filters/path1/" vs Path2 "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/"
2025/11/12 03:48:20 INFO  : Bisync successful
2025/11/12 03:48:20 NOTICE: (08)  : copy-listings exclude-initial
2025/11/12 03:48:20 NOTICE: (09)  : test EXCLUDE - delete RCLONE_TEST files in excluded directories
2025/11/12 03:48:20 NOTICE: (10)  : delete-file TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/subdir/subdirA/RCLONE_TEST
2025/11/12 03:48:20 DEBUG : Creating backend with remote "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/subdir/subdirA/"
2025/11/12 03:48:21 DEBUG : fs cache: renaming cache item "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/subdir/subdirA/" to be canonical "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/subdir/subdirA"
2025/11/12 03:48:22 INFO  : RCLONE_TEST: Deleted
2025/11/12 03:48:22 NOTICE: (11)  : delete-file /tmp/034802go/check_access_filters/path1/subdir-not/RCLONE_TEST
2025/11/12 03:48:22 DEBUG : Creating backend with remote "/tmp/034802go/check_access_filters/path1/subdir-not/"
2025/11/12 03:48:22 DEBUG : fs cache: renaming cache item "/tmp/034802go/check_access_filters/path1/subdir-not/" to be canonical "/tmp/034802go/check_access_filters/path1/subdir-not"
2025/11/12 03:48:22 INFO  : RCLONE_TEST: Deleted
2025/11/12 03:48:22 NOTICE: (12)  : delete-file TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/subdir-not/subdir-not2/RCLONE_TEST
2025/11/12 03:48:22 DEBUG : Creating backend with remote "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/subdir-not/subdir-not2/"
2025/11/12 03:48:23 DEBUG : fs cache: renaming cache item "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/subdir-not/subdir-not2/" to be canonical "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/subdir-not/subdir-not2"
2025/11/12 03:48:24 INFO  : RCLONE_TEST: Deleted
2025/11/12 03:48:24 NOTICE: (13)  : delete-file /tmp/034802go/check_access_filters/path1/subdirX/RCLONE_TEST
2025/11/12 03:48:24 DEBUG : Creating backend with remote "/tmp/034802go/check_access_filters/path1/subdirX/"
2025/11/12 03:48:24 DEBUG : fs cache: renaming cache item "/tmp/034802go/check_access_filters/path1/subdirX/" to be canonical "/tmp/034802go/check_access_filters/path1/subdirX"
2025/11/12 03:48:24 INFO  : RCLONE_TEST: Deleted
2025/11/12 03:48:24 NOTICE: (14)  : test EXCLUDE - test should PASS
2025/11/12 03:48:24 NOTICE: (15)  : bisync check-access filters-file=/tmp/034802go/workdir/exclude-other-filtersfile.txt
2025/11/12 03:48:28 INFO  : subdir: Set directory modification time (using SetModTime)
2025/11/12 03:48:28 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/11/12 03:48:28 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/11/12 03:48:28 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/11/12 03:48:28 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/11/12 03:48:28 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/11/12 03:48:28 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/11/12 03:48:28 DEBUG : B2 bucket rclone-test-bapahet9fubo path 034802go/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:48:28 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/11/12 03:48:28 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/11/12 03:48:28 INFO  : Synching Path1 "/tmp/034802go/check_access_filters/path1/" with Path2 "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/"
2025/11/12 03:48:28 INFO  : Using filters file /tmp/034802go/workdir/exclude-other-filtersfile.txt
2025/11/12 03:48:28 INFO  : Building Path1 and Path2 listings
2025/11/12 03:48:29 INFO  : Path1 checking for diffs
2025/11/12 03:48:29 INFO  : Path2 checking for diffs
2025/11/12 03:48:29 INFO  : Checking access health
2025/11/12 03:48:29 INFO  : Found 3 matching "RCLONE_TEST" files on both paths
2025/11/12 03:48:29 INFO  : No changes found
2025/11/12 03:48:29 INFO  : Updating listings
2025/11/12 03:48:29 INFO  : Validating listings for Path1 "/tmp/034802go/check_access_filters/path1/" vs Path2 "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/"
2025/11/12 03:48:29 INFO  : Bisync successful
2025/11/12 03:48:29 NOTICE: (16)  : copy-listings exclude-pass-run
2025/11/12 03:48:29 NOTICE: (17)  : test EXCLUDE - delete RCLONE_TEST files in included directories
2025/11/12 03:48:29 NOTICE: (18)  : delete-file TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/RCLONE_TEST
2025/11/12 03:48:29 DEBUG : Creating backend with remote "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/"
2025/11/12 03:48:30 DEBUG : fs cache: renaming cache item "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/" to be canonical "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2"
2025/11/12 03:48:31 INFO  : RCLONE_TEST: Deleted
2025/11/12 03:48:31 NOTICE: (19)  : delete-file /tmp/034802go/check_access_filters/path1/subdir/RCLONE_TEST
2025/11/12 03:48:31 DEBUG : Creating backend with remote "/tmp/034802go/check_access_filters/path1/subdir/"
2025/11/12 03:48:31 DEBUG : fs cache: renaming cache item "/tmp/034802go/check_access_filters/path1/subdir/" to be canonical "/tmp/034802go/check_access_filters/path1/subdir"
2025/11/12 03:48:31 INFO  : RCLONE_TEST: Deleted
2025/11/12 03:48:31 NOTICE: (20)  : test EXCLUDE - test should ABORT
2025/11/12 03:48:31 NOTICE: (21)  : bisync check-access filters-file=/tmp/034802go/workdir/exclude-other-filtersfile.txt
2025/11/12 03:48:34 INFO  : subdir: Set directory modification time (using SetModTime)
2025/11/12 03:48:34 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/11/12 03:48:34 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/11/12 03:48:34 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/11/12 03:48:34 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/11/12 03:48:34 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/11/12 03:48:34 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/11/12 03:48:34 DEBUG : B2 bucket rclone-test-bapahet9fubo path 034802go/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:48:34 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/11/12 03:48:34 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/11/12 03:48:34 INFO  : Synching Path1 "/tmp/034802go/check_access_filters/path1/" with Path2 "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/"
2025/11/12 03:48:34 INFO  : Using filters file /tmp/034802go/workdir/exclude-other-filtersfile.txt
2025/11/12 03:48:34 INFO  : Building Path1 and Path2 listings
2025/11/12 03:48:35 INFO  : Path1 checking for diffs
2025/11/12 03:48:35 INFO  : - Path1    File was deleted          - subdir/RCLONE_TEST
2025/11/12 03:48:35 INFO  : Path1:    1 changes:    0 new,    0 modified,    1 deleted
2025/11/12 03:48:35 INFO  : Path2 checking for diffs
2025/11/12 03:48:35 INFO  : - Path2    File was deleted          - RCLONE_TEST
2025/11/12 03:48:35 INFO  : Path2:    1 changes:    0 new,    0 modified,    1 deleted
2025/11/12 03:48:35 INFO  : Checking access health
2025/11/12 03:48:35 ERROR : -          Access test failed: Path1 file not found in Path2 - RCLONE_TEST
2025/11/12 03:48:35 ERROR : -          Access test failed: Path2 file not found in Path1 - subdir/RCLONE_TEST
2025/11/12 03:48:35 ERROR : Bisync critical error: check file check failed
2025/11/12 03:48:35 ERROR : Bisync aborted. Must run --resync to recover.
2025/11/12 03:48:35 NOTICE: Bisync error: bisync aborted
2025/11/12 03:48:35 NOTICE: (22)  : move-listings exclude-error-run
2025/11/12 03:48:35 NOTICE: (23)  : test INCLUDE - OTHER TESTS
2025/11/12 03:48:35 NOTICE: (24)  : test reset to the initial state
2025/11/12 03:48:35 NOTICE: (25)  : copy-dir /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access_filters/initial /tmp/034802go/check_access_filters/path1/
2025/11/12 03:48:35 DEBUG : Creating backend with remote "/tmp/034802go/check_access_filters/path1/"
2025/11/12 03:48:35 DEBUG : fs cache: renaming cache item "/tmp/034802go/check_access_filters/path1/" to be canonical "/tmp/034802go/check_access_filters/path1"
2025/11/12 03:48:35 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/11/12 03:48:35 DEBUG : Added delayed dir = "subdir-not", newDst=subdir-not
2025/11/12 03:48:35 DEBUG : file2.txt: size = 0 OK
2025/11/12 03:48:35 DEBUG : file1.txt: size = 0 OK
2025/11/12 03:48:35 INFO  : subdir: Set directory modification time (using SetModTime)
2025/11/12 03:48:35 DEBUG : file2.txt: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/11/12 03:48:35 DEBUG : Added delayed dir = "subdir", newDst=subdir
2025/11/12 03:48:35 DEBUG : file1.txt: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/11/12 03:48:35 DEBUG : file2.txt: Unchanged skipping
2025/11/12 03:48:35 DEBUG : file1.txt: Unchanged skipping
2025/11/12 03:48:35 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/11/12 03:48:35 DEBUG : Added delayed dir = "subdirX", newDst=subdirX
2025/11/12 03:48:35 DEBUG : file3.txt: size = 0 OK
2025/11/12 03:48:35 DEBUG : file4.txt: size = 0 OK
2025/11/12 03:48:35 DEBUG : file3.txt: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/11/12 03:48:35 DEBUG : file3.txt: Unchanged skipping
2025/11/12 03:48:35 DEBUG : file4.txt: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/11/12 03:48:35 DEBUG : file4.txt: Unchanged skipping
2025/11/12 03:48:35 DEBUG : RCLONE_TEST: size = 109 OK
2025/11/12 03:48:35 DEBUG : RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/11/12 03:48:35 DEBUG : RCLONE_TEST: Unchanged skipping
2025/11/12 03:48:35 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:35 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/11/12 03:48:35 DEBUG : Added delayed dir = "subdirX/subdirX1", newDst=subdirX/subdirX1
2025/11/12 03:48:35 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:35 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/11/12 03:48:35 DEBUG : Added delayed dir = "subdir-not/subdir-not2", newDst=subdir-not/subdir-not2
2025/11/12 03:48:35 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:35 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/11/12 03:48:35 DEBUG : subdirX/file20.txt: size = 0 OK
2025/11/12 03:48:35 DEBUG : subdirX/file20.txt: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/11/12 03:48:35 DEBUG : subdirX/file20.txt: Unchanged skipping
2025/11/12 03:48:35 DEBUG : subdir-not/file20.txt: size = 0 OK
2025/11/12 03:48:35 DEBUG : Added delayed dir = "subdir/subdirA", newDst=subdir/subdirA
2025/11/12 03:48:35 DEBUG : subdir-not/file20.txt: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/11/12 03:48:35 DEBUG : subdir-not/file20.txt: Unchanged skipping
2025/11/12 03:48:35 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/11/12 03:48:35 DEBUG : Added delayed dir = "subdir/subdirB", newDst=subdir/subdirB
2025/11/12 03:48:35 DEBUG : subdir/file20.txt: size = 0 OK
2025/11/12 03:48:35 DEBUG : subdir/file20.txt: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/11/12 03:48:35 DEBUG : subdir/file20.txt: Unchanged skipping
2025/11/12 03:48:35 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:35 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/11/12 03:48:35 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Unchanged skipping
2025/11/12 03:48:35 DEBUG : subdir-not/subdir-not2/file30.txt: size = 0 OK
2025/11/12 03:48:35 DEBUG : subdir-not/subdir-not2/file30.txt: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/11/12 03:48:35 DEBUG : subdir-not/subdir-not2/file30.txt: Unchanged skipping
2025/11/12 03:48:35 DEBUG : subdir/subdirB/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:35 DEBUG : subdir/subdirB/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/11/12 03:48:35 DEBUG : subdir/subdirB/file30.txt: size = 0 OK
2025/11/12 03:48:35 DEBUG : subdir/subdirB/RCLONE_TEST: Unchanged skipping
2025/11/12 03:48:35 DEBUG : subdir/subdirB/file30.txt: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/11/12 03:48:35 DEBUG : subdir/subdirB/file30.txt: Unchanged skipping
2025/11/12 03:48:35 DEBUG : subdir/subdirA/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:35 DEBUG : subdir/subdirA/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/11/12 03:48:35 DEBUG : subdir/subdirA/RCLONE_TEST: Unchanged skipping
2025/11/12 03:48:35 DEBUG : subdirX/subdirX1/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:35 DEBUG : subdirX/subdirX1/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/11/12 03:48:35 DEBUG : subdirX/subdirX1/RCLONE_TEST: Unchanged skipping
2025/11/12 03:48:35 DEBUG : subdirX/subdirX1/file30.txt: size = 0 OK
2025/11/12 03:48:35 DEBUG : subdir/subdirA/file30.txt: size = 0 OK
2025/11/12 03:48:35 DEBUG : subdir/subdirA/file30.txt: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/11/12 03:48:35 DEBUG : subdir/subdirA/file30.txt: Unchanged skipping
2025/11/12 03:48:35 DEBUG : subdirX/subdirX1/file30.txt: Size and modification time the same (differ by 0s, within tolerance 1ns)
2025/11/12 03:48:35 DEBUG : subdirX/subdirX1/file30.txt: Unchanged skipping
2025/11/12 03:48:35 DEBUG : Local file system at /tmp/034802go/check_access_filters/path1: Waiting for checks to finish
2025/11/12 03:48:35 DEBUG : Local file system at /tmp/034802go/check_access_filters/path1: Waiting for transfers to finish
2025/11/12 03:48:35 DEBUG : subdir-not/RCLONE_TEST.16d95000.partial: size = 109 OK
2025/11/12 03:48:35 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: size = 109 OK
2025/11/12 03:48:35 DEBUG : subdirX/RCLONE_TEST.fd5b40a2.partial: size = 109 OK
2025/11/12 03:48:35 DEBUG : subdir-not/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:35 DEBUG : subdirX/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:35 DEBUG : subdir-not/RCLONE_TEST.16d95000.partial: renamed to: subdir-not/RCLONE_TEST
2025/11/12 03:48:35 DEBUG : subdirX/RCLONE_TEST.fd5b40a2.partial: renamed to: subdirX/RCLONE_TEST
2025/11/12 03:48:35 INFO  : subdir-not/RCLONE_TEST: Copied (new)
2025/11/12 03:48:35 INFO  : subdirX/RCLONE_TEST: Copied (new)
2025/11/12 03:48:35 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:48:35 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: renamed to: subdir/RCLONE_TEST
2025/11/12 03:48:35 INFO  : subdir/RCLONE_TEST: Copied (new)
2025/11/12 03:48:35 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/11/12 03:48:35 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/11/12 03:48:35 INFO  : subdir: Set directory modification time (using SetModTime)
2025/11/12 03:48:35 NOTICE: (26)  : sync-dir /tmp/034802go/check_access_filters/path1/ TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/
2025/11/12 03:48:35 DEBUG : fs cache: switching user supplied name "/tmp/034802go/check_access_filters/path1/" for canonical name "/tmp/034802go/check_access_filters/path1"
2025/11/12 03:48:35 DEBUG : fs cache: switching user supplied name "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/" for canonical name "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2"
2025/11/12 03:48:35 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:35 DEBUG : file1.txt: size = 0 OK
2025/11/12 03:48:35 DEBUG : file1.txt: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/11/12 03:48:35 DEBUG : file1.txt: Unchanged skipping
2025/11/12 03:48:35 DEBUG : file3.txt: size = 0 OK
2025/11/12 03:48:35 DEBUG : file3.txt: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/11/12 03:48:35 DEBUG : file3.txt: Unchanged skipping
2025/11/12 03:48:35 DEBUG : file2.txt: size = 0 OK
2025/11/12 03:48:35 DEBUG : file2.txt: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/11/12 03:48:35 DEBUG : file2.txt: Unchanged skipping
2025/11/12 03:48:35 DEBUG : file4.txt: size = 0 OK
2025/11/12 03:48:35 DEBUG : file4.txt: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/11/12 03:48:35 DEBUG : file4.txt: Unchanged skipping
2025/11/12 03:48:35 DEBUG : subdirX/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:35 DEBUG : subdirX/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/11/12 03:48:35 DEBUG : subdirX/RCLONE_TEST: Unchanged skipping
2025/11/12 03:48:35 DEBUG : subdirX/file20.txt: size = 0 OK
2025/11/12 03:48:35 DEBUG : subdirX/file20.txt: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/11/12 03:48:35 DEBUG : subdirX/file20.txt: Unchanged skipping
2025/11/12 03:48:35 DEBUG : subdir-not/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:35 DEBUG : subdir-not/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/11/12 03:48:35 DEBUG : subdir-not/RCLONE_TEST: Unchanged skipping
2025/11/12 03:48:35 DEBUG : subdir-not/file20.txt: size = 0 OK
2025/11/12 03:48:35 DEBUG : subdir-not/file20.txt: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/11/12 03:48:35 DEBUG : subdir-not/file20.txt: Unchanged skipping
2025/11/12 03:48:36 DEBUG : subdir/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:36 DEBUG : subdir/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/11/12 03:48:36 DEBUG : subdir/RCLONE_TEST: Unchanged skipping
2025/11/12 03:48:36 DEBUG : subdir/file20.txt: size = 0 OK
2025/11/12 03:48:36 DEBUG : subdir/file20.txt: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/11/12 03:48:36 DEBUG : subdir/file20.txt: Unchanged skipping
2025/11/12 03:48:36 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:36 DEBUG : subdir-not/subdir-not2/file30.txt: size = 0 OK
2025/11/12 03:48:36 DEBUG : subdir-not/subdir-not2/file30.txt: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/11/12 03:48:36 DEBUG : subdir-not/subdir-not2/file30.txt: Unchanged skipping
2025/11/12 03:48:36 DEBUG : subdirX/subdirX1/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:36 DEBUG : subdirX/subdirX1/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/11/12 03:48:36 DEBUG : subdirX/subdirX1/RCLONE_TEST: Unchanged skipping
2025/11/12 03:48:36 DEBUG : subdirX/subdirX1/file30.txt: size = 0 OK
2025/11/12 03:48:36 DEBUG : subdirX/subdirX1/file30.txt: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/11/12 03:48:36 DEBUG : subdirX/subdirX1/file30.txt: Unchanged skipping
2025/11/12 03:48:36 DEBUG : subdir/subdirB/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:36 DEBUG : subdir/subdirB/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/11/12 03:48:36 DEBUG : subdir/subdirB/RCLONE_TEST: Unchanged skipping
2025/11/12 03:48:36 DEBUG : subdir/subdirB/file30.txt: size = 0 OK
2025/11/12 03:48:36 DEBUG : subdir/subdirB/file30.txt: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/11/12 03:48:36 DEBUG : subdir/subdirB/file30.txt: Unchanged skipping
2025/11/12 03:48:36 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:48:36 DEBUG : subdir/subdirA/file30.txt: size = 0 OK
2025/11/12 03:48:36 DEBUG : subdir/subdirA/file30.txt: Size and modification time the same (differ by 0s, within tolerance 1ms)
2025/11/12 03:48:36 DEBUG : subdir/subdirA/file30.txt: Unchanged skipping
2025/11/12 03:48:36 DEBUG : B2 bucket rclone-test-bapahet9fubo path 034802go/check_access_filters/path2: Waiting for checks to finish
2025/11/12 03:48:36 DEBUG : B2 bucket rclone-test-bapahet9fubo path 034802go/check_access_filters/path2: Waiting for transfers to finish
2025/11/12 03:48:36 DEBUG : RCLONE_TEST: size = 109 OK
2025/11/12 03:48:36 DEBUG : RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK
2025/11/12 03:48:36 INFO  : RCLONE_TEST: Copied (new)
2025/11/12 03:48:36 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:36 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK
2025/11/12 03:48:36 INFO  : subdir-not/subdir-not2/RCLONE_TEST: Copied (new)
2025/11/12 03:48:37 DEBUG : subdir/subdirA/RCLONE_TEST: size = 109 OK
2025/11/12 03:48:37 DEBUG : subdir/subdirA/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK
2025/11/12 03:48:37 INFO  : subdir/subdirA/RCLONE_TEST: Copied (new)
2025/11/12 03:48:37 DEBUG : Waiting for deletions to finish
2025/11/12 03:48:37 NOTICE: (27)  : copy-file /tmp/034802go/datadir/test_check_access_filters-piyojel3/include-other-filtersfile.txt /tmp/034802go/workdir/
2025/11/12 03:48:37 DEBUG : copyFile "/tmp/034802go/datadir/test_check_access_filters-piyojel3/include-other-filtersfile.txt" to "/tmp/034802go/workdir/" as ""
2025/11/12 03:48:37 DEBUG : Creating backend with remote "/tmp/034802go/datadir/test_check_access_filters-piyojel3/include-other-filtersfile.txt"
2025/11/12 03:48:37 DEBUG : Creating backend with remote "/tmp/034802go/workdir/"
2025/11/12 03:48:37 DEBUG : operations.CopyFile "include-other-filtersfile.txt" to "Local file system at /tmp/034802go/workdir" as "include-other-filtersfile.txt"
2025/11/12 03:48:37 DEBUG : include-other-filtersfile.txt: Need to transfer - File not found at Destination
2025/11/12 03:48:37 DEBUG : include-other-filtersfile.txt.8126a844.partial: size = 178 OK
2025/11/12 03:48:37 DEBUG : include-other-filtersfile.txt: md5 = 2ec13b2813141ed088e5978ef5a47b0e OK
2025/11/12 03:48:37 DEBUG : include-other-filtersfile.txt.8126a844.partial: renamed to: include-other-filtersfile.txt
2025/11/12 03:48:37 INFO  : include-other-filtersfile.txt: Copied (new)
2025/11/12 03:48:37 NOTICE: (28)  : bisync resync filters-file=/tmp/034802go/workdir/include-other-filtersfile.txt
2025/11/12 03:48:41 INFO  : subdir: Set directory modification time (using SetModTime)
2025/11/12 03:48:41 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/11/12 03:48:41 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/11/12 03:48:41 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/11/12 03:48:41 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/11/12 03:48:41 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/11/12 03:48:41 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/11/12 03:48:41 DEBUG : B2 bucket rclone-test-bapahet9fubo path 034802go/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:48:41 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/11/12 03:48:41 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/11/12 03:48:41 INFO  : Synching Path1 "/tmp/034802go/check_access_filters/path1/" with Path2 "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/"
2025/11/12 03:48:41 INFO  : Using filters file /tmp/034802go/workdir/include-other-filtersfile.txt
2025/11/12 03:48:41 INFO  : Storing filters file hash to /tmp/034802go/workdir/include-other-filtersfile.txt.md5
2025/11/12 03:48:41 INFO  : Copying Path2 files to Path1
2025/11/12 03:48:41 INFO  : - Path2    Resync is copying files to         - Path1
2025/11/12 03:48:42 INFO  : There was nothing to transfer
2025/11/12 03:48:42 INFO  : - Path1    Resync is copying files to         - Path2
2025/11/12 03:48:42 INFO  : There was nothing to transfer
2025/11/12 03:48:42 INFO  : Resync updating listings
2025/11/12 03:48:42 INFO  : Validating listings for Path1 "/tmp/034802go/check_access_filters/path1/" vs Path2 "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/"
2025/11/12 03:48:42 INFO  : Bisync successful
2025/11/12 03:48:42 NOTICE: (29)  : test INCLUDE - test include/exclude filters for check access
2025/11/12 03:48:42 NOTICE: (30)  : bisync check-access filters-file=/tmp/034802go/workdir/include-other-filtersfile.txt
2025/11/12 03:48:46 INFO  : subdir: Set directory modification time (using SetModTime)
2025/11/12 03:48:46 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/11/12 03:48:46 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/11/12 03:48:46 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/11/12 03:48:46 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/11/12 03:48:46 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/11/12 03:48:46 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/11/12 03:48:46 DEBUG : B2 bucket rclone-test-bapahet9fubo path 034802go/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:48:46 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/11/12 03:48:46 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/11/12 03:48:46 INFO  : Synching Path1 "/tmp/034802go/check_access_filters/path1/" with Path2 "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/"
2025/11/12 03:48:46 INFO  : Using filters file /tmp/034802go/workdir/include-other-filtersfile.txt
2025/11/12 03:48:46 INFO  : Building Path1 and Path2 listings
2025/11/12 03:48:46 INFO  : Path1 checking for diffs
2025/11/12 03:48:46 INFO  : Path2 checking for diffs
2025/11/12 03:48:46 INFO  : Checking access health
2025/11/12 03:48:46 INFO  : Found 5 matching "RCLONE_TEST" files on both paths
2025/11/12 03:48:46 INFO  : No changes found
2025/11/12 03:48:46 INFO  : Updating listings
2025/11/12 03:48:46 INFO  : Validating listings for Path1 "/tmp/034802go/check_access_filters/path1/" vs Path2 "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/"
2025/11/12 03:48:46 INFO  : Bisync successful
2025/11/12 03:48:46 NOTICE: (31)  : copy-listings include-initial
2025/11/12 03:48:46 NOTICE: (32)  : test INCLUDE - delete RCLONE_TEST files in excluded directories
2025/11/12 03:48:46 NOTICE: (33)  : delete-file TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/subdir/subdirA/RCLONE_TEST
2025/11/12 03:48:46 DEBUG : fs cache: switching user supplied name "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/subdir/subdirA/" for canonical name "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/subdir/subdirA"
2025/11/12 03:48:48 INFO  : RCLONE_TEST: Deleted
2025/11/12 03:48:48 NOTICE: (34)  : delete-file /tmp/034802go/check_access_filters/path1/subdir-not/RCLONE_TEST
2025/11/12 03:48:48 DEBUG : fs cache: switching user supplied name "/tmp/034802go/check_access_filters/path1/subdir-not/" for canonical name "/tmp/034802go/check_access_filters/path1/subdir-not"
2025/11/12 03:48:48 INFO  : RCLONE_TEST: Deleted
2025/11/12 03:48:48 NOTICE: (35)  : delete-file TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/subdir-not/subdir-not2/RCLONE_TEST
2025/11/12 03:48:48 DEBUG : fs cache: switching user supplied name "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/subdir-not/subdir-not2/" for canonical name "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/subdir-not/subdir-not2"
2025/11/12 03:48:49 INFO  : RCLONE_TEST: Deleted
2025/11/12 03:48:49 NOTICE: (36)  : test INCLUDE - test should PASS
2025/11/12 03:48:49 NOTICE: (37)  : bisync check-access filters-file=/tmp/034802go/workdir/include-other-filtersfile.txt
2025/11/12 03:48:53 INFO  : subdir: Set directory modification time (using SetModTime)
2025/11/12 03:48:53 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/11/12 03:48:53 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/11/12 03:48:53 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/11/12 03:48:53 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/11/12 03:48:53 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/11/12 03:48:53 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/11/12 03:48:53 DEBUG : B2 bucket rclone-test-bapahet9fubo path 034802go/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:48:53 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/11/12 03:48:53 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/11/12 03:48:53 INFO  : Synching Path1 "/tmp/034802go/check_access_filters/path1/" with Path2 "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/"
2025/11/12 03:48:53 INFO  : Using filters file /tmp/034802go/workdir/include-other-filtersfile.txt
2025/11/12 03:48:53 INFO  : Building Path1 and Path2 listings
2025/11/12 03:48:53 INFO  : Path1 checking for diffs
2025/11/12 03:48:53 INFO  : Path2 checking for diffs
2025/11/12 03:48:53 INFO  : Checking access health
2025/11/12 03:48:53 INFO  : Found 5 matching "RCLONE_TEST" files on both paths
2025/11/12 03:48:53 INFO  : No changes found
2025/11/12 03:48:53 INFO  : Updating listings
2025/11/12 03:48:53 INFO  : Validating listings for Path1 "/tmp/034802go/check_access_filters/path1/" vs Path2 "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/"
2025/11/12 03:48:53 INFO  : Bisync successful
2025/11/12 03:48:53 NOTICE: (38)  : copy-listings include-pass-run
2025/11/12 03:48:53 NOTICE: (39)  : test INCLUDE - delete RCLONE_TEST files in included directories
2025/11/12 03:48:53 NOTICE: (40)  : delete-file TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/RCLONE_TEST
2025/11/12 03:48:53 DEBUG : fs cache: switching user supplied name "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/" for canonical name "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2"
2025/11/12 03:48:54 INFO  : RCLONE_TEST: Deleted
2025/11/12 03:48:54 NOTICE: (41)  : delete-file /tmp/034802go/check_access_filters/path1/subdir/RCLONE_TEST
2025/11/12 03:48:54 DEBUG : fs cache: switching user supplied name "/tmp/034802go/check_access_filters/path1/subdir/" for canonical name "/tmp/034802go/check_access_filters/path1/subdir"
2025/11/12 03:48:54 INFO  : RCLONE_TEST: Deleted
2025/11/12 03:48:54 NOTICE: (42)  : delete-file /tmp/034802go/check_access_filters/path1/subdirX/subdirX1/RCLONE_TEST
2025/11/12 03:48:54 DEBUG : Creating backend with remote "/tmp/034802go/check_access_filters/path1/subdirX/subdirX1/"
2025/11/12 03:48:54 DEBUG : fs cache: renaming cache item "/tmp/034802go/check_access_filters/path1/subdirX/subdirX1/" to be canonical "/tmp/034802go/check_access_filters/path1/subdirX/subdirX1"
2025/11/12 03:48:54 INFO  : RCLONE_TEST: Deleted
2025/11/12 03:48:54 NOTICE: (43)  : test INCLUDE - test should ABORT
2025/11/12 03:48:54 NOTICE: (44)  : bisync check-access filters-file=/tmp/034802go/workdir/include-other-filtersfile.txt
2025/11/12 03:48:57 INFO  : subdir: Set directory modification time (using SetModTime)
2025/11/12 03:48:57 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/11/12 03:48:57 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/11/12 03:48:57 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/11/12 03:48:57 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/11/12 03:48:57 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/11/12 03:48:57 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/11/12 03:48:57 DEBUG : B2 bucket rclone-test-bapahet9fubo path 034802go/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:48:57 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/11/12 03:48:57 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/11/12 03:48:57 INFO  : Synching Path1 "/tmp/034802go/check_access_filters/path1/" with Path2 "TestB2:rclone-test-bapahet9fubo/034802go/check_access_filters/path2/"
2025/11/12 03:48:57 INFO  : Using filters file /tmp/034802go/workdir/include-other-filtersfile.txt
2025/11/12 03:48:57 INFO  : Building Path1 and Path2 listings
2025/11/12 03:48:58 INFO  : Path1 checking for diffs
2025/11/12 03:48:58 INFO  : - Path1    File was deleted          - subdir/RCLONE_TEST
2025/11/12 03:48:58 INFO  : - Path1    File was deleted          - subdirX/subdirX1/RCLONE_TEST
2025/11/12 03:48:58 INFO  : Path1:    2 changes:    0 new,    0 modified,    2 deleted
2025/11/12 03:48:58 INFO  : Path2 checking for diffs
2025/11/12 03:48:58 INFO  : - Path2    File was deleted          - RCLONE_TEST
2025/11/12 03:48:58 INFO  : Path2:    1 changes:    0 new,    0 modified,    1 deleted
2025/11/12 03:48:58 INFO  : Checking access health
2025/11/12 03:48:58 ERROR : Access test failed: Path1 count 3, Path2 count 4 - RCLONE_TEST
2025/11/12 03:48:58 ERROR : -          Access test failed: Path1 file not found in Path2 - RCLONE_TEST
2025/11/12 03:48:58 ERROR : -          Access test failed: Path2 file not found in Path1 - subdirX/subdirX1/RCLONE_TEST
2025/11/12 03:48:58 ERROR : -          Access test failed: Path2 file not found in Path1 - subdir/RCLONE_TEST
2025/11/12 03:48:58 ERROR : Bisync critical error: check file check failed
2025/11/12 03:48:58 ERROR : Bisync aborted. Must run --resync to recover.
2025/11/12 03:48:58 NOTICE: Bisync error: bisync aborted
2025/11/12 03:48:58 NOTICE: (45)  : move-listings include-error-run
2025/11/12 03:48:58 DEBUG : Waiting for deletions to finish
2025/11/12 03:48:58 INFO  : subdirX/subdirX1/file30.txt: Deleted
2025/11/12 03:48:58 INFO  : subdirX/file20.txt: Deleted
2025/11/12 03:48:58 INFO  : subdir-not/file20.txt: Deleted
2025/11/12 03:48:58 INFO  : file3.txt: Deleted
2025/11/12 03:48:58 INFO  : subdirX/RCLONE_TEST: Deleted
2025/11/12 03:48:58 INFO  : subdir/file20.txt: Deleted
2025/11/12 03:48:58 INFO  : subdir/subdirB/file30.txt: Deleted
2025/11/12 03:48:58 INFO  : subdir/subdirB/RCLONE_TEST: Deleted
2025/11/12 03:48:58 INFO  : RCLONE_TEST: Deleted
2025/11/12 03:48:58 INFO  : file1.txt: Deleted
2025/11/12 03:48:58 INFO  : subdir/subdirA/RCLONE_TEST: Deleted
2025/11/12 03:48:58 INFO  : subdir/subdirA/file30.txt: Deleted
2025/11/12 03:48:58 INFO  : file2.txt: Deleted
2025/11/12 03:48:58 INFO  : file4.txt: Deleted
2025/11/12 03:48:58 INFO  : subdir-not/subdir-not2/file30.txt: Deleted
2025/11/12 03:48:58 INFO  : subdir-not/subdir-not2/RCLONE_TEST: Deleted
2025/11/12 03:48:58 DEBUG : removing 4 level 2 directories
2025/11/12 03:48:58 INFO  : subdirX/subdirX1: Removing directory
2025/11/12 03:48:58 INFO  : subdir/subdirA: Removing directory
2025/11/12 03:48:58 INFO  : subdir-not/subdir-not2: Removing directory
2025/11/12 03:48:58 INFO  : subdir/subdirB: Removing directory
2025/11/12 03:48:58 DEBUG : removing 3 level 1 directories
2025/11/12 03:48:58 INFO  : subdirX: Removing directory
2025/11/12 03:48:58 INFO  : subdir: Removing directory
2025/11/12 03:48:58 INFO  : subdir-not: Removing directory
2025/11/12 03:48:58 DEBUG : removing 1 level 0 directories
2025/11/12 03:48:58 INFO  : Local file system at /tmp/034802go/check_access_filters/path1: Removing directory
2025/11/12 03:48:58 INFO  : B2 bucket rclone-test-bapahet9fubo path 034802go/check_access_filters/path2: cleaning bucket "rclone-test-bapahet9fubo" of all files
2025/11/12 03:48:58 DEBUG : RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f4238fd51c20a48a7_d20251112_m034854_c001_v7007000_t0000_u01762919334129")
2025/11/12 03:48:58 DEBUG : RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1199616c54b7f120_d20251112_m034836_c001_v0001113_t0047_u01762919316055")
2025/11/12 03:48:58 DEBUG : RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f414136f5a58f513d_d20251112_m034830_c001_v7007000_t0000_u01762919310969")
2025/11/12 03:48:58 DEBUG : RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1199616c54b7f0bf_d20251112_m034808_c001_v0001113_t0017_u01762919288402")
2025/11/12 03:48:58 DEBUG : file1.txt: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1054bd56beb6d895_d20251112_m034808_c001_v0001106_t0010_u01762919288025")
2025/11/12 03:48:58 DEBUG : file2.txt: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1123cc620c93a631_d20251112_m034809_c001_v0001117_t0053_u01762919289161")
2025/11/12 03:48:58 DEBUG : file3.txt: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f11546feaf25eee7b_d20251112_m034808_c001_v0001183_t0018_u01762919288213")
2025/11/12 03:48:58 DEBUG : file4.txt: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f11546feaf25eee7d_d20251112_m034808_c001_v0001183_t0014_u01762919288823")
2025/11/12 03:48:58 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f4238fd51c20a48b3_d20251112_m034857_c001_v7007000_t0000_u01762919337761")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1173180d65d16378_d20251112_m034856_c001_v0001157_t0033_u01762919336418")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1123cc620c93a762_d20251112_m034854_c001_v0001117_t0019_u01762919334684")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f4098ef17184b6d43_d20251112_m034853_c001_v7007000_t0000_u01762919333012")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1134c58f4a24d774_d20251112_m034851_c001_v0001109_t0031_u01762919331474")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f11546feaf25eef97_d20251112_m034849_c001_v0001183_t0049_u01762919329573")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f413f2cbeee8df732_d20251112_m034846_c001_v7007000_t0000_u01762919326276")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f103e8b20d81e60fb_d20251112_m034844_c001_v0001130_t0012_u01762919324943")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1199616c54b7f13b_d20251112_m034843_c001_v0001113_t0040_u01762919323130")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f413f2cbeee8df72f_d20251112_m034841_c001_v7007000_t0000_u01762919321447")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f115fbbb87b4c2873_d20251112_m034840_c001_v0001102_t0050_u01762919320067")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1054bd56beb6d8f1_d20251112_m034837_c001_v0001106_t0053_u01762919317968")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f414136f5a58f5147_d20251112_m034834_c001_v7007000_t0000_u01762919314726")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1180e44d82fab225_d20251112_m034833_c001_v0001093_t0024_u01762919313275")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1054bd56beb6d8e1_d20251112_m034831_c001_v0001106_t0032_u01762919311514")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f414136f5a58f5137_d20251112_m034828_c001_v7007000_t0000_u01762919308900")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f109f6bb49198e7c6_d20251112_m034827_c001_v0001172_t0015_u01762919307310")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1123cc620c93a697_d20251112_m034824_c001_v0001117_t0029_u01762919304554")
2025/11/12 03:48:59 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f4216311f44b80b94_d20251112_m034819_c001_v7007000_t0000_u01762919299417")
2025/11/12 03:49:00 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f103c3ef43d51a1f1_d20251112_m034818_c001_v0001184_t0054_u01762919298215")
2025/11/12 03:49:00 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f11546feaf25eeebc_d20251112_m034816_c001_v0001183_t0003_u01762919296711")
2025/11/12 03:49:00 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f4216311f44b80b8b_d20251112_m034815_c001_v7007000_t0000_u01762919295060")
2025/11/12 03:49:00 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f111e7d031056fab7_d20251112_m034813_c001_v0001099_t0038_u01762919293207")
2025/11/12 03:49:00 DEBUG : modtime_write_test: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1199616c54b7f0d1_d20251112_m034811_c001_v0001113_t0048_u01762919291178")
2025/11/12 03:49:00 DEBUG : subdir-not/RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f11546feaf25eee85_d20251112_m034809_c001_v0001183_t0012_u01762919289236")
2025/11/12 03:49:00 DEBUG : subdir-not/file20.txt: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f11546feaf25eee87_d20251112_m034809_c001_v0001183_t0056_u01762919289466")
2025/11/12 03:49:00 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f4238fd51c20a4899_d20251112_m034849_c001_v7007000_t0000_u01762919329032")
2025/11/12 03:49:00 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f11546feaf25eef48_d20251112_m034836_c001_v0001183_t0050_u01762919316582")
2025/11/12 03:49:00 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f405f627b9fca6ddb_d20251112_m034824_c001_v7007000_t0000_u01762919304005")
2025/11/12 03:49:00 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1054bd56beb6d89f_d20251112_m034809_c001_v0001106_t0036_u01762919289700")
2025/11/12 03:49:00 DEBUG : subdir-not/subdir-not2/file30.txt: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f11546feaf25eee8b_d20251112_m034809_c001_v0001183_t0055_u01762919289708")
2025/11/12 03:49:00 DEBUG : subdir/RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1123cc620c93a633_d20251112_m034809_c001_v0001117_t0000_u01762919289806")
2025/11/12 03:49:00 DEBUG : subdir/file20.txt: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f11546feaf25eee8f_d20251112_m034809_c001_v0001183_t0046_u01762919289918")
2025/11/12 03:49:00 DEBUG : subdir/subdirA/RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f414136f5a58f516d_d20251112_m034847_c001_v7007000_t0000_u01762919327932")
2025/11/12 03:49:00 DEBUG : subdir/subdirA/RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1123cc620c93a6e7_d20251112_m034836_c001_v0001117_t0012_u01762919316784")
2025/11/12 03:49:00 DEBUG : subdir/subdirA/RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f407ae726371670c9_d20251112_m034821_c001_v7007000_t0000_u01762919301990")
2025/11/12 03:49:00 DEBUG : subdir/subdirA/RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1054bd56beb6d8a1_d20251112_m034810_c001_v0001106_t0050_u01762919290328")
2025/11/12 03:49:00 DEBUG : subdir/subdirA/file30.txt: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f11546feaf25eee97_d20251112_m034810_c001_v0001183_t0010_u01762919290341")
2025/11/12 03:49:00 DEBUG : subdir/subdirB/RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1199616c54b7f0cd_d20251112_m034809_c001_v0001113_t0044_u01762919289971")
2025/11/12 03:49:01 DEBUG : subdir/subdirB/file30.txt: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f11546feaf25eee91_d20251112_m034810_c001_v0001183_t0035_u01762919290134")
2025/11/12 03:49:01 DEBUG : subdirX/RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1054bd56beb6d89d_d20251112_m034808_c001_v0001106_t0047_u01762919288894")
2025/11/12 03:49:01 DEBUG : subdirX/file20.txt: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1199616c54b7f0c3_d20251112_m034808_c001_v0001113_t0057_u01762919288903")
2025/11/12 03:49:01 DEBUG : subdirX/subdirX1/RCLONE_TEST: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f11546feaf25eee83_d20251112_m034809_c001_v0001183_t0013_u01762919289025")
2025/11/12 03:49:01 DEBUG : subdirX/subdirX1/file30.txt: Deleting (id "4_z7f827dd320dd7b6b9fa80e1b_f1199616c54b7f0c7_d20251112_m034809_c001_v0001113_t0028_u01762919289191")
    bisync_test.go:608: TEST check_access_filters PASSED
2025/11/12 03:49:01 DEBUG : B2 bucket rclone-test-bapahet9fubo: Purge remote
2025/11/12 03:49:01 INFO  : B2 bucket rclone-test-bapahet9fubo: cleaning bucket "rclone-test-bapahet9fubo" of all files
--- PASS: TestBisyncLocalRemote (62.26s)
    --- PASS: TestBisyncLocalRemote/check_access_filters (59.23s)
=== RUN   TestBisyncRemoteRemote
2025/11/12 03:49:04 DEBUG : Creating backend with remote "TestB2:rclone-test-yedabut0tedu"
2025/11/12 03:49:04 NOTICE: remote: TestB2:rclone-test-yedabut0tedu
=== RUN   TestBisyncRemoteRemote/check_sync
2025/11/12 03:49:04 DEBUG : Creating backend with remote "TestB2:rclone-test-yedabut0tedu/034904ba"
2025/11/12 03:49:05 INFO  : path1: Making directory
2025/11/12 03:49:07 DEBUG : Creating backend with remote "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path1"
2025/11/12 03:49:08 INFO  : path2: Making directory
2025/11/12 03:49:08 DEBUG : Creating backend with remote "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path2"
2025/11/12 03:49:09 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_sync/initial"
2025/11/12 03:49:09 DEBUG : Creating backend with remote "/tmp/034904ba/initdir/test_check_sync-lojebaf6"
2025/11/12 03:49:09 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:49:09 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:09 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:09 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:09 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:09 DEBUG : file5.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:09 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:09 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:09 DEBUG : file8.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:09 DEBUG : file1.txt.56d0d699.partial: size = 0 OK
2025/11/12 03:49:09 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:49:09 DEBUG : file2.txt.3230ad67.partial: size = 0 OK
2025/11/12 03:49:09 DEBUG : file3.txt.a74079f2.partial: size = 0 OK
2025/11/12 03:49:09 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:49:09 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt
2025/11/12 03:49:09 INFO  : file1.txt: Copied (new)
2025/11/12 03:49:09 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt
2025/11/12 03:49:09 INFO  : file2.txt: Copied (new)
2025/11/12 03:49:09 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:49:09 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt
2025/11/12 03:49:09 INFO  : file3.txt: Copied (new)
2025/11/12 03:49:09 DEBUG : file5.txt.6e808e0e.partial: size = 0 OK
2025/11/12 03:49:09 DEBUG : file6.txt.0a60f5f0.partial: size = 0 OK
2025/11/12 03:49:09 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:49:09 DEBUG : file5.txt.6e808e0e.partial: renamed to: file5.txt
2025/11/12 03:49:09 INFO  : file5.txt: Copied (new)
2025/11/12 03:49:09 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:49:09 DEBUG : file6.txt.0a60f5f0.partial: renamed to: file6.txt
2025/11/12 03:49:09 INFO  : file6.txt: Copied (new)
2025/11/12 03:49:09 DEBUG : file7.txt.9f102165.partial: size = 0 OK
2025/11/12 03:49:09 DEBUG : file8.txt.b300b322.partial: size = 0 OK
2025/11/12 03:49:09 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:49:09 DEBUG : file7.txt.9f102165.partial: renamed to: file7.txt
2025/11/12 03:49:09 INFO  : file7.txt: Copied (new)
2025/11/12 03:49:09 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:49:09 DEBUG : file8.txt.b300b322.partial: renamed to: file8.txt
2025/11/12 03:49:09 INFO  : file8.txt: Copied (new)
2025/11/12 03:49:09 DEBUG : file4.txt.fbf05a9b.partial: size = 0 OK
2025/11/12 03:49:09 DEBUG : Local file system at /tmp/034904ba/initdir/test_check_sync-lojebaf6: Waiting for checks to finish
2025/11/12 03:49:09 DEBUG : Local file system at /tmp/034904ba/initdir/test_check_sync-lojebaf6: Waiting for transfers to finish
2025/11/12 03:49:09 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/11/12 03:49:09 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK
2025/11/12 03:49:09 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt
2025/11/12 03:49:09 INFO  : file4.txt: Copied (new)
2025/11/12 03:49:09 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/11/12 03:49:09 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST
2025/11/12 03:49:09 INFO  : RCLONE_TEST: Copied (new)
2025/11/12 03:49:09 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_sync/modfiles"
2025/11/12 03:49:09 DEBUG : Creating backend with remote "/tmp/034904ba/datadir/test_check_sync-tiqofor7"
2025/11/12 03:49:09 DEBUG : _testdir_path1.._testdir_path2.path1.lst: Need to transfer - File not found at Destination
2025/11/12 03:49:09 DEBUG : _testdir_path1.._testdir_path2.path2.lst: Need to transfer - File not found at Destination
2025/11/12 03:49:09 DEBUG : Local file system at /tmp/034904ba/datadir/test_check_sync-tiqofor7: Waiting for checks to finish
2025/11/12 03:49:09 DEBUG : _testdir_path1.._testdir_path2.path1.lst.ba8cd101.partial: size = 792 OK
2025/11/12 03:49:09 DEBUG : _testdir_path1.._testdir_path2.path1.lst: md5 = fdb18e0dff6961813e12c57227d2e854 OK
2025/11/12 03:49:09 DEBUG : _testdir_path1.._testdir_path2.path1.lst.ba8cd101.partial: renamed to: _testdir_path1.._testdir_path2.path1.lst
2025/11/12 03:49:09 INFO  : _testdir_path1.._testdir_path2.path1.lst: Copied (new)
2025/11/12 03:49:09 DEBUG : _testdir_path1.._testdir_path2.path2.lst.f764d166.partial: size = 792 OK
2025/11/12 03:49:09 DEBUG : _testdir_path1.._testdir_path2.path2.lst: md5 = d6ce44a26af9c2110b1750fe88dc4b69 OK
2025/11/12 03:49:09 DEBUG : _testdir_path1.._testdir_path2.path2.lst.f764d166.partial: renamed to: _testdir_path1.._testdir_path2.path2.lst
2025/11/12 03:49:09 INFO  : _testdir_path1.._testdir_path2.path2.lst: Copied (new)
2025/11/12 03:49:09 DEBUG : Local file system at /tmp/034904ba/datadir/test_check_sync-tiqofor7: Waiting for transfers to finish
2025/11/12 03:49:09 INFO  : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path1: cleaning bucket "rclone-test-yedabut0tedu" of all files
2025/11/12 03:49:10 INFO  : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path2: cleaning bucket "rclone-test-yedabut0tedu" of all files
2025/11/12 03:49:11 NOTICE: checking initFs Local file system at /tmp/034904ba/initdir/test_check_sync-lojebaf6
2025/11/12 03:49:11 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:49:11 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:11 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:11 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:11 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:11 DEBUG : file5.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:11 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:11 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:11 DEBUG : file8.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:11 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path1: Waiting for checks to finish
2025/11/12 03:49:11 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path1: Waiting for transfers to finish
2025/11/12 03:49:12 DEBUG : file1.txt: size = 0 OK
2025/11/12 03:49:12 DEBUG : file1.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:49:12 INFO  : file1.txt: Copied (new)
2025/11/12 03:49:12 DEBUG : file2.txt: size = 0 OK
2025/11/12 03:49:12 DEBUG : file2.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:49:12 INFO  : file2.txt: Copied (new)
2025/11/12 03:49:12 DEBUG : file4.txt: size = 0 OK
2025/11/12 03:49:12 DEBUG : file4.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:49:12 INFO  : file4.txt: Copied (new)
2025/11/12 03:49:12 DEBUG : file5.txt: size = 0 OK
2025/11/12 03:49:12 DEBUG : file5.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:49:12 INFO  : file5.txt: Copied (new)
2025/11/12 03:49:13 DEBUG : file3.txt: size = 0 OK
2025/11/12 03:49:13 DEBUG : file3.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:49:13 INFO  : file3.txt: Copied (new)
2025/11/12 03:49:13 DEBUG : file7.txt: size = 0 OK
2025/11/12 03:49:13 DEBUG : file7.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:49:13 INFO  : file7.txt: Copied (new)
2025/11/12 03:49:13 DEBUG : RCLONE_TEST: size = 109 OK
2025/11/12 03:49:13 DEBUG : RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK
2025/11/12 03:49:13 INFO  : RCLONE_TEST: Copied (new)
2025/11/12 03:49:13 DEBUG : file6.txt: size = 0 OK
2025/11/12 03:49:13 DEBUG : file6.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:49:13 INFO  : file6.txt: Copied (new)
2025/11/12 03:49:13 DEBUG : file8.txt: size = 0 OK
2025/11/12 03:49:13 DEBUG : file8.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:49:13 INFO  : file8.txt: Copied (new)
2025/11/12 03:49:13 NOTICE: checking Path1 B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path1
2025/11/12 03:49:13 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/11/12 03:49:13 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:13 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:13 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:13 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:13 DEBUG : file5.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:13 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:13 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:13 DEBUG : file8.txt: Need to transfer - File not found at Destination
2025/11/12 03:49:13 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path2: Waiting for checks to finish
2025/11/12 03:49:13 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path2: Waiting for transfers to finish
2025/11/12 03:49:14 DEBUG : file3.txt: Clearing upload URL because of error: no tomes available (503 service_unavailable): trying again in 1s
2025/11/12 03:49:14 DEBUG : pacer: low level retry 1/1 (error no tomes available (503 service_unavailable): trying again in 1s)
2025/11/12 03:49:14 DEBUG : pacer: Rate limited, increasing sleep to 1s
2025/11/12 03:49:14 DEBUG : file3.txt: Received error: no tomes available (503 service_unavailable): trying again in 1s - low level retry 0/10
2025/11/12 03:49:14 DEBUG : pacer: Reducing sleep to 500ms
2025/11/12 03:49:14 DEBUG : pacer: Reducing sleep to 250ms
2025/11/12 03:49:14 DEBUG : file1.txt: size = 0 OK
2025/11/12 03:49:14 DEBUG : file1.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:49:14 INFO  : file1.txt: Copied (new)
2025/11/12 03:49:15 DEBUG : pacer: Reducing sleep to 125ms
2025/11/12 03:49:15 DEBUG : RCLONE_TEST: size = 109 OK
2025/11/12 03:49:15 DEBUG : RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK
2025/11/12 03:49:15 INFO  : RCLONE_TEST: Copied (new)
2025/11/12 03:49:15 DEBUG : pacer: Reducing sleep to 62.5ms
2025/11/12 03:49:15 DEBUG : file2.txt: size = 0 OK
2025/11/12 03:49:15 DEBUG : file2.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:49:15 INFO  : file2.txt: Copied (new)
2025/11/12 03:49:16 DEBUG : pacer: Reducing sleep to 31.25ms
2025/11/12 03:49:16 DEBUG : file5.txt: size = 0 OK
2025/11/12 03:49:16 DEBUG : file5.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:49:16 INFO  : file5.txt: Copied (new)
2025/11/12 03:49:16 DEBUG : pacer: Reducing sleep to 15.625ms
2025/11/12 03:49:16 DEBUG : file4.txt: size = 0 OK
2025/11/12 03:49:16 DEBUG : file4.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:49:16 INFO  : file4.txt: Copied (new)
2025/11/12 03:49:16 DEBUG : pacer: Reducing sleep to 10ms
2025/11/12 03:49:16 DEBUG : file6.txt: size = 0 OK
2025/11/12 03:49:16 DEBUG : file6.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:49:16 INFO  : file6.txt: Copied (new)
2025/11/12 03:49:16 DEBUG : file7.txt: size = 0 OK
2025/11/12 03:49:16 DEBUG : file7.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:49:16 INFO  : file7.txt: Copied (new)
2025/11/12 03:49:16 DEBUG : file3.txt: size = 0 OK
2025/11/12 03:49:16 DEBUG : file3.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:49:16 INFO  : file3.txt: Copied (new)
2025/11/12 03:49:16 DEBUG : file8.txt: size = 0 OK
2025/11/12 03:49:16 DEBUG : file8.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK
2025/11/12 03:49:16 INFO  : file8.txt: Copied (new)
2025/11/12 03:49:16 NOTICE: checking path2 B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path2
2025/11/12 03:49:17 NOTICE: (01)  : test check-sync
2025/11/12 03:49:17 NOTICE: (02)  : test initial bisync
2025/11/12 03:49:17 NOTICE: (03)  : bisync resync
2025/11/12 03:49:24 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:49:24 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:49:24 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/11/12 03:49:24 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/11/12 03:49:24 INFO  : Synching Path1 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path1/" with Path2 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path2/"
2025/11/12 03:49:24 INFO  : Copying Path2 files to Path1
2025/11/12 03:49:24 INFO  : - Path2    Resync is copying files to         - Path1
2025/11/12 03:49:25 INFO  : There was nothing to transfer
2025/11/12 03:49:25 INFO  : - Path1    Resync is copying files to         - Path2
2025/11/12 03:49:25 INFO  : There was nothing to transfer
2025/11/12 03:49:25 INFO  : Resync updating listings
2025/11/12 03:49:25 INFO  : Validating listings for Path1 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path1/" vs Path2 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path2/"
2025/11/12 03:49:25 INFO  : Bisync successful
2025/11/12 03:49:25 NOTICE: (04)  : test 1. run check-sync-only on a clean sync
2025/11/12 03:49:25 NOTICE: (05)  : bisync check-sync-only
2025/11/12 03:49:33 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:49:33 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:49:33 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/11/12 03:49:33 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/11/12 03:49:33 INFO  : Validating listings for Path1 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path1/" vs Path2 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path2/"
2025/11/12 03:49:33 INFO  : Bisync successful
2025/11/12 03:49:33 NOTICE: (06)  : test 2. inject modified listings into the workdir
2025/11/12 03:49:33 NOTICE: (07)  : copy-as /tmp/034904ba/datadir/test_check_sync-tiqofor7/_testdir_path1.._testdir_path2.path1.lst /tmp/034904ba/workdir/ TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path1.lst
2025/11/12 03:49:33 DEBUG : copyFile "/tmp/034904ba/datadir/test_check_sync-tiqofor7/_testdir_path1.._testdir_path2.path1.lst" to "/tmp/034904ba/workdir/" as "TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path1.lst"
2025/11/12 03:49:33 DEBUG : Creating backend with remote "/tmp/034904ba/datadir/test_check_sync-tiqofor7/_testdir_path1.._testdir_path2.path1.lst"
2025/11/12 03:49:33 DEBUG : Creating backend with remote "/tmp/034904ba/workdir/"
2025/11/12 03:49:33 DEBUG : operations.CopyFile "_testdir_path1.._testdir_path2.path1.lst" to "Local file system at /tmp/034904ba/workdir" as "TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path1.lst"
2025/11/12 03:49:33 DEBUG : _testdir_path1.._testdir_path2.path1.lst: size = 792 (Local file system at /tmp/034904ba/datadir/test_check_sync-tiqofor7)
2025/11/12 03:49:33 DEBUG : TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path1.lst: size = 620 (Local file system at /tmp/034904ba/workdir)
2025/11/12 03:49:33 DEBUG : _testdir_path1.._testdir_path2.path1.lst: Sizes differ
2025/11/12 03:49:33 DEBUG : TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_syn.f121f14a.partial: size = 792 OK
2025/11/12 03:49:33 DEBUG : _testdir_path1.._testdir_path2.path1.lst: md5 = fdb18e0dff6961813e12c57227d2e854 OK
2025/11/12 03:49:33 DEBUG : TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_syn.f121f14a.partial: renamed to: TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path1.lst
2025/11/12 03:49:33 INFO  : _testdir_path1.._testdir_path2.path1.lst: Copied (replaced existing) to: TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path1.lst
2025/11/12 03:49:33 NOTICE: (08)  : copy-as /tmp/034904ba/datadir/test_check_sync-tiqofor7/_testdir_path1.._testdir_path2.path2.lst /tmp/034904ba/workdir/ TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path2.lst
2025/11/12 03:49:33 DEBUG : copyFile "/tmp/034904ba/datadir/test_check_sync-tiqofor7/_testdir_path1.._testdir_path2.path2.lst" to "/tmp/034904ba/workdir/" as "TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path2.lst"
2025/11/12 03:49:33 DEBUG : Creating backend with remote "/tmp/034904ba/datadir/test_check_sync-tiqofor7/_testdir_path1.._testdir_path2.path2.lst"
2025/11/12 03:49:33 DEBUG : Creating backend with remote "/tmp/034904ba/workdir/"
2025/11/12 03:49:33 DEBUG : operations.CopyFile "_testdir_path1.._testdir_path2.path2.lst" to "Local file system at /tmp/034904ba/workdir" as "TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path2.lst"
2025/11/12 03:49:33 DEBUG : _testdir_path1.._testdir_path2.path2.lst: size = 792 (Local file system at /tmp/034904ba/datadir/test_check_sync-tiqofor7)
2025/11/12 03:49:33 DEBUG : TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path2.lst: size = 620 (Local file system at /tmp/034904ba/workdir)
2025/11/12 03:49:33 DEBUG : _testdir_path1.._testdir_path2.path2.lst: Sizes differ
2025/11/12 03:49:33 DEBUG : TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_syn.bcc9f12d.partial: size = 792 OK
2025/11/12 03:49:33 DEBUG : _testdir_path1.._testdir_path2.path2.lst: md5 = d6ce44a26af9c2110b1750fe88dc4b69 OK
2025/11/12 03:49:33 DEBUG : TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_syn.bcc9f12d.partial: renamed to: TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path2.lst
2025/11/12 03:49:33 INFO  : _testdir_path1.._testdir_path2.path2.lst: Copied (replaced existing) to: TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path2.lst
2025/11/12 03:49:33 NOTICE: (09)  : test 3. run check-sync-only on modified listings
2025/11/12 03:49:33 NOTICE: (10)  : bisync check-sync-only
2025/11/12 03:49:42 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:49:42 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:49:42 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/11/12 03:49:42 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/11/12 03:49:42 INFO  : Validating listings for Path1 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path1/" vs Path2 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path2/"
2025/11/12 03:49:42 ERROR : -          Path1 file not found in Path2      - file2.txt
2025/11/12 03:49:42 ERROR : -          Path2 file not found in Path1      - file1.txt
2025/11/12 03:49:42 ERROR : Bisync critical error: path1 and path2 are out of sync, run --resync to recover
2025/11/12 03:49:42 ERROR : Bisync aborted. Must run --resync to recover.
2025/11/12 03:49:42 NOTICE: Bisync error: bisync aborted
2025/11/12 03:49:42 NOTICE: (11)  : copy-listings check-sync-only
2025/11/12 03:49:42 NOTICE: (12)  : test 4. run normal sync to check that it aborts
2025/11/12 03:49:42 NOTICE: (13)  : bisync
2025/11/12 03:49:51 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:49:51 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:49:51 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/11/12 03:49:51 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/11/12 03:49:51 INFO  : Synching Path1 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path1/" with Path2 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path2/"
2025/11/12 03:49:51 ERROR : Bisync critical error: cannot find prior Path1 or Path2 listings, likely due to critical error on prior run 
Tip: here are the filenames we were looking for. Do they exist? 
Path1: /tmp/034904ba/workdir/TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path1.lst
Path2: /tmp/034904ba/workdir/TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path2.lst
Try running this command to inspect the work dir: 
rclone lsl "/tmp/034904ba/workdir"
2025/11/12 03:49:51 ERROR : Bisync aborted. Must run --resync to recover.
2025/11/12 03:49:51 NOTICE: Bisync error: bisync aborted
2025/11/12 03:49:51 NOTICE: (14)  : test 5. prune failure listings after critical abort
2025/11/12 03:49:51 NOTICE: (15)  : delete-glob /tmp/034904ba/workdir/ *.lst
2025/11/12 03:49:51 DEBUG : Creating backend with remote "/tmp/034904ba/workdir/"
2025/11/12 03:49:51 DEBUG : fs cache: renaming cache item "/tmp/034904ba/workdir/" to be canonical "/tmp/034904ba/workdir"
2025/11/12 03:49:51 DEBUG : Waiting for deletions to finish
2025/11/12 03:49:51 NOTICE: (16)  : delete-glob /tmp/034904ba/workdir/ *.lst-err
2025/11/12 03:49:51 DEBUG : fs cache: switching user supplied name "/tmp/034904ba/workdir/" for canonical name "/tmp/034904ba/workdir"
2025/11/12 03:49:51 DEBUG : Waiting for deletions to finish
2025/11/12 03:49:51 INFO  : TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path1.lst-err: Deleted
2025/11/12 03:49:51 INFO  : TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path2.lst-err: Deleted
2025/11/12 03:49:51 NOTICE: (17)  : delete-glob /tmp/034904ba/workdir/ *.lst-new
2025/11/12 03:49:51 DEBUG : fs cache: switching user supplied name "/tmp/034904ba/workdir/" for canonical name "/tmp/034904ba/workdir"
2025/11/12 03:49:51 DEBUG : Waiting for deletions to finish
2025/11/12 03:49:51 INFO  : TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path1.lst-new: Deleted
2025/11/12 03:49:51 INFO  : TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path1..TestB2_rclone-test-yedabut0tedu_034904ba_check_sync_path2.path2.lst-new: Deleted
2025/11/12 03:49:51 NOTICE: (18)  : test 6. run resync
2025/11/12 03:49:51 NOTICE: (19)  : bisync resync
2025/11/12 03:50:00 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:50:00 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:50:00 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/11/12 03:50:00 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/11/12 03:50:00 INFO  : Synching Path1 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path1/" with Path2 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path2/"
2025/11/12 03:50:00 INFO  : Copying Path2 files to Path1
2025/11/12 03:50:00 INFO  : - Path2    Resync is copying files to         - Path1
2025/11/12 03:50:00 INFO  : There was nothing to transfer
2025/11/12 03:50:00 INFO  : - Path1    Resync is copying files to         - Path2
2025/11/12 03:50:00 INFO  : There was nothing to transfer
2025/11/12 03:50:00 INFO  : Resync updating listings
2025/11/12 03:50:00 INFO  : Validating listings for Path1 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path1/" vs Path2 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path2/"
2025/11/12 03:50:00 INFO  : Bisync successful
2025/11/12 03:50:00 NOTICE: (20)  : test 7. run normal sync with check-sync enabled (default)
2025/11/12 03:50:00 NOTICE: (21)  : bisync
2025/11/12 03:50:09 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:50:09 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:50:09 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/11/12 03:50:09 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/11/12 03:50:09 INFO  : Synching Path1 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path1/" with Path2 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path2/"
2025/11/12 03:50:09 INFO  : Building Path1 and Path2 listings
2025/11/12 03:50:09 INFO  : Path1 checking for diffs
2025/11/12 03:50:09 INFO  : Path2 checking for diffs
2025/11/12 03:50:09 INFO  : No changes found
2025/11/12 03:50:09 INFO  : Updating listings
2025/11/12 03:50:09 INFO  : Validating listings for Path1 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path1/" vs Path2 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path2/"
2025/11/12 03:50:09 INFO  : Bisync successful
2025/11/12 03:50:09 NOTICE: (22)  : test 8. run normal sync with no-check-sync
2025/11/12 03:50:09 NOTICE: (23)  : bisync no-check-sync
2025/11/12 03:50:17 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:50:17 DEBUG : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata
2025/11/12 03:50:17 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/11/12 03:50:17 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/11/12 03:50:17 INFO  : Synching Path1 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path1/" with Path2 "TestB2:rclone-test-yedabut0tedu/034904ba/check_sync/path2/"
2025/11/12 03:50:17 INFO  : Building Path1 and Path2 listings
2025/11/12 03:50:18 INFO  : Path1 checking for diffs
2025/11/12 03:50:18 INFO  : Path2 checking for diffs
2025/11/12 03:50:18 INFO  : No changes found
2025/11/12 03:50:18 INFO  : Updating listings
2025/11/12 03:50:18 INFO  : Bisync successful
2025/11/12 03:50:18 INFO  : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path1: cleaning bucket "rclone-test-yedabut0tedu" of all files
2025/11/12 03:50:18 DEBUG : RCLONE_TEST: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f11111e0e3d84df4f_d20251112_m034912_c001_v0001157_t0032_u01762919352735")
2025/11/12 03:50:18 DEBUG : file1.txt: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f111e576d7bf55024_d20251112_m034912_c001_v0001171_t0017_u01762919352166")
2025/11/12 03:50:18 DEBUG : file2.txt: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1123a215ff5203e9_d20251112_m034912_c001_v0001150_t0021_u01762919352354")
2025/11/12 03:50:18 DEBUG : file3.txt: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f114b1e4d4616e5cc_d20251112_m034912_c001_v0001105_t0023_u01762919352544")
2025/11/12 03:50:18 DEBUG : file4.txt: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f111e576d7bf55026_d20251112_m034912_c001_v0001171_t0012_u01762919352451")
2025/11/12 03:50:18 DEBUG : file5.txt: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1123a215ff5203eb_d20251112_m034912_c001_v0001150_t0025_u01762919352587")
2025/11/12 03:50:18 DEBUG : file6.txt: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f111e576d7bf5502a_d20251112_m034912_c001_v0001171_t0033_u01762919352779")
2025/11/12 03:50:18 DEBUG : file7.txt: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1123a215ff5203ef_d20251112_m034912_c001_v0001150_t0056_u01762919352953")
2025/11/12 03:50:18 DEBUG : file8.txt: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f114b1e4d4616e5ce_d20251112_m034913_c001_v0001105_t0049_u01762919353110")
2025/11/12 03:50:18 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f4216311f44b81002_d20251112_m035013_c001_v7007000_t0000_u01762919413698")
2025/11/12 03:50:18 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f11940668cc7b0e87_d20251112_m035012_c001_v0001036_t0049_u01762919412210")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f111e576d7bf551e7_d20251112_m035010_c001_v0001171_t0000_u01762919410045")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f4216311f44b80fe1_d20251112_m035004_c001_v7007000_t0000_u01762919404922")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f115067710a82f584_d20251112_m035003_c001_v0001154_t0018_u01762919403353")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f11111e0e3d84e015_d20251112_m035001_c001_v0001157_t0047_u01762919401362")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f4216311f44b80fd9_d20251112_m034956_c001_v7007000_t0000_u01762919396387")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f105dcfd84b56a533_d20251112_m034954_c001_v0001144_t0054_u01762919394497")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1123a215ff520476_d20251112_m034952_c001_v0001150_t0044_u01762919392161")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f4199673b39dac37b_d20251112_m034947_c001_v7007000_t0000_u01762919387298")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f102b742f9e645fc1_d20251112_m034946_c001_v0001179_t0051_u01762919386056")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f114b1e4d4616e61e_d20251112_m034942_c001_v0001105_t0025_u01762919382979")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f411858a37525ff29_d20251112_m034937_c001_v7007000_t0000_u01762919377964")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f109e4867249f399e_d20251112_m034936_c001_v0001106_t0034_u01762919376423")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f111e576d7bf550bc_d20251112_m034934_c001_v0001171_t0015_u01762919374162")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f4192668b7fc7754c_d20251112_m034929_c001_v7007000_t0000_u01762919369253")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f116f10c55956bb47_d20251112_m034927_c001_v0001099_t0039_u01762919367821")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f11111e0e3d84df8a_d20251112_m034925_c001_v0001157_t0033_u01762919365799")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f4192668b7fc7753d_d20251112_m034920_c001_v7007000_t0000_u01762919360853")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f115042ad0c9e5048_d20251112_m034919_c001_v0001134_t0029_u01762919359537")
2025/11/12 03:50:19 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1123a215ff5203fc_d20251112_m034917_c001_v0001150_t0052_u01762919357128")
2025/11/12 03:50:20 INFO  : B2 bucket rclone-test-yedabut0tedu path 034904ba/check_sync/path2: cleaning bucket "rclone-test-yedabut0tedu" of all files
2025/11/12 03:50:20 DEBUG : RCLONE_TEST: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1198c7db7081137e_d20251112_m034915_c001_v0001037_t0025_u01762919355075")
2025/11/12 03:50:20 DEBUG : file1.txt: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1015e33d89356eb3_d20251112_m034914_c001_v0001099_t0049_u01762919354505")
2025/11/12 03:50:20 DEBUG : file2.txt: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1144c5267fc13a53_d20251112_m034914_c001_v0001171_t0058_u01762919354882")
2025/11/12 03:50:20 DEBUG : file3.txt: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f11641427d4b50377_d20251112_m034916_c001_v0001044_t0012_u01762919356244")
2025/11/12 03:50:20 DEBUG : file4.txt: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1015e33d89356ebd_d20251112_m034915_c001_v0001099_t0014_u01762919355946")
2025/11/12 03:50:20 DEBUG : file5.txt: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1198c7db70811384_d20251112_m034916_c001_v0001037_t0015_u01762919356009")
2025/11/12 03:50:20 DEBUG : file6.txt: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1144c5267fc13a63_d20251112_m034916_c001_v0001171_t0049_u01762919356074")
2025/11/12 03:50:20 DEBUG : file7.txt: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1198c7db70811388_d20251112_m034916_c001_v0001037_t0026_u01762919356392")
2025/11/12 03:50:20 DEBUG : file8.txt: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1015e33d89356ec2_d20251112_m034916_c001_v0001099_t0030_u01762919356468")
2025/11/12 03:50:20 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f4103e53acd3439f3_d20251112_m035017_c001_v7007000_t0000_u01762919417873")
2025/11/12 03:50:20 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f11872c442a89a59c_d20251112_m035016_c001_v0001184_t0052_u01762919416568")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f11641427d4b503e4_d20251112_m035014_c001_v0001044_t0059_u01762919414243")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f422c1db6896ea6ca_d20251112_m035009_c001_v7007000_t0000_u01762919409312")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f103f63d4a3e295b5_d20251112_m035007_c001_v0001036_t0016_u01762919407790")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1198c7db70811475_d20251112_m035005_c001_v0001037_t0016_u01762919405466")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f420ad3cb32c5e7d4_d20251112_m035000_c001_v7007000_t0000_u01762919400420")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1038ef565c3575a9_d20251112_m034959_c001_v0001176_t0032_u01762919399207")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1144c5267fc13b6d_d20251112_m034956_c001_v0001171_t0029_u01762919396939")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f408fa5ef1db3f17e_d20251112_m034951_c001_v7007000_t0000_u01762919391606")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f11113607fedee1be_d20251112_m034950_c001_v0001181_t0039_u01762919390328")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1015e33d89356f45_d20251112_m034947_c001_v0001099_t0039_u01762919387863")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f404f8df6aad8e03b_d20251112_m034942_c001_v7007000_t0000_u01762919382432")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1177a6c742da37f1_d20251112_m034940_c001_v0001044_t0042_u01762919380977")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f11641427d4b503a2_d20251112_m034938_c001_v0001044_t0028_u01762919378525")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f404f8df6aad8e028_d20251112_m034933_c001_v7007000_t0000_u01762919373609")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f111d9f59df969b25_d20251112_m034932_c001_v0001150_t0021_u01762919372376")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1198c7db708113bd_d20251112_m034929_c001_v0001037_t0059_u01762919369810")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f4199673b39dac198_d20251112_m034924_c001_v7007000_t0000_u01762919364876")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1100516f477adaa7_d20251112_m034923_c001_v0001102_t0034_u01762919363358")
2025/11/12 03:50:21 DEBUG : modtime_write_test: Deleting (id "4_z1f227d1320ed7b6b9fa80e1b_f1144c5267fc13a89_d20251112_m034921_c001_v0001171_t0052_u01762919361042")
    bisync_test.go:608: TEST check_sync PASSED
2025/11/12 03:50:22 DEBUG : B2 bucket rclone-test-yedabut0tedu: Purge remote
2025/11/12 03:50:22 INFO  : B2 bucket rclone-test-yedabut0tedu: cleaning bucket "rclone-test-yedabut0tedu" of all files
--- PASS: TestBisyncRemoteRemote (79.59s)
    --- PASS: TestBisyncRemoteRemote/check_sync (77.43s)
PASS
2025/11/12 03:50:23 DEBUG : B2 bucket rclone-test-foyidik9mobu: Purge remote
2025/11/12 03:50:23 INFO  : B2 bucket rclone-test-foyidik9mobu: cleaning bucket "rclone-test-foyidik9mobu" of all files
2025/11/12 03:50:24 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$/^check_sync$'" - Finished OK in 2m23.222455251s (try 3/5)