"./bisync.test -test.v -test.timeout 1h0m0s -remote TestB2: -list-retries 5 -verbose -test.run '^TestBisyncRemoteLocal$/^(basic|check_access_filters)$'" - Starting (try 3/5) 2024/12/13 04:53:21 DEBUG : Creating backend with remote "TestB2:rclone-test-jukawuh6ralo" 2024/12/13 04:53:21 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2024/12/13 04:53:22 DEBUG : Creating backend with remote "/tmp/rclone2570505971" === RUN TestBisyncRemoteLocal 2024/12/13 04:53:22 DEBUG : Creating backend with remote "TestB2:rclone-test-lihejen9waza" 2024/12/13 04:53:23 NOTICE: remote: TestB2:rclone-test-lihejen9waza === RUN TestBisyncRemoteLocal/basic 2024/12/13 04:53:23 DEBUG : Creating backend with remote "TestB2:rclone-test-lihejen9waza/045323ni" 2024/12/13 04:53:23 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2024/12/13 04:53:24 DEBUG : path1: Making directory 2024/12/13 04:53:25 DEBUG : Creating backend with remote "TestB2:rclone-test-lihejen9waza/045323ni/basic/path1" 2024/12/13 04:53:26 DEBUG : Creating backend with remote "/tmp/045323ni" 2024/12/13 04:53:26 DEBUG : Creating backend with remote "/tmp/045323ni/basic/path2" 2024/12/13 04:53:26 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_basic/initial" 2024/12/13 04:53:26 DEBUG : Creating backend with remote "/tmp/045323ni/initdir/test_basic-qohuduw6" 2024/12/13 04:53:26 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:26 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:26 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:26 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:26 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:26 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:26 DEBUG : file1.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:26 DEBUG : subdir: Making directory with metadata 2024/12/13 04:53:26 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2024/12/13 04:53:26 DEBUG : Added delayed dir = "subdir", newDst=subdir 2024/12/13 04:53:26 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:26 DEBUG : Local file system at /tmp/045323ni/initdir/test_basic-qohuduw6: Waiting for checks to finish 2024/12/13 04:53:26 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:26 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:26 DEBUG : Local file system at /tmp/045323ni/initdir/test_basic-qohuduw6: Waiting for transfers to finish 2024/12/13 04:53:26 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:26 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST 2024/12/13 04:53:26 INFO : RCLONE_TEST: Copied (new) 2024/12/13 04:53:26 DEBUG : file1.copy1.txt.5028a97.partial: renamed to: file1.copy1.txt 2024/12/13 04:53:26 INFO : file1.copy1.txt: Copied (new) 2024/12/13 04:53:26 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:26 DEBUG : file1.copy2.txt.5028a97.partial: renamed to: file1.copy2.txt 2024/12/13 04:53:26 INFO : file1.copy2.txt: Copied (new) 2024/12/13 04:53:26 DEBUG : file1.copy3.txt.5028a97.partial: renamed to: file1.copy3.txt 2024/12/13 04:53:26 INFO : file1.copy3.txt: Copied (new) 2024/12/13 04:53:26 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:26 DEBUG : file1.copy5.txt.5028a97.partial: renamed to: file1.copy5.txt 2024/12/13 04:53:26 INFO : file1.copy5.txt: Copied (new) 2024/12/13 04:53:26 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:26 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:26 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt 2024/12/13 04:53:26 INFO : file1.txt: Copied (new) 2024/12/13 04:53:26 DEBUG : file1.copy4.txt.5028a97.partial: renamed to: file1.copy4.txt 2024/12/13 04:53:26 INFO : file1.copy4.txt: Copied (new) 2024/12/13 04:53:26 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:26 DEBUG : subdir/file20.txt.5028a97.partial: renamed to: subdir/file20.txt 2024/12/13 04:53:26 INFO : subdir/file20.txt: Copied (new) 2024/12/13 04:53:26 INFO : subdir: Set directory modification time (using SetModTime) 2024/12/13 04:53:26 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_basic/modfiles" 2024/12/13 04:53:26 DEBUG : Creating backend with remote "/tmp/045323ni/datadir/test_basic-yayokeb1" 2024/12/13 04:53:26 DEBUG : file1.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:26 DEBUG : Local file system at /tmp/045323ni/datadir/test_basic-yayokeb1: Waiting for checks to finish 2024/12/13 04:53:26 DEBUG : Local file system at /tmp/045323ni/datadir/test_basic-yayokeb1: Waiting for transfers to finish 2024/12/13 04:53:26 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2024/12/13 04:53:26 DEBUG : file1.txt.925c801f.partial: renamed to: file1.txt 2024/12/13 04:53:26 INFO : file1.txt: Copied (new) 2024/12/13 04:53:27 ERROR : : error listing: directory not found 2024/12/13 04:53:27 NOTICE: checking initFs Local file system at /tmp/045323ni/initdir/test_basic-qohuduw6 2024/12/13 04:53:27 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:27 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:27 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:27 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:27 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:27 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:27 DEBUG : file1.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:27 DEBUG : subdir: Making directory 2024/12/13 04:53:27 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:27 DEBUG : B2 bucket rclone-test-lihejen9waza path 045323ni/basic/path1: Waiting for checks to finish 2024/12/13 04:53:27 DEBUG : B2 bucket rclone-test-lihejen9waza path 045323ni/basic/path1: Waiting for transfers to finish 2024/12/13 04:53:28 DEBUG : file1.copy3.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:28 INFO : file1.copy3.txt: Copied (new) 2024/12/13 04:53:28 DEBUG : file1.copy1.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:28 INFO : file1.copy1.txt: Copied (new) 2024/12/13 04:53:28 DEBUG : file1.copy2.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:28 INFO : file1.copy2.txt: Copied (new) 2024/12/13 04:53:28 DEBUG : file1.copy4.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:28 INFO : file1.copy4.txt: Copied (new) 2024/12/13 04:53:28 DEBUG : RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2024/12/13 04:53:28 INFO : RCLONE_TEST: Copied (new) 2024/12/13 04:53:28 DEBUG : file1.copy5.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:28 INFO : file1.copy5.txt: Copied (new) 2024/12/13 04:53:28 DEBUG : file1.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:28 INFO : file1.txt: Copied (new) 2024/12/13 04:53:28 DEBUG : subdir/file20.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:28 INFO : subdir/file20.txt: Copied (new) 2024/12/13 04:53:28 NOTICE: checking Path1 B2 bucket rclone-test-lihejen9waza path 045323ni/basic/path1 2024/12/13 04:53:29 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:29 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:29 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:29 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:29 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:29 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:29 DEBUG : file1.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:29 DEBUG : subdir: Making directory with metadata 2024/12/13 04:53:29 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2024/12/13 04:53:29 DEBUG : Added delayed dir = "subdir", newDst=subdir 2024/12/13 04:53:29 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:29 DEBUG : Local file system at /tmp/045323ni/basic/path2: Waiting for checks to finish 2024/12/13 04:53:29 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:29 DEBUG : file1.copy2.txt.5028a97.partial: renamed to: file1.copy2.txt 2024/12/13 04:53:29 INFO : file1.copy2.txt: Copied (new) 2024/12/13 04:53:29 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:29 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:29 DEBUG : file1.copy3.txt.5028a97.partial: renamed to: file1.copy3.txt 2024/12/13 04:53:29 INFO : file1.copy3.txt: Copied (new) 2024/12/13 04:53:29 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:29 DEBUG : file1.copy5.txt.5028a97.partial: renamed to: file1.copy5.txt 2024/12/13 04:53:29 INFO : file1.copy5.txt: Copied (new) 2024/12/13 04:53:29 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:29 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt 2024/12/13 04:53:29 INFO : file1.txt: Copied (new) 2024/12/13 04:53:29 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:29 DEBUG : subdir/file20.txt.5028a97.partial: renamed to: subdir/file20.txt 2024/12/13 04:53:29 INFO : subdir/file20.txt: Copied (new) 2024/12/13 04:53:29 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:29 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST 2024/12/13 04:53:29 INFO : RCLONE_TEST: Copied (new) 2024/12/13 04:53:29 DEBUG : Local file system at /tmp/045323ni/basic/path2: Waiting for transfers to finish 2024/12/13 04:53:29 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:29 DEBUG : file1.copy4.txt.5028a97.partial: renamed to: file1.copy4.txt 2024/12/13 04:53:29 INFO : file1.copy4.txt: Copied (new) 2024/12/13 04:53:29 DEBUG : file1.copy1.txt.5028a97.partial: renamed to: file1.copy1.txt 2024/12/13 04:53:29 INFO : file1.copy1.txt: Copied (new) 2024/12/13 04:53:29 INFO : subdir: Set directory modification time (using SetModTime) 2024/12/13 04:53:29 NOTICE: checking path2 Local file system at /tmp/045323ni/basic/path2 2024/12/13 04:53:29 NOTICE: (01) : test basic 2024/12/13 04:53:29 NOTICE: (02) : test initial bisync 2024/12/13 04:53:29 NOTICE: (03) : bisync resync 2024/12/13 04:53:30 INFO : subdir: Set directory modification time (using SetModTime) 2024/12/13 04:53:30 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2024/12/13 04:53:30 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2024/12/13 04:53:30 INFO : Synching Path1 "TestB2:rclone-test-lihejen9waza/045323ni/basic/path1/" with Path2 "/tmp/045323ni/basic/path2/" 2024/12/13 04:53:30 INFO : Copying Path2 files to Path1 2024/12/13 04:53:30 INFO : - Path2 Resync is copying files to - Path1 2024/12/13 04:53:30 INFO : - Path1 Resync is copying files to - Path2 2024/12/13 04:53:30 INFO : Resync updating listings 2024/12/13 04:53:30 INFO : Validating listings for Path1 "TestB2:rclone-test-lihejen9waza/045323ni/basic/path1/" vs Path2 "/tmp/045323ni/basic/path2/" 2024/12/13 04:53:30 INFO : Bisync successful 2024/12/13 04:53:30 NOTICE: (04) : test place newer files on both paths 2024/12/13 04:53:30 NOTICE: (05) : touch-copy 2001-01-02 /tmp/045323ni/datadir/test_basic-yayokeb1/file1.txt /tmp/045323ni/basic/path2/ 2024/12/13 04:53:30 INFO : file1.txt: Copied (replaced existing) 2024/12/13 04:53:30 NOTICE: (06) : copy-as /tmp/045323ni/datadir/test_basic-yayokeb1/file1.txt TestB2:rclone-test-lihejen9waza/045323ni/basic/path1/subdir file20.txt 2024/12/13 04:53:33 INFO : file1.txt: Copied (replaced existing) to: file20.txt 2024/12/13 04:53:33 NOTICE: (07) : test bisync run 2024/12/13 04:53:33 NOTICE: (08) : bisync 2024/12/13 04:53:34 INFO : subdir: Set directory modification time (using SetModTime) 2024/12/13 04:53:34 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2024/12/13 04:53:34 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2024/12/13 04:53:34 INFO : Synching Path1 "TestB2:rclone-test-lihejen9waza/045323ni/basic/path1/" with Path2 "/tmp/045323ni/basic/path2/" 2024/12/13 04:53:34 INFO : Building Path1 and Path2 listings 2024/12/13 04:53:35 INFO : Path1 checking for diffs 2024/12/13 04:53:35 INFO : - Path1 File changed: size (larger), time (newer) - subdir/file20.txt 2024/12/13 04:53:35 INFO : Path1: 1 changes:  0 new,  1 modified,  0 deleted 2024/12/13 04:53:35 INFO : (Modified:  1 newer,  0 older,  1 larger,  0 smaller) 2024/12/13 04:53:35 INFO : Path2 checking for diffs 2024/12/13 04:53:35 INFO : - Path2 File changed: size (larger), time (newer) - file1.txt 2024/12/13 04:53:35 INFO : Path2: 1 changes:  0 new,  1 modified,  0 deleted 2024/12/13 04:53:35 INFO : (Modified:  1 newer,  0 older,  1 larger,  0 smaller) 2024/12/13 04:53:35 INFO : Applying changes 2024/12/13 04:53:35 INFO : - Path1 Queue copy to Path2 - /tmp/045323ni/basic/path2/subdir/file20.txt 2024/12/13 04:53:35 INFO : - Path2 Queue copy to Path1 - TestB2:rclone-test-lihejen9waza/045323ni/basic/path1/file1.txt 2024/12/13 04:53:35 INFO : - Path2 Do queued copies to - Path1 2024/12/13 04:53:35 INFO : file1.txt: Copied (replaced existing) 2024/12/13 04:53:35 INFO : - Path1 Do queued copies to - Path2 2024/12/13 04:53:36 INFO : subdir/file20.txt: Copied (replaced existing) 2024/12/13 04:53:36 INFO : Updating listings 2024/12/13 04:53:36 INFO : Validating listings for Path1 "TestB2:rclone-test-lihejen9waza/045323ni/basic/path1/" vs Path2 "/tmp/045323ni/basic/path2/" 2024/12/13 04:53:36 INFO : Bisync successful bisync_test.go:558: TEST basic PASSED === RUN TestBisyncRemoteLocal/check_access_filters 2024/12/13 04:53:37 DEBUG : path1: Making directory 2024/12/13 04:53:37 DEBUG : Creating backend with remote "TestB2:rclone-test-lihejen9waza/045323ni/check_access_filters/path1" 2024/12/13 04:53:38 DEBUG : Creating backend with remote "/tmp/045323ni/check_access_filters/path2" 2024/12/13 04:53:38 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access_filters/initial" 2024/12/13 04:53:38 DEBUG : Creating backend with remote "/tmp/045323ni/initdir/test_check_access_filters-lubuweq0" 2024/12/13 04:53:38 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : file1.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : file2.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : file3.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : file4.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : subdir: Making directory with metadata 2024/12/13 04:53:38 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2024/12/13 04:53:38 DEBUG : Added delayed dir = "subdir", newDst=subdir 2024/12/13 04:53:38 DEBUG : subdir-not: Making directory with metadata 2024/12/13 04:53:38 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:38 INFO : subdir-not: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2024/12/13 04:53:38 DEBUG : Added delayed dir = "subdir-not", newDst=subdir-not 2024/12/13 04:53:38 DEBUG : subdirX: Making directory with metadata 2024/12/13 04:53:38 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt 2024/12/13 04:53:38 INFO : file1.txt: Copied (new) 2024/12/13 04:53:38 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:38 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt 2024/12/13 04:53:38 INFO : file2.txt: Copied (new) 2024/12/13 04:53:38 INFO : subdirX: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2024/12/13 04:53:38 DEBUG : Added delayed dir = "subdirX", newDst=subdirX 2024/12/13 04:53:38 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : subdirX/subdirX1: Making directory with metadata 2024/12/13 04:53:38 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:38 INFO : subdirX/subdirX1: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2024/12/13 04:53:38 DEBUG : Added delayed dir = "subdirX/subdirX1", newDst=subdirX/subdirX1 2024/12/13 04:53:38 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:38 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:38 DEBUG : file4.txt.5028a97.partial: renamed to: file4.txt 2024/12/13 04:53:38 INFO : file4.txt: Copied (new) 2024/12/13 04:53:38 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST 2024/12/13 04:53:38 INFO : RCLONE_TEST: Copied (new) 2024/12/13 04:53:38 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : file3.txt.5028a97.partial: renamed to: file3.txt 2024/12/13 04:53:38 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:38 INFO : file3.txt: Copied (new) 2024/12/13 04:53:38 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : subdir-not/subdir-not2: Making directory with metadata 2024/12/13 04:53:38 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : subdir/subdirA: Making directory with metadata 2024/12/13 04:53:38 INFO : subdir-not/subdir-not2: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2024/12/13 04:53:38 DEBUG : Added delayed dir = "subdir-not/subdir-not2", newDst=subdir-not/subdir-not2 2024/12/13 04:53:38 INFO : subdir/subdirA: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2024/12/13 04:53:38 DEBUG : Added delayed dir = "subdir/subdirA", newDst=subdir/subdirA 2024/12/13 04:53:38 DEBUG : subdir/subdirB: Making directory with metadata 2024/12/13 04:53:38 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : subdirX/subdirX1/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:38 INFO : subdir/subdirB: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2024/12/13 04:53:38 DEBUG : Added delayed dir = "subdir/subdirB", newDst=subdir/subdirB 2024/12/13 04:53:38 DEBUG : subdirX/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:38 DEBUG : subdirX/subdirX1/file30.txt.5028a97.partial: renamed to: subdirX/subdirX1/file30.txt 2024/12/13 04:53:38 INFO : subdirX/subdirX1/file30.txt: Copied (new) 2024/12/13 04:53:38 DEBUG : subdirX/file20.txt.5028a97.partial: renamed to: subdirX/file20.txt 2024/12/13 04:53:38 INFO : subdirX/file20.txt: Copied (new) 2024/12/13 04:53:38 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : subdir-not/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:38 DEBUG : subdir-not/file20.txt.5028a97.partial: renamed to: subdir-not/file20.txt 2024/12/13 04:53:38 INFO : subdir-not/file20.txt: Copied (new) 2024/12/13 04:53:38 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : Local file system at /tmp/045323ni/initdir/test_check_access_filters-lubuweq0: Waiting for checks to finish 2024/12/13 04:53:38 DEBUG : Local file system at /tmp/045323ni/initdir/test_check_access_filters-lubuweq0: Waiting for transfers to finish 2024/12/13 04:53:38 DEBUG : subdirX/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:38 DEBUG : subdir-not/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:38 DEBUG : subdirX/RCLONE_TEST.cf9a93ac.partial: renamed to: subdirX/RCLONE_TEST 2024/12/13 04:53:38 INFO : subdirX/RCLONE_TEST: Copied (new) 2024/12/13 04:53:38 DEBUG : subdir-not/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir-not/RCLONE_TEST 2024/12/13 04:53:38 INFO : subdir-not/RCLONE_TEST: Copied (new) 2024/12/13 04:53:38 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:38 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:38 DEBUG : subdir/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir/RCLONE_TEST 2024/12/13 04:53:38 INFO : subdir/RCLONE_TEST: Copied (new) 2024/12/13 04:53:38 DEBUG : subdir/file20.txt.5028a97.partial: renamed to: subdir/file20.txt 2024/12/13 04:53:38 INFO : subdir/file20.txt: Copied (new) 2024/12/13 04:53:38 DEBUG : subdir-not/subdir-not2/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:38 DEBUG : subdir-not/subdir-not2/file30.txt.5028a97.partial: renamed to: subdir-not/subdir-not2/file30.txt 2024/12/13 04:53:38 INFO : subdir-not/subdir-not2/file30.txt: Copied (new) 2024/12/13 04:53:38 DEBUG : subdir/subdirB/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:38 DEBUG : subdir/subdirB/file30.txt.5028a97.partial: renamed to: subdir/subdirB/file30.txt 2024/12/13 04:53:38 INFO : subdir/subdirB/file30.txt: Copied (new) 2024/12/13 04:53:38 DEBUG : subdir/subdirB/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:38 DEBUG : subdir/subdirB/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir/subdirB/RCLONE_TEST 2024/12/13 04:53:38 INFO : subdir/subdirB/RCLONE_TEST: Copied (new) 2024/12/13 04:53:38 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:38 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir-not/subdir-not2/RCLONE_TEST 2024/12/13 04:53:38 INFO : subdir-not/subdir-not2/RCLONE_TEST: Copied (new) 2024/12/13 04:53:38 DEBUG : subdir/subdirA/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:38 DEBUG : subdir/subdirA/file30.txt.5028a97.partial: renamed to: subdir/subdirA/file30.txt 2024/12/13 04:53:38 INFO : subdir/subdirA/file30.txt: Copied (new) 2024/12/13 04:53:38 DEBUG : subdir/subdirA/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:38 DEBUG : subdir/subdirA/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir/subdirA/RCLONE_TEST 2024/12/13 04:53:38 INFO : subdir/subdirA/RCLONE_TEST: Copied (new) 2024/12/13 04:53:38 DEBUG : subdirX/subdirX1/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:38 DEBUG : subdirX/subdirX1/RCLONE_TEST.cf9a93ac.partial: renamed to: subdirX/subdirX1/RCLONE_TEST 2024/12/13 04:53:38 INFO : subdirX/subdirX1/RCLONE_TEST: Copied (new) 2024/12/13 04:53:38 INFO : subdirX/subdirX1: Set directory modification time (using SetModTime) 2024/12/13 04:53:38 INFO : subdir-not/subdir-not2: Set directory modification time (using SetModTime) 2024/12/13 04:53:38 INFO : subdir/subdirA: Set directory modification time (using SetModTime) 2024/12/13 04:53:38 INFO : subdir/subdirB: Set directory modification time (using SetModTime) 2024/12/13 04:53:38 INFO : subdirX: Set directory modification time (using SetModTime) 2024/12/13 04:53:38 INFO : subdir: Set directory modification time (using SetModTime) 2024/12/13 04:53:38 INFO : subdir-not: Set directory modification time (using SetModTime) 2024/12/13 04:53:38 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access_filters/modfiles" 2024/12/13 04:53:38 DEBUG : Creating backend with remote "/tmp/045323ni/datadir/test_check_access_filters-setelaz0" 2024/12/13 04:53:38 DEBUG : exclude-other-filtersfile.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : include-other-filtersfile.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:38 DEBUG : Local file system at /tmp/045323ni/datadir/test_check_access_filters-setelaz0: Waiting for checks to finish 2024/12/13 04:53:38 DEBUG : Local file system at /tmp/045323ni/datadir/test_check_access_filters-setelaz0: Waiting for transfers to finish 2024/12/13 04:53:38 DEBUG : exclude-other-filtersfile.txt: md5 = 5fcc6205d7df1c2e9ed3a15a1356b345 OK 2024/12/13 04:53:38 DEBUG : exclude-other-filtersfile.txt.9180e6d6.partial: renamed to: exclude-other-filtersfile.txt 2024/12/13 04:53:38 INFO : exclude-other-filtersfile.txt: Copied (new) 2024/12/13 04:53:38 DEBUG : include-other-filtersfile.txt: md5 = 2ec13b2813141ed088e5978ef5a47b0e OK 2024/12/13 04:53:38 DEBUG : include-other-filtersfile.txt.5fb1cd78.partial: renamed to: include-other-filtersfile.txt 2024/12/13 04:53:38 INFO : include-other-filtersfile.txt: Copied (new) 2024/12/13 04:53:39 ERROR : : error listing: directory not found 2024/12/13 04:53:39 NOTICE: checking initFs Local file system at /tmp/045323ni/initdir/test_check_access_filters-lubuweq0 2024/12/13 04:53:40 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : file1.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : file2.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : file3.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : file4.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : subdir: Making directory 2024/12/13 04:53:40 DEBUG : subdir-not: Making directory 2024/12/13 04:53:40 DEBUG : subdirX: Making directory 2024/12/13 04:53:40 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : subdirX/subdirX1: Making directory 2024/12/13 04:53:40 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : subdir/subdirA: Making directory 2024/12/13 04:53:40 DEBUG : subdir/subdirB: Making directory 2024/12/13 04:53:40 DEBUG : subdir-not/subdir-not2: Making directory 2024/12/13 04:53:40 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:40 DEBUG : B2 bucket rclone-test-lihejen9waza path 045323ni/check_access_filters/path1: Waiting for checks to finish 2024/12/13 04:53:40 DEBUG : B2 bucket rclone-test-lihejen9waza path 045323ni/check_access_filters/path1: Waiting for transfers to finish 2024/12/13 04:53:40 DEBUG : file1.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:40 INFO : file1.txt: Copied (new) 2024/12/13 04:53:41 DEBUG : file2.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:41 INFO : file2.txt: Copied (new) 2024/12/13 04:53:41 DEBUG : file4.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:41 INFO : file4.txt: Copied (new) 2024/12/13 04:53:41 DEBUG : subdirX/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2024/12/13 04:53:41 INFO : subdirX/RCLONE_TEST: Copied (new) 2024/12/13 04:53:41 DEBUG : subdirX/file20.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:41 INFO : subdirX/file20.txt: Copied (new) 2024/12/13 04:53:41 DEBUG : RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2024/12/13 04:53:41 INFO : RCLONE_TEST: Copied (new) 2024/12/13 04:53:41 DEBUG : subdirX/subdirX1/file30.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:41 INFO : subdirX/subdirX1/file30.txt: Copied (new) 2024/12/13 04:53:41 DEBUG : subdirX/subdirX1/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2024/12/13 04:53:41 INFO : subdirX/subdirX1/RCLONE_TEST: Copied (new) 2024/12/13 04:53:41 DEBUG : subdir-not/file20.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:41 INFO : subdir-not/file20.txt: Copied (new) 2024/12/13 04:53:41 DEBUG : file3.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:41 INFO : file3.txt: Copied (new) 2024/12/13 04:53:41 DEBUG : subdir/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2024/12/13 04:53:41 INFO : subdir/RCLONE_TEST: Copied (new) 2024/12/13 04:53:42 DEBUG : subdir-not/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2024/12/13 04:53:42 INFO : subdir-not/RCLONE_TEST: Copied (new) 2024/12/13 04:53:42 DEBUG : subdir/file20.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:42 INFO : subdir/file20.txt: Copied (new) 2024/12/13 04:53:42 DEBUG : subdir/subdirA/file30.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:42 INFO : subdir/subdirA/file30.txt: Copied (new) 2024/12/13 04:53:42 DEBUG : subdir/subdirB/file30.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:42 INFO : subdir/subdirB/file30.txt: Copied (new) 2024/12/13 04:53:42 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2024/12/13 04:53:42 INFO : subdir-not/subdir-not2/RCLONE_TEST: Copied (new) 2024/12/13 04:53:42 DEBUG : subdir/subdirA/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2024/12/13 04:53:42 INFO : subdir/subdirA/RCLONE_TEST: Copied (new) 2024/12/13 04:53:42 DEBUG : subdir-not/subdir-not2/file30.txt: sha1 = da39a3ee5e6b4b0d3255bfef95601890afd80709 OK 2024/12/13 04:53:42 INFO : subdir-not/subdir-not2/file30.txt: Copied (new) 2024/12/13 04:53:42 DEBUG : subdir/subdirB/RCLONE_TEST: sha1 = c799ac3b0eacf2b6fc3e741a7bea196aa129aab2 OK 2024/12/13 04:53:42 INFO : subdir/subdirB/RCLONE_TEST: Copied (new) 2024/12/13 04:53:42 NOTICE: checking Path1 B2 bucket rclone-test-lihejen9waza path 045323ni/check_access_filters/path1 2024/12/13 04:53:43 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : file1.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : file2.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : file3.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : file4.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : subdir: Making directory with metadata 2024/12/13 04:53:43 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2024/12/13 04:53:43 DEBUG : Added delayed dir = "subdir", newDst=subdir 2024/12/13 04:53:43 DEBUG : subdir-not: Making directory with metadata 2024/12/13 04:53:43 INFO : subdir-not: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2024/12/13 04:53:43 DEBUG : Added delayed dir = "subdir-not", newDst=subdir-not 2024/12/13 04:53:43 DEBUG : subdirX: Making directory with metadata 2024/12/13 04:53:43 INFO : subdirX: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2024/12/13 04:53:43 DEBUG : Added delayed dir = "subdirX", newDst=subdirX 2024/12/13 04:53:43 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : subdirX/subdirX1: Making directory with metadata 2024/12/13 04:53:43 INFO : subdirX/subdirX1: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2024/12/13 04:53:43 DEBUG : Added delayed dir = "subdirX/subdirX1", newDst=subdirX/subdirX1 2024/12/13 04:53:43 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : subdir/subdirA: Making directory with metadata 2024/12/13 04:53:43 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:43 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt 2024/12/13 04:53:43 INFO : file1.txt: Copied (new) 2024/12/13 04:53:43 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:43 INFO : subdir/subdirA: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2024/12/13 04:53:43 DEBUG : subdir-not/subdir-not2: Making directory with metadata 2024/12/13 04:53:43 DEBUG : Added delayed dir = "subdir/subdirA", newDst=subdir/subdirA 2024/12/13 04:53:43 DEBUG : subdir/subdirB: Making directory with metadata 2024/12/13 04:53:43 INFO : subdir-not/subdir-not2: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2024/12/13 04:53:43 INFO : subdir/subdirB: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2024/12/13 04:53:43 DEBUG : Added delayed dir = "subdir-not/subdir-not2", newDst=subdir-not/subdir-not2 2024/12/13 04:53:43 DEBUG : Added delayed dir = "subdir/subdirB", newDst=subdir/subdirB 2024/12/13 04:53:43 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:43 DEBUG : file3.txt.5028a97.partial: renamed to: file3.txt 2024/12/13 04:53:43 INFO : file3.txt: Copied (new) 2024/12/13 04:53:43 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:43 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt 2024/12/13 04:53:43 INFO : file2.txt: Copied (new) 2024/12/13 04:53:43 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination 2024/12/13 04:53:43 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:43 DEBUG : subdirX/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:43 DEBUG : file4.txt.5028a97.partial: renamed to: file4.txt 2024/12/13 04:53:43 INFO : file4.txt: Copied (new) 2024/12/13 04:53:43 DEBUG : subdirX/file20.txt.5028a97.partial: renamed to: subdirX/file20.txt 2024/12/13 04:53:43 INFO : subdirX/file20.txt: Copied (new) 2024/12/13 04:53:43 DEBUG : Local file system at /tmp/045323ni/check_access_filters/path2: Waiting for checks to finish 2024/12/13 04:53:43 DEBUG : Local file system at /tmp/045323ni/check_access_filters/path2: Waiting for transfers to finish 2024/12/13 04:53:43 DEBUG : subdirX/subdirX1/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:43 DEBUG : subdirX/subdirX1/file30.txt.5028a97.partial: renamed to: subdirX/subdirX1/file30.txt 2024/12/13 04:53:43 INFO : subdirX/subdirX1/file30.txt: Copied (new) 2024/12/13 04:53:43 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:43 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST 2024/12/13 04:53:43 DEBUG : subdirX/subdirX1/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:43 INFO : RCLONE_TEST: Copied (new) 2024/12/13 04:53:43 DEBUG : subdirX/subdirX1/RCLONE_TEST.cf9a93ac.partial: renamed to: subdirX/subdirX1/RCLONE_TEST 2024/12/13 04:53:43 INFO : subdirX/subdirX1/RCLONE_TEST: Copied (new) 2024/12/13 04:53:43 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:43 DEBUG : subdir/file20.txt.5028a97.partial: renamed to: subdir/file20.txt 2024/12/13 04:53:43 INFO : subdir/file20.txt: Copied (new) 2024/12/13 04:53:43 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:43 DEBUG : subdir/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir/RCLONE_TEST 2024/12/13 04:53:43 INFO : subdir/RCLONE_TEST: Copied (new) 2024/12/13 04:53:43 DEBUG : subdir-not/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:43 DEBUG : subdir-not/file20.txt.5028a97.partial: renamed to: subdir-not/file20.txt 2024/12/13 04:53:43 INFO : subdir-not/file20.txt: Copied (new) 2024/12/13 04:53:43 DEBUG : subdir-not/subdir-not2/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:43 DEBUG : subdir-not/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:43 DEBUG : subdir-not/subdir-not2/file30.txt.5028a97.partial: renamed to: subdir-not/subdir-not2/file30.txt 2024/12/13 04:53:43 INFO : subdir-not/subdir-not2/file30.txt: Copied (new) 2024/12/13 04:53:43 DEBUG : subdir-not/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir-not/RCLONE_TEST 2024/12/13 04:53:43 INFO : subdir-not/RCLONE_TEST: Copied (new) 2024/12/13 04:53:43 DEBUG : subdir/subdirB/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:43 DEBUG : subdir/subdirB/file30.txt.5028a97.partial: renamed to: subdir/subdirB/file30.txt 2024/12/13 04:53:43 INFO : subdir/subdirB/file30.txt: Copied (new) 2024/12/13 04:53:43 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:43 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir-not/subdir-not2/RCLONE_TEST 2024/12/13 04:53:43 DEBUG : subdirX/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:43 INFO : subdir-not/subdir-not2/RCLONE_TEST: Copied (new) 2024/12/13 04:53:43 DEBUG : subdirX/RCLONE_TEST.cf9a93ac.partial: renamed to: subdirX/RCLONE_TEST 2024/12/13 04:53:43 INFO : subdirX/RCLONE_TEST: Copied (new) 2024/12/13 04:53:43 DEBUG : subdir/subdirA/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2024/12/13 04:53:43 DEBUG : subdir/subdirA/file30.txt.5028a97.partial: renamed to: subdir/subdirA/file30.txt 2024/12/13 04:53:43 INFO : subdir/subdirA/file30.txt: Copied (new) 2024/12/13 04:53:43 DEBUG : subdir/subdirB/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:43 DEBUG : subdir/subdirB/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir/subdirB/RCLONE_TEST 2024/12/13 04:53:43 INFO : subdir/subdirB/RCLONE_TEST: Copied (new) 2024/12/13 04:53:43 DEBUG : subdir/subdirA/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2024/12/13 04:53:43 DEBUG : subdir/subdirA/RCLONE_TEST.cf9a93ac.partial: renamed to: subdir/subdirA/RCLONE_TEST 2024/12/13 04:53:43 INFO : subdir/subdirA/RCLONE_TEST: Copied (new) 2024/12/13 04:53:43 INFO : subdir/subdirB: Set directory modification time (using SetModTime) 2024/12/13 04:53:43 INFO : subdir-not/subdir-not2: Set directory modification time (using SetModTime) 2024/12/13 04:53:43 INFO : subdir/subdirA: Set directory modification time (using SetModTime) 2024/12/13 04:53:43 INFO : subdirX/subdirX1: Set directory modification time (using SetModTime) 2024/12/13 04:53:43 INFO : subdirX: Set directory modification time (using SetModTime) 2024/12/13 04:53:43 INFO : subdir: Set directory modification time (using SetModTime) 2024/12/13 04:53:43 INFO : subdir-not: Set directory modification time (using SetModTime) 2024/12/13 04:53:43 NOTICE: checking path2 Local file system at /tmp/045323ni/check_access_filters/path2 2024/12/13 04:53:43 NOTICE: (01) : test check-access-filters 2024/12/13 04:53:43 NOTICE: (02) : test EXCLUDE - OTHER TESTS 2024/12/13 04:53:43 NOTICE: (03) : copy-file /tmp/045323ni/datadir/test_check_access_filters-setelaz0/exclude-other-filtersfile.txt /tmp/045323ni/workdir/ 2024/12/13 04:53:43 INFO : exclude-other-filtersfile.txt: Copied (new) 2024/12/13 04:53:43 NOTICE: (04) : test resync to get the filters file md5 built. 2024/12/13 04:53:43 NOTICE: (05) : bisync resync filters-file=/tmp/045323ni/workdir/exclude-other-filtersfile.txt 2024/12/13 04:53:43 INFO : subdir: Set directory modification time (using SetModTime) 2024/12/13 04:53:43 INFO : subdir-not: Set directory modification time (using SetModTime) 2024/12/13 04:53:43 INFO : subdirX: Set directory modification time (using SetModTime) 2024/12/13 04:53:43 INFO : subdirX/subdirX1: Set directory modification time (using SetModTime) 2024/12/13 04:53:43 INFO : subdir/subdirA: Set directory modification time (using SetModTime) 2024/12/13 04:53:43 INFO : subdir/subdirB: Set directory modification time (using SetModTime) 2024/12/13 04:53:43 INFO : subdir-not/subdir-not2: Set directory modification time (using SetModTime) 2024/12/13 04:53:43 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2024/12/13 04:53:43 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2024/12/13 04:53:43 INFO : Synching Path1 "TestB2:rclone-test-lihejen9waza/045323ni/check_access_filters/path1/" with Path2 "/tmp/045323ni/check_access_filters/path2/" 2024/12/13 04:53:43 INFO : Using filters file /tmp/045323ni/workdir/exclude-other-filtersfile.txt 2024/12/13 04:53:43 INFO : Storing filters file hash to /tmp/045323ni/workdir/exclude-other-filtersfile.txt.md5 2024/12/13 04:53:43 INFO : Copying Path2 files to Path1 2024/12/13 04:53:43 INFO : - Path2 Resync is copying files to - Path1 2024/12/13 04:53:44 INFO : - Path1 Resync is copying files to - Path2 2024/12/13 04:53:45 INFO : Resync updating listings 2024/12/13 04:53:45 INFO : Validating listings for Path1 "TestB2:rclone-test-lihejen9waza/045323ni/check_access_filters/path1/" vs Path2 "/tmp/045323ni/check_access_filters/path2/" 2024/12/13 04:53:45 INFO : Bisync successful 2024/12/13 04:53:45 NOTICE: (06) : test EXCLUDE - test filters for check access 2024/12/13 04:53:45 NOTICE: (07) : bisync check-access filters-file=/tmp/045323ni/workdir/exclude-other-filtersfile.txt 2024/12/13 04:53:46 INFO : subdir: Set directory modification time (using SetModTime) 2024/12/13 04:53:46 INFO : subdir-not: Set directory modification time (using SetModTime) 2024/12/13 04:53:46 INFO : subdirX: Set directory modification time (using SetModTime) 2024/12/13 04:53:46 INFO : subdir/subdirA: Set directory modification time (using SetModTime) 2024/12/13 04:53:46 INFO : subdir/subdirB: Set directory modification time (using SetModTime) 2024/12/13 04:53:46 INFO : subdir-not/subdir-not2: Set directory modification time (using SetModTime) 2024/12/13 04:53:46 INFO : subdirX/subdirX1: Set directory modification time (using SetModTime) 2024/12/13 04:53:46 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2024/12/13 04:53:46 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2024/12/13 04:53:46 INFO : Synching Path1 "TestB2:rclone-test-lihejen9waza/045323ni/check_access_filters/path1/" with Path2 "/tmp/045323ni/check_access_filters/path2/" 2024/12/13 04:53:46 INFO : Using filters file /tmp/045323ni/workdir/exclude-other-filtersfile.txt 2024/12/13 04:53:46 INFO : Building Path1 and Path2 listings 2024/12/13 04:53:46 INFO : Path1 checking for diffs 2024/12/13 04:53:46 INFO : Path2 checking for diffs 2024/12/13 04:53:46 INFO : Checking access health 2024/12/13 04:53:46 INFO : Found 3 matching "RCLONE_TEST" files on both paths 2024/12/13 04:53:46 INFO : No changes found 2024/12/13 04:53:46 INFO : Updating listings 2024/12/13 04:53:46 INFO : Validating listings for Path1 "TestB2:rclone-test-lihejen9waza/045323ni/check_access_filters/path1/" vs Path2 "/tmp/045323ni/check_access_filters/path2/" 2024/12/13 04:53:46 INFO : Bisync successful 2024/12/13 04:53:46 NOTICE: (08) : copy-listings exclude-initial 2024/12/13 04:53:46 NOTICE: (09) : test EXCLUDE - delete RCLONE_TEST files in excluded directories 2024/12/13 04:53:46 NOTICE: (10) : delete-file /tmp/045323ni/check_access_filters/path2/subdir/subdirA/RCLONE_TEST 2024/12/13 04:53:46 INFO : RCLONE_TEST: Deleted 2024/12/13 04:53:46 NOTICE: (11) : delete-file TestB2:rclone-test-lihejen9waza/045323ni/check_access_filters/path1/subdir-not/RCLONE_TEST 2024/12/13 04:53:48 INFO : RCLONE_TEST: Deleted 2024/12/13 04:53:48 NOTICE: (12) : delete-file /tmp/045323ni/check_access_filters/path2/subdir-not/subdir-not2/RCLONE_TEST 2024/12/13 04:53:48 INFO : RCLONE_TEST: Deleted 2024/12/13 04:53:48 NOTICE: (13) : delete-file TestB2:rclone-test-lihejen9waza/045323ni/check_access_filters/path1/subdirX/RCLONE_TEST 2024/12/13 04:53:50 INFO : RCLONE_TEST: Deleted 2024/12/13 04:53:50 NOTICE: (14) : test EXCLUDE - test should PASS 2024/12/13 04:53:50 NOTICE: (15) : bisync check-access filters-file=/tmp/045323ni/workdir/exclude-other-filtersfile.txt 2024/12/13 04:53:52 INFO : subdir: Set directory modification time (using SetModTime) 2024/12/13 04:53:52 INFO : subdir-not: Set directory modification time (using SetModTime) 2024/12/13 04:53:52 INFO : subdirX: Set directory modification time (using SetModTime) 2024/12/13 04:53:52 INFO : subdir/subdirA: Set directory modification time (using SetModTime) 2024/12/13 04:53:52 INFO : subdir/subdirB: Set directory modification time (using SetModTime) 2024/12/13 04:53:52 INFO : subdir-not/subdir-not2: Set directory modification time (using SetModTime) 2024/12/13 04:53:52 INFO : subdirX/subdirX1: Set directory modification time (using SetModTime) 2024/12/13 04:53:52 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2024/12/13 04:53:52 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2024/12/13 04:53:52 INFO : Synching Path1 "TestB2:rclone-test-lihejen9waza/045323ni/check_access_filters/path1/" with Path2 "/tmp/045323ni/check_access_filters/path2/" 2024/12/13 04:53:52 INFO : Using filters file /tmp/045323ni/workdir/exclude-other-filtersfile.txt 2024/12/13 04:53:52 INFO : Building Path1 and Path2 listings 2024/12/13 04:53:53 INFO : Path1 checking for diffs 2024/12/13 04:53:53 INFO : Path2 checking for diffs 2024/12/13 04:53:53 INFO : Checking access health 2024/12/13 04:53:53 INFO : Found 3 matching "RCLONE_TEST" files on both paths 2024/12/13 04:53:53 INFO : No changes found 2024/12/13 04:53:53 INFO : Updating listings 2024/12/13 04:53:53 INFO : Validating listings for Path1 "TestB2:rclone-test-lihejen9waza/045323ni/check_access_filters/path1/" vs Path2 "/tmp/045323ni/check_access_filters/path2/" 2024/12/13 04:53:53 INFO : Bisync successful 2024/12/13 04:53:53 NOTICE: (16) : copy-listings exclude-pass-run 2024/12/13 04:53:53 NOTICE: (17) : test EXCLUDE - delete RCLONE_TEST files in included directories 2024/12/13 04:53:53 NOTICE: (18) : delete-file /tmp/045323ni/check_access_filters/path2/RCLONE_TEST 2024/12/13 04:53:53 INFO : RCLONE_TEST: Deleted 2024/12/13 04:53:53 NOTICE: (19) : delete-file TestB2:rclone-test-lihejen9waza/045323ni/check_access_filters/path1/subdir/RCLONE_TEST 2024/12/13 04:53:55 INFO : RCLONE_TEST: Deleted 2024/12/13 04:53:55 NOTICE: (20) : test EXCLUDE - test should ABORT 2024/12/13 04:53:55 NOTICE: (21) : bisync check-access filters-file=/tmp/045323ni/workdir/exclude-other-filtersfile.txt 2024/12/13 04:53:57 INFO : subdir: Set directory modification time (using SetModTime) 2024/12/13 04:53:57 INFO : subdir-not: Set directory modification time (using SetModTime) 2024/12/13 04:53:57 INFO : subdirX: Set directory modification time (using SetModTime) 2024/12/13 04:53:57 INFO : subdirX/subdirX1: Set directory modification time (using SetModTime) 2024/12/13 04:53:57 INFO : subdir-not/subdir-not2: Set directory modification time (using SetModTime) 2024/12/13 04:53:57 INFO : subdir/subdirA: Set directory modification time (using SetModTime) 2024/12/13 04:53:57 INFO : subdir/subdirB: Set directory modification time (using SetModTime) 2024/12/13 04:53:57 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2024/12/13 04:53:57 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2024/12/13 04:53:57 INFO : Synching Path1 "TestB2:rclone-test-lihejen9waza/045323ni/check_access_filters/path1/" with Path2 "/tmp/045323ni/check_access_filters/path2/" 2024/12/13 04:53:57 INFO : Using filters file /tmp/045323ni/workdir/exclude-other-filtersfile.txt 2024/12/13 04:53:57 INFO : Building Path1 and Path2 listings 2024/12/13 04:53:57 INFO : Path1 checking for diffs 2024/12/13 04:53:57 INFO : - Path1 File was deleted - subdir/RCLONE_TEST 2024/12/13 04:53:57 INFO : Path1: 1 changes:  0 new,  0 modified,  1 deleted 2024/12/13 04:53:57 INFO : Path2 checking for diffs 2024/12/13 04:53:57 INFO : - Path2 File was deleted - RCLONE_TEST 2024/12/13 04:53:57 INFO : Path2: 1 changes:  0 new,  0 modified,  1 deleted 2024/12/13 04:53:57 INFO : Checking access health 2024/12/13 04:53:57 ERROR : -  Access test failed: Path1 file not found in Path2 - RCLONE_TEST 2024/12/13 04:53:57 ERROR : -  Access test failed: Path2 file not found in Path1 - subdir/RCLONE_TEST 2024/12/13 04:53:57 ERROR : Bisync critical error: check file check failed 2024/12/13 04:53:57 ERROR : Bisync aborted. Must run --resync to recover. 2024/12/13 04:53:57 NOTICE: Bisync error: bisync aborted 2024/12/13 04:53:57 NOTICE: (22) : move-listings exclude-error-run 2024/12/13 04:53:57 NOTICE: (23) : test INCLUDE - OTHER TESTS 2024/12/13 04:53:57 NOTICE: (24) : test reset to the initial state 2024/12/13 04:53:57 NOTICE: (25) : copy-dir /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access_filters/initial TestB2:rclone-test-lihejen9waza/045323ni/check_access_filters/path1/ 2024/12/13 04:53:59 INFO : subdirX/RCLONE_TEST: Copied (new) 2024/12/13 04:54:00 INFO : subdir/RCLONE_TEST: Copied (new) 2024/12/13 04:54:00 INFO : subdir-not/RCLONE_TEST: Copied (new) 2024/12/13 04:54:00 NOTICE: (26) : sync-dir TestB2:rclone-test-lihejen9waza/045323ni/check_access_filters/path1/ /tmp/045323ni/check_access_filters/path2/ 2024/12/13 04:54:00 INFO : RCLONE_TEST: Copied (new) 2024/12/13 04:54:01 INFO : subdir/subdirA/RCLONE_TEST: Copied (new) 2024/12/13 04:54:01 INFO : subdir-not/subdir-not2/RCLONE_TEST: Copied (new) 2024/12/13 04:54:01 NOTICE: (27) : copy-file /tmp/045323ni/datadir/test_check_access_filters-setelaz0/include-other-filtersfile.txt /tmp/045323ni/workdir/ 2024/12/13 04:54:01 INFO : include-other-filtersfile.txt: Copied (new) 2024/12/13 04:54:01 NOTICE: (28) : bisync resync filters-file=/tmp/045323ni/workdir/include-other-filtersfile.txt bisync_test.go:966: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:966 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:976 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:1041 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:745 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:492 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:356 Error: Received unexpected error: Post "https://pod-000-1117-18.backblaze.com/b2api/v1/b2_upload_file/4f924d8350ddbbeb9f380e1b/c001_v0001117_t0008": EOF Test: TestBisyncRemoteLocal/check_access_filters 2024/12/13 04:54:01 DEBUG : B2 bucket rclone-test-lihejen9waza: Purge remote 2024/12/13 04:54:01 INFO : B2 bucket rclone-test-lihejen9waza: cleaning bucket "rclone-test-lihejen9waza" of all files 2024/12/13 04:54:02 DEBUG : 045323ni/check_access_filters/path1/RCLONE_TEST: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f103f27ca60f35ad5_d20241213_m045341_c001_v0001172_t0011_u01734065621122") 2024/12/13 04:54:02 DEBUG : 045323ni/check_access_filters/path1/file1.txt: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f109089eb634f0b93_d20241213_m045340_c001_v0001183_t0032_u01734065620746") 2024/12/13 04:54:02 DEBUG : 045323ni/check_access_filters/path1/file2.txt: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f10836f1c7df56c2e_d20241213_m045340_c001_v0001137_t0031_u01734065620935") 2024/12/13 04:54:02 DEBUG : 045323ni/check_access_filters/path1/file3.txt: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f1188e2a4b3f8661a_d20241213_m045341_c001_v0001117_t0045_u01734065621308") 2024/12/13 04:54:02 DEBUG : 045323ni/check_access_filters/path1/file4.txt: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f109089eb634f0ba7_d20241213_m045341_c001_v0001183_t0015_u01734065621001") 2024/12/13 04:54:02 DEBUG : 045323ni/check_access_filters/path1/modtime_write_test: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f4137a25646268efb_d20241213_m045357_c001_v7007000_t0000_u01734065637285") 2024/12/13 04:54:02 DEBUG : 045323ni/check_access_filters/path1/modtime_write_test: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f10165b681c459f28_d20241213_m045356_c001_v0001101_t0024_u01734065636788") 2024/12/13 04:54:02 DEBUG : 045323ni/check_access_filters/path1/modtime_write_test: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f1188e2a4b3f8665d_d20241213_m045356_c001_v0001117_t0017_u01734065636032") 2024/12/13 04:54:02 DEBUG : 045323ni/check_access_filters/path1/modtime_write_test: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f4137a25646268efa_d20241213_m045352_c001_v7007000_t0000_u01734065632871") 2024/12/13 04:54:02 DEBUG : 045323ni/check_access_filters/path1/modtime_write_test: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f104fcd022560e48c_d20241213_m045352_c001_v0001183_t0055_u01734065632644") 2024/12/13 04:54:02 DEBUG : 045323ni/check_access_filters/path1/modtime_write_test: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f10836f1c7df56c4e_d20241213_m045351_c001_v0001137_t0018_u01734065631376") 2024/12/13 04:54:02 DEBUG : 045323ni/check_access_filters/path1/modtime_write_test: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f403661e5c9ae774f_d20241213_m045346_c001_v7007000_t0000_u01734065626214") 2024/12/13 04:54:02 DEBUG : 045323ni/check_access_filters/path1/modtime_write_test: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f1134ce6e81362bb8_d20241213_m045345_c001_v0001180_t0047_u01734065625945") 2024/12/13 04:54:02 DEBUG : 045323ni/check_access_filters/path1/modtime_write_test: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f103f27ca60f35af9_d20241213_m045345_c001_v0001172_t0017_u01734065625123") 2024/12/13 04:54:02 DEBUG : 045323ni/check_access_filters/path1/modtime_write_test: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f403661e5c9ae774b_d20241213_m045343_c001_v7007000_t0000_u01734065623827") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/modtime_write_test: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f112152a5f4b68f70_d20241213_m045343_c001_v0001183_t0040_u01734065623610") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/modtime_write_test: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f109089eb634f0c2d_d20241213_m045343_c001_v0001183_t0038_u01734065623182") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdir-not/RCLONE_TEST: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f10836f1c7df56c70_d20241213_m045400_c001_v0001137_t0047_u01734065640216") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdir-not/RCLONE_TEST: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f407af66b016ec707_d20241213_m045348_c001_v7007000_t0000_u01734065628777") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdir-not/RCLONE_TEST: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f103f27ca60f35add_d20241213_m045341_c001_v0001172_t0026_u01734065621677") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdir-not/file20.txt: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f109089eb634f0bd9_d20241213_m045341_c001_v0001183_t0009_u01734065621710") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdir-not/subdir-not2/RCLONE_TEST: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f109089eb634f0c00_d20241213_m045342_c001_v0001183_t0018_u01734065622410") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdir-not/subdir-not2/file30.txt: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f10836f1c7df56c38_d20241213_m045342_c001_v0001137_t0007_u01734065622413") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdir/RCLONE_TEST: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f103f27ca60f35b37_d20241213_m045400_c001_v0001172_t0027_u01734065640053") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdir/RCLONE_TEST: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f407af66b016ec712_d20241213_m045355_c001_v7007000_t0000_u01734065635470") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdir/RCLONE_TEST: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f10836f1c7df56c34_d20241213_m045341_c001_v0001137_t0035_u01734065621782") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdir/file20.txt: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f109089eb634f0be3_d20241213_m045341_c001_v0001183_t0036_u01734065621938") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdir/subdirA/RCLONE_TEST: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f103f27ca60f35ae1_d20241213_m045342_c001_v0001172_t0018_u01734065622153") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdir/subdirA/file30.txt: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f109089eb634f0bef_d20241213_m045342_c001_v0001183_t0042_u01734065622180") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdir/subdirB/RCLONE_TEST: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f1188e2a4b3f86622_d20241213_m045342_c001_v0001117_t0026_u01734065622038") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdir/subdirB/file30.txt: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f10836f1c7df56c36_d20241213_m045342_c001_v0001137_t0049_u01734065622059") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdirX/RCLONE_TEST: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f109089eb634f0fd8_d20241213_m045359_c001_v0001183_t0005_u01734065639853") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdirX/RCLONE_TEST: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f4074200a604ab392_d20241213_m045350_c001_v7007000_t0000_u01734065630825") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdirX/RCLONE_TEST: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f10836f1c7df56c30_d20241213_m045341_c001_v0001137_t0033_u01734065621196") 2024/12/13 04:54:03 DEBUG : 045323ni/check_access_filters/path1/subdirX/file20.txt: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f109089eb634f0bbf_d20241213_m045341_c001_v0001183_t0044_u01734065621253") 2024/12/13 04:54:04 DEBUG : 045323ni/check_access_filters/path1/subdirX/subdirX1/RCLONE_TEST: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f10836f1c7df56c32_d20241213_m045341_c001_v0001137_t0048_u01734065621457") 2024/12/13 04:54:04 DEBUG : 045323ni/check_access_filters/path1/subdirX/subdirX1/file30.txt: Deleting (id "4_z4f924d8350ddbbeb9f380e1b_f109089eb634f0bca_d20241213_m045341_c001_v0001183_t0035_u01734065621467") --- FAIL: TestBisyncRemoteLocal (42.40s) --- PASS: TestBisyncRemoteLocal/basic (14.68s) --- FAIL: TestBisyncRemoteLocal/check_access_filters (23.72s) FAIL 2024/12/13 04:54:04 DEBUG : B2 bucket rclone-test-jukawuh6ralo: Purge remote 2024/12/13 04:54:04 INFO : B2 bucket rclone-test-jukawuh6ralo: cleaning bucket "rclone-test-jukawuh6ralo" of all files 2024/12/13 04:54:05 NOTICE: purge failed: directory not found "./bisync.test -test.v -test.timeout 1h0m0s -remote TestB2: -list-retries 5 -verbose -test.run '^TestBisyncRemoteLocal$/^(basic|check_access_filters)$'" - Finished ERROR in 43.779854501s (try 3/5): exit status 1: Failed [TestBisyncRemoteLocal/check_access_filters]