"./bisync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^TestBisyncLocalRemote$/^(changes|check_filename)$|^TestBisyncRemoteLocal$/^check_access_filters$|^TestBisyncRemoteRemote$/^(check_access_filters|max_delete_path1)$'" - Starting (try 3/5)
2025/05/12 03:34:28 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-vivasoc8soxe"
2025/05/12 03:34:28 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/12 03:34:28 DEBUG : Starting OpenDrive session with ID: 51b034859b59acdf4b9844a183934f96f660f20291c5f4c40a5c262914431781
2025/05/12 03:34:29 DEBUG : Creating backend with remote "/tmp/rclone3708731771"
=== RUN   TestBisyncRemoteLocal
2025/05/12 03:34:29 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-gacuxes5woli"
2025/05/12 03:34:29 DEBUG : Starting OpenDrive session with ID: e4c4dda6929371cb7fcd454195ca99836c2bddc0b10b510118a0ca31a858b4ef
2025/05/12 03:34:29 NOTICE: remote: TestOpenDrive:rclone-test-gacuxes5woli
=== RUN   TestBisyncRemoteLocal/check_access_filters
2025/05/12 03:34:29 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-gacuxes5woli/033429du"
2025/05/12 03:34:29 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/12 03:34:30 DEBUG : Starting OpenDrive session with ID: 01b6a40ced7f6aeeb9a3ca21f83fe950224b2b6f4e7f24efd856b35cc5ca10c4
2025/05/12 03:34:30 INFO  : path1: Making directory
2025/05/12 03:34:31 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1"
2025/05/12 03:34:32 DEBUG : Starting OpenDrive session with ID: 76a1c06e1cd4c411d6eb0e7f97bc8027406bc822faba1e595c21df377ded564e
2025/05/12 03:34:33 DEBUG : Creating backend with remote "/tmp/033429du"
2025/05/12 03:34:33 DEBUG : Creating backend with remote "/tmp/033429du/check_access_filters/path2"
2025/05/12 03:34:33 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access_filters/initial"
2025/05/12 03:34:33 DEBUG : Creating backend with remote "/tmp/033429du/initdir/test_check_access_filters-furerey5"
2025/05/12 03:34:33 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : subdir: Making directory with metadata
2025/05/12 03:34:33 INFO  : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:34:33 DEBUG : Added delayed dir = "subdir", newDst=subdir
2025/05/12 03:34:33 DEBUG : subdir-not: Making directory with metadata
2025/05/12 03:34:33 INFO  : subdir-not: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:34:33 DEBUG : Added delayed dir = "subdir-not", newDst=subdir-not
2025/05/12 03:34:33 DEBUG : subdirX: Making directory with metadata
2025/05/12 03:34:33 INFO  : subdirX: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:34:33 DEBUG : Added delayed dir = "subdirX", newDst=subdirX
2025/05/12 03:34:33 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : subdirX/subdirX1: Making directory with metadata
2025/05/12 03:34:33 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : subdir/subdirA: Making directory with metadata
2025/05/12 03:34:33 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:33 INFO  : subdir/subdirA: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:34:33 DEBUG : Added delayed dir = "subdir/subdirA", newDst=subdir/subdirA
2025/05/12 03:34:33 DEBUG : subdir/subdirB: Making directory with metadata
2025/05/12 03:34:33 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt
2025/05/12 03:34:33 INFO  : file1.txt: Copied (new)
2025/05/12 03:34:33 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:33 INFO  : subdir/subdirB: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:34:33 DEBUG : Added delayed dir = "subdir/subdirB", newDst=subdir/subdirB
2025/05/12 03:34:33 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST
2025/05/12 03:34:33 INFO  : RCLONE_TEST: Copied (new)
2025/05/12 03:34:33 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:33 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt
2025/05/12 03:34:33 INFO  : file2.txt: Copied (new)
2025/05/12 03:34:33 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:33 DEBUG : file3.txt.5028a97.partial: renamed to: file3.txt
2025/05/12 03:34:33 INFO  : file3.txt: Copied (new)
2025/05/12 03:34:33 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:33 DEBUG : file4.txt.5028a97.partial: renamed to: file4.txt
2025/05/12 03:34:33 INFO  : file4.txt: Copied (new)
2025/05/12 03:34:33 DEBUG : subdirX/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:33 DEBUG : subdirX/file20.txt.5028a97.partial: renamed to: subdirX/file20.txt
2025/05/12 03:34:33 INFO  : subdirX/file20.txt: Copied (new)
2025/05/12 03:34:33 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : subdir-not/subdir-not2: Making directory with metadata
2025/05/12 03:34:33 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:33 INFO  : subdir-not/subdir-not2: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:34:33 DEBUG : Added delayed dir = "subdir-not/subdir-not2", newDst=subdir-not/subdir-not2
2025/05/12 03:34:33 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:33 DEBUG : subdir/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir/RCLONE_TEST
2025/05/12 03:34:33 DEBUG : subdirX/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:33 INFO  : subdir/RCLONE_TEST: Copied (new)
2025/05/12 03:34:33 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : subdir/file20.txt.5028a97.partial: renamed to: subdir/file20.txt
2025/05/12 03:34:33 INFO  : subdir/file20.txt: Copied (new)
2025/05/12 03:34:33 DEBUG : subdirX/RCLONE_TEST.cf9a93ac.partial: renamed to: subdirX/RCLONE_TEST
2025/05/12 03:34:33 INFO  : subdirX/RCLONE_TEST: Copied (new)
2025/05/12 03:34:33 DEBUG : subdir/subdirB/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:33 DEBUG : subdir/subdirB/file30.txt.5028a97.partial: renamed to: subdir/subdirB/file30.txt
2025/05/12 03:34:33 INFO  : subdir/subdirB/file30.txt: Copied (new)
2025/05/12 03:34:33 DEBUG : subdir/subdirA/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:33 DEBUG : subdir/subdirA/file30.txt.5028a97.partial: renamed to: subdir/subdirA/file30.txt
2025/05/12 03:34:33 INFO  : subdir/subdirA/file30.txt: Copied (new)
2025/05/12 03:34:33 DEBUG : subdir-not/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:33 DEBUG : subdir/subdirA/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:33 DEBUG : subdir/subdirA/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir/subdirA/RCLONE_TEST
2025/05/12 03:34:33 INFO  : subdir/subdirA/RCLONE_TEST: Copied (new)
2025/05/12 03:34:33 DEBUG : subdir-not/file20.txt.5028a97.partial: renamed to: subdir-not/file20.txt
2025/05/12 03:34:33 INFO  : subdir-not/file20.txt: Copied (new)
2025/05/12 03:34:33 DEBUG : subdir/subdirB/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:33 DEBUG : subdir/subdirB/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir/subdirB/RCLONE_TEST
2025/05/12 03:34:33 INFO  : subdir/subdirB/RCLONE_TEST: Copied (new)
2025/05/12 03:34:33 DEBUG : subdir-not/subdir-not2/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:33 INFO  : subdirX/subdirX1: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:34:33 DEBUG : Added delayed dir = "subdirX/subdirX1", newDst=subdirX/subdirX1
2025/05/12 03:34:33 DEBUG : subdir-not/subdir-not2/file30.txt.5028a97.partial: renamed to: subdir-not/subdir-not2/file30.txt
2025/05/12 03:34:33 INFO  : subdir-not/subdir-not2/file30.txt: Copied (new)
2025/05/12 03:34:33 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:33 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir-not/subdir-not2/RCLONE_TEST
2025/05/12 03:34:33 INFO  : subdir-not/subdir-not2/RCLONE_TEST: Copied (new)
2025/05/12 03:34:33 DEBUG : subdir-not/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:33 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : subdir-not/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir-not/RCLONE_TEST
2025/05/12 03:34:33 INFO  : subdir-not/RCLONE_TEST: Copied (new)
2025/05/12 03:34:33 DEBUG : Local file system at /tmp/033429du/initdir/test_check_access_filters-furerey5: Waiting for checks to finish
2025/05/12 03:34:33 DEBUG : Local file system at /tmp/033429du/initdir/test_check_access_filters-furerey5: Waiting for transfers to finish
2025/05/12 03:34:33 DEBUG : subdirX/subdirX1/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:33 DEBUG : subdirX/subdirX1/file30.txt.5028a97.partial: renamed to: subdirX/subdirX1/file30.txt
2025/05/12 03:34:33 INFO  : subdirX/subdirX1/file30.txt: Copied (new)
2025/05/12 03:34:33 DEBUG : subdirX/subdirX1/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:33 DEBUG : subdirX/subdirX1/RCLONE_TEST.cf9a93ac.partial: renamed to: subdirX/subdirX1/RCLONE_TEST
2025/05/12 03:34:33 INFO  : subdirX/subdirX1/RCLONE_TEST: Copied (new)
2025/05/12 03:34:33 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/05/12 03:34:33 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/05/12 03:34:33 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/05/12 03:34:33 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/05/12 03:34:33 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/05/12 03:34:33 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:34:33 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/05/12 03:34:33 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access_filters/modfiles"
2025/05/12 03:34:33 DEBUG : Creating backend with remote "/tmp/033429du/datadir/test_check_access_filters-yuvohew6"
2025/05/12 03:34:33 DEBUG : exclude-other-filtersfile.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : include-other-filtersfile.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : Local file system at /tmp/033429du/datadir/test_check_access_filters-yuvohew6: Waiting for checks to finish
2025/05/12 03:34:33 DEBUG : Local file system at /tmp/033429du/datadir/test_check_access_filters-yuvohew6: Waiting for transfers to finish
2025/05/12 03:34:33 DEBUG : include-other-filtersfile.txt: md5 = 2ec13b2813141ed088e5978ef5a47b0e OK
2025/05/12 03:34:33 DEBUG : include-other-filtersfile.txt.5fb1cd78.partial: renamed to: include-other-filtersfile.txt
2025/05/12 03:34:33 INFO  : include-other-filtersfile.txt: Copied (new)
2025/05/12 03:34:33 DEBUG : exclude-other-filtersfile.txt: md5 = 5fcc6205d7df1c2e9ed3a15a1356b345 OK
2025/05/12 03:34:33 DEBUG : exclude-other-filtersfile.txt.9180e6d6.partial: renamed to: exclude-other-filtersfile.txt
2025/05/12 03:34:33 INFO  : exclude-other-filtersfile.txt: Copied (new)
2025/05/12 03:34:33 ERROR : : error listing: directory not found
2025/05/12 03:34:33 ERROR : : error listing: directory not found
2025/05/12 03:34:33 NOTICE: checking initFs Local file system at /tmp/033429du/initdir/test_check_access_filters-furerey5
2025/05/12 03:34:33 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:33 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:33 INFO  : subdir: Making directory
2025/05/12 03:34:34 INFO  : subdir-not: Making directory
2025/05/12 03:34:35 INFO  : subdirX: Making directory
2025/05/12 03:34:35 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:35 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:35 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:35 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:35 INFO  : subdir/subdirA: Making directory
2025/05/12 03:34:35 INFO  : subdir-not/subdir-not2: Making directory
2025/05/12 03:34:35 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:35 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:35 INFO  : subdirX/subdirX1: Making directory
2025/05/12 03:34:35 INFO  : subdir/subdirB: Making directory
2025/05/12 03:34:36 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:36 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:36 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:36 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:36 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:36 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:36 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:36 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:36 DEBUG : OpenDrive root 'rclone-test-gacuxes5woli/033429du/check_access_filters/path1': Waiting for checks to finish
2025/05/12 03:34:36 DEBUG : OpenDrive root 'rclone-test-gacuxes5woli/033429du/check_access_filters/path1': Waiting for transfers to finish
2025/05/12 03:34:37 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:37 INFO  : file1.txt: Copied (new)
2025/05/12 03:34:37 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:37 INFO  : file4.txt: Copied (new)
2025/05/12 03:34:38 DEBUG : RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:34:38 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:38 INFO  : file3.txt: Copied (new)
2025/05/12 03:34:38 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:38 INFO  : file2.txt: Copied (new)
2025/05/12 03:34:38 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:38 INFO  : subdir/file20.txt: Copied (new)
2025/05/12 03:34:38 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:38 INFO  : RCLONE_TEST: Copied (new)
2025/05/12 03:34:39 DEBUG : subdir/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:34:39 DEBUG : subdir-not/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:39 INFO  : subdir-not/file20.txt: Copied (new)
2025/05/12 03:34:39 DEBUG : subdir-not/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:34:40 DEBUG : subdirX/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:40 INFO  : subdirX/file20.txt: Copied (new)
2025/05/12 03:34:40 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:40 INFO  : subdir/RCLONE_TEST: Copied (new)
2025/05/12 03:34:40 DEBUG : subdirX/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:34:40 DEBUG : subdir-not/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:40 INFO  : subdir-not/RCLONE_TEST: Copied (new)
2025/05/12 03:34:41 DEBUG : subdirX/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:41 INFO  : subdirX/RCLONE_TEST: Copied (new)
2025/05/12 03:34:42 DEBUG : subdir/subdirB/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:42 INFO  : subdir/subdirB/file30.txt: Copied (new)
2025/05/12 03:34:42 DEBUG : subdir/subdirB/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:34:42 DEBUG : subdir/subdirA/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:34:42 DEBUG : subdir/subdirA/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:42 INFO  : subdir/subdirA/file30.txt: Copied (new)
2025/05/12 03:34:43 DEBUG : subdir/subdirB/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:43 INFO  : subdir/subdirB/RCLONE_TEST: Copied (new)
2025/05/12 03:34:43 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:34:43 DEBUG : subdir/subdirA/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:43 INFO  : subdir/subdirA/RCLONE_TEST: Copied (new)
2025/05/12 03:34:43 DEBUG : subdir-not/subdir-not2/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:43 INFO  : subdir-not/subdir-not2/file30.txt: Copied (new)
2025/05/12 03:34:44 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:44 INFO  : subdir-not/subdir-not2/RCLONE_TEST: Copied (new)
2025/05/12 03:34:44 DEBUG : subdirX/subdirX1/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:34:45 DEBUG : subdirX/subdirX1/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:45 INFO  : subdirX/subdirX1/file30.txt: Copied (new)
2025/05/12 03:34:45 DEBUG : subdirX/subdirX1/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:45 INFO  : subdirX/subdirX1/RCLONE_TEST: Copied (new)
2025/05/12 03:34:45 NOTICE: checking Path1 OpenDrive root 'rclone-test-gacuxes5woli/033429du/check_access_filters/path1'
2025/05/12 03:34:46 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : subdir: Making directory with metadata
2025/05/12 03:34:46 INFO  : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:34:46 DEBUG : Added delayed dir = "subdir", newDst=subdir
2025/05/12 03:34:46 DEBUG : subdir-not: Making directory with metadata
2025/05/12 03:34:46 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:46 INFO  : subdir-not: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:34:46 DEBUG : Added delayed dir = "subdir-not", newDst=subdir-not
2025/05/12 03:34:46 DEBUG : subdirX: Making directory with metadata
2025/05/12 03:34:46 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt
2025/05/12 03:34:46 INFO  : file1.txt: Copied (new)
2025/05/12 03:34:46 INFO  : subdirX: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:34:46 DEBUG : Added delayed dir = "subdirX", newDst=subdirX
2025/05/12 03:34:46 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:46 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt
2025/05/12 03:34:46 INFO  : file2.txt: Copied (new)
2025/05/12 03:34:46 DEBUG : subdirX/subdirX1: Making directory with metadata
2025/05/12 03:34:46 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : subdir/subdirA: Making directory with metadata
2025/05/12 03:34:46 INFO  : subdirX/subdirX1: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:34:46 DEBUG : Added delayed dir = "subdirX/subdirX1", newDst=subdirX/subdirX1
2025/05/12 03:34:46 INFO  : subdir/subdirA: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:34:46 DEBUG : Added delayed dir = "subdir/subdirA", newDst=subdir/subdirA
2025/05/12 03:34:46 DEBUG : subdir/subdirB: Making directory with metadata
2025/05/12 03:34:46 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:46 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:46 INFO  : subdir/subdirB: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:34:46 DEBUG : Added delayed dir = "subdir/subdirB", newDst=subdir/subdirB
2025/05/12 03:34:46 DEBUG : file3.txt.5028a97.partial: renamed to: file3.txt
2025/05/12 03:34:46 INFO  : file3.txt: Copied (new)
2025/05/12 03:34:46 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : subdir-not/subdir-not2: Making directory with metadata
2025/05/12 03:34:46 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:46 INFO  : subdir-not/subdir-not2: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:34:46 DEBUG : Added delayed dir = "subdir-not/subdir-not2", newDst=subdir-not/subdir-not2
2025/05/12 03:34:46 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:34:46 DEBUG : Local file system at /tmp/033429du/check_access_filters/path2: Waiting for checks to finish
2025/05/12 03:34:46 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:46 DEBUG : subdirX/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:46 DEBUG : file4.txt.5028a97.partial: renamed to: file4.txt
2025/05/12 03:34:46 INFO  : file4.txt: Copied (new)
2025/05/12 03:34:46 DEBUG : subdirX/file20.txt.5028a97.partial: renamed to: subdirX/file20.txt
2025/05/12 03:34:46 INFO  : subdirX/file20.txt: Copied (new)
2025/05/12 03:34:46 DEBUG : Local file system at /tmp/033429du/check_access_filters/path2: Waiting for transfers to finish
2025/05/12 03:34:46 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:46 DEBUG : subdirX/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:46 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST
2025/05/12 03:34:46 INFO  : RCLONE_TEST: Copied (new)
2025/05/12 03:34:46 DEBUG : subdirX/RCLONE_TEST.cf9a93ac.partial: renamed to: subdirX/RCLONE_TEST
2025/05/12 03:34:46 INFO  : subdirX/RCLONE_TEST: Copied (new)
2025/05/12 03:34:46 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:46 DEBUG : subdir/file20.txt.5028a97.partial: renamed to: subdir/file20.txt
2025/05/12 03:34:46 INFO  : subdir/file20.txt: Copied (new)
2025/05/12 03:34:46 DEBUG : subdirX/subdirX1/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:46 DEBUG : subdirX/subdirX1/file30.txt.5028a97.partial: renamed to: subdirX/subdirX1/file30.txt
2025/05/12 03:34:46 INFO  : subdirX/subdirX1/file30.txt: Copied (new)
2025/05/12 03:34:46 DEBUG : subdir-not/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:46 DEBUG : subdir-not/file20.txt.5028a97.partial: renamed to: subdir-not/file20.txt
2025/05/12 03:34:46 INFO  : subdir-not/file20.txt: Copied (new)
2025/05/12 03:34:46 DEBUG : subdirX/subdirX1/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:46 DEBUG : subdirX/subdirX1/RCLONE_TEST.cf9a93ac.partial: renamed to: subdirX/subdirX1/RCLONE_TEST
2025/05/12 03:34:46 INFO  : subdirX/subdirX1/RCLONE_TEST: Copied (new)
2025/05/12 03:34:46 DEBUG : subdir-not/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:46 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:46 DEBUG : subdir-not/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir-not/RCLONE_TEST
2025/05/12 03:34:46 DEBUG : subdir/subdirB/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:46 INFO  : subdir-not/RCLONE_TEST: Copied (new)
2025/05/12 03:34:46 DEBUG : subdir/subdirB/file30.txt.5028a97.partial: renamed to: subdir/subdirB/file30.txt
2025/05/12 03:34:46 INFO  : subdir/subdirB/file30.txt: Copied (new)
2025/05/12 03:34:46 DEBUG : subdir-not/subdir-not2/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:46 DEBUG : subdir-not/subdir-not2/file30.txt.5028a97.partial: renamed to: subdir-not/subdir-not2/file30.txt
2025/05/12 03:34:46 INFO  : subdir-not/subdir-not2/file30.txt: Copied (new)
2025/05/12 03:34:46 DEBUG : subdir/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir/RCLONE_TEST
2025/05/12 03:34:46 INFO  : subdir/RCLONE_TEST: Copied (new)
2025/05/12 03:34:46 DEBUG : subdir/subdirA/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:34:46 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:46 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir-not/subdir-not2/RCLONE_TEST
2025/05/12 03:34:46 INFO  : subdir-not/subdir-not2/RCLONE_TEST: Copied (new)
2025/05/12 03:34:46 DEBUG : subdir/subdirA/file30.txt.5028a97.partial: renamed to: subdir/subdirA/file30.txt
2025/05/12 03:34:46 INFO  : subdir/subdirA/file30.txt: Copied (new)
2025/05/12 03:34:46 DEBUG : subdir/subdirA/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:46 DEBUG : subdir/subdirA/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir/subdirA/RCLONE_TEST
2025/05/12 03:34:46 DEBUG : subdir/subdirB/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:34:46 INFO  : subdir/subdirA/RCLONE_TEST: Copied (new)
2025/05/12 03:34:46 DEBUG : subdir/subdirB/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir/subdirB/RCLONE_TEST
2025/05/12 03:34:46 INFO  : subdir/subdirB/RCLONE_TEST: Copied (new)
2025/05/12 03:34:46 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/05/12 03:34:46 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/05/12 03:34:46 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/05/12 03:34:46 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/05/12 03:34:46 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/05/12 03:34:46 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:34:46 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/05/12 03:34:46 NOTICE: checking path2 Local file system at /tmp/033429du/check_access_filters/path2
2025/05/12 03:34:46 NOTICE: (01)  : test check-access-filters
2025/05/12 03:34:46 NOTICE: (02)  : test EXCLUDE - OTHER TESTS
2025/05/12 03:34:46 NOTICE: (03)  : copy-file /tmp/033429du/datadir/test_check_access_filters-yuvohew6/exclude-other-filtersfile.txt /tmp/033429du/workdir/
2025/05/12 03:34:46 INFO  : exclude-other-filtersfile.txt: Copied (new)
2025/05/12 03:34:46 NOTICE: (04)  : test resync to get the filters file md5 built.
2025/05/12 03:34:46 NOTICE: (05)  : bisync resync filters-file=/tmp/033429du/workdir/exclude-other-filtersfile.txt
2025/05/12 03:34:48 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:34:48 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/05/12 03:34:48 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/05/12 03:34:48 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/05/12 03:34:48 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/05/12 03:34:48 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/05/12 03:34:48 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/05/12 03:34:48 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:34:48 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/05/12 03:34:48 INFO  : Synching Path1 "TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/" with Path2 "/tmp/033429du/check_access_filters/path2/"
2025/05/12 03:34:48 INFO  : Using filters file /tmp/033429du/workdir/exclude-other-filtersfile.txt
2025/05/12 03:34:48 INFO  : Storing filters file hash to /tmp/033429du/workdir/exclude-other-filtersfile.txt.md5
2025/05/12 03:34:48 INFO  : Copying Path2 files to Path1
2025/05/12 03:34:48 INFO  : - Path2    Resync is copying files to         - Path1
2025/05/12 03:34:48 INFO  : - Path1    Resync is copying files to         - Path2
2025/05/12 03:34:49 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:34:49 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/05/12 03:34:49 INFO  : Resync updating listings
2025/05/12 03:34:49 INFO  : Validating listings for Path1 "TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/" vs Path2 "/tmp/033429du/check_access_filters/path2/"
2025/05/12 03:34:49 INFO  : Bisync successful
2025/05/12 03:34:49 NOTICE: (06)  : test EXCLUDE - test filters for check access
2025/05/12 03:34:49 NOTICE: (07)  : bisync check-access filters-file=/tmp/033429du/workdir/exclude-other-filtersfile.txt
2025/05/12 03:34:51 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:34:51 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/05/12 03:34:51 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/05/12 03:34:51 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/05/12 03:34:51 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/05/12 03:34:51 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/05/12 03:34:51 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/05/12 03:34:51 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:34:51 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/05/12 03:34:51 INFO  : Synching Path1 "TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/" with Path2 "/tmp/033429du/check_access_filters/path2/"
2025/05/12 03:34:51 INFO  : Using filters file /tmp/033429du/workdir/exclude-other-filtersfile.txt
2025/05/12 03:34:51 INFO  : Building Path1 and Path2 listings
2025/05/12 03:34:51 INFO  : Path1 checking for diffs
2025/05/12 03:34:51 INFO  : Path2 checking for diffs
2025/05/12 03:34:51 INFO  : Checking access health
2025/05/12 03:34:51 INFO  : Found 3 matching "RCLONE_TEST" files on both paths
2025/05/12 03:34:51 INFO  : No changes found
2025/05/12 03:34:51 INFO  : Updating listings
2025/05/12 03:34:51 INFO  : Validating listings for Path1 "TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/" vs Path2 "/tmp/033429du/check_access_filters/path2/"
2025/05/12 03:34:51 INFO  : Bisync successful
2025/05/12 03:34:51 NOTICE: (08)  : copy-listings exclude-initial
2025/05/12 03:34:51 NOTICE: (09)  : test EXCLUDE - delete RCLONE_TEST files in excluded directories
2025/05/12 03:34:51 NOTICE: (10)  : delete-file /tmp/033429du/check_access_filters/path2/subdir/subdirA/RCLONE_TEST
2025/05/12 03:34:51 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:34:51 NOTICE: (11)  : delete-file TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/subdir-not/RCLONE_TEST
2025/05/12 03:34:53 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:34:53 NOTICE: (12)  : delete-file /tmp/033429du/check_access_filters/path2/subdir-not/subdir-not2/RCLONE_TEST
2025/05/12 03:34:53 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:34:53 NOTICE: (13)  : delete-file TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/subdirX/RCLONE_TEST
2025/05/12 03:34:55 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:34:55 NOTICE: (14)  : test EXCLUDE - test should PASS
2025/05/12 03:34:55 NOTICE: (15)  : bisync check-access filters-file=/tmp/033429du/workdir/exclude-other-filtersfile.txt
2025/05/12 03:34:57 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:34:57 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/05/12 03:34:57 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/05/12 03:34:57 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/05/12 03:34:57 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/05/12 03:34:57 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/05/12 03:34:57 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/05/12 03:34:57 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:34: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/05/12 03:34:57 INFO  : Synching Path1 "TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/" with Path2 "/tmp/033429du/check_access_filters/path2/"
2025/05/12 03:34:57 INFO  : Using filters file /tmp/033429du/workdir/exclude-other-filtersfile.txt
2025/05/12 03:34:57 INFO  : Building Path1 and Path2 listings
2025/05/12 03:34:57 INFO  : Path1 checking for diffs
2025/05/12 03:34:57 INFO  : Path2 checking for diffs
2025/05/12 03:34:57 INFO  : Checking access health
2025/05/12 03:34:57 INFO  : Found 3 matching "RCLONE_TEST" files on both paths
2025/05/12 03:34:57 INFO  : No changes found
2025/05/12 03:34:57 INFO  : Updating listings
2025/05/12 03:34:57 INFO  : Validating listings for Path1 "TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/" vs Path2 "/tmp/033429du/check_access_filters/path2/"
2025/05/12 03:34:57 INFO  : Bisync successful
2025/05/12 03:34:57 NOTICE: (16)  : copy-listings exclude-pass-run
2025/05/12 03:34:57 NOTICE: (17)  : test EXCLUDE - delete RCLONE_TEST files in included directories
2025/05/12 03:34:57 NOTICE: (18)  : delete-file /tmp/033429du/check_access_filters/path2/RCLONE_TEST
2025/05/12 03:34:57 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:34:57 NOTICE: (19)  : delete-file TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/subdir/RCLONE_TEST
2025/05/12 03:34:59 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:34:59 NOTICE: (20)  : test EXCLUDE - test should ABORT
2025/05/12 03:34:59 NOTICE: (21)  : bisync check-access filters-file=/tmp/033429du/workdir/exclude-other-filtersfile.txt
2025/05/12 03:35:01 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:35:01 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/05/12 03:35:01 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/05/12 03:35:01 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/05/12 03:35:01 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/05/12 03:35:01 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/05/12 03:35:01 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/05/12 03:35:01 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:35:01 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/05/12 03:35:01 INFO  : Synching Path1 "TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/" with Path2 "/tmp/033429du/check_access_filters/path2/"
2025/05/12 03:35:01 INFO  : Using filters file /tmp/033429du/workdir/exclude-other-filtersfile.txt
2025/05/12 03:35:01 INFO  : Building Path1 and Path2 listings
2025/05/12 03:35:02 INFO  : Path1 checking for diffs
2025/05/12 03:35:02 INFO  : - Path1    File was deleted          - subdir/RCLONE_TEST
2025/05/12 03:35:02 INFO  : Path1:    1 changes:    0 new,    0 modified,    1 deleted
2025/05/12 03:35:02 INFO  : Path2 checking for diffs
2025/05/12 03:35:02 INFO  : - Path2    File was deleted          - RCLONE_TEST
2025/05/12 03:35:02 INFO  : Path2:    1 changes:    0 new,    0 modified,    1 deleted
2025/05/12 03:35:02 INFO  : Checking access health
2025/05/12 03:35:02 ERROR : -          Access test failed: Path1 file not found in Path2 - RCLONE_TEST
2025/05/12 03:35:02 ERROR : -          Access test failed: Path2 file not found in Path1 - subdir/RCLONE_TEST
2025/05/12 03:35:02 ERROR : Bisync critical error: check file check failed
2025/05/12 03:35:02 ERROR : Bisync aborted. Must run --resync to recover.
2025/05/12 03:35:02 NOTICE: Bisync error: bisync aborted
2025/05/12 03:35:02 NOTICE: (22)  : move-listings exclude-error-run
2025/05/12 03:35:02 NOTICE: (23)  : test INCLUDE - OTHER TESTS
2025/05/12 03:35:02 NOTICE: (24)  : test reset to the initial state
2025/05/12 03:35:02 NOTICE: (25)  : copy-dir /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access_filters/initial TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/
2025/05/12 03:35:05 INFO  : subdirX/RCLONE_TEST: Copied (new)
2025/05/12 03:35:05 INFO  : subdir/RCLONE_TEST: Copied (new)
2025/05/12 03:35:05 INFO  : subdir-not/RCLONE_TEST: Copied (new)
2025/05/12 03:35:05 NOTICE: (26)  : sync-dir TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/ /tmp/033429du/check_access_filters/path2/
2025/05/12 03:35:05 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:35:05 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/05/12 03:35:05 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/05/12 03:35:05 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/05/12 03:35:05 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/05/12 03:35:05 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/05/12 03:35:05 INFO  : RCLONE_TEST: Copied (new)
2025/05/12 03:35:05 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/05/12 03:35:06 INFO  : subdir/subdirA/RCLONE_TEST: Copied (new)
2025/05/12 03:35:06 INFO  : subdir-not/subdir-not2/RCLONE_TEST: Copied (new)
2025/05/12 03:35:06 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/05/12 03:35:06 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/05/12 03:35:06 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/05/12 03:35:06 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:35:06 NOTICE: (27)  : copy-file /tmp/033429du/datadir/test_check_access_filters-yuvohew6/include-other-filtersfile.txt /tmp/033429du/workdir/
2025/05/12 03:35:06 INFO  : include-other-filtersfile.txt: Copied (new)
2025/05/12 03:35:06 NOTICE: (28)  : bisync resync filters-file=/tmp/033429du/workdir/include-other-filtersfile.txt
2025/05/12 03:35:08 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:35:08 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/05/12 03:35:08 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/05/12 03:35:08 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/05/12 03:35:08 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/05/12 03:35:08 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/05/12 03:35:08 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/05/12 03:35:08 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:35:08 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/05/12 03:35:08 INFO  : Synching Path1 "TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/" with Path2 "/tmp/033429du/check_access_filters/path2/"
2025/05/12 03:35:08 INFO  : Using filters file /tmp/033429du/workdir/include-other-filtersfile.txt
2025/05/12 03:35:08 INFO  : Storing filters file hash to /tmp/033429du/workdir/include-other-filtersfile.txt.md5
2025/05/12 03:35:08 INFO  : Copying Path2 files to Path1
2025/05/12 03:35:08 INFO  : - Path2    Resync is copying files to         - Path1
2025/05/12 03:35:09 INFO  : - Path1    Resync is copying files to         - Path2
2025/05/12 03:35:09 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:35:09 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/05/12 03:35:09 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/05/12 03:35:09 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/05/12 03:35:09 INFO  : Resync updating listings
2025/05/12 03:35:09 INFO  : Validating listings for Path1 "TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/" vs Path2 "/tmp/033429du/check_access_filters/path2/"
2025/05/12 03:35:09 INFO  : Bisync successful
2025/05/12 03:35:09 NOTICE: (29)  : test INCLUDE - test include/exclude filters for check access
2025/05/12 03:35:09 NOTICE: (30)  : bisync check-access filters-file=/tmp/033429du/workdir/include-other-filtersfile.txt
2025/05/12 03:35:11 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:35:11 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/05/12 03:35:11 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/05/12 03:35:11 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/05/12 03:35:11 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/05/12 03:35:11 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/05/12 03:35:11 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/05/12 03:35:11 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:35:11 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/05/12 03:35:11 INFO  : Synching Path1 "TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/" with Path2 "/tmp/033429du/check_access_filters/path2/"
2025/05/12 03:35:11 INFO  : Using filters file /tmp/033429du/workdir/include-other-filtersfile.txt
2025/05/12 03:35:11 INFO  : Building Path1 and Path2 listings
2025/05/12 03:35:12 INFO  : Path1 checking for diffs
2025/05/12 03:35:12 INFO  : Path2 checking for diffs
2025/05/12 03:35:12 INFO  : Checking access health
2025/05/12 03:35:12 INFO  : Found 5 matching "RCLONE_TEST" files on both paths
2025/05/12 03:35:12 INFO  : No changes found
2025/05/12 03:35:12 INFO  : Updating listings
2025/05/12 03:35:12 INFO  : Validating listings for Path1 "TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/" vs Path2 "/tmp/033429du/check_access_filters/path2/"
2025/05/12 03:35:12 INFO  : Bisync successful
2025/05/12 03:35:12 NOTICE: (31)  : copy-listings include-initial
2025/05/12 03:35:12 NOTICE: (32)  : test INCLUDE - delete RCLONE_TEST files in excluded directories
2025/05/12 03:35:12 NOTICE: (33)  : delete-file /tmp/033429du/check_access_filters/path2/subdir/subdirA/RCLONE_TEST
2025/05/12 03:35:12 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:35:12 NOTICE: (34)  : delete-file TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/subdir-not/RCLONE_TEST
2025/05/12 03:35:12 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:35:12 NOTICE: (35)  : delete-file /tmp/033429du/check_access_filters/path2/subdir-not/subdir-not2/RCLONE_TEST
2025/05/12 03:35:12 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:35:12 NOTICE: (36)  : test INCLUDE - test should PASS
2025/05/12 03:35:12 NOTICE: (37)  : bisync check-access filters-file=/tmp/033429du/workdir/include-other-filtersfile.txt
2025/05/12 03:35:14 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:35:14 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/05/12 03:35:14 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/05/12 03:35:14 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/05/12 03:35:14 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/05/12 03:35:14 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/05/12 03:35:14 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/05/12 03:35:14 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:35:14 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/05/12 03:35:14 INFO  : Synching Path1 "TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/" with Path2 "/tmp/033429du/check_access_filters/path2/"
2025/05/12 03:35:14 INFO  : Using filters file /tmp/033429du/workdir/include-other-filtersfile.txt
2025/05/12 03:35:14 INFO  : Building Path1 and Path2 listings
2025/05/12 03:35:15 INFO  : Path1 checking for diffs
2025/05/12 03:35:15 INFO  : Path2 checking for diffs
2025/05/12 03:35:15 INFO  : Checking access health
2025/05/12 03:35:15 INFO  : Found 5 matching "RCLONE_TEST" files on both paths
2025/05/12 03:35:15 INFO  : No changes found
2025/05/12 03:35:15 INFO  : Updating listings
2025/05/12 03:35:15 INFO  : Validating listings for Path1 "TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/" vs Path2 "/tmp/033429du/check_access_filters/path2/"
2025/05/12 03:35:15 INFO  : Bisync successful
2025/05/12 03:35:15 NOTICE: (38)  : copy-listings include-pass-run
2025/05/12 03:35:15 NOTICE: (39)  : test INCLUDE - delete RCLONE_TEST files in included directories
2025/05/12 03:35:15 NOTICE: (40)  : delete-file /tmp/033429du/check_access_filters/path2/RCLONE_TEST
2025/05/12 03:35:15 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:35:15 NOTICE: (41)  : delete-file TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/subdir/RCLONE_TEST
2025/05/12 03:35:15 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:35:15 NOTICE: (42)  : delete-file TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/subdirX/subdirX1/RCLONE_TEST
2025/05/12 03:35:17 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:35:17 NOTICE: (43)  : test INCLUDE - test should ABORT
2025/05/12 03:35:17 NOTICE: (44)  : bisync check-access filters-file=/tmp/033429du/workdir/include-other-filtersfile.txt
2025/05/12 03:35:19 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:35:19 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/05/12 03:35:19 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/05/12 03:35:19 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/05/12 03:35:19 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/05/12 03:35:19 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/05/12 03:35:19 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/05/12 03:35:19 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:35: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/05/12 03:35:19 INFO  : Synching Path1 "TestOpenDrive:rclone-test-gacuxes5woli/033429du/check_access_filters/path1/" with Path2 "/tmp/033429du/check_access_filters/path2/"
2025/05/12 03:35:19 INFO  : Using filters file /tmp/033429du/workdir/include-other-filtersfile.txt
2025/05/12 03:35:19 INFO  : Building Path1 and Path2 listings
2025/05/12 03:35:20 INFO  : Path1 checking for diffs
2025/05/12 03:35:20 INFO  : - Path1    File was deleted          - subdir/RCLONE_TEST
2025/05/12 03:35:20 INFO  : - Path1    File was deleted          - subdirX/subdirX1/RCLONE_TEST
2025/05/12 03:35:20 INFO  : Path1:    2 changes:    0 new,    0 modified,    2 deleted
2025/05/12 03:35:20 INFO  : Path2 checking for diffs
2025/05/12 03:35:20 INFO  : - Path2    File was deleted          - RCLONE_TEST
2025/05/12 03:35:20 INFO  : Path2:    1 changes:    0 new,    0 modified,    1 deleted
2025/05/12 03:35:20 INFO  : Checking access health
2025/05/12 03:35:20 ERROR : Access test failed: Path1 count 3, Path2 count 4 - RCLONE_TEST
2025/05/12 03:35:20 ERROR : -          Access test failed: Path1 file not found in Path2 - RCLONE_TEST
2025/05/12 03:35:20 ERROR : -          Access test failed: Path2 file not found in Path1 - subdirX/subdirX1/RCLONE_TEST
2025/05/12 03:35:20 ERROR : -          Access test failed: Path2 file not found in Path1 - subdir/RCLONE_TEST
2025/05/12 03:35:20 ERROR : Bisync critical error: check file check failed
2025/05/12 03:35:20 ERROR : Bisync aborted. Must run --resync to recover.
2025/05/12 03:35:20 NOTICE: Bisync error: bisync aborted
2025/05/12 03:35:20 NOTICE: (45)  : move-listings include-error-run
    bisync_test.go:560: TEST check_access_filters PASSED
