"./bisync.test -test.v -test.timeout 1h0m0s -remote TestS3GCS: -verbose -test.run '^TestBisyncLocalRemote$/^filtersfile_checks$|^TestBisyncRemoteLocal$/^filtersfile_checks$'" - Starting (try 2/5) 2025/04/14 02:37:45 DEBUG : Creating backend with remote "TestS3GCS:rclone-test-borudug6tohi" 2025/04/14 02:37:45 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/14 02:37:45 DEBUG : Creating backend with remote "/tmp/rclone1868762098" === RUN TestBisyncRemoteLocal 2025/04/14 02:37:45 DEBUG : Creating backend with remote "TestS3GCS:rclone-test-soxiqor0hiqi" 2025/04/14 02:37:45 NOTICE: remote: TestS3GCS:rclone-test-soxiqor0hiqi === RUN TestBisyncRemoteLocal/filtersfile_checks 2025/04/14 02:37:45 DEBUG : Creating backend with remote "TestS3GCS:rclone-test-soxiqor0hiqi/023745pu" 2025/04/14 02:37:45 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/14 02:37:46 INFO : path1: Making directory 2025/04/14 02:37:47 INFO : S3 bucket rclone-test-soxiqor0hiqi path 023745pu: Bucket "rclone-test-soxiqor0hiqi" created with ACL "" 2025/04/14 02:37:47 DEBUG : Creating backend with remote "TestS3GCS:rclone-test-soxiqor0hiqi/023745pu/filtersfile_checks/path1" 2025/04/14 02:37:47 DEBUG : Creating backend with remote "/tmp/023745pu" 2025/04/14 02:37:47 DEBUG : Creating backend with remote "/tmp/023745pu/filtersfile_checks/path2" 2025/04/14 02:37:47 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_filtersfile_checks/initial" 2025/04/14 02:37:47 DEBUG : Creating backend with remote "/tmp/023745pu/initdir/test_filtersfile_checks-wanuweq9" 2025/04/14 02:37:47 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/04/14 02:37:47 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/04/14 02:37:47 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/04/14 02:37:47 DEBUG : subdir: Making directory with metadata 2025/04/14 02:37:47 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/04/14 02:37:47 DEBUG : Added delayed dir = "subdir", newDst=subdir 2025/04/14 02:37:47 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/04/14 02:37:47 DEBUG : Local file system at /tmp/023745pu/initdir/test_filtersfile_checks-wanuweq9: Waiting for checks to finish 2025/04/14 02:37:47 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:37:47 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt 2025/04/14 02:37:47 INFO : file1.txt: Copied (new) 2025/04/14 02:37:47 DEBUG : Local file system at /tmp/023745pu/initdir/test_filtersfile_checks-wanuweq9: Waiting for transfers to finish 2025/04/14 02:37:47 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:37:47 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:37:47 DEBUG : subdir/file20.txt.5028a97.partial: renamed to: subdir/file20.txt 2025/04/14 02:37:47 INFO : subdir/file20.txt: Copied (new) 2025/04/14 02:37:47 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt 2025/04/14 02:37:47 INFO : file2.txt: Copied (new) 2025/04/14 02:37:47 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/04/14 02:37:47 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST 2025/04/14 02:37:47 INFO : RCLONE_TEST: Copied (new) 2025/04/14 02:37:47 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:37:47 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_filtersfile_checks/modfiles" 2025/04/14 02:37:47 DEBUG : Creating backend with remote "/tmp/023745pu/datadir/test_filtersfile_checks-yirahaj4" 2025/04/14 02:37:47 DEBUG : filtersfile.txt: Need to transfer - File not found at Destination 2025/04/14 02:37:47 DEBUG : filtersfile2.txt: Need to transfer - File not found at Destination 2025/04/14 02:37:47 DEBUG : hold.txt: Need to transfer - File not found at Destination 2025/04/14 02:37:47 DEBUG : Local file system at /tmp/023745pu/datadir/test_filtersfile_checks-yirahaj4: Waiting for checks to finish 2025/04/14 02:37:47 DEBUG : Local file system at /tmp/023745pu/datadir/test_filtersfile_checks-yirahaj4: Waiting for transfers to finish 2025/04/14 02:37:47 DEBUG : filtersfile.txt: md5 = cbf4389cb34d9e160689d1578eb5707f OK 2025/04/14 02:37:47 DEBUG : filtersfile.txt.f1af69b0.partial: renamed to: filtersfile.txt 2025/04/14 02:37:47 INFO : filtersfile.txt: Copied (new) 2025/04/14 02:37:47 DEBUG : filtersfile2.txt: md5 = 95acc1e3b5beda465d9b2cb32808588c OK 2025/04/14 02:37:47 DEBUG : hold.txt: md5 = 628c2241b6ba4e313ef08bdfcf1cd964 OK 2025/04/14 02:37:47 DEBUG : hold.txt.627e309f.partial: renamed to: hold.txt 2025/04/14 02:37:47 INFO : hold.txt: Copied (new) 2025/04/14 02:37:47 DEBUG : filtersfile2.txt.9f8671d3.partial: renamed to: filtersfile2.txt 2025/04/14 02:37:47 INFO : filtersfile2.txt: Copied (new) 2025/04/14 02:37:48 ERROR : : error listing: directory not found 2025/04/14 02:37:48 NOTICE: checking initFs Local file system at /tmp/023745pu/initdir/test_filtersfile_checks-wanuweq9 2025/04/14 02:37:49 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/04/14 02:37:49 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/04/14 02:37:49 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/04/14 02:37:49 INFO : subdir: Making directory 2025/04/14 02:37:49 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/04/14 02:37:49 DEBUG : S3 bucket rclone-test-soxiqor0hiqi path 023745pu/filtersfile_checks/path1: Waiting for checks to finish 2025/04/14 02:37:49 DEBUG : S3 bucket rclone-test-soxiqor0hiqi path 023745pu/filtersfile_checks/path1: Waiting for transfers to finish 2025/04/14 02:37:49 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:37:49 INFO : file2.txt: Copied (new) 2025/04/14 02:37:49 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:37:49 INFO : subdir/file20.txt: Copied (new) 2025/04/14 02:37:49 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/04/14 02:37:49 INFO : RCLONE_TEST: Copied (new) 2025/04/14 02:37:49 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:37:49 INFO : file1.txt: Copied (new) 2025/04/14 02:37:49 NOTICE: checking Path1 S3 bucket rclone-test-soxiqor0hiqi path 023745pu/filtersfile_checks/path1 2025/04/14 02:37:50 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/04/14 02:37:50 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/04/14 02:37:50 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/04/14 02:37:50 DEBUG : subdir: Making directory with metadata 2025/04/14 02:37:50 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/04/14 02:37:50 DEBUG : Added delayed dir = "subdir", newDst=subdir 2025/04/14 02:37:50 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/04/14 02:37:50 DEBUG : Local file system at /tmp/023745pu/filtersfile_checks/path2: Waiting for checks to finish 2025/04/14 02:37:50 DEBUG : Local file system at /tmp/023745pu/filtersfile_checks/path2: Waiting for transfers to finish 2025/04/14 02:37:50 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:37:50 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt 2025/04/14 02:37:50 INFO : file1.txt: Copied (new) 2025/04/14 02:37:50 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:37:50 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:37:50 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt 2025/04/14 02:37:50 INFO : file2.txt: Copied (new) 2025/04/14 02:37:50 DEBUG : subdir/file20.txt.5028a97.partial: renamed to: subdir/file20.txt 2025/04/14 02:37:50 INFO : subdir/file20.txt: Copied (new) 2025/04/14 02:37:50 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/04/14 02:37:50 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST 2025/04/14 02:37:50 INFO : RCLONE_TEST: Copied (new) 2025/04/14 02:37:50 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:37:50 NOTICE: checking path2 Local file system at /tmp/023745pu/filtersfile_checks/path2 2025/04/14 02:37:50 NOTICE: [36m(01) :[0m [34mtest filtersfile-checks[0m 2025/04/14 02:37:50 NOTICE: [36m(02) :[0m [34mtest initial bisync[0m 2025/04/14 02:37:50 NOTICE: [36m(03) :[0m [34mbisync resync[0m 2025/04/14 02:37:51 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:37:51 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m 2025/04/14 02:37: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/04/14 02:37:51 INFO : Synching Path1 "TestS3GCS:rclone-test-soxiqor0hiqi/023745pu/filtersfile_checks/path1/" with Path2 "/tmp/023745pu/filtersfile_checks/path2/" 2025/04/14 02:37:51 INFO : Copying Path2 files to Path1 2025/04/14 02:37:51 INFO : - [34mPath2[0m [35mResync is copying files to[0m - [36mPath1[0m 2025/04/14 02:37:52 INFO : - [36mPath1[0m [35mResync is copying files to[0m - [36mPath2[0m 2025/04/14 02:37:53 INFO : Resync updating listings 2025/04/14 02:37:53 INFO : Validating listings for Path1 "TestS3GCS:rclone-test-soxiqor0hiqi/023745pu/filtersfile_checks/path1/" vs Path2 "/tmp/023745pu/filtersfile_checks/path2/" 2025/04/14 02:37:53 INFO : [32mBisync successful[0m 2025/04/14 02:37:53 NOTICE: [36m(04) :[0m [34mtest 1. inject filters file in workdir.[0m 2025/04/14 02:37:53 NOTICE: [36m(05) :[0m [34mcopy-file /tmp/023745pu/datadir/test_filtersfile_checks-yirahaj4/filtersfile.txt /tmp/023745pu/workdir/[0m 2025/04/14 02:37:53 INFO : filtersfile.txt: Copied (new) 2025/04/14 02:37:53 NOTICE: [36m(06) :[0m [34mtest 2. run with filters-file but without md5. should abort.[0m 2025/04/14 02:37:53 NOTICE: [36m(07) :[0m [34mbisync filters-file=/tmp/023745pu/workdir/filtersfile.txt[0m 2025/04/14 02:37:54 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:37:54 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m 2025/04/14 02:37:54 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/04/14 02:37:54 INFO : Synching Path1 "TestS3GCS:rclone-test-soxiqor0hiqi/023745pu/filtersfile_checks/path1/" with Path2 "/tmp/023745pu/filtersfile_checks/path2/" 2025/04/14 02:37:54 INFO : Using filters file /tmp/023745pu/workdir/filtersfile.txt 2025/04/14 02:37:54 ERROR : [31mBisync critical error: filters file md5 hash not found (must run --resync): /tmp/023745pu/workdir/filtersfile.txt[0m 2025/04/14 02:37:54 ERROR : [31mBisync aborted. Must run --resync to recover.[0m 2025/04/14 02:37:54 NOTICE: Bisync error: bisync aborted 2025/04/14 02:37:54 NOTICE: [36m(08) :[0m [34mtest 3. run without filters-file. should be blocked due to prior abort.[0m 2025/04/14 02:37:54 NOTICE: [36m(09) :[0m [34mbisync[0m 2025/04/14 02:37:55 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:37:55 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m 2025/04/14 02:37:55 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/04/14 02:37:55 INFO : Synching Path1 "TestS3GCS:rclone-test-soxiqor0hiqi/023745pu/filtersfile_checks/path1/" with Path2 "/tmp/023745pu/filtersfile_checks/path2/" 2025/04/14 02:37:55 ERROR : [31mBisync critical error: cannot find prior Path1 or Path2 listings, likely due to critical error on prior run [35mTip: here are the filenames we were looking for. Do they exist? [0m[36mPath1: [94m/tmp/023745pu/workdir/TestS3GCS_rclone-test-soxiqor0hiqi_023745pu_filtersfile_checks_path1..tmp_023745pu_filtersfile_checks_path2.path1.lst[0m [0m[36mPath2: [94m/tmp/023745pu/workdir/TestS3GCS_rclone-test-soxiqor0hiqi_023745pu_filtersfile_checks_path1..tmp_023745pu_filtersfile_checks_path2.path2.lst[0m [0m[35mTry running this command to inspect the work dir: [0m[96mrclone lsl "/tmp/023745pu/workdir"[0m[0m 2025/04/14 02:37:55 ERROR : [31mBisync aborted. Must run --resync to recover.[0m 2025/04/14 02:37:55 NOTICE: Bisync error: bisync aborted 2025/04/14 02:37:55 NOTICE: [36m(10) :[0m [34mtest 4. run with filters-file and resync.[0m 2025/04/14 02:37:55 NOTICE: [36m(11) :[0m [34mbisync filters-file=/tmp/023745pu/workdir/filtersfile.txt resync[0m 2025/04/14 02:37:56 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:37:56 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m 2025/04/14 02:37:56 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/04/14 02:37:56 INFO : Synching Path1 "TestS3GCS:rclone-test-soxiqor0hiqi/023745pu/filtersfile_checks/path1/" with Path2 "/tmp/023745pu/filtersfile_checks/path2/" 2025/04/14 02:37:56 INFO : Using filters file /tmp/023745pu/workdir/filtersfile.txt 2025/04/14 02:37:56 INFO : Storing filters file hash to /tmp/023745pu/workdir/filtersfile.txt.md5 2025/04/14 02:37:56 INFO : Copying Path2 files to Path1 2025/04/14 02:37:56 INFO : - [34mPath2[0m [35mResync is copying files to[0m - [36mPath1[0m 2025/04/14 02:37:57 INFO : - [36mPath1[0m [35mResync is copying files to[0m - [36mPath2[0m 2025/04/14 02:37:58 INFO : Resync updating listings 2025/04/14 02:37:58 INFO : Validating listings for Path1 "TestS3GCS:rclone-test-soxiqor0hiqi/023745pu/filtersfile_checks/path1/" vs Path2 "/tmp/023745pu/filtersfile_checks/path2/" 2025/04/14 02:37:58 INFO : [32mBisync successful[0m 2025/04/14 02:37:58 NOTICE: [36m(12) :[0m [34mtest 5. run with filters-file alone. should run.[0m 2025/04/14 02:37:58 NOTICE: [36m(13) :[0m [34mbisync filters-file=/tmp/023745pu/workdir/filtersfile.txt[0m 2025/04/14 02:37:59 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:37:59 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m 2025/04/14 02:37:59 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/04/14 02:37:59 INFO : Synching Path1 "TestS3GCS:rclone-test-soxiqor0hiqi/023745pu/filtersfile_checks/path1/" with Path2 "/tmp/023745pu/filtersfile_checks/path2/" 2025/04/14 02:37:59 INFO : Using filters file /tmp/023745pu/workdir/filtersfile.txt 2025/04/14 02:37:59 INFO : Building Path1 and Path2 listings 2025/04/14 02:38:00 INFO : Path1 checking for diffs 2025/04/14 02:38:00 INFO : Path2 checking for diffs 2025/04/14 02:38:00 INFO : No changes found 2025/04/14 02:38:00 INFO : Updating listings 2025/04/14 02:38:00 INFO : Validating listings for Path1 "TestS3GCS:rclone-test-soxiqor0hiqi/023745pu/filtersfile_checks/path1/" vs Path2 "/tmp/023745pu/filtersfile_checks/path2/" 2025/04/14 02:38:00 INFO : [32mBisync successful[0m 2025/04/14 02:38:00 NOTICE: [36m(14) :[0m [34mtest 6. push changed filters-file to workdir.[0m 2025/04/14 02:38:00 NOTICE: [36m(15) :[0m [34mcopy-as /tmp/023745pu/datadir/test_filtersfile_checks-yirahaj4/filtersfile2.txt /tmp/023745pu/workdir/ filtersfile.txt[0m 2025/04/14 02:38:00 INFO : filtersfile2.txt: Copied (replaced existing) to: filtersfile.txt 2025/04/14 02:38:00 NOTICE: [36m(16) :[0m [34mtest 7. run with filters-file alone. should abort.[0m 2025/04/14 02:38:00 NOTICE: [36m(17) :[0m [34mbisync filters-file=/tmp/023745pu/workdir/filtersfile.txt[0m 2025/04/14 02:38:02 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:38:02 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m 2025/04/14 02:38:02 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/04/14 02:38:02 INFO : Synching Path1 "TestS3GCS:rclone-test-soxiqor0hiqi/023745pu/filtersfile_checks/path1/" with Path2 "/tmp/023745pu/filtersfile_checks/path2/" 2025/04/14 02:38:02 INFO : Using filters file /tmp/023745pu/workdir/filtersfile.txt 2025/04/14 02:38:02 ERROR : [31mBisync critical error: filters file has changed (must run --resync): /tmp/023745pu/workdir/filtersfile.txt[0m 2025/04/14 02:38:02 ERROR : [31mBisync aborted. Must run --resync to recover.[0m 2025/04/14 02:38:02 NOTICE: Bisync error: bisync aborted 2025/04/14 02:38:02 NOTICE: [36m(18) :[0m [34mtest 8. run with filters-file and resync and dry-run. should do the dry-run but still cause next non-resync run to abort.[0m 2025/04/14 02:38:02 NOTICE: [36m(19) :[0m [34mbisync filters-file=/tmp/023745pu/workdir/filtersfile.txt resync dry-run[0m 2025/04/14 02:38:03 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:38:03 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m 2025/04/14 02:38: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/04/14 02:38:03 INFO : Synching Path1 "TestS3GCS:rclone-test-soxiqor0hiqi/023745pu/filtersfile_checks/path1/" with Path2 "/tmp/023745pu/filtersfile_checks/path2/" 2025/04/14 02:38:03 INFO : Using filters file /tmp/023745pu/workdir/filtersfile.txt 2025/04/14 02:38:03 INFO : Skipped storing filters file hash to /tmp/023745pu/workdir/filtersfile.txt.md5 as --dry-run is set 2025/04/14 02:38:03 INFO : Copying Path2 files to Path1 2025/04/14 02:38:03 NOTICE: - [34mPath2[0m [35mResync is copying files to[0m - [36mPath1[0m 2025/04/14 02:38:04 NOTICE: - [36mPath1[0m [35mResync is copying files to[0m - [36mPath2[0m 2025/04/14 02:38:05 INFO : Resync updating listings 2025/04/14 02:38:05 INFO : [32mBisync successful[0m 2025/04/14 02:38:05 NOTICE: [36m(20) :[0m [34mtest 9. run with filters-file alone. should abort.[0m 2025/04/14 02:38:05 NOTICE: [36m(21) :[0m [34mbisync filters-file=/tmp/023745pu/workdir/filtersfile.txt[0m 2025/04/14 02:38:06 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:38:06 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m 2025/04/14 02:38: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/04/14 02:38:06 INFO : Synching Path1 "TestS3GCS:rclone-test-soxiqor0hiqi/023745pu/filtersfile_checks/path1/" with Path2 "/tmp/023745pu/filtersfile_checks/path2/" 2025/04/14 02:38:06 INFO : Using filters file /tmp/023745pu/workdir/filtersfile.txt 2025/04/14 02:38:06 ERROR : [31mBisync critical error: filters file has changed (must run --resync): /tmp/023745pu/workdir/filtersfile.txt[0m 2025/04/14 02:38:06 ERROR : [31mBisync aborted. Must run --resync to recover.[0m 2025/04/14 02:38:06 NOTICE: Bisync error: bisync aborted bisync_test.go:560: [32mTEST filtersfile_checks PASSED[0m 2025/04/14 02:38:06 DEBUG : S3 bucket rclone-test-soxiqor0hiqi: Purge remote 2025/04/14 02:38:07 DEBUG : S3 bucket rclone-test-soxiqor0hiqi: bucket is versioned: false 2025/04/14 02:38:07 DEBUG : Waiting for deletions to finish 2025/04/14 02:38:08 INFO : S3 bucket rclone-test-soxiqor0hiqi: Bucket "rclone-test-soxiqor0hiqi" deleted --- PASS: TestBisyncRemoteLocal (22.17s) --- PASS: TestBisyncRemoteLocal/filtersfile_checks (21.00s) === RUN TestBisyncLocalRemote 2025/04/14 02:38:08 DEBUG : Creating backend with remote "TestS3GCS:rclone-test-nejelix4tupe" 2025/04/14 02:38:08 NOTICE: remote: TestS3GCS:rclone-test-nejelix4tupe === RUN TestBisyncLocalRemote/filtersfile_checks 2025/04/14 02:38:08 DEBUG : Creating backend with remote "/tmp/023808ho" 2025/04/14 02:38:08 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/14 02:38:08 DEBUG : Creating backend with remote "/tmp/023808ho/filtersfile_checks/path1" 2025/04/14 02:38:08 DEBUG : Creating backend with remote "TestS3GCS:rclone-test-nejelix4tupe/023808ho" 2025/04/14 02:38:08 INFO : path2: Making directory 2025/04/14 02:38:09 INFO : S3 bucket rclone-test-nejelix4tupe path 023808ho: Bucket "rclone-test-nejelix4tupe" created with ACL "" 2025/04/14 02:38:09 DEBUG : Creating backend with remote "TestS3GCS:rclone-test-nejelix4tupe/023808ho/filtersfile_checks/path2" 2025/04/14 02:38:10 DEBUG : Creating backend with remote "/tmp/023808ho/initdir/test_filtersfile_checks-qeseyak5" 2025/04/14 02:38:10 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/04/14 02:38:10 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/04/14 02:38:10 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/04/14 02:38:10 DEBUG : subdir: Making directory with metadata 2025/04/14 02:38:10 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/04/14 02:38:10 DEBUG : Added delayed dir = "subdir", newDst=subdir 2025/04/14 02:38:10 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/04/14 02:38:10 DEBUG : Local file system at /tmp/023808ho/initdir/test_filtersfile_checks-qeseyak5: Waiting for checks to finish 2025/04/14 02:38:10 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:38:10 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt 2025/04/14 02:38:10 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:38:10 INFO : file1.txt: Copied (new) 2025/04/14 02:38:10 DEBUG : Local file system at /tmp/023808ho/initdir/test_filtersfile_checks-qeseyak5: Waiting for transfers to finish 2025/04/14 02:38:10 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt 2025/04/14 02:38:10 INFO : file2.txt: Copied (new) 2025/04/14 02:38:10 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:38:10 DEBUG : subdir/file20.txt.5028a97.partial: renamed to: subdir/file20.txt 2025/04/14 02:38:10 INFO : subdir/file20.txt: Copied (new) 2025/04/14 02:38:10 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/04/14 02:38:10 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST 2025/04/14 02:38:10 INFO : RCLONE_TEST: Copied (new) 2025/04/14 02:38:10 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:38:10 DEBUG : Creating backend with remote "/tmp/023808ho/datadir/test_filtersfile_checks-tewoqel4" 2025/04/14 02:38:10 DEBUG : filtersfile.txt: Need to transfer - File not found at Destination 2025/04/14 02:38:10 DEBUG : filtersfile2.txt: Need to transfer - File not found at Destination 2025/04/14 02:38:10 DEBUG : hold.txt: Need to transfer - File not found at Destination 2025/04/14 02:38:10 DEBUG : Local file system at /tmp/023808ho/datadir/test_filtersfile_checks-tewoqel4: Waiting for checks to finish 2025/04/14 02:38:10 DEBUG : Local file system at /tmp/023808ho/datadir/test_filtersfile_checks-tewoqel4: Waiting for transfers to finish 2025/04/14 02:38:10 DEBUG : filtersfile2.txt: md5 = 95acc1e3b5beda465d9b2cb32808588c OK 2025/04/14 02:38:10 DEBUG : filtersfile2.txt.9f8671d3.partial: renamed to: filtersfile2.txt 2025/04/14 02:38:10 INFO : filtersfile2.txt: Copied (new) 2025/04/14 02:38:10 DEBUG : hold.txt: md5 = 628c2241b6ba4e313ef08bdfcf1cd964 OK 2025/04/14 02:38:10 DEBUG : hold.txt.627e309f.partial: renamed to: hold.txt 2025/04/14 02:38:10 INFO : hold.txt: Copied (new) 2025/04/14 02:38:10 DEBUG : filtersfile.txt: md5 = cbf4389cb34d9e160689d1578eb5707f OK 2025/04/14 02:38:10 DEBUG : filtersfile.txt.f1af69b0.partial: renamed to: filtersfile.txt 2025/04/14 02:38:10 INFO : filtersfile.txt: Copied (new) 2025/04/14 02:38:10 ERROR : : error listing: directory not found 2025/04/14 02:38:11 NOTICE: checking initFs Local file system at /tmp/023808ho/initdir/test_filtersfile_checks-qeseyak5 2025/04/14 02:38:11 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/04/14 02:38:11 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/04/14 02:38:11 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/04/14 02:38:11 DEBUG : subdir: Making directory with metadata 2025/04/14 02:38:11 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2025/04/14 02:38:11 DEBUG : Added delayed dir = "subdir", newDst=subdir 2025/04/14 02:38:11 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/04/14 02:38:11 DEBUG : Local file system at /tmp/023808ho/filtersfile_checks/path1: Waiting for checks to finish 2025/04/14 02:38:11 DEBUG : Local file system at /tmp/023808ho/filtersfile_checks/path1: Waiting for transfers to finish 2025/04/14 02:38:11 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:38:11 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt 2025/04/14 02:38:11 INFO : file1.txt: Copied (new) 2025/04/14 02:38:11 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:38:11 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt 2025/04/14 02:38:11 INFO : file2.txt: Copied (new) 2025/04/14 02:38:11 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:38:11 DEBUG : subdir/file20.txt.5028a97.partial: renamed to: subdir/file20.txt 2025/04/14 02:38:11 INFO : subdir/file20.txt: Copied (new) 2025/04/14 02:38:11 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/04/14 02:38:11 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST 2025/04/14 02:38:11 INFO : RCLONE_TEST: Copied (new) 2025/04/14 02:38:11 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:38:11 NOTICE: checking Path1 Local file system at /tmp/023808ho/filtersfile_checks/path1 2025/04/14 02:38:11 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2025/04/14 02:38:11 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/04/14 02:38:11 DEBUG : file2.txt: Need to transfer - File not found at Destination 2025/04/14 02:38:11 INFO : subdir: Making directory 2025/04/14 02:38:11 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2025/04/14 02:38:11 DEBUG : S3 bucket rclone-test-nejelix4tupe path 023808ho/filtersfile_checks/path2: Waiting for checks to finish 2025/04/14 02:38:11 DEBUG : S3 bucket rclone-test-nejelix4tupe path 023808ho/filtersfile_checks/path2: Waiting for transfers to finish 2025/04/14 02:38:11 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2025/04/14 02:38:11 INFO : RCLONE_TEST: Copied (new) 2025/04/14 02:38:11 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:38:11 INFO : subdir/file20.txt: Copied (new) 2025/04/14 02:38:11 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:38:11 INFO : file2.txt: Copied (new) 2025/04/14 02:38:11 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2025/04/14 02:38:11 INFO : file1.txt: Copied (new) 2025/04/14 02:38:11 NOTICE: checking path2 S3 bucket rclone-test-nejelix4tupe path 023808ho/filtersfile_checks/path2 2025/04/14 02:38:12 NOTICE: [36m(01) :[0m [34mtest filtersfile-checks[0m 2025/04/14 02:38:12 NOTICE: [36m(02) :[0m [34mtest initial bisync[0m 2025/04/14 02:38:12 NOTICE: [36m(03) :[0m [34mbisync resync[0m 2025/04/14 02:38:14 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:38:14 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m 2025/04/14 02:38: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/04/14 02:38:14 INFO : Synching Path1 "/tmp/023808ho/filtersfile_checks/path1/" with Path2 "TestS3GCS:rclone-test-nejelix4tupe/023808ho/filtersfile_checks/path2/" 2025/04/14 02:38:14 INFO : Copying Path2 files to Path1 2025/04/14 02:38:14 INFO : - [34mPath2[0m [35mResync is copying files to[0m - [36mPath1[0m 2025/04/14 02:38:15 INFO : - [36mPath1[0m [35mResync is copying files to[0m - [36mPath2[0m 2025/04/14 02:38:15 INFO : Resync updating listings 2025/04/14 02:38:15 INFO : Validating listings for Path1 "/tmp/023808ho/filtersfile_checks/path1/" vs Path2 "TestS3GCS:rclone-test-nejelix4tupe/023808ho/filtersfile_checks/path2/" 2025/04/14 02:38:15 INFO : [32mBisync successful[0m 2025/04/14 02:38:15 NOTICE: [36m(04) :[0m [34mtest 1. inject filters file in workdir.[0m 2025/04/14 02:38:15 NOTICE: [36m(05) :[0m [34mcopy-file /tmp/023808ho/datadir/test_filtersfile_checks-tewoqel4/filtersfile.txt /tmp/023808ho/workdir/[0m 2025/04/14 02:38:15 INFO : filtersfile.txt: Copied (new) 2025/04/14 02:38:15 NOTICE: [36m(06) :[0m [34mtest 2. run with filters-file but without md5. should abort.[0m 2025/04/14 02:38:15 NOTICE: [36m(07) :[0m [34mbisync filters-file=/tmp/023808ho/workdir/filtersfile.txt[0m 2025/04/14 02:38:17 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:38:17 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m 2025/04/14 02:38:17 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/04/14 02:38:17 INFO : Synching Path1 "/tmp/023808ho/filtersfile_checks/path1/" with Path2 "TestS3GCS:rclone-test-nejelix4tupe/023808ho/filtersfile_checks/path2/" 2025/04/14 02:38:17 INFO : Using filters file /tmp/023808ho/workdir/filtersfile.txt 2025/04/14 02:38:17 ERROR : [31mBisync critical error: filters file md5 hash not found (must run --resync): /tmp/023808ho/workdir/filtersfile.txt[0m 2025/04/14 02:38:17 ERROR : [31mBisync aborted. Must run --resync to recover.[0m 2025/04/14 02:38:17 NOTICE: Bisync error: bisync aborted 2025/04/14 02:38:17 NOTICE: [36m(08) :[0m [34mtest 3. run without filters-file. should be blocked due to prior abort.[0m 2025/04/14 02:38:17 NOTICE: [36m(09) :[0m [34mbisync[0m 2025/04/14 02:38:18 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:38:18 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m 2025/04/14 02:38: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/04/14 02:38:18 INFO : Synching Path1 "/tmp/023808ho/filtersfile_checks/path1/" with Path2 "TestS3GCS:rclone-test-nejelix4tupe/023808ho/filtersfile_checks/path2/" 2025/04/14 02:38:18 ERROR : [31mBisync critical error: cannot find prior Path1 or Path2 listings, likely due to critical error on prior run [35mTip: here are the filenames we were looking for. Do they exist? [0m[36mPath1: [94m/tmp/023808ho/workdir/tmp_023808ho_filtersfile_checks_path1..TestS3GCS_rclone-test-nejelix4tupe_023808ho_filtersfile_checks_path2.path1.lst[0m [0m[36mPath2: [94m/tmp/023808ho/workdir/tmp_023808ho_filtersfile_checks_path1..TestS3GCS_rclone-test-nejelix4tupe_023808ho_filtersfile_checks_path2.path2.lst[0m [0m[35mTry running this command to inspect the work dir: [0m[96mrclone lsl "/tmp/023808ho/workdir"[0m[0m 2025/04/14 02:38:18 ERROR : [31mBisync aborted. Must run --resync to recover.[0m 2025/04/14 02:38:18 NOTICE: Bisync error: bisync aborted 2025/04/14 02:38:18 NOTICE: [36m(10) :[0m [34mtest 4. run with filters-file and resync.[0m 2025/04/14 02:38:18 NOTICE: [36m(11) :[0m [34mbisync filters-file=/tmp/023808ho/workdir/filtersfile.txt resync[0m 2025/04/14 02:38:19 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:38:19 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m 2025/04/14 02:38: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/04/14 02:38:19 INFO : Synching Path1 "/tmp/023808ho/filtersfile_checks/path1/" with Path2 "TestS3GCS:rclone-test-nejelix4tupe/023808ho/filtersfile_checks/path2/" 2025/04/14 02:38:19 INFO : Using filters file /tmp/023808ho/workdir/filtersfile.txt 2025/04/14 02:38:19 INFO : Storing filters file hash to /tmp/023808ho/workdir/filtersfile.txt.md5 2025/04/14 02:38:19 INFO : Copying Path2 files to Path1 2025/04/14 02:38:19 INFO : - [34mPath2[0m [35mResync is copying files to[0m - [36mPath1[0m 2025/04/14 02:38:20 INFO : - [36mPath1[0m [35mResync is copying files to[0m - [36mPath2[0m 2025/04/14 02:38:21 INFO : Resync updating listings 2025/04/14 02:38:21 INFO : Validating listings for Path1 "/tmp/023808ho/filtersfile_checks/path1/" vs Path2 "TestS3GCS:rclone-test-nejelix4tupe/023808ho/filtersfile_checks/path2/" 2025/04/14 02:38:21 INFO : [32mBisync successful[0m 2025/04/14 02:38:21 NOTICE: [36m(12) :[0m [34mtest 5. run with filters-file alone. should run.[0m 2025/04/14 02:38:21 NOTICE: [36m(13) :[0m [34mbisync filters-file=/tmp/023808ho/workdir/filtersfile.txt[0m 2025/04/14 02:38:22 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:38:22 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m 2025/04/14 02:38:22 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/04/14 02:38:22 INFO : Synching Path1 "/tmp/023808ho/filtersfile_checks/path1/" with Path2 "TestS3GCS:rclone-test-nejelix4tupe/023808ho/filtersfile_checks/path2/" 2025/04/14 02:38:22 INFO : Using filters file /tmp/023808ho/workdir/filtersfile.txt 2025/04/14 02:38:22 INFO : Building Path1 and Path2 listings 2025/04/14 02:38:23 INFO : Path1 checking for diffs 2025/04/14 02:38:23 INFO : Path2 checking for diffs 2025/04/14 02:38:23 INFO : No changes found 2025/04/14 02:38:23 INFO : Updating listings 2025/04/14 02:38:23 INFO : Validating listings for Path1 "/tmp/023808ho/filtersfile_checks/path1/" vs Path2 "TestS3GCS:rclone-test-nejelix4tupe/023808ho/filtersfile_checks/path2/" 2025/04/14 02:38:23 INFO : [32mBisync successful[0m 2025/04/14 02:38:23 NOTICE: [36m(14) :[0m [34mtest 6. push changed filters-file to workdir.[0m 2025/04/14 02:38:23 NOTICE: [36m(15) :[0m [34mcopy-as /tmp/023808ho/datadir/test_filtersfile_checks-tewoqel4/filtersfile2.txt /tmp/023808ho/workdir/ filtersfile.txt[0m 2025/04/14 02:38:23 INFO : filtersfile2.txt: Copied (replaced existing) to: filtersfile.txt 2025/04/14 02:38:23 NOTICE: [36m(16) :[0m [34mtest 7. run with filters-file alone. should abort.[0m 2025/04/14 02:38:23 NOTICE: [36m(17) :[0m [34mbisync filters-file=/tmp/023808ho/workdir/filtersfile.txt[0m 2025/04/14 02:38:24 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:38:24 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m 2025/04/14 02:38:24 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/04/14 02:38:24 INFO : Synching Path1 "/tmp/023808ho/filtersfile_checks/path1/" with Path2 "TestS3GCS:rclone-test-nejelix4tupe/023808ho/filtersfile_checks/path2/" 2025/04/14 02:38:24 INFO : Using filters file /tmp/023808ho/workdir/filtersfile.txt 2025/04/14 02:38:24 ERROR : [31mBisync critical error: filters file has changed (must run --resync): /tmp/023808ho/workdir/filtersfile.txt[0m 2025/04/14 02:38:24 ERROR : [31mBisync aborted. Must run --resync to recover.[0m 2025/04/14 02:38:24 NOTICE: Bisync error: bisync aborted 2025/04/14 02:38:24 NOTICE: [36m(18) :[0m [34mtest 8. run with filters-file and resync and dry-run. should do the dry-run but still cause next non-resync run to abort.[0m 2025/04/14 02:38:24 NOTICE: [36m(19) :[0m [34mbisync filters-file=/tmp/023808ho/workdir/filtersfile.txt resync dry-run[0m 2025/04/14 02:38:26 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:38:26 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m 2025/04/14 02:38:26 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/04/14 02:38:26 INFO : Synching Path1 "/tmp/023808ho/filtersfile_checks/path1/" with Path2 "TestS3GCS:rclone-test-nejelix4tupe/023808ho/filtersfile_checks/path2/" 2025/04/14 02:38:26 INFO : Using filters file /tmp/023808ho/workdir/filtersfile.txt 2025/04/14 02:38:26 INFO : Skipped storing filters file hash to /tmp/023808ho/workdir/filtersfile.txt.md5 as --dry-run is set 2025/04/14 02:38:26 INFO : Copying Path2 files to Path1 2025/04/14 02:38:26 NOTICE: - [34mPath2[0m [35mResync is copying files to[0m - [36mPath1[0m 2025/04/14 02:38:27 NOTICE: - [36mPath1[0m [35mResync is copying files to[0m - [36mPath2[0m 2025/04/14 02:38:27 INFO : Resync updating listings 2025/04/14 02:38:27 INFO : [32mBisync successful[0m 2025/04/14 02:38:27 NOTICE: [36m(20) :[0m [34mtest 9. run with filters-file alone. should abort.[0m 2025/04/14 02:38:27 NOTICE: [36m(21) :[0m [34mbisync filters-file=/tmp/023808ho/workdir/filtersfile.txt[0m 2025/04/14 02:38:28 INFO : subdir: Set directory modification time (using SetModTime) 2025/04/14 02:38:28 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m 2025/04/14 02:38:28 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2025/04/14 02:38:28 INFO : Synching Path1 "/tmp/023808ho/filtersfile_checks/path1/" with Path2 "TestS3GCS:rclone-test-nejelix4tupe/023808ho/filtersfile_checks/path2/" 2025/04/14 02:38:28 INFO : Using filters file /tmp/023808ho/workdir/filtersfile.txt 2025/04/14 02:38:28 ERROR : [31mBisync critical error: filters file has changed (must run --resync): /tmp/023808ho/workdir/filtersfile.txt[0m 2025/04/14 02:38:28 ERROR : [31mBisync aborted. Must run --resync to recover.[0m 2025/04/14 02:38:28 NOTICE: Bisync error: bisync aborted bisync_test.go:560: [32mTEST filtersfile_checks PASSED[0m 2025/04/14 02:38:29 DEBUG : S3 bucket rclone-test-nejelix4tupe: Purge remote 2025/04/14 02:38:29 DEBUG : S3 bucket rclone-test-nejelix4tupe: bucket is versioned: false 2025/04/14 02:38:29 DEBUG : Waiting for deletions to finish 2025/04/14 02:38:30 INFO : S3 bucket rclone-test-nejelix4tupe: Bucket "rclone-test-nejelix4tupe" deleted --- PASS: TestBisyncLocalRemote (22.63s) --- PASS: TestBisyncLocalRemote/filtersfile_checks (21.54s) PASS 2025/04/14 02:38:30 DEBUG : S3 bucket rclone-test-borudug6tohi: Purge remote 2025/04/14 02:38:31 ERROR : S3 bucket rclone-test-borudug6tohi: Failed to read versioning status, assuming unversioned: operation error S3: GetBucketVersioning, https response error StatusCode: 404, RequestID: , HostID: , api error NoSuchBucket: The specified bucket does not exist. 2025/04/14 02:38:31 DEBUG : S3 bucket rclone-test-borudug6tohi: bucket is versioned: false 2025/04/14 02:38:31 DEBUG : Waiting for deletions to finish 2025/04/14 02:38:32 NOTICE: purge failed: directory not found "./bisync.test -test.v -test.timeout 1h0m0s -remote TestS3GCS: -verbose -test.run '^TestBisyncLocalRemote$/^filtersfile_checks$|^TestBisyncRemoteLocal$/^filtersfile_checks$'" - Finished OK in 46.263887381s (try 2/5)