2025/05/12 03:35:20 DEBUG : OpenDrive root 'rclone-test-gacuxes5woli': Purge remote
--- PASS: TestBisyncRemoteLocal (52.12s)
    --- PASS: TestBisyncRemoteLocal/check_access_filters (50.75s)
=== RUN   TestBisyncLocalRemote
2025/05/12 03:35:21 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-rumokot6peve"
2025/05/12 03:35:21 DEBUG : Starting OpenDrive session with ID: fb9872ecdb05124450d95591bc8d3f7a566002ed52e351875b7557d36cfc7993
2025/05/12 03:35:21 NOTICE: remote: TestOpenDrive:rclone-test-rumokot6peve
=== RUN   TestBisyncLocalRemote/changes
2025/05/12 03:35:21 DEBUG : Creating backend with remote "/tmp/033521ro"
2025/05/12 03:35:21 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/12 03:35:21 DEBUG : Creating backend with remote "/tmp/033521ro/changes/path1"
2025/05/12 03:35:21 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-rumokot6peve/033521ro"
2025/05/12 03:35:22 DEBUG : Starting OpenDrive session with ID: d7756cf8f343ad532cbf7228d044a0b7ed9e1631dbcbf4e9fb68a0fa9220982c
2025/05/12 03:35:22 INFO  : path2: Making directory
2025/05/12 03:35:23 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2"
2025/05/12 03:35:24 DEBUG : Starting OpenDrive session with ID: 779b35c69fee5861c6151f1bae1800250c235e61115f9388ad4a2f1ef412d604
2025/05/12 03:35:25 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_changes/initial"
2025/05/12 03:35:25 DEBUG : Creating backend with remote "/tmp/033521ro/initdir/test_changes-vadolad7"
2025/05/12 03:35:25 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file5.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file8.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : Local file system at /tmp/033521ro/initdir/test_changes-vadolad7: Waiting for checks to finish
2025/05/12 03:35:25 DEBUG : Local file system at /tmp/033521ro/initdir/test_changes-vadolad7: Waiting for transfers to finish
2025/05/12 03:35:25 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:25 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:25 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt
2025/05/12 03:35:25 INFO  : file1.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:35:25 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:25 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt
2025/05/12 03:35:25 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST
2025/05/12 03:35:25 INFO  : RCLONE_TEST: Copied (new)
2025/05/12 03:35:25 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:25 INFO  : file2.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file3.txt.5028a97.partial: renamed to: file3.txt
2025/05/12 03:35:25 INFO  : file3.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:25 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:25 DEBUG : file4.txt.5028a97.partial: renamed to: file4.txt
2025/05/12 03:35:25 INFO  : file4.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file7.txt.5028a97.partial: renamed to: file7.txt
2025/05/12 03:35:25 INFO  : file7.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:25 DEBUG : file8.txt.5028a97.partial: renamed to: file8.txt
2025/05/12 03:35:25 INFO  : file8.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file6.txt.5028a97.partial: renamed to: file6.txt
2025/05/12 03:35:25 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:25 INFO  : file6.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file5.txt.5028a97.partial: renamed to: file5.txt
2025/05/12 03:35:25 INFO  : file5.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_changes/modfiles"
2025/05/12 03:35:25 DEBUG : Creating backend with remote "/tmp/033521ro/datadir/test_changes-waliqok3"
2025/05/12 03:35:25 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file10.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file11.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file5L.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file5R.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : Local file system at /tmp/033521ro/datadir/test_changes-waliqok3: Waiting for checks to finish
2025/05/12 03:35:25 DEBUG : Local file system at /tmp/033521ro/datadir/test_changes-waliqok3: Waiting for transfers to finish
2025/05/12 03:35:25 DEBUG : file10.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK
2025/05/12 03:35:25 DEBUG : file10.txt.925c801f.partial: renamed to: file10.txt
2025/05/12 03:35:25 INFO  : file10.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK
2025/05/12 03:35:25 DEBUG : file2.txt: md5 = fb3ecfb2800400fb01b0bfd39903e9fb OK
2025/05/12 03:35:25 DEBUG : file2.txt.f8ac1735.partial: renamed to: file2.txt
2025/05/12 03:35:25 INFO  : file2.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file11.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK
2025/05/12 03:35:25 DEBUG : file11.txt.925c801f.partial: renamed to: file11.txt
2025/05/12 03:35:25 INFO  : file11.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file5L.txt: md5 = 0860a03592626642f8fd6c8bfb447d2a OK
2025/05/12 03:35:25 DEBUG : file1.txt.925c801f.partial: renamed to: file1.txt
2025/05/12 03:35:25 INFO  : file1.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file5L.txt.c32cc336.partial: renamed to: file5L.txt
2025/05/12 03:35:25 INFO  : file5L.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file6.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK
2025/05/12 03:35:25 DEBUG : file6.txt.925c801f.partial: renamed to: file6.txt
2025/05/12 03:35:25 INFO  : file6.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file5R.txt: md5 = 979a803b15d27df0c31ad7d29006d10b OK
2025/05/12 03:35:25 DEBUG : file5R.txt.aa998d0a.partial: renamed to: file5R.txt
2025/05/12 03:35:25 INFO  : file5R.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file7.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK
2025/05/12 03:35:25 DEBUG : file7.txt.925c801f.partial: renamed to: file7.txt
2025/05/12 03:35:25 INFO  : file7.txt: Copied (new)
2025/05/12 03:35:25 ERROR : : error listing: directory not found
2025/05/12 03:35:25 ERROR : : error listing: directory not found
2025/05/12 03:35:25 NOTICE: checking initFs Local file system at /tmp/033521ro/initdir/test_changes-vadolad7
2025/05/12 03:35:25 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file5.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file8.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : Local file system at /tmp/033521ro/changes/path1: Waiting for checks to finish
2025/05/12 03:35:25 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:25 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt
2025/05/12 03:35:25 INFO  : file1.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : Local file system at /tmp/033521ro/changes/path1: Waiting for transfers to finish
2025/05/12 03:35:25 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:25 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt
2025/05/12 03:35:25 INFO  : file2.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:25 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:25 DEBUG : file5.txt.5028a97.partial: renamed to: file5.txt
2025/05/12 03:35:25 INFO  : file5.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:35:25 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST
2025/05/12 03:35:25 INFO  : RCLONE_TEST: Copied (new)
2025/05/12 03:35:25 DEBUG : file4.txt.5028a97.partial: renamed to: file4.txt
2025/05/12 03:35:25 INFO  : file4.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:25 DEBUG : file3.txt.5028a97.partial: renamed to: file3.txt
2025/05/12 03:35:25 INFO  : file3.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:25 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:25 DEBUG : file7.txt.5028a97.partial: renamed to: file7.txt
2025/05/12 03:35:25 INFO  : file7.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file8.txt.5028a97.partial: renamed to: file8.txt
2025/05/12 03:35:25 INFO  : file8.txt: Copied (new)
2025/05/12 03:35:25 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:25 DEBUG : file6.txt.5028a97.partial: renamed to: file6.txt
2025/05/12 03:35:25 INFO  : file6.txt: Copied (new)
2025/05/12 03:35:25 NOTICE: checking Path1 Local file system at /tmp/033521ro/changes/path1
2025/05/12 03:35:25 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file5.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : file8.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:35:25 DEBUG : OpenDrive root 'rclone-test-rumokot6peve/033521ro/changes/path2': Waiting for checks to finish
2025/05/12 03:35:25 DEBUG : OpenDrive root 'rclone-test-rumokot6peve/033521ro/changes/path2': Waiting for transfers to finish
2025/05/12 03:35:28 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:28 INFO  : file2.txt: Copied (new)
2025/05/12 03:35:28 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:28 INFO  : file1.txt: Copied (new)
2025/05/12 03:35:28 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:28 INFO  : file3.txt: Copied (new)
2025/05/12 03:35:29 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:29 INFO  : file5.txt: Copied (new)
2025/05/12 03:35:29 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:29 INFO  : file4.txt: Copied (new)
2025/05/12 03:35:30 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:30 INFO  : file6.txt: Copied (new)
2025/05/12 03:35:30 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:30 INFO  : file7.txt: Copied (new)
2025/05/12 03:35:31 DEBUG : RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:35:31 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:31 INFO  : file8.txt: Copied (new)
2025/05/12 03:35:32 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:35:32 INFO  : RCLONE_TEST: Copied (new)
2025/05/12 03:35:32 NOTICE: checking path2 OpenDrive root 'rclone-test-rumokot6peve/033521ro/changes/path2'
2025/05/12 03:35:32 NOTICE: (01)  : test changes
2025/05/12 03:35:32 NOTICE: (02)  : test initial bisync
2025/05/12 03:35:32 NOTICE: (03)  : bisync resync
2025/05/12 03:35:34 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:35: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/05/12 03:35:34 INFO  : Synching Path1 "/tmp/033521ro/changes/path1/" with Path2 "TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/"
2025/05/12 03:35:34 INFO  : Copying Path2 files to Path1
2025/05/12 03:35:34 INFO  : - Path2    Resync is copying files to         - Path1
2025/05/12 03:35:34 INFO  : - Path1    Resync is copying files to         - Path2
2025/05/12 03:35:34 INFO  : Resync updating listings
2025/05/12 03:35:34 INFO  : Validating listings for Path1 "/tmp/033521ro/changes/path1/" vs Path2 "TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/"
2025/05/12 03:35:34 INFO  : Bisync successful
2025/05/12 03:35:34 NOTICE: (04)  : test make modifications on both paths
2025/05/12 03:35:34 NOTICE: (05)  : test new on path2 - file10
2025/05/12 03:35:34 NOTICE: (06)  : touch-copy 2001-01-02 /tmp/033521ro/datadir/test_changes-waliqok3/file10.txt TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/
2025/05/12 03:35:38 INFO  : file10.txt: Copied (new)
2025/05/12 03:35:38 NOTICE: (07)  : test newer on path2 - file1
2025/05/12 03:35:38 NOTICE: (08)  : touch-copy 2001-01-02 /tmp/033521ro/datadir/test_changes-waliqok3/file1.txt TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/
2025/05/12 03:35:40 INFO  : file1.txt: Copied (replaced existing)
2025/05/12 03:35:40 NOTICE: (09)  : test new on path1 - file11
2025/05/12 03:35:40 NOTICE: (10)  : touch-copy 2001-01-02 /tmp/033521ro/datadir/test_changes-waliqok3/file11.txt /tmp/033521ro/changes/path1/
2025/05/12 03:35:40 INFO  : file11.txt: Copied (new)
2025/05/12 03:35:40 NOTICE: (11)  : test newer on path1 - file2
2025/05/12 03:35:40 NOTICE: (12)  : touch-copy 2001-01-02 /tmp/033521ro/datadir/test_changes-waliqok3/file2.txt /tmp/033521ro/changes/path1/
2025/05/12 03:35:40 INFO  : file2.txt: Copied (replaced existing)
2025/05/12 03:35:40 NOTICE: (13)  : test deleted on path2 - file3
2025/05/12 03:35:40 NOTICE: (14)  : delete-file TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/file3.txt
2025/05/12 03:35:41 INFO  : file3.txt: Deleted
2025/05/12 03:35:41 NOTICE: (15)  : test deleted on path1 - file4
2025/05/12 03:35:41 NOTICE: (16)  : delete-file /tmp/033521ro/changes/path1/file4.txt
2025/05/12 03:35:41 INFO  : file4.txt: Deleted
2025/05/12 03:35:41 NOTICE: (17)  : test deleted on both paths - file8
2025/05/12 03:35:41 NOTICE: (18)  : delete-file /tmp/033521ro/changes/path1/file8.txt
2025/05/12 03:35:41 INFO  : file8.txt: Deleted
2025/05/12 03:35:41 NOTICE: (19)  : delete-file TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/file8.txt
2025/05/12 03:35:42 INFO  : file8.txt: Deleted
2025/05/12 03:35:42 NOTICE: (20)  : test changed on both paths - file5 (file5R, file5L)
2025/05/12 03:35:42 NOTICE: (21)  : touch-glob 2001-01-02 /tmp/033521ro/datadir/test_changes-waliqok3/ file5R.txt
2025/05/12 03:35:42 NOTICE: (22)  : copy-as /tmp/033521ro/datadir/test_changes-waliqok3/file5R.txt TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/ file5.txt
2025/05/12 03:35:44 INFO  : file5R.txt: Copied (replaced existing) to: file5.txt
2025/05/12 03:35:44 NOTICE: (23)  : touch-glob 2001-03-04 /tmp/033521ro/datadir/test_changes-waliqok3/ file5L.txt
2025/05/12 03:35:44 NOTICE: (24)  : copy-as /tmp/033521ro/datadir/test_changes-waliqok3/file5L.txt /tmp/033521ro/changes/path1/ file5.txt
2025/05/12 03:35:44 INFO  : file5L.txt: Copied (replaced existing) to: file5.txt
2025/05/12 03:35:44 NOTICE: (25)  : test newer on path2 and deleted on path1 - file6
2025/05/12 03:35:44 NOTICE: (26)  : touch-copy 2001-01-02 /tmp/033521ro/datadir/test_changes-waliqok3/file6.txt TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/
2025/05/12 03:35:47 INFO  : file6.txt: Copied (replaced existing)
2025/05/12 03:35:47 NOTICE: (27)  : delete-file /tmp/033521ro/changes/path1/file6.txt
2025/05/12 03:35:47 INFO  : file6.txt: Deleted
2025/05/12 03:35:47 NOTICE: (28)  : test newer on path1 and deleted on path2 - file7
2025/05/12 03:35:47 NOTICE: (29)  : touch-copy 2001-01-02 /tmp/033521ro/datadir/test_changes-waliqok3/file7.txt /tmp/033521ro/changes/path1/
2025/05/12 03:35:47 INFO  : file7.txt: Copied (replaced existing)
2025/05/12 03:35:47 NOTICE: (30)  : delete-file TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/file7.txt
2025/05/12 03:35:47 INFO  : file7.txt: Deleted
2025/05/12 03:35:47 NOTICE: (31)  : test bisync run
2025/05/12 03:35:47 NOTICE: (32)  : bisync
2025/05/12 03:35:49 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:35:49 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/05/12 03:35:49 INFO  : Synching Path1 "/tmp/033521ro/changes/path1/" with Path2 "TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/"
2025/05/12 03:35:49 INFO  : Building Path1 and Path2 listings
2025/05/12 03:35:49 INFO  : Path1 checking for diffs
2025/05/12 03:35:49 INFO  : - Path1    File changed: size (larger), time (newer) - file2.txt
2025/05/12 03:35:49 INFO  : - Path1    File was deleted          - file4.txt
2025/05/12 03:35:49 INFO  : - Path1    File changed: size (larger), time (newer) - file5.txt
2025/05/12 03:35:49 INFO  : - Path1    File was deleted          - file6.txt
2025/05/12 03:35:49 INFO  : - Path1    File changed: size (larger), time (newer) - file7.txt
2025/05/12 03:35:49 INFO  : - Path1    File was deleted          - file8.txt
2025/05/12 03:35:49 INFO  : - Path1    File is new               - file11.txt
2025/05/12 03:35:49 INFO  : Path1:    7 changes:    1 new,    3 modified,    3 deleted
2025/05/12 03:35:49 INFO  : (Modified:    3 newer,    0 older,    3 larger,    0 smaller)
2025/05/12 03:35:49 INFO  : Path2 checking for diffs
2025/05/12 03:35:49 INFO  : - Path2    File changed: size (larger), time (newer) - file1.txt
2025/05/12 03:35:49 INFO  : - Path2    File was deleted          - file3.txt
2025/05/12 03:35:49 INFO  : - Path2    File changed: size (larger), time (newer) - file5.txt
2025/05/12 03:35:49 INFO  : - Path2    File changed: size (larger), time (newer) - file6.txt
2025/05/12 03:35:49 INFO  : - Path2    File was deleted          - file7.txt
2025/05/12 03:35:49 INFO  : - Path2    File was deleted          - file8.txt
2025/05/12 03:35:49 INFO  : - Path2    File is new               - file10.txt
2025/05/12 03:35:49 INFO  : Path2:    7 changes:    1 new,    3 modified,    3 deleted
2025/05/12 03:35:49 INFO  : (Modified:    3 newer,    0 older,    3 larger,    0 smaller)
2025/05/12 03:35:49 INFO  : Applying changes
2025/05/12 03:35:49 INFO  : Checking potential conflicts...
2025/05/12 03:35:50 ERROR : file5.txt: md5 differ
2025/05/12 03:35:50 NOTICE: OpenDrive root 'rclone-test-rumokot6peve/033521ro/changes/path2': 1 differences found
2025/05/12 03:35:50 NOTICE: OpenDrive root 'rclone-test-rumokot6peve/033521ro/changes/path2': 1 errors while checking
2025/05/12 03:35:50 INFO  : Finished checking the potential conflicts. 1 differences found
2025/05/12 03:35:50 INFO  : - Path1    Queue copy to Path2       - TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/file11.txt
2025/05/12 03:35:50 INFO  : - Path1    Queue copy to Path2       - TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/file2.txt
2025/05/12 03:35:50 INFO  : - Path2    Queue delete              - TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/file4.txt
2025/05/12 03:35:50 NOTICE: - WARNING  New or changed in both paths       - file5.txt
2025/05/12 03:35:50 NOTICE: - Path1    Renaming Path1 copy                - /tmp/033521ro/changes/path1/file5.txt.conflict1
2025/05/12 03:35:50 INFO  : file5.txt: Moved (server-side) to: file5.txt.conflict1
2025/05/12 03:35:50 NOTICE: - Path1    Queue copy to Path2       - TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/file5.txt.conflict1
2025/05/12 03:35:50 NOTICE: - Path2    Renaming Path2 copy                - TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/file5.txt.conflict2
2025/05/12 03:35:50 INFO  : file5.txt: Moved (server-side) to: file5.txt.conflict2
2025/05/12 03:35:50 NOTICE: - Path2    Queue copy to Path1       - /tmp/033521ro/changes/path1/file5.txt.conflict2
2025/05/12 03:35:50 INFO  : - Path2    Queue copy to Path1       - /tmp/033521ro/changes/path1/file6.txt
2025/05/12 03:35:50 INFO  : - Path1    Queue copy to Path2       - TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/file7.txt
2025/05/12 03:35:50 INFO  : - Path2    Queue copy to Path1       - /tmp/033521ro/changes/path1/file1.txt
2025/05/12 03:35:50 INFO  : - Path2    Queue copy to Path1       - /tmp/033521ro/changes/path1/file10.txt
2025/05/12 03:35:50 INFO  : - Path1    Queue delete              - /tmp/033521ro/changes/path1/file3.txt
2025/05/12 03:35:50 INFO  : - Path2    Do queued copies to                - Path1
2025/05/12 03:35:51 INFO  : file10.txt: Copied (new)
2025/05/12 03:35:51 INFO  : file1.txt: Copied (replaced existing)
2025/05/12 03:35:51 INFO  : file5.txt.conflict2: Copied (new)
2025/05/12 03:35:51 INFO  : file6.txt: Copied (new)
2025/05/12 03:35:51 INFO  : file3.txt: Deleted
2025/05/12 03:35:51 INFO  : - Path1    Do queued copies to                - Path2
2025/05/12 03:35:52 INFO  : file2.txt: Copied (replaced existing)
2025/05/12 03:35:53 INFO  : file11.txt: Copied (new)
2025/05/12 03:35:53 INFO  : file7.txt: Copied (new)
2025/05/12 03:35:53 INFO  : file5.txt.conflict1: Copied (new)
2025/05/12 03:35:53 INFO  : file4.txt: Deleted
2025/05/12 03:35:53 INFO  : Updating listings
2025/05/12 03:35:53 INFO  : Validating listings for Path1 "/tmp/033521ro/changes/path1/" vs Path2 "TestOpenDrive:rclone-test-rumokot6peve/033521ro/changes/path2/"
2025/05/12 03:35:53 INFO  : Bisync successful
    bisync_test.go:560: TEST changes PASSED
=== RUN   TestBisyncLocalRemote/check_filename
2025/05/12 03:35:54 DEBUG : Creating backend with remote "/tmp/033521ro/check_filename/path1"
2025/05/12 03:35:54 INFO  : path2: Making directory
2025/05/12 03:35:54 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-rumokot6peve/033521ro/check_filename/path2"
2025/05/12 03:35:54 DEBUG : Starting OpenDrive session with ID: 2c5c843d59f91d8a099f512358881d0e81175002d725c619fb3940ca040c5d76
2025/05/12 03:35:55 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_filename/initial"
2025/05/12 03:35:55 DEBUG : Creating backend with remote "/tmp/033521ro/initdir/test_check_filename-tufacij7"
2025/05/12 03:35:55 DEBUG : .chk_file: Need to transfer - File not found at Destination
2025/05/12 03:35:55 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:55 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:55 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:55 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:55 DEBUG : subdir: Making directory with metadata
2025/05/12 03:35:55 INFO  : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:35:55 DEBUG : Added delayed dir = "subdir", newDst=subdir
2025/05/12 03:35:55 DEBUG : subdir/.chk_file: Need to transfer - File not found at Destination
2025/05/12 03:35:55 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:55 DEBUG : Local file system at /tmp/033521ro/initdir/test_check_filename-tufacij7: Waiting for checks to finish
2025/05/12 03:35:55 DEBUG : Local file system at /tmp/033521ro/initdir/test_check_filename-tufacij7: Waiting for transfers to finish
2025/05/12 03:35:55 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:55 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt
2025/05/12 03:35:55 INFO  : file1.txt: Copied (new)
2025/05/12 03:35:55 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:55 DEBUG : file3.txt.5028a97.partial: renamed to: file3.txt
2025/05/12 03:35:55 INFO  : file3.txt: Copied (new)
2025/05/12 03:35:55 DEBUG : .chk_file: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:35:55 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:55 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:55 DEBUG : .chk_file.cf9a93ac.partial: renamed to: .chk_file
2025/05/12 03:35:55 INFO  : .chk_file: Copied (new)
2025/05/12 03:35:55 DEBUG : file4.txt.5028a97.partial: renamed to: file4.txt
2025/05/12 03:35:55 INFO  : file4.txt: Copied (new)
2025/05/12 03:35:55 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt
2025/05/12 03:35:55 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:55 INFO  : file2.txt: Copied (new)
2025/05/12 03:35:55 DEBUG : subdir/file20.txt.5028a97.partial: renamed to: subdir/file20.txt
2025/05/12 03:35:55 INFO  : subdir/file20.txt: Copied (new)
2025/05/12 03:35:55 DEBUG : subdir/.chk_file: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:35:55 DEBUG : subdir/.chk_file.cf9a93ac.partial: renamed to: subdir/.chk_file
2025/05/12 03:35:55 INFO  : subdir/.chk_file: Copied (new)
2025/05/12 03:35:55 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:35:55 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_filename/modfiles"
2025/05/12 03:35:55 DEBUG : Creating backend with remote "/tmp/033521ro/datadir/test_check_filename-cijuyow8"
2025/05/12 03:35:55 DEBUG : hold.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:55 DEBUG : Local file system at /tmp/033521ro/datadir/test_check_filename-cijuyow8: Waiting for checks to finish
2025/05/12 03:35:55 DEBUG : Local file system at /tmp/033521ro/datadir/test_check_filename-cijuyow8: Waiting for transfers to finish
2025/05/12 03:35:55 DEBUG : hold.txt: md5 = 628c2241b6ba4e313ef08bdfcf1cd964 OK
2025/05/12 03:35:55 DEBUG : hold.txt.627e309f.partial: renamed to: hold.txt
2025/05/12 03:35:55 INFO  : hold.txt: Copied (new)
2025/05/12 03:35:55 ERROR : : error listing: directory not found
2025/05/12 03:35:55 ERROR : : error listing: directory not found
2025/05/12 03:35:55 NOTICE: checking initFs Local file system at /tmp/033521ro/initdir/test_check_filename-tufacij7
2025/05/12 03:35:55 DEBUG : .chk_file: Need to transfer - File not found at Destination
2025/05/12 03:35:55 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:55 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:55 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:55 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:55 DEBUG : subdir: Making directory with metadata
2025/05/12 03:35:55 INFO  : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:35:55 DEBUG : Added delayed dir = "subdir", newDst=subdir
2025/05/12 03:35:55 DEBUG : subdir/.chk_file: Need to transfer - File not found at Destination
2025/05/12 03:35:55 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:55 DEBUG : Local file system at /tmp/033521ro/check_filename/path1: Waiting for checks to finish
2025/05/12 03:35:55 DEBUG : Local file system at /tmp/033521ro/check_filename/path1: Waiting for transfers to finish
2025/05/12 03:35:55 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:55 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:55 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt
2025/05/12 03:35:55 INFO  : file1.txt: Copied (new)
2025/05/12 03:35:55 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt
2025/05/12 03:35:55 INFO  : file2.txt: Copied (new)
2025/05/12 03:35:55 DEBUG : .chk_file: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:35:55 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:55 DEBUG : .chk_file.cf9a93ac.partial: renamed to: .chk_file
2025/05/12 03:35:55 INFO  : .chk_file: Copied (new)
2025/05/12 03:35:55 DEBUG : file3.txt.5028a97.partial: renamed to: file3.txt
2025/05/12 03:35:55 INFO  : file3.txt: Copied (new)
2025/05/12 03:35:55 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:55 DEBUG : file4.txt.5028a97.partial: renamed to: file4.txt
2025/05/12 03:35:55 INFO  : file4.txt: Copied (new)
2025/05/12 03:35:55 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:55 DEBUG : subdir/file20.txt.5028a97.partial: renamed to: subdir/file20.txt
2025/05/12 03:35:55 INFO  : subdir/file20.txt: Copied (new)
2025/05/12 03:35:55 DEBUG : subdir/.chk_file: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:35:55 DEBUG : subdir/.chk_file.cf9a93ac.partial: renamed to: subdir/.chk_file
2025/05/12 03:35:55 INFO  : subdir/.chk_file: Copied (new)
2025/05/12 03:35:55 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:35:55 NOTICE: checking Path1 Local file system at /tmp/033521ro/check_filename/path1
2025/05/12 03:35:56 DEBUG : .chk_file: Need to transfer - File not found at Destination
2025/05/12 03:35:56 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:56 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:56 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:56 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:56 INFO  : subdir: Making directory
2025/05/12 03:35:57 DEBUG : subdir/.chk_file: Need to transfer - File not found at Destination
2025/05/12 03:35:57 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:35:57 DEBUG : OpenDrive root 'rclone-test-rumokot6peve/033521ro/check_filename/path2': Waiting for checks to finish
2025/05/12 03:35:57 DEBUG : OpenDrive root 'rclone-test-rumokot6peve/033521ro/check_filename/path2': Waiting for transfers to finish
2025/05/12 03:35:58 DEBUG : .chk_file: Uploading chunk 0, size=109, remain=0
2025/05/12 03:35:59 DEBUG : .chk_file: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:35:59 INFO  : .chk_file: Copied (new)
2025/05/12 03:35:59 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:59 INFO  : file1.txt: Copied (new)
2025/05/12 03:35:59 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:59 INFO  : file3.txt: Copied (new)
2025/05/12 03:35:59 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:35:59 INFO  : file2.txt: Copied (new)
2025/05/12 03:36:00 DEBUG : subdir/.chk_file: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:00 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:00 INFO  : file4.txt: Copied (new)
2025/05/12 03:36:00 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:00 INFO  : subdir/file20.txt: Copied (new)
2025/05/12 03:36:01 DEBUG : subdir/.chk_file: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:01 INFO  : subdir/.chk_file: Copied (new)
2025/05/12 03:36:01 NOTICE: checking path2 OpenDrive root 'rclone-test-rumokot6peve/033521ro/check_filename/path2'
2025/05/12 03:36:01 NOTICE: (01)  : test check-filename
2025/05/12 03:36:01 NOTICE: (02)  : test initial bisync
2025/05/12 03:36:01 NOTICE: (03)  : bisync resync
2025/05/12 03:36:03 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:36:03 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:36:03 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/05/12 03:36:03 INFO  : Synching Path1 "/tmp/033521ro/check_filename/path1/" with Path2 "TestOpenDrive:rclone-test-rumokot6peve/033521ro/check_filename/path2/"
2025/05/12 03:36:03 INFO  : Copying Path2 files to Path1
2025/05/12 03:36:03 INFO  : - Path2    Resync is copying files to         - Path1
2025/05/12 03:36:03 INFO  : - Path1    Resync is copying files to         - Path2
2025/05/12 03:36:04 INFO  : Resync updating listings
2025/05/12 03:36:04 INFO  : Validating listings for Path1 "/tmp/033521ro/check_filename/path1/" vs Path2 "TestOpenDrive:rclone-test-rumokot6peve/033521ro/check_filename/path2/"
2025/05/12 03:36:04 INFO  : Bisync successful
2025/05/12 03:36:04 NOTICE: (04)  : test 1. see that check-access passes with the initial setup
2025/05/12 03:36:04 NOTICE: (05)  : bisync check-access check-filename=.chk_file
2025/05/12 03:36:06 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:36:06 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:36:06 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/05/12 03:36:06 INFO  : Synching Path1 "/tmp/033521ro/check_filename/path1/" with Path2 "TestOpenDrive:rclone-test-rumokot6peve/033521ro/check_filename/path2/"
2025/05/12 03:36:06 INFO  : Building Path1 and Path2 listings
2025/05/12 03:36:06 INFO  : Path1 checking for diffs
2025/05/12 03:36:06 INFO  : Path2 checking for diffs
2025/05/12 03:36:06 INFO  : Checking access health
2025/05/12 03:36:06 INFO  : Found 2 matching ".chk_file" files on both paths
2025/05/12 03:36:06 INFO  : No changes found
2025/05/12 03:36:06 INFO  : Updating listings
2025/05/12 03:36:06 INFO  : Validating listings for Path1 "/tmp/033521ro/check_filename/path1/" vs Path2 "TestOpenDrive:rclone-test-rumokot6peve/033521ro/check_filename/path2/"
2025/05/12 03:36:06 INFO  : Bisync successful
2025/05/12 03:36:06 NOTICE: (06)  : copy-listings initial-pass
2025/05/12 03:36:06 NOTICE: (07)  : test 2. delete the remote subdir .chk_file, run sync. should fail critical.
2025/05/12 03:36:06 NOTICE: (08)  : delete-file TestOpenDrive:rclone-test-rumokot6peve/033521ro/check_filename/path2/subdir/.chk_file
2025/05/12 03:36:08 INFO  : .chk_file: Deleted
2025/05/12 03:36:08 NOTICE: (09)  : bisync check-access check-filename=.chk_file
2025/05/12 03:36:09 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:36:09 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:36:09 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/05/12 03:36:09 INFO  : Synching Path1 "/tmp/033521ro/check_filename/path1/" with Path2 "TestOpenDrive:rclone-test-rumokot6peve/033521ro/check_filename/path2/"
2025/05/12 03:36:09 INFO  : Building Path1 and Path2 listings
2025/05/12 03:36:10 INFO  : Path1 checking for diffs
2025/05/12 03:36:10 INFO  : Path2 checking for diffs
2025/05/12 03:36:10 INFO  : - Path2    File was deleted          - subdir/.chk_file
2025/05/12 03:36:10 INFO  : Path2:    1 changes:    0 new,    0 modified,    1 deleted
2025/05/12 03:36:10 INFO  : Checking access health
2025/05/12 03:36:10 ERROR : Access test failed: Path1 count 2, Path2 count 1 - .chk_file
2025/05/12 03:36:10 ERROR : -          Access test failed: Path1 file not found in Path2 - subdir/.chk_file
2025/05/12 03:36:10 ERROR : Bisync critical error: check file check failed
2025/05/12 03:36:10 ERROR : Bisync aborted. Must run --resync to recover.
2025/05/12 03:36:10 NOTICE: Bisync error: bisync aborted
2025/05/12 03:36:10 NOTICE: (10)  : move-listings path2-missing
2025/05/12 03:36:10 NOTICE: (11)  : test 3. put the remote subdir .chk_file back, run resync.
2025/05/12 03:36:10 NOTICE: (12)  : copy-file /tmp/033521ro/check_filename/path1/subdir/.chk_file TestOpenDrive:rclone-test-rumokot6peve/033521ro/check_filename/path2/subdir/
2025/05/12 03:36:13 INFO  : .chk_file: Copied (new)
2025/05/12 03:36:13 NOTICE: (13)  : bisync check-access resync check-filename=.chk_file
2025/05/12 03:36:15 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:36:15 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:36: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/05/12 03:36:15 INFO  : Synching Path1 "/tmp/033521ro/check_filename/path1/" with Path2 "TestOpenDrive:rclone-test-rumokot6peve/033521ro/check_filename/path2/"
2025/05/12 03:36:15 INFO  : Copying Path2 files to Path1
2025/05/12 03:36:15 INFO  : Checking access health
2025/05/12 03:36:15 INFO  : Found 2 matching ".chk_file" files on both paths
2025/05/12 03:36:15 INFO  : - Path2    Resync is copying files to         - Path1
2025/05/12 03:36:16 INFO  : - Path1    Resync is copying files to         - Path2
2025/05/12 03:36:16 INFO  : Resync updating listings
2025/05/12 03:36:16 INFO  : Validating listings for Path1 "/tmp/033521ro/check_filename/path1/" vs Path2 "TestOpenDrive:rclone-test-rumokot6peve/033521ro/check_filename/path2/"
2025/05/12 03:36:16 INFO  : Bisync successful
2025/05/12 03:36:16 NOTICE: (14)  : test 4. run sync with check-access. should pass.
2025/05/12 03:36:16 NOTICE: (15)  : bisync check-access check-filename=.chk_file
2025/05/12 03:36:18 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:36:18 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:36:18 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": true,
	"DownloadHash": false
}
2025/05/12 03:36:18 INFO  : Synching Path1 "/tmp/033521ro/check_filename/path1/" with Path2 "TestOpenDrive:rclone-test-rumokot6peve/033521ro/check_filename/path2/"
2025/05/12 03:36:18 INFO  : Building Path1 and Path2 listings
2025/05/12 03:36:18 INFO  : Path1 checking for diffs
2025/05/12 03:36:18 INFO  : Path2 checking for diffs
2025/05/12 03:36:18 INFO  : Checking access health
2025/05/12 03:36:18 INFO  : Found 2 matching ".chk_file" files on both paths
2025/05/12 03:36:18 INFO  : No changes found
2025/05/12 03:36:18 INFO  : Updating listings
2025/05/12 03:36:18 INFO  : Validating listings for Path1 "/tmp/033521ro/check_filename/path1/" vs Path2 "TestOpenDrive:rclone-test-rumokot6peve/033521ro/check_filename/path2/"
2025/05/12 03:36:18 INFO  : Bisync successful
    bisync_test.go:560: TEST check_filename PASSED
2025/05/12 03:36:19 DEBUG : OpenDrive root 'rclone-test-rumokot6peve': Purge remote
--- PASS: TestBisyncLocalRemote (58.71s)
    --- PASS: TestBisyncLocalRemote/changes (32.22s)
    --- PASS: TestBisyncLocalRemote/check_filename (25.17s)
=== RUN   TestBisyncRemoteRemote
2025/05/12 03:36:19 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-qonaxav2tuco"
2025/05/12 03:36:20 DEBUG : Starting OpenDrive session with ID: f0afddf373d62b1364621d39569d2ecde1250f86b575575367ae0cf2207ef902
2025/05/12 03:36:20 NOTICE: remote: TestOpenDrive:rclone-test-qonaxav2tuco
=== RUN   TestBisyncRemoteRemote/check_access_filters
2025/05/12 03:36:20 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa"
2025/05/12 03:36:20 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/05/12 03:36:21 DEBUG : Starting OpenDrive session with ID: 4ff1e7cb688f2b569ffe93331ed2a82fbac31b6754a2e7f31f402b797763961d
2025/05/12 03:36:21 INFO  : path1: Making directory
2025/05/12 03:36:22 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1"
2025/05/12 03:36:22 DEBUG : Starting OpenDrive session with ID: c82336072a33e99e80cd70f8b808bfaf302b7c4c9a5a1e8b165047712366121c
2025/05/12 03:36:23 INFO  : path2: Making directory
2025/05/12 03:36:24 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2"
2025/05/12 03:36:24 DEBUG : Starting OpenDrive session with ID: 221329adde914c704fdd0eb129b612d2582651bb2705a8c8c69b4392a512c40b
2025/05/12 03:36:25 DEBUG : Creating backend with remote "/tmp/033620fa/initdir/test_check_access_filters-lewigiv0"
2025/05/12 03:36:25 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : subdir: Making directory with metadata
2025/05/12 03:36:25 INFO  : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:36:25 DEBUG : Added delayed dir = "subdir", newDst=subdir
2025/05/12 03:36:25 DEBUG : subdir-not: Making directory with metadata
2025/05/12 03:36:25 INFO  : subdir-not: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:36:25 DEBUG : Added delayed dir = "subdir-not", newDst=subdir-not
2025/05/12 03:36:25 DEBUG : subdirX: Making directory with metadata
2025/05/12 03:36:25 INFO  : subdirX: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:36:25 DEBUG : Added delayed dir = "subdirX", newDst=subdirX
2025/05/12 03:36:25 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : subdirX/subdirX1: Making directory with metadata
2025/05/12 03:36:25 INFO  : subdirX/subdirX1: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:36:25 DEBUG : Added delayed dir = "subdirX/subdirX1", newDst=subdirX/subdirX1
2025/05/12 03:36:25 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:25 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt
2025/05/12 03:36:25 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : subdir/subdirA: Making directory with metadata
2025/05/12 03:36:25 INFO  : subdir/subdirA: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:36:25 DEBUG : Added delayed dir = "subdir/subdirA", newDst=subdir/subdirA
2025/05/12 03:36:25 DEBUG : subdir/subdirB: Making directory with metadata
2025/05/12 03:36:25 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : subdir-not/subdir-not2: Making directory with metadata
2025/05/12 03:36:25 INFO  : subdir/subdirB: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:36:25 DEBUG : Added delayed dir = "subdir/subdirB", newDst=subdir/subdirB
2025/05/12 03:36:25 INFO  : subdir-not/subdir-not2: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/05/12 03:36:25 DEBUG : Added delayed dir = "subdir-not/subdir-not2", newDst=subdir-not/subdir-not2
2025/05/12 03:36:25 INFO  : file1.txt: Copied (new)
2025/05/12 03:36:25 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:25 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:25 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt
2025/05/12 03:36:25 INFO  : file2.txt: Copied (new)
2025/05/12 03:36:25 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:25 DEBUG : Local file system at /tmp/033620fa/initdir/test_check_access_filters-lewigiv0: Waiting for checks to finish
2025/05/12 03:36:25 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST
2025/05/12 03:36:25 DEBUG : Local file system at /tmp/033620fa/initdir/test_check_access_filters-lewigiv0: Waiting for transfers to finish
2025/05/12 03:36:25 INFO  : RCLONE_TEST: Copied (new)
2025/05/12 03:36:25 DEBUG : subdirX/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:25 DEBUG : subdirX/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:25 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:25 DEBUG : subdirX/file20.txt.5028a97.partial: renamed to: subdirX/file20.txt
2025/05/12 03:36:25 INFO  : subdirX/file20.txt: Copied (new)
2025/05/12 03:36:25 DEBUG : subdirX/RCLONE_TEST.cf9a93ac.partial: renamed to: subdirX/RCLONE_TEST
2025/05/12 03:36:25 INFO  : subdirX/RCLONE_TEST: Copied (new)
2025/05/12 03:36:25 DEBUG : file3.txt.5028a97.partial: renamed to: file3.txt
2025/05/12 03:36:25 INFO  : file3.txt: Copied (new)
2025/05/12 03:36:25 DEBUG : subdirX/subdirX1/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:25 DEBUG : file4.txt.5028a97.partial: renamed to: file4.txt
2025/05/12 03:36:25 INFO  : file4.txt: Copied (new)
2025/05/12 03:36:25 DEBUG : subdirX/subdirX1/file30.txt.5028a97.partial: renamed to: subdirX/subdirX1/file30.txt
2025/05/12 03:36:25 INFO  : subdirX/subdirX1/file30.txt: Copied (new)
2025/05/12 03:36:25 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:25 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:25 DEBUG : subdir/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir/RCLONE_TEST
2025/05/12 03:36:25 INFO  : subdir/RCLONE_TEST: Copied (new)
2025/05/12 03:36:25 DEBUG : subdir/file20.txt.5028a97.partial: renamed to: subdir/file20.txt
2025/05/12 03:36:25 INFO  : subdir/file20.txt: Copied (new)
2025/05/12 03:36:25 DEBUG : subdirX/subdirX1/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:25 DEBUG : subdir-not/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:25 DEBUG : subdir-not/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir-not/RCLONE_TEST
2025/05/12 03:36:25 DEBUG : subdirX/subdirX1/RCLONE_TEST.cf9a93ac.partial: renamed to: subdirX/subdirX1/RCLONE_TEST
2025/05/12 03:36:25 INFO  : subdir-not/RCLONE_TEST: Copied (new)
2025/05/12 03:36:25 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:25 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir-not/subdir-not2/RCLONE_TEST
2025/05/12 03:36:25 INFO  : subdir-not/subdir-not2/RCLONE_TEST: Copied (new)
2025/05/12 03:36:25 DEBUG : subdir-not/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:25 DEBUG : subdir-not/file20.txt.5028a97.partial: renamed to: subdir-not/file20.txt
2025/05/12 03:36:25 INFO  : subdir-not/file20.txt: Copied (new)
2025/05/12 03:36:25 DEBUG : subdir-not/subdir-not2/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:25 DEBUG : subdir-not/subdir-not2/file30.txt.5028a97.partial: renamed to: subdir-not/subdir-not2/file30.txt
2025/05/12 03:36:25 INFO  : subdir-not/subdir-not2/file30.txt: Copied (new)
2025/05/12 03:36:25 DEBUG : subdir/subdirB/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:25 DEBUG : subdir/subdirB/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir/subdirB/RCLONE_TEST
2025/05/12 03:36:25 INFO  : subdir/subdirB/RCLONE_TEST: Copied (new)
2025/05/12 03:36:25 DEBUG : subdir/subdirB/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:25 DEBUG : subdir/subdirB/file30.txt.5028a97.partial: renamed to: subdir/subdirB/file30.txt
2025/05/12 03:36:25 INFO  : subdir/subdirB/file30.txt: Copied (new)
2025/05/12 03:36:25 DEBUG : subdir/subdirA/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:25 DEBUG : subdir/subdirA/file30.txt.5028a97.partial: renamed to: subdir/subdirA/file30.txt
2025/05/12 03:36:25 INFO  : subdir/subdirA/file30.txt: Copied (new)
2025/05/12 03:36:25 DEBUG : subdir/subdirA/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:25 DEBUG : subdir/subdirA/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir/subdirA/RCLONE_TEST
2025/05/12 03:36:25 INFO  : subdir/subdirA/RCLONE_TEST: Copied (new)
2025/05/12 03:36:25 INFO  : subdirX/subdirX1/RCLONE_TEST: Copied (new)
2025/05/12 03:36:25 INFO  : subdirX/subdirX1: Set directory modification time (using SetModTime)
2025/05/12 03:36:25 INFO  : subdir/subdirA: Set directory modification time (using SetModTime)
2025/05/12 03:36:25 INFO  : subdir/subdirB: Set directory modification time (using SetModTime)
2025/05/12 03:36:25 INFO  : subdir-not/subdir-not2: Set directory modification time (using SetModTime)
2025/05/12 03:36:25 INFO  : subdirX: Set directory modification time (using SetModTime)
2025/05/12 03:36:25 INFO  : subdir: Set directory modification time (using SetModTime)
2025/05/12 03:36:25 INFO  : subdir-not: Set directory modification time (using SetModTime)
2025/05/12 03:36:25 DEBUG : Creating backend with remote "/tmp/033620fa/datadir/test_check_access_filters-budunix4"
2025/05/12 03:36:25 DEBUG : exclude-other-filtersfile.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : include-other-filtersfile.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:25 DEBUG : Local file system at /tmp/033620fa/datadir/test_check_access_filters-budunix4: Waiting for checks to finish
2025/05/12 03:36:25 DEBUG : Local file system at /tmp/033620fa/datadir/test_check_access_filters-budunix4: Waiting for transfers to finish
2025/05/12 03:36:25 DEBUG : include-other-filtersfile.txt: md5 = 2ec13b2813141ed088e5978ef5a47b0e OK
2025/05/12 03:36:25 DEBUG : include-other-filtersfile.txt.5fb1cd78.partial: renamed to: include-other-filtersfile.txt
2025/05/12 03:36:25 INFO  : include-other-filtersfile.txt: Copied (new)
2025/05/12 03:36:25 DEBUG : exclude-other-filtersfile.txt: md5 = 5fcc6205d7df1c2e9ed3a15a1356b345 OK
2025/05/12 03:36:25 DEBUG : exclude-other-filtersfile.txt.9180e6d6.partial: renamed to: exclude-other-filtersfile.txt
2025/05/12 03:36:25 INFO  : exclude-other-filtersfile.txt: Copied (new)
2025/05/12 03:36:26 ERROR : : error listing: directory not found
2025/05/12 03:36:26 ERROR : : error listing: directory not found
2025/05/12 03:36:26 NOTICE: checking initFs Local file system at /tmp/033620fa/initdir/test_check_access_filters-lewigiv0
2025/05/12 03:36:26 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:26 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:26 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:26 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:26 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:26 INFO  : subdir: Making directory
2025/05/12 03:36:27 INFO  : subdir-not: Making directory
2025/05/12 03:36:27 INFO  : subdirX: Making directory
2025/05/12 03:36:27 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:27 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:27 INFO  : subdirX/subdirX1: Making directory
2025/05/12 03:36:27 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:27 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:27 INFO  : subdir/subdirA: Making directory
2025/05/12 03:36:27 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:27 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:27 INFO  : subdir-not/subdir-not2: Making directory
2025/05/12 03:36:28 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:28 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:30 INFO  : subdir/subdirB: Making directory
2025/05/12 03:36:30 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:30 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:31 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:31 INFO  : file1.txt: Copied (new)
2025/05/12 03:36:31 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:31 INFO  : file3.txt: Copied (new)
2025/05/12 03:36:31 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:31 INFO  : file4.txt: Copied (new)
2025/05/12 03:36:31 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:31 INFO  : file2.txt: Copied (new)
2025/05/12 03:36:31 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:31 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:31 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:31 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:31 DEBUG : OpenDrive root 'rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1': Waiting for checks to finish
2025/05/12 03:36:31 DEBUG : OpenDrive root 'rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1': Waiting for transfers to finish
2025/05/12 03:36:32 DEBUG : RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:32 DEBUG : subdirX/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:32 DEBUG : subdirX/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:32 INFO  : subdirX/file20.txt: Copied (new)
2025/05/12 03:36:33 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:33 INFO  : subdir/file20.txt: Copied (new)
2025/05/12 03:36:33 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:33 INFO  : RCLONE_TEST: Copied (new)
2025/05/12 03:36:33 DEBUG : subdirX/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:33 INFO  : subdirX/RCLONE_TEST: Copied (new)
2025/05/12 03:36:33 DEBUG : subdir/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:34 DEBUG : subdir-not/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:34 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:34 INFO  : subdir/RCLONE_TEST: Copied (new)
2025/05/12 03:36:34 DEBUG : subdir-not/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:34 INFO  : subdir-not/file20.txt: Copied (new)
2025/05/12 03:36:35 DEBUG : subdir-not/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:35 INFO  : subdir-not/RCLONE_TEST: Copied (new)
2025/05/12 03:36:35 DEBUG : subdirX/subdirX1/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:35 DEBUG : subdirX/subdirX1/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:35 INFO  : subdirX/subdirX1/file30.txt: Copied (new)
2025/05/12 03:36:35 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:35 DEBUG : subdirX/subdirX1/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:35 INFO  : subdirX/subdirX1/RCLONE_TEST: Copied (new)
2025/05/12 03:36:36 DEBUG : subdir-not/subdir-not2/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:36 INFO  : subdir-not/subdir-not2/file30.txt: Copied (new)
2025/05/12 03:36:36 DEBUG : subdir/subdirA/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:36 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:36 INFO  : subdir-not/subdir-not2/RCLONE_TEST: Copied (new)
2025/05/12 03:36:37 DEBUG : subdir/subdirA/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:37 INFO  : subdir/subdirA/file30.txt: Copied (new)
2025/05/12 03:36:37 DEBUG : subdir/subdirB/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:37 DEBUG : subdir/subdirA/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:37 INFO  : subdir/subdirA/RCLONE_TEST: Copied (new)
2025/05/12 03:36:37 DEBUG : subdir/subdirB/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:37 INFO  : subdir/subdirB/file30.txt: Copied (new)
2025/05/12 03:36:38 DEBUG : subdir/subdirB/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:38 INFO  : subdir/subdirB/RCLONE_TEST: Copied (new)
    bisync_test.go:1943: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:1943
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:458
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:358
        	Error:      	Received unexpected error:
        	            	failed to get folder list: Directory doesn't exist (Error 404)
        	Test:       	TestBisyncRemoteRemote/check_access_filters
        	Messages:   	setting up path1
2025/05/12 03:36:38 NOTICE: checking Path1 OpenDrive root 'rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1'
2025/05/12 03:36:39 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:39 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:39 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:39 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:39 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:39 INFO  : subdir: Making directory
2025/05/12 03:36:40 INFO  : subdir-not: Making directory
2025/05/12 03:36:40 INFO  : subdirX: Making directory
2025/05/12 03:36:40 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:40 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:40 INFO  : subdirX/subdirX1: Making directory
2025/05/12 03:36:40 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:40 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:40 INFO  : subdir/subdirA: Making directory
2025/05/12 03:36:40 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:40 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:40 INFO  : subdir-not/subdir-not2: Making directory
2025/05/12 03:36:41 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:41 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:42 INFO  : subdir/subdirB: Making directory
2025/05/12 03:36:42 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:42 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:42 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:42 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:42 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination
2025/05/12 03:36:42 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination
2025/05/12 03:36:42 DEBUG : OpenDrive root 'rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2': Waiting for checks to finish
2025/05/12 03:36:42 DEBUG : OpenDrive root 'rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2': Waiting for transfers to finish
2025/05/12 03:36:42 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:42 INFO  : file3.txt: Copied (new)
2025/05/12 03:36:44 DEBUG : RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:44 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:44 INFO  : file1.txt: Copied (new)
2025/05/12 03:36:44 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:44 INFO  : file4.txt: Copied (new)
2025/05/12 03:36:45 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:45 INFO  : RCLONE_TEST: Copied (new)
2025/05/12 03:36:45 DEBUG : subdirX/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:45 DEBUG : subdirX/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:45 INFO  : subdirX/file20.txt: Copied (new)
2025/05/12 03:36:46 DEBUG : subdirX/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:46 INFO  : subdirX/RCLONE_TEST: Copied (new)
2025/05/12 03:36:46 DEBUG : subdir/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:46 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:46 INFO  : file2.txt: Copied (new)
2025/05/12 03:36:46 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:46 INFO  : subdir/file20.txt: Copied (new)
2025/05/12 03:36:47 DEBUG : subdir-not/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:47 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:47 INFO  : subdir/RCLONE_TEST: Copied (new)
2025/05/12 03:36:47 DEBUG : subdir-not/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:47 INFO  : subdir-not/file20.txt: Copied (new)
2025/05/12 03:36:48 DEBUG : subdirX/subdirX1/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:48 DEBUG : subdir-not/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:48 INFO  : subdir-not/RCLONE_TEST: Copied (new)
2025/05/12 03:36:48 DEBUG : subdirX/subdirX1/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:48 INFO  : subdirX/subdirX1/file30.txt: Copied (new)
2025/05/12 03:36:49 DEBUG : subdirX/subdirX1/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:49 INFO  : subdirX/subdirX1/RCLONE_TEST: Copied (new)
2025/05/12 03:36:49 DEBUG : subdir/subdirA/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:49 DEBUG : subdir/subdirA/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:49 INFO  : subdir/subdirA/file30.txt: Copied (new)
2025/05/12 03:36:50 DEBUG : subdir/subdirB/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:50 DEBUG : subdir/subdirA/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:50 INFO  : subdir/subdirA/RCLONE_TEST: Copied (new)
2025/05/12 03:36:50 DEBUG : subdir/subdirB/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:50 INFO  : subdir/subdirB/file30.txt: Copied (new)
2025/05/12 03:36:50 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Uploading chunk 0, size=109, remain=0
2025/05/12 03:36:50 DEBUG : subdir/subdirB/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:50 INFO  : subdir/subdirB/RCLONE_TEST: Copied (new)
2025/05/12 03:36:51 DEBUG : subdir-not/subdir-not2/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:36:51 INFO  : subdir-not/subdir-not2/file30.txt: Copied (new)
2025/05/12 03:36:51 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:36:51 INFO  : subdir-not/subdir-not2/RCLONE_TEST: Copied (new)
2025/05/12 03:36:51 NOTICE: checking path2 OpenDrive root 'rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2'
2025/05/12 03:36:52 NOTICE: (01)  : test check-access-filters
2025/05/12 03:36:52 NOTICE: (02)  : test EXCLUDE - OTHER TESTS
2025/05/12 03:36:52 NOTICE: (03)  : copy-file /tmp/033620fa/datadir/test_check_access_filters-budunix4/exclude-other-filtersfile.txt /tmp/033620fa/workdir/
2025/05/12 03:36:52 INFO  : exclude-other-filtersfile.txt: Copied (new)
2025/05/12 03:36:52 NOTICE: (04)  : test resync to get the filters file md5 built.
2025/05/12 03:36:52 NOTICE: (05)  : bisync resync filters-file=/tmp/033620fa/workdir/exclude-other-filtersfile.txt
2025/05/12 03:36:56 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:36:56 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/05/12 03:36:56 INFO  : Synching Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/" with Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/"
2025/05/12 03:36:56 INFO  : Using filters file /tmp/033620fa/workdir/exclude-other-filtersfile.txt
2025/05/12 03:36:56 INFO  : Storing filters file hash to /tmp/033620fa/workdir/exclude-other-filtersfile.txt.md5
2025/05/12 03:36:56 INFO  : Copying Path2 files to Path1
2025/05/12 03:36:56 INFO  : - Path2    Resync is copying files to         - Path1
2025/05/12 03:36:56 INFO  : - Path1    Resync is copying files to         - Path2
2025/05/12 03:36:57 INFO  : Resync updating listings
2025/05/12 03:36:57 INFO  : Validating listings for Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/" vs Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/"
2025/05/12 03:36:57 INFO  : Bisync successful
2025/05/12 03:36:57 NOTICE: (06)  : test EXCLUDE - test filters for check access
2025/05/12 03:36:57 NOTICE: (07)  : bisync check-access filters-file=/tmp/033620fa/workdir/exclude-other-filtersfile.txt
2025/05/12 03:37:01 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:37:01 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/05/12 03:37:01 INFO  : Synching Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/" with Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/"
2025/05/12 03:37:01 INFO  : Using filters file /tmp/033620fa/workdir/exclude-other-filtersfile.txt
2025/05/12 03:37:01 INFO  : Building Path1 and Path2 listings
2025/05/12 03:37:01 INFO  : Path1 checking for diffs
2025/05/12 03:37:01 INFO  : Path2 checking for diffs
2025/05/12 03:37:01 INFO  : Checking access health
2025/05/12 03:37:01 INFO  : Found 3 matching "RCLONE_TEST" files on both paths
2025/05/12 03:37:01 INFO  : No changes found
2025/05/12 03:37:01 INFO  : Updating listings
2025/05/12 03:37:01 INFO  : Validating listings for Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/" vs Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/"
2025/05/12 03:37:01 INFO  : Bisync successful
2025/05/12 03:37:01 NOTICE: (08)  : copy-listings exclude-initial
2025/05/12 03:37:01 NOTICE: (09)  : test EXCLUDE - delete RCLONE_TEST files in excluded directories
2025/05/12 03:37:01 NOTICE: (10)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/subdir/subdirA/RCLONE_TEST
2025/05/12 03:37:03 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:37:03 NOTICE: (11)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/subdir-not/RCLONE_TEST
2025/05/12 03:37:05 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:37:05 NOTICE: (12)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/subdir-not/subdir-not2/RCLONE_TEST
2025/05/12 03:37:07 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:37:07 NOTICE: (13)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/subdirX/RCLONE_TEST
2025/05/12 03:37:08 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:37:08 NOTICE: (14)  : test EXCLUDE - test should PASS
2025/05/12 03:37:08 NOTICE: (15)  : bisync check-access filters-file=/tmp/033620fa/workdir/exclude-other-filtersfile.txt
2025/05/12 03:37:12 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:37:12 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/05/12 03:37:12 INFO  : Synching Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/" with Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/"
2025/05/12 03:37:12 INFO  : Using filters file /tmp/033620fa/workdir/exclude-other-filtersfile.txt
2025/05/12 03:37:12 INFO  : Building Path1 and Path2 listings
2025/05/12 03:37:13 INFO  : Path1 checking for diffs
2025/05/12 03:37:13 INFO  : Path2 checking for diffs
2025/05/12 03:37:13 INFO  : Checking access health
2025/05/12 03:37:13 INFO  : Found 3 matching "RCLONE_TEST" files on both paths
2025/05/12 03:37:13 INFO  : No changes found
2025/05/12 03:37:13 INFO  : Updating listings
2025/05/12 03:37:13 INFO  : Validating listings for Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/" vs Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/"
2025/05/12 03:37:13 INFO  : Bisync successful
2025/05/12 03:37:13 NOTICE: (16)  : copy-listings exclude-pass-run
2025/05/12 03:37:13 NOTICE: (17)  : test EXCLUDE - delete RCLONE_TEST files in included directories
2025/05/12 03:37:13 NOTICE: (18)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/RCLONE_TEST
2025/05/12 03:37:14 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:37:14 NOTICE: (19)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/subdir/RCLONE_TEST
2025/05/12 03:37:16 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:37:16 NOTICE: (20)  : test EXCLUDE - test should ABORT
2025/05/12 03:37:16 NOTICE: (21)  : bisync check-access filters-file=/tmp/033620fa/workdir/exclude-other-filtersfile.txt
2025/05/12 03:37:20 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:37:20 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/05/12 03:37:20 INFO  : Synching Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/" with Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/"
2025/05/12 03:37:20 INFO  : Using filters file /tmp/033620fa/workdir/exclude-other-filtersfile.txt
2025/05/12 03:37:20 INFO  : Building Path1 and Path2 listings
2025/05/12 03:37:20 INFO  : Path1 checking for diffs
2025/05/12 03:37:20 INFO  : - Path1    File was deleted          - subdir/RCLONE_TEST
2025/05/12 03:37:20 INFO  : Path1:    1 changes:    0 new,    0 modified,    1 deleted
2025/05/12 03:37:20 INFO  : Path2 checking for diffs
2025/05/12 03:37:20 INFO  : - Path2    File was deleted          - RCLONE_TEST
2025/05/12 03:37:20 INFO  : Path2:    1 changes:    0 new,    0 modified,    1 deleted
2025/05/12 03:37:20 INFO  : Checking access health
2025/05/12 03:37:20 ERROR : -          Access test failed: Path1 file not found in Path2 - RCLONE_TEST
2025/05/12 03:37:20 ERROR : -          Access test failed: Path2 file not found in Path1 - subdir/RCLONE_TEST
2025/05/12 03:37:20 ERROR : Bisync critical error: check file check failed
2025/05/12 03:37:20 ERROR : Bisync aborted. Must run --resync to recover.
2025/05/12 03:37:20 NOTICE: Bisync error: bisync aborted
2025/05/12 03:37:20 NOTICE: (22)  : move-listings exclude-error-run
2025/05/12 03:37:20 NOTICE: (23)  : test INCLUDE - OTHER TESTS
2025/05/12 03:37:20 NOTICE: (24)  : test reset to the initial state
2025/05/12 03:37:20 NOTICE: (25)  : copy-dir /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access_filters/initial TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/
2025/05/12 03:37:23 INFO  : subdirX/RCLONE_TEST: Copied (new)
2025/05/12 03:37:24 INFO  : subdir/RCLONE_TEST: Copied (new)
2025/05/12 03:37:24 INFO  : subdir-not/RCLONE_TEST: Copied (new)
2025/05/12 03:37:24 NOTICE: (26)  : sync-dir TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/ TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/
2025/05/12 03:37:24 INFO  : RCLONE_TEST: Copied (server-side copy)
2025/05/12 03:37:25 INFO  : subdir-not/subdir-not2/RCLONE_TEST: Copied (server-side copy)
2025/05/12 03:37:25 INFO  : subdir/subdirA/RCLONE_TEST: Copied (server-side copy)
2025/05/12 03:37:25 NOTICE: (27)  : copy-file /tmp/033620fa/datadir/test_check_access_filters-budunix4/include-other-filtersfile.txt /tmp/033620fa/workdir/
2025/05/12 03:37:25 INFO  : include-other-filtersfile.txt: Copied (new)
2025/05/12 03:37:25 NOTICE: (28)  : bisync resync filters-file=/tmp/033620fa/workdir/include-other-filtersfile.txt
2025/05/12 03:37:29 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:37:29 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/05/12 03:37:29 INFO  : Synching Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/" with Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/"
2025/05/12 03:37:29 INFO  : Using filters file /tmp/033620fa/workdir/include-other-filtersfile.txt
2025/05/12 03:37:29 INFO  : Storing filters file hash to /tmp/033620fa/workdir/include-other-filtersfile.txt.md5
2025/05/12 03:37:29 INFO  : Copying Path2 files to Path1
2025/05/12 03:37:29 INFO  : - Path2    Resync is copying files to         - Path1
2025/05/12 03:37:29 INFO  : - Path1    Resync is copying files to         - Path2
2025/05/12 03:37:30 INFO  : Resync updating listings
2025/05/12 03:37:30 INFO  : Validating listings for Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/" vs Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/"
2025/05/12 03:37:30 INFO  : Bisync successful
2025/05/12 03:37:30 NOTICE: (29)  : test INCLUDE - test include/exclude filters for check access
2025/05/12 03:37:30 NOTICE: (30)  : bisync check-access filters-file=/tmp/033620fa/workdir/include-other-filtersfile.txt
2025/05/12 03:37:34 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:37:34 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/05/12 03:37:34 INFO  : Synching Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/" with Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/"
2025/05/12 03:37:34 INFO  : Using filters file /tmp/033620fa/workdir/include-other-filtersfile.txt
2025/05/12 03:37:34 INFO  : Building Path1 and Path2 listings
2025/05/12 03:37:35 INFO  : Path1 checking for diffs
2025/05/12 03:37:35 INFO  : Path2 checking for diffs
2025/05/12 03:37:35 INFO  : Checking access health
2025/05/12 03:37:35 INFO  : Found 5 matching "RCLONE_TEST" files on both paths
2025/05/12 03:37:35 INFO  : No changes found
2025/05/12 03:37:35 INFO  : Updating listings
2025/05/12 03:37:35 INFO  : Validating listings for Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/" vs Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/"
2025/05/12 03:37:35 INFO  : Bisync successful
2025/05/12 03:37:35 NOTICE: (31)  : copy-listings include-initial
2025/05/12 03:37:35 NOTICE: (32)  : test INCLUDE - delete RCLONE_TEST files in excluded directories
2025/05/12 03:37:35 NOTICE: (33)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/subdir/subdirA/RCLONE_TEST
2025/05/12 03:37:35 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:37:35 NOTICE: (34)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/subdir-not/RCLONE_TEST
2025/05/12 03:37:35 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:37:35 NOTICE: (35)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/subdir-not/subdir-not2/RCLONE_TEST
2025/05/12 03:37:36 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:37:36 NOTICE: (36)  : test INCLUDE - test should PASS
2025/05/12 03:37:36 NOTICE: (37)  : bisync check-access filters-file=/tmp/033620fa/workdir/include-other-filtersfile.txt
2025/05/12 03:37:40 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:37:40 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/05/12 03:37:40 INFO  : Synching Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/" with Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/"
2025/05/12 03:37:40 INFO  : Using filters file /tmp/033620fa/workdir/include-other-filtersfile.txt
2025/05/12 03:37:40 INFO  : Building Path1 and Path2 listings
2025/05/12 03:37:41 INFO  : Path1 checking for diffs
2025/05/12 03:37:41 INFO  : Path2 checking for diffs
2025/05/12 03:37:41 INFO  : Checking access health
2025/05/12 03:37:41 INFO  : Found 5 matching "RCLONE_TEST" files on both paths
2025/05/12 03:37:41 INFO  : No changes found
2025/05/12 03:37:41 INFO  : Updating listings
2025/05/12 03:37:41 INFO  : Validating listings for Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/" vs Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/"
2025/05/12 03:37:41 INFO  : Bisync successful
2025/05/12 03:37:41 NOTICE: (38)  : copy-listings include-pass-run
2025/05/12 03:37:41 NOTICE: (39)  : test INCLUDE - delete RCLONE_TEST files in included directories
2025/05/12 03:37:41 NOTICE: (40)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/RCLONE_TEST
2025/05/12 03:37:41 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:37:41 NOTICE: (41)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/subdir/RCLONE_TEST
2025/05/12 03:37:41 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:37:41 NOTICE: (42)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/subdirX/subdirX1/RCLONE_TEST
2025/05/12 03:37:43 INFO  : RCLONE_TEST: Deleted
2025/05/12 03:37:43 NOTICE: (43)  : test INCLUDE - test should ABORT
2025/05/12 03:37:43 NOTICE: (44)  : bisync check-access filters-file=/tmp/033620fa/workdir/include-other-filtersfile.txt
2025/05/12 03:37:47 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:37:47 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/05/12 03:37:47 INFO  : Synching Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path1/" with Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/check_access_filters/path2/"
2025/05/12 03:37:47 INFO  : Using filters file /tmp/033620fa/workdir/include-other-filtersfile.txt
2025/05/12 03:37:47 INFO  : Building Path1 and Path2 listings
2025/05/12 03:37:48 INFO  : Path1 checking for diffs
2025/05/12 03:37:48 INFO  : - Path1    File was deleted          - subdir/RCLONE_TEST
2025/05/12 03:37:48 INFO  : - Path1    File was deleted          - subdirX/subdirX1/RCLONE_TEST
2025/05/12 03:37:48 INFO  : Path1:    2 changes:    0 new,    0 modified,    2 deleted
2025/05/12 03:37:48 INFO  : Path2 checking for diffs
2025/05/12 03:37:48 INFO  : - Path2    File was deleted          - RCLONE_TEST
2025/05/12 03:37:48 INFO  : Path2:    1 changes:    0 new,    0 modified,    1 deleted
2025/05/12 03:37:48 INFO  : Checking access health
2025/05/12 03:37:48 ERROR : Access test failed: Path1 count 3, Path2 count 4 - RCLONE_TEST
2025/05/12 03:37:48 ERROR : -          Access test failed: Path1 file not found in Path2 - RCLONE_TEST
2025/05/12 03:37:48 ERROR : -          Access test failed: Path2 file not found in Path1 - subdir/RCLONE_TEST
2025/05/12 03:37:48 ERROR : -          Access test failed: Path2 file not found in Path1 - subdirX/subdirX1/RCLONE_TEST
2025/05/12 03:37:48 ERROR : Bisync critical error: check file check failed
2025/05/12 03:37:48 ERROR : Bisync aborted. Must run --resync to recover.
2025/05/12 03:37:48 NOTICE: Bisync error: bisync aborted
2025/05/12 03:37:48 NOTICE: (45)  : move-listings include-error-run
    bisync_test.go:560: TEST check_access_filters PASSED
=== RUN   TestBisyncRemoteRemote/max_delete_path1
2025/05/12 03:37:49 INFO  : path1: Making directory
2025/05/12 03:37:49 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path1"
2025/05/12 03:37:49 DEBUG : Starting OpenDrive session with ID: e74e9aa11d520f0987601f3daf35414852b3af5d636e37bd1395c267907a0d32
2025/05/12 03:37:50 INFO  : path2: Making directory
2025/05/12 03:37:50 DEBUG : Creating backend with remote "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path2"
2025/05/12 03:37:51 DEBUG : Starting OpenDrive session with ID: 03b54a479f0239473a1f518f45148718974924b1309cc4b13943d92408a1508b
2025/05/12 03:37:52 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_max_delete_path1/initial"
2025/05/12 03:37:52 DEBUG : Creating backend with remote "/tmp/033620fa/initdir/test_max_delete_path1-hesabeb2"
2025/05/12 03:37:52 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:52 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:52 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:52 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:52 DEBUG : file5.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:52 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:52 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:52 DEBUG : file8.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:52 DEBUG : file9.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:52 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:37:52 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt
2025/05/12 03:37:52 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:37:52 DEBUG : file4.txt.5028a97.partial: renamed to: file4.txt
2025/05/12 03:37:52 INFO  : file4.txt: Copied (new)
2025/05/12 03:37:52 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:37:52 DEBUG : file3.txt.5028a97.partial: renamed to: file3.txt
2025/05/12 03:37:52 INFO  : file3.txt: Copied (new)
2025/05/12 03:37:52 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:37:52 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt
2025/05/12 03:37:52 INFO  : file1.txt: Copied (new)
2025/05/12 03:37:52 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:37:52 DEBUG : file5.txt.5028a97.partial: renamed to: file5.txt
2025/05/12 03:37:52 INFO  : file5.txt: Copied (new)
2025/05/12 03:37:52 DEBUG : Local file system at /tmp/033620fa/initdir/test_max_delete_path1-hesabeb2: Waiting for checks to finish
2025/05/12 03:37:52 DEBUG : Local file system at /tmp/033620fa/initdir/test_max_delete_path1-hesabeb2: Waiting for transfers to finish
2025/05/12 03:37:52 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:37:52 DEBUG : file6.txt.5028a97.partial: renamed to: file6.txt
2025/05/12 03:37:52 INFO  : file6.txt: Copied (new)
2025/05/12 03:37:52 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:37:52 DEBUG : file8.txt.5028a97.partial: renamed to: file8.txt
2025/05/12 03:37:52 INFO  : file8.txt: Copied (new)
2025/05/12 03:37:52 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:37:52 DEBUG : file7.txt.5028a97.partial: renamed to: file7.txt
2025/05/12 03:37:52 INFO  : file7.txt: Copied (new)
2025/05/12 03:37:52 INFO  : file2.txt: Copied (new)
2025/05/12 03:37:52 DEBUG : file9.txt: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:37:52 DEBUG : file9.txt.cf9a93ac.partial: renamed to: file9.txt
2025/05/12 03:37:52 INFO  : file9.txt: Copied (new)
2025/05/12 03:37:52 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_max_delete_path1/modfiles"
2025/05/12 03:37:52 DEBUG : Creating backend with remote "/tmp/033620fa/datadir/test_max_delete_path1-lesinel5"
2025/05/12 03:37:52 DEBUG : hold.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:52 DEBUG : Local file system at /tmp/033620fa/datadir/test_max_delete_path1-lesinel5: Waiting for checks to finish
2025/05/12 03:37:52 DEBUG : Local file system at /tmp/033620fa/datadir/test_max_delete_path1-lesinel5: Waiting for transfers to finish
2025/05/12 03:37:52 DEBUG : hold.txt: md5 = 628c2241b6ba4e313ef08bdfcf1cd964 OK
2025/05/12 03:37:52 DEBUG : hold.txt.627e309f.partial: renamed to: hold.txt
2025/05/12 03:37:52 INFO  : hold.txt: Copied (new)
2025/05/12 03:37:52 ERROR : : error listing: directory not found
2025/05/12 03:37:52 ERROR : : error listing: directory not found
2025/05/12 03:37:52 NOTICE: checking initFs Local file system at /tmp/033620fa/initdir/test_max_delete_path1-hesabeb2
2025/05/12 03:37:53 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:53 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:53 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:53 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:53 DEBUG : file5.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:53 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:53 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:53 DEBUG : file8.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:53 DEBUG : file9.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:53 DEBUG : OpenDrive root 'rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path1': Waiting for checks to finish
2025/05/12 03:37:53 DEBUG : OpenDrive root 'rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path1': Waiting for transfers to finish
2025/05/12 03:37:55 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:37:55 INFO  : file1.txt: Copied (new)
2025/05/12 03:37:55 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:37:55 INFO  : file2.txt: Copied (new)
2025/05/12 03:37:55 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:37:55 INFO  : file3.txt: Copied (new)
2025/05/12 03:37:56 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:37:56 INFO  : file4.txt: Copied (new)
2025/05/12 03:37:57 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:37:57 INFO  : file7.txt: Copied (new)
2025/05/12 03:37:58 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:37:58 INFO  : file8.txt: Copied (new)
2025/05/12 03:37:58 DEBUG : file9.txt: Uploading chunk 0, size=109, remain=0
2025/05/12 03:37:58 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:37:58 INFO  : file6.txt: Copied (new)
2025/05/12 03:37:58 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:37:58 INFO  : file5.txt: Copied (new)
2025/05/12 03:37:59 DEBUG : file9.txt: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:37:59 INFO  : file9.txt: Copied (new)
2025/05/12 03:37:59 NOTICE: checking Path1 OpenDrive root 'rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path1'
2025/05/12 03:37:59 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:59 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:59 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:59 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:59 DEBUG : file5.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:59 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:59 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:59 DEBUG : file8.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:59 DEBUG : file9.txt: Need to transfer - File not found at Destination
2025/05/12 03:37:59 DEBUG : OpenDrive root 'rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path2': Waiting for checks to finish
2025/05/12 03:37:59 DEBUG : OpenDrive root 'rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path2': Waiting for transfers to finish
2025/05/12 03:38:01 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:38:01 INFO  : file1.txt: Copied (new)
2025/05/12 03:38:02 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:38:02 INFO  : file3.txt: Copied (new)
2025/05/12 03:38:02 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:38:02 INFO  : file4.txt: Copied (new)
2025/05/12 03:38:02 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:38:02 INFO  : file2.txt: Copied (new)
2025/05/12 03:38:03 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:38:03 INFO  : file5.txt: Copied (new)
2025/05/12 03:38:03 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:38:03 INFO  : file6.txt: Copied (new)
2025/05/12 03:38:03 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:38:03 INFO  : file7.txt: Copied (new)
2025/05/12 03:38:04 DEBUG : file9.txt: Uploading chunk 0, size=109, remain=0
2025/05/12 03:38:04 DEBUG : file9.txt: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/05/12 03:38:04 INFO  : file9.txt: Copied (new)
2025/05/12 03:38:05 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/05/12 03:38:05 INFO  : file8.txt: Copied (new)
2025/05/12 03:38:05 NOTICE: checking path2 OpenDrive root 'rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path2'
2025/05/12 03:38:05 NOTICE: (01)  : test max-delete-path1
2025/05/12 03:38:05 NOTICE: (02)  : test initial bisync
2025/05/12 03:38:05 NOTICE: (03)  : bisync resync
2025/05/12 03:38:09 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:38: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/05/12 03:38:09 INFO  : Synching Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path1/" with Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path2/"
2025/05/12 03:38:09 INFO  : Copying Path2 files to Path1
2025/05/12 03:38:09 INFO  : - Path2    Resync is copying files to         - Path1
2025/05/12 03:38:09 INFO  : - Path1    Resync is copying files to         - Path2
2025/05/12 03:38:09 INFO  : Resync updating listings
2025/05/12 03:38:09 INFO  : Validating listings for Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path1/" vs Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path2/"
2025/05/12 03:38:09 INFO  : Bisync successful
2025/05/12 03:38:09 NOTICE: (04)  : test delete >50% of local files
2025/05/12 03:38:09 NOTICE: (05)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path1/file1.txt
2025/05/12 03:38:11 INFO  : file1.txt: Deleted
2025/05/12 03:38:11 NOTICE: (06)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path1/file2.txt
2025/05/12 03:38:11 INFO  : file2.txt: Deleted
2025/05/12 03:38:11 NOTICE: (07)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path1/file3.txt
2025/05/12 03:38:11 INFO  : file3.txt: Deleted
2025/05/12 03:38:11 NOTICE: (08)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path1/file4.txt
2025/05/12 03:38:12 INFO  : file4.txt: Deleted
2025/05/12 03:38:12 NOTICE: (09)  : delete-file TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path1/file5.txt
2025/05/12 03:38:12 INFO  : file5.txt: Deleted
2025/05/12 03:38:12 NOTICE: (10)  : test sync should fail due to too many local deletes
2025/05/12 03:38:12 NOTICE: (11)  : bisync
2025/05/12 03:38:16 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:38:16 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/05/12 03:38:16 INFO  : Synching Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path1/" with Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path2/"
2025/05/12 03:38:16 INFO  : Building Path1 and Path2 listings
2025/05/12 03:38:16 INFO  : Path1 checking for diffs
2025/05/12 03:38:16 INFO  : - Path1    File was deleted          - file1.txt
2025/05/12 03:38:16 INFO  : - Path1    File was deleted          - file2.txt
2025/05/12 03:38:16 INFO  : - Path1    File was deleted          - file3.txt
2025/05/12 03:38:16 INFO  : - Path1    File was deleted          - file4.txt
2025/05/12 03:38:16 INFO  : - Path1    File was deleted          - file5.txt
2025/05/12 03:38:16 INFO  : Path1:    5 changes:    0 new,    0 modified,    5 deleted
2025/05/12 03:38:16 INFO  : Path2 checking for diffs
2025/05/12 03:38:16 ERROR : Safety abort: too many deletes (>50%, 5 of 9) on Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path1/". Run with --force if desired.
2025/05/12 03:38:16 NOTICE: Bisync aborted. Please try again.
2025/05/12 03:38:16 NOTICE: Bisync error: too many deletes
2025/05/12 03:38:16 NOTICE: (12)  : copy-listings initial-fail
2025/05/12 03:38:16 NOTICE: (13)  : test change max-delete limit to 60%. sync should run.
2025/05/12 03:38:16 NOTICE: (14)  : bisync max-delete=60
2025/05/12 03:38:20 INFO  : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.
2025/05/12 03:38:20 INFO  : Bisyncing with Comparison Settings: 
{
	"Modtime": true,
	"Size": true,
	"Checksum": false,
	"HashType1": 0,
	"HashType2": 0,
	"NoSlowHash": false,
	"SlowHashSyncOnly": false,
	"SlowHashDetected": false,
	"DownloadHash": false
}
2025/05/12 03:38:20 INFO  : Synching Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path1/" with Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path2/"
2025/05/12 03:38:20 INFO  : Building Path1 and Path2 listings
2025/05/12 03:38:21 INFO  : Path1 checking for diffs
2025/05/12 03:38:21 INFO  : - Path1    File was deleted          - file1.txt
2025/05/12 03:38:21 INFO  : - Path1    File was deleted          - file2.txt
2025/05/12 03:38:21 INFO  : - Path1    File was deleted          - file3.txt
2025/05/12 03:38:21 INFO  : - Path1    File was deleted          - file4.txt
2025/05/12 03:38:21 INFO  : - Path1    File was deleted          - file5.txt
2025/05/12 03:38:21 INFO  : Path1:    5 changes:    0 new,    0 modified,    5 deleted
2025/05/12 03:38:21 INFO  : Path2 checking for diffs
2025/05/12 03:38:21 INFO  : Applying changes
2025/05/12 03:38:21 INFO  : - Path2    Queue delete              - TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path2/file1.txt
2025/05/12 03:38:21 INFO  : - Path2    Queue delete              - TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path2/file2.txt
2025/05/12 03:38:21 INFO  : - Path2    Queue delete              - TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path2/file3.txt
2025/05/12 03:38:21 INFO  : - Path2    Queue delete              - TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path2/file4.txt
2025/05/12 03:38:21 INFO  : - Path2    Queue delete              - TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path2/file5.txt
2025/05/12 03:38:21 INFO  : - Path1    Do queued copies to                - Path2
2025/05/12 03:38:21 INFO  : file2.txt: Deleted
2025/05/12 03:38:21 INFO  : file4.txt: Deleted
2025/05/12 03:38:21 INFO  : file5.txt: Deleted
2025/05/12 03:38:21 INFO  : file1.txt: Deleted
2025/05/12 03:38:22 INFO  : file3.txt: Deleted
2025/05/12 03:38:22 INFO  : Updating listings
2025/05/12 03:38:22 INFO  : Validating listings for Path1 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path1/" vs Path2 "TestOpenDrive:rclone-test-qonaxav2tuco/033620fa/max_delete_path1/path2/"
2025/05/12 03:38:22 INFO  : Bisync successful
    bisync_test.go:560: TEST max_delete_path1 PASSED
2025/05/12 03:38:23 DEBUG : OpenDrive root 'rclone-test-qonaxav2tuco': Purge remote
--- FAIL: TestBisyncRemoteRemote (124.37s)
    --- FAIL: TestBisyncRemoteRemote/check_access_filters (88.71s)
    --- PASS: TestBisyncRemoteRemote/max_delete_path1 (33.97s)
FAIL
2025/05/12 03:38:24 DEBUG : OpenDrive root 'rclone-test-vivasoc8soxe': Purge remote
2025/05/12 03:38:24 NOTICE: purge failed: directory not found
"./bisync.test -test.v -test.timeout 1h0m0s -remote TestOpenDrive: -verbose -test.run '^TestBisyncLocalRemote$/^(changes|check_filename)$|^TestBisyncRemoteLocal$/^check_access_filters$|^TestBisyncRemoteRemote$/^(check_access_filters|max_delete_path1)$'" - Finished ERROR in 3m56.526659714s (try 3/5): exit status 1: Failed [TestBisyncRemoteRemote/check_access_filters]