"./bisync.test -test.v -test.timeout 1h0m0s -remote TestFTPPureftpd: -verbose -test.run '^TestBisyncRemoteRemote$/^(check_access_filters|check_filename)$'" - Starting (try 2/5) 2026/08/31 04:03:40 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-molated8yusu" 2026/08/31 04:03:40 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/08/31 04:03:40 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:03:40 DEBUG : Setting host=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/08/31 04:03:40 DEBUG : Setting user=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/08/31 04:03:40 DEBUG : Setting pass=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/08/31 04:03:40 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/08/31 04:03:40 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:03:40 DEBUG : Setting host=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/08/31 04:03:40 DEBUG : Setting user=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/08/31 04:03:40 DEBUG : Setting pass=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/08/31 04:03:40 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/08/31 04:03:40 DEBUG : ftp://172.17.0.4:21/rclone-test-molated8yusu: Connecting to FTP server 2026/08/31 04:03:40 DEBUG : ftp://172.17.0.4:21/rclone-test-molated8yusu: dial("tcp","172.17.0.4:21") 2026/08/31 04:03:40 DEBUG : ftp://172.17.0.4:21/rclone-test-molated8yusu: > dial: conn=172.17.0.1:59590->172.17.0.4:21, err= 2026/08/31 04:03:44 DEBUG : Creating backend with remote "/tmp/rclone1851032859" === RUN TestBisyncRemoteRemote 2026/08/31 04:03:44 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-tedetoz6cudi" 2026/08/31 04:03:44 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:03:44 DEBUG : Setting host=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/08/31 04:03:44 DEBUG : Setting user=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/08/31 04:03:44 DEBUG : Setting pass=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/08/31 04:03:44 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/08/31 04:03:44 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:03:44 DEBUG : Setting host=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/08/31 04:03:44 DEBUG : Setting user=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/08/31 04:03:44 DEBUG : Setting pass=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/08/31 04:03:44 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/08/31 04:03:44 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: Connecting to FTP server 2026/08/31 04:03:44 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: dial("tcp","172.17.0.4:21") 2026/08/31 04:03:44 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: > dial: conn=172.17.0.1:42832->172.17.0.4:21, err= 2026/08/31 04:03:46 NOTICE: remote: TestFTPPureftpd:rclone-test-tedetoz6cudi === RUN TestBisyncRemoteRemote/check_access_filters 2026/08/31 04:03:47 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-tedetoz6cudi/040346cekojis5" 2026/08/31 04:03:47 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:03:47 DEBUG : Setting host=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/08/31 04:03:47 DEBUG : Setting user=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/08/31 04:03:47 DEBUG : Setting pass=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/08/31 04:03:47 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/08/31 04:03:47 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:03:47 DEBUG : Setting host=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/08/31 04:03:47 DEBUG : Setting user=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/08/31 04:03:47 DEBUG : Setting pass=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/08/31 04:03:47 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/08/31 04:03:47 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5: Connecting to FTP server 2026/08/31 04:03:47 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5: dial("tcp","172.17.0.4:21") 2026/08/31 04:03:47 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5: > dial: conn=172.17.0.1:42850->172.17.0.4:21, err= 2026/08/31 04:03:49 DEBUG : fs cache: renaming cache item "TestFTPPureftpd:rclone-test-tedetoz6cudi/040346cekojis5" to be canonical "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5" 2026/08/31 04:03:49 INFO : path1: Making directory 2026/08/31 04:03:49 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1" 2026/08/31 04:03:49 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:03:49 DEBUG : Setting host=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/08/31 04:03:49 DEBUG : Setting user=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/08/31 04:03:49 DEBUG : Setting pass=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/08/31 04:03:49 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/08/31 04:03:49 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:03:49 DEBUG : Setting host=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/08/31 04:03:49 DEBUG : Setting user=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/08/31 04:03:49 DEBUG : Setting pass=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/08/31 04:03:49 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/08/31 04:03:49 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Connecting to FTP server 2026/08/31 04:03:49 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:03:49 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:42862->172.17.0.4:21, err= 2026/08/31 04:03:52 DEBUG : fs cache: renaming cache item "TestFTPPureftpd:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1" to be canonical "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1" 2026/08/31 04:03:52 DEBUG : fs cache: switching user supplied name "TestFTPPureftpd:rclone-test-tedetoz6cudi/040346cekojis5" for canonical name "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5" 2026/08/31 04:03:52 INFO : path2: Making directory 2026/08/31 04:03:52 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2" 2026/08/31 04:03:52 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:03:52 DEBUG : Setting host=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/08/31 04:03:52 DEBUG : Setting user=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/08/31 04:03:52 DEBUG : Setting pass=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/08/31 04:03:52 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/08/31 04:03:52 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:03:52 DEBUG : Setting host=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/08/31 04:03:52 DEBUG : Setting user=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/08/31 04:03:52 DEBUG : Setting pass=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/08/31 04:03:52 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/08/31 04:03:52 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Connecting to FTP server 2026/08/31 04:03:52 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:03:52 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:45722->172.17.0.4:21, err= 2026/08/31 04:03:54 DEBUG : fs cache: renaming cache item "TestFTPPureftpd:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2" to be canonical "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2" 2026/08/31 04:03:54 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access_filters/initial" 2026/08/31 04:03:54 DEBUG : Creating backend with remote "/tmp/040346cekojis5/initdir/test_check_access_filters-quvujab3" 2026/08/31 04:03:54 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : file3.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : file4.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : subdir-not: Making directory with metadata 2026/08/31 04:03:54 INFO : subdir-not: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2026/08/31 04:03:54 DEBUG : Added delayed dir = "subdir-not", newDst=subdir-not 2026/08/31 04:03:54 DEBUG : subdir: Making directory with metadata 2026/08/31 04:03:54 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2026/08/31 04:03:54 DEBUG : Added delayed dir = "subdir", newDst=subdir 2026/08/31 04:03:54 DEBUG : subdirX: Making directory with metadata 2026/08/31 04:03:54 INFO : subdirX: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2026/08/31 04:03:54 DEBUG : Added delayed dir = "subdirX", newDst=subdirX 2026/08/31 04:03:54 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : subdirX/subdirX1: Making directory with metadata 2026/08/31 04:03:54 INFO : subdirX/subdirX1: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2026/08/31 04:03:54 DEBUG : Added delayed dir = "subdirX/subdirX1", newDst=subdirX/subdirX1 2026/08/31 04:03:54 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/08/31 04:03:54 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/08/31 04:03:54 DEBUG : file2.txt.3230ad67.partial: size = 0 OK 2026/08/31 04:03:54 DEBUG : file3.txt.a74079f2.partial: size = 0 OK 2026/08/31 04:03:54 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : subdir-not/subdir-not2: Making directory with metadata 2026/08/31 04:03:54 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/08/31 04:03:54 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/08/31 04:03:54 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/08/31 04:03:54 INFO : subdir-not/subdir-not2: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2026/08/31 04:03:54 DEBUG : Added delayed dir = "subdir-not/subdir-not2", newDst=subdir-not/subdir-not2 2026/08/31 04:03:54 DEBUG : subdir/subdirA: Making directory with metadata 2026/08/31 04:03:54 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/08/31 04:03:54 INFO : file1.txt: Copied (new) 2026/08/31 04:03:54 INFO : subdir/subdirA: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2026/08/31 04:03:54 DEBUG : Added delayed dir = "subdir/subdirA", newDst=subdir/subdirA 2026/08/31 04:03:54 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/08/31 04:03:54 DEBUG : subdir/subdirB: Making directory with metadata 2026/08/31 04:03:54 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 INFO : subdir/subdirB: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2026/08/31 04:03:54 DEBUG : Added delayed dir = "subdir/subdirB", newDst=subdir/subdirB 2026/08/31 04:03:54 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2026/08/31 04:03:54 INFO : file2.txt: Copied (new) 2026/08/31 04:03:54 DEBUG : file4.txt.fbf05a9b.partial: size = 0 OK 2026/08/31 04:03:54 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/08/31 04:03:54 DEBUG : subdirX/RCLONE_TEST.fd5b40a2.partial: size = 109 OK 2026/08/31 04:03:54 DEBUG : subdirX/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/08/31 04:03:54 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2026/08/31 04:03:54 INFO : file4.txt: Copied (new) 2026/08/31 04:03:54 DEBUG : subdirX/RCLONE_TEST.fd5b40a2.partial: renamed to: subdirX/RCLONE_TEST 2026/08/31 04:03:54 INFO : subdirX/RCLONE_TEST: Copied (new) 2026/08/31 04:03:54 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/08/31 04:03:54 INFO : RCLONE_TEST: Copied (new) 2026/08/31 04:03:54 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2026/08/31 04:03:54 INFO : file3.txt: Copied (new) 2026/08/31 04:03:54 DEBUG : subdirX/file20.txt.0c4add8a.partial: size = 0 OK 2026/08/31 04:03:54 DEBUG : subdirX/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/08/31 04:03:54 DEBUG : subdirX/file20.txt.0c4add8a.partial: renamed to: subdirX/file20.txt 2026/08/31 04:03:54 DEBUG : subdirX/subdirX1/file30.txt.0106cff7.partial: size = 0 OK 2026/08/31 04:03:54 INFO : subdirX/file20.txt: Copied (new) 2026/08/31 04:03:54 DEBUG : subdir-not/file20.txt.e2b8d4dd.partial: size = 0 OK 2026/08/31 04:03:54 DEBUG : subdirX/subdirX1/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/08/31 04:03:54 DEBUG : subdir-not/RCLONE_TEST.16d95000.partial: size = 109 OK 2026/08/31 04:03:54 DEBUG : subdirX/subdirX1/file30.txt.0106cff7.partial: renamed to: subdirX/subdirX1/file30.txt 2026/08/31 04:03:54 INFO : subdirX/subdirX1/file30.txt: Copied (new) 2026/08/31 04:03:54 DEBUG : subdir-not/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/08/31 04:03:54 DEBUG : subdir-not/RCLONE_TEST.16d95000.partial: renamed to: subdir-not/RCLONE_TEST 2026/08/31 04:03:54 INFO : subdir-not/RCLONE_TEST: Copied (new) 2026/08/31 04:03:54 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: size = 109 OK 2026/08/31 04:03:54 DEBUG : subdir-not/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/08/31 04:03:54 DEBUG : subdir-not/file20.txt.e2b8d4dd.partial: renamed to: subdir-not/file20.txt 2026/08/31 04:03:54 INFO : subdir-not/file20.txt: Copied (new) 2026/08/31 04:03:54 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.51791ac5.partial: size = 109 OK 2026/08/31 04:03:54 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK 2026/08/31 04:03:54 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/08/31 04:03:54 DEBUG : subdirX/subdirX1/RCLONE_TEST.09a85483.partial: size = 109 OK 2026/08/31 04:03:54 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2026/08/31 04:03:54 INFO : subdir/file20.txt: Copied (new) 2026/08/31 04:03:54 DEBUG : subdir/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/08/31 04:03:54 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: renamed to: subdir/RCLONE_TEST 2026/08/31 04:03:54 INFO : subdir/RCLONE_TEST: Copied (new) 2026/08/31 04:03:54 DEBUG : subdir/subdirA/RCLONE_TEST.b780822c.partial: size = 109 OK 2026/08/31 04:03:54 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/08/31 04:03:54 DEBUG : subdirX/subdirX1/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/08/31 04:03:54 DEBUG : subdirX/subdirX1/RCLONE_TEST.09a85483.partial: renamed to: subdirX/subdirX1/RCLONE_TEST 2026/08/31 04:03:54 INFO : subdirX/subdirX1/RCLONE_TEST: Copied (new) 2026/08/31 04:03:54 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.51791ac5.partial: renamed to: subdir-not/subdir-not2/RCLONE_TEST 2026/08/31 04:03:54 INFO : subdir-not/subdir-not2/RCLONE_TEST: Copied (new) 2026/08/31 04:03:54 DEBUG : subdir/subdirA/file30.txt.03485624.partial: size = 0 OK 2026/08/31 04:03:54 DEBUG : subdir/subdirA/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/08/31 04:03:54 DEBUG : subdir/subdirA/file30.txt.03485624.partial: renamed to: subdir/subdirA/file30.txt 2026/08/31 04:03:54 INFO : subdir/subdirA/file30.txt: Copied (new) 2026/08/31 04:03:54 DEBUG : subdir/subdirA/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/08/31 04:03:54 DEBUG : subdir-not/subdir-not2/file30.txt.e99a79ee.partial: size = 0 OK 2026/08/31 04:03:54 DEBUG : subdir/subdirA/RCLONE_TEST.b780822c.partial: renamed to: subdir/subdirA/RCLONE_TEST 2026/08/31 04:03:54 INFO : subdir/subdirA/RCLONE_TEST: Copied (new) 2026/08/31 04:03:54 DEBUG : subdir-not/subdir-not2/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/08/31 04:03:54 DEBUG : subdir-not/subdir-not2/file30.txt.e99a79ee.partial: renamed to: subdir-not/subdir-not2/file30.txt 2026/08/31 04:03:54 INFO : subdir-not/subdir-not2/file30.txt: Copied (new) 2026/08/31 04:03:54 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : subdir/subdirB/RCLONE_TEST.37da2e99.partial: size = 109 OK 2026/08/31 04:03:54 DEBUG : subdir/subdirB/RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/08/31 04:03:54 DEBUG : subdir/subdirB/RCLONE_TEST.37da2e99.partial: renamed to: subdir/subdirB/RCLONE_TEST 2026/08/31 04:03:54 INFO : subdir/subdirB/RCLONE_TEST: Copied (new) 2026/08/31 04:03:54 DEBUG : Local file system at /tmp/040346cekojis5/initdir/test_check_access_filters-quvujab3: Waiting for checks to finish 2026/08/31 04:03:54 DEBUG : subdir/subdirB/file30.txt.ca7c4d29.partial: size = 0 OK 2026/08/31 04:03:54 DEBUG : Local file system at /tmp/040346cekojis5/initdir/test_check_access_filters-quvujab3: Waiting for transfers to finish 2026/08/31 04:03:54 DEBUG : subdir/subdirB/file30.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/08/31 04:03:54 DEBUG : subdir/subdirB/file30.txt.ca7c4d29.partial: renamed to: subdir/subdirB/file30.txt 2026/08/31 04:03:54 INFO : subdir/subdirB/file30.txt: Copied (new) 2026/08/31 04:03:54 INFO : subdir-not/subdir-not2: Set directory modification time (using SetModTime) 2026/08/31 04:03:54 INFO : subdirX/subdirX1: Set directory modification time (using SetModTime) 2026/08/31 04:03:54 INFO : subdir/subdirA: Set directory modification time (using SetModTime) 2026/08/31 04:03:54 INFO : subdir/subdirB: Set directory modification time (using SetModTime) 2026/08/31 04:03:54 INFO : subdir-not: Set directory modification time (using SetModTime) 2026/08/31 04:03:54 INFO : subdir: Set directory modification time (using SetModTime) 2026/08/31 04:03:54 INFO : subdirX: Set directory modification time (using SetModTime) 2026/08/31 04:03:54 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access_filters/modfiles" 2026/08/31 04:03:54 DEBUG : Creating backend with remote "/tmp/040346cekojis5/datadir/test_check_access_filters-sojedac8" 2026/08/31 04:03:54 DEBUG : exclude-other-filtersfile.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : exclude-other-filtersfile.txt.955454a7.partial: size = 173 OK 2026/08/31 04:03:54 DEBUG : exclude-other-filtersfile.txt: md5 = 5fcc6205d7df1c2e9ed3a15a1356b345 OK 2026/08/31 04:03:54 DEBUG : exclude-other-filtersfile.txt.955454a7.partial: renamed to: exclude-other-filtersfile.txt 2026/08/31 04:03:54 INFO : exclude-other-filtersfile.txt: Copied (new) 2026/08/31 04:03:54 DEBUG : include-other-filtersfile.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : Local file system at /tmp/040346cekojis5/datadir/test_check_access_filters-sojedac8: Waiting for checks to finish 2026/08/31 04:03:54 DEBUG : Local file system at /tmp/040346cekojis5/datadir/test_check_access_filters-sojedac8: Waiting for transfers to finish 2026/08/31 04:03:54 DEBUG : include-other-filtersfile.txt.8126a844.partial: size = 178 OK 2026/08/31 04:03:54 DEBUG : include-other-filtersfile.txt: md5 = 2ec13b2813141ed088e5978ef5a47b0e OK 2026/08/31 04:03:54 DEBUG : include-other-filtersfile.txt.8126a844.partial: renamed to: include-other-filtersfile.txt 2026/08/31 04:03:54 INFO : include-other-filtersfile.txt: Copied (new) 2026/08/31 04:03:54 DEBUG : Waiting for deletions to finish 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:32657") 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:33248->172.17.0.4:32657, err= 2026/08/31 04:03:54 ERROR : error listing: directory not found 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:36803") 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:35626->172.17.0.4:36803, err= 2026/08/31 04:03:54 ERROR : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Failed to list "": directory not found 2026/08/31 04:03:54 DEBUG : removing 1 level 0 directories 2026/08/31 04:03:54 INFO : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Removing directory 2026/08/31 04:03:54 ERROR : Failed to rmdir: directory not found 2026/08/31 04:03:54 DEBUG : Waiting for deletions to finish 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:30567") 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:42876->172.17.0.4:30567, err= 2026/08/31 04:03:54 ERROR : error listing: directory not found 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:35963") 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:45360->172.17.0.4:35963, err= 2026/08/31 04:03:54 ERROR : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Failed to list "": directory not found 2026/08/31 04:03:54 DEBUG : removing 1 level 0 directories 2026/08/31 04:03:54 INFO : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Removing directory 2026/08/31 04:03:54 ERROR : Failed to rmdir: directory not found 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:30873") 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:56312->172.17.0.4:30873, err= 2026/08/31 04:03:54 ERROR : error listing: directory not found 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:39198") 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:42210->172.17.0.4:39198, err= 2026/08/31 04:03:54 ERROR : error listing: directory not found 2026/08/31 04:03:54 NOTICE: checking initFs Local file system at /tmp/040346cekojis5/initdir/test_check_access_filters-quvujab3 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:37215") 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:44342->172.17.0.4:37215, err= 2026/08/31 04:03:54 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : file3.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : file4.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 INFO : subdir-not: Making directory 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Connecting to FTP server 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Connecting to FTP server 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Connecting to FTP server 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Connecting to FTP server 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:45736->172.17.0.4:21, err= 2026/08/31 04:03:54 INFO : subdir: Making directory 2026/08/31 04:03:54 INFO : subdirX: Making directory 2026/08/31 04:03:54 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 INFO : subdirX/subdirX1: Making directory 2026/08/31 04:03:54 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 INFO : subdir/subdirA: Making directory 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Connecting to FTP server 2026/08/31 04:03:54 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 INFO : subdir-not/subdir-not2: Making directory 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Connecting to FTP server 2026/08/31 04:03:54 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:45752->172.17.0.4:21, err= 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:45758->172.17.0.4:21, err= 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:45774->172.17.0.4:21, err= 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:45784->172.17.0.4:21, err= 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:03:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:45792->172.17.0.4:21, err= 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:34946") 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:35292->172.17.0.4:34946, err= 2026/08/31 04:03:58 DEBUG : file2.txt.3230ad67.partial: size = 0 OK 2026/08/31 04:03:58 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2026/08/31 04:03:58 INFO : file2.txt: Copied (new) 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:35235") 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:44912->172.17.0.4:35235, err= 2026/08/31 04:03:58 DEBUG : file4.txt.fbf05a9b.partial: size = 0 OK 2026/08/31 04:03:58 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2026/08/31 04:03:58 INFO : file4.txt: Copied (new) 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:39494") 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:46410->172.17.0.4:39494, err= 2026/08/31 04:03:58 DEBUG : subdirX/RCLONE_TEST.fd5b40a2.partial: size = 109 OK 2026/08/31 04:03:58 DEBUG : subdirX/RCLONE_TEST.fd5b40a2.partial: renamed to: subdirX/RCLONE_TEST 2026/08/31 04:03:58 INFO : subdirX/RCLONE_TEST: Copied (new) 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:33157") 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:46312->172.17.0.4:33157, err= 2026/08/31 04:03:58 DEBUG : subdirX/file20.txt.0c4add8a.partial: size = 0 OK 2026/08/31 04:03:58 DEBUG : subdirX/file20.txt.0c4add8a.partial: renamed to: subdirX/file20.txt 2026/08/31 04:03:58 INFO : subdirX/file20.txt: Copied (new) 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:34679") 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:55012->172.17.0.4:34679, err= 2026/08/31 04:03:58 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: size = 109 OK 2026/08/31 04:03:58 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: renamed to: subdir/RCLONE_TEST 2026/08/31 04:03:58 INFO : subdir/RCLONE_TEST: Copied (new) 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:37299") 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:52358->172.17.0.4:37299, err= 2026/08/31 04:03:58 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK 2026/08/31 04:03:58 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2026/08/31 04:03:58 INFO : subdir/file20.txt: Copied (new) 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:37497") 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:59776->172.17.0.4:37497, err= 2026/08/31 04:03:58 DEBUG : subdir-not/RCLONE_TEST.16d95000.partial: size = 109 OK 2026/08/31 04:03:58 DEBUG : subdir-not/RCLONE_TEST.16d95000.partial: renamed to: subdir-not/RCLONE_TEST 2026/08/31 04:03:58 INFO : subdir-not/RCLONE_TEST: Copied (new) 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:37124") 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:54638->172.17.0.4:37124, err= 2026/08/31 04:03:58 DEBUG : subdir-not/file20.txt.e2b8d4dd.partial: size = 0 OK 2026/08/31 04:03:58 DEBUG : subdir-not/file20.txt.e2b8d4dd.partial: renamed to: subdir-not/file20.txt 2026/08/31 04:03:58 INFO : subdir-not/file20.txt: Copied (new) 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:38860") 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:49092->172.17.0.4:38860, err= 2026/08/31 04:03:58 DEBUG : subdirX/subdirX1/RCLONE_TEST.09a85483.partial: size = 109 OK 2026/08/31 04:03:58 DEBUG : subdirX/subdirX1/RCLONE_TEST.09a85483.partial: renamed to: subdirX/subdirX1/RCLONE_TEST 2026/08/31 04:03:58 INFO : subdirX/subdirX1/RCLONE_TEST: Copied (new) 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:39510") 2026/08/31 04:03:58 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:50800->172.17.0.4:39510, err= 2026/08/31 04:03:58 DEBUG : subdirX/subdirX1/file30.txt.0106cff7.partial: size = 0 OK 2026/08/31 04:03:58 DEBUG : subdirX/subdirX1/file30.txt.0106cff7.partial: renamed to: subdirX/subdirX1/file30.txt 2026/08/31 04:03:58 INFO : subdirX/subdirX1/file30.txt: Copied (new) 2026/08/31 04:04:01 INFO : subdir/subdirB: Making directory 2026/08/31 04:04:01 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:01 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination 2026/08/31 04:04:01 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:01 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination 2026/08/31 04:04:01 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:34092") 2026/08/31 04:04:01 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:57510->172.17.0.4:34092, err= 2026/08/31 04:04:01 DEBUG : subdir/subdirB/RCLONE_TEST.37da2e99.partial: size = 109 OK 2026/08/31 04:04:01 DEBUG : subdir/subdirB/RCLONE_TEST.37da2e99.partial: renamed to: subdir/subdirB/RCLONE_TEST 2026/08/31 04:04:01 INFO : subdir/subdirB/RCLONE_TEST: Copied (new) 2026/08/31 04:04:01 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:36937") 2026/08/31 04:04:01 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:38934->172.17.0.4:36937, err= 2026/08/31 04:04:01 DEBUG : subdir/subdirB/file30.txt.ca7c4d29.partial: size = 0 OK 2026/08/31 04:04:01 DEBUG : subdir/subdirB/file30.txt.ca7c4d29.partial: renamed to: subdir/subdirB/file30.txt 2026/08/31 04:04:01 INFO : subdir/subdirB/file30.txt: Copied (new) 2026/08/31 04:04:01 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:31654") 2026/08/31 04:04:01 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:49826->172.17.0.4:31654, err= 2026/08/31 04:04:01 DEBUG : subdir/subdirA/RCLONE_TEST.b780822c.partial: size = 109 OK 2026/08/31 04:04:01 DEBUG : subdir/subdirA/RCLONE_TEST.b780822c.partial: renamed to: subdir/subdirA/RCLONE_TEST 2026/08/31 04:04:01 INFO : subdir/subdirA/RCLONE_TEST: Copied (new) 2026/08/31 04:04:01 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:35175") 2026/08/31 04:04:01 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:37246->172.17.0.4:35175, err= 2026/08/31 04:04:01 DEBUG : subdir/subdirA/file30.txt.03485624.partial: size = 0 OK 2026/08/31 04:04:01 DEBUG : subdir/subdirA/file30.txt.03485624.partial: renamed to: subdir/subdirA/file30.txt 2026/08/31 04:04:01 INFO : subdir/subdirA/file30.txt: Copied (new) 2026/08/31 04:04:01 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:33383") 2026/08/31 04:04:01 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:49032->172.17.0.4:33383, err= 2026/08/31 04:04:01 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/08/31 04:04:01 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/08/31 04:04:01 INFO : file1.txt: Copied (new) 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:38952") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:52458->172.17.0.4:38952, err= 2026/08/31 04:04:02 DEBUG : file3.txt.a74079f2.partial: size = 0 OK 2026/08/31 04:04:02 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2026/08/31 04:04:02 INFO : file3.txt: Copied (new) 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:35643") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:35418->172.17.0.4:35643, err= 2026/08/31 04:04:02 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/08/31 04:04:02 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/08/31 04:04:02 INFO : RCLONE_TEST: Copied (new) 2026/08/31 04:04:02 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:02 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Waiting for checks to finish 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Waiting for transfers to finish 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:33358") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:45848->172.17.0.4:33358, err= 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:32223") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:39066->172.17.0.4:32223, err= 2026/08/31 04:04:02 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.51791ac5.partial: size = 109 OK 2026/08/31 04:04:02 DEBUG : subdir-not/subdir-not2/file30.txt.e99a79ee.partial: size = 0 OK 2026/08/31 04:04:02 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.51791ac5.partial: renamed to: subdir-not/subdir-not2/RCLONE_TEST 2026/08/31 04:04:02 INFO : subdir-not/subdir-not2/RCLONE_TEST: Copied (new) 2026/08/31 04:04:02 DEBUG : subdir-not/subdir-not2/file30.txt.e99a79ee.partial: renamed to: subdir-not/subdir-not2/file30.txt 2026/08/31 04:04:02 INFO : subdir-not/subdir-not2/file30.txt: Copied (new) 2026/08/31 04:04:02 NOTICE: checking Path1 ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:34193") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:38022->172.17.0.4:34193, err= 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:38259") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:33883") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:60258->172.17.0.4:33883, err= 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:41204->172.17.0.4:38259, err= 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:31331") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:44446->172.17.0.4:31331, err= 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:35072") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:35700") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:35446->172.17.0.4:35700, err= 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:55474->172.17.0.4:35072, err= 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:30492") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:31119") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:60218->172.17.0.4:30492, err= 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:50594->172.17.0.4:31119, err= 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:32377") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:35480->172.17.0.4:32377, err= 2026/08/31 04:04:02 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:02 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/08/31 04:04:02 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/08/31 04:04:02 DEBUG : file3.txt: Need to transfer - File not found at Destination 2026/08/31 04:04:02 DEBUG : file4.txt: Need to transfer - File not found at Destination 2026/08/31 04:04:02 INFO : subdir-not: Making directory 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Connecting to FTP server 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Connecting to FTP server 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Connecting to FTP server 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Connecting to FTP server 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:47716->172.17.0.4:21, err= 2026/08/31 04:04:02 INFO : subdir: Making directory 2026/08/31 04:04:02 INFO : subdirX: Making directory 2026/08/31 04:04:02 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:02 DEBUG : subdirX/file20.txt: Need to transfer - File not found at Destination 2026/08/31 04:04:02 INFO : subdirX/subdirX1: Making directory 2026/08/31 04:04:02 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:02 DEBUG : subdir-not/file20.txt: Need to transfer - File not found at Destination 2026/08/31 04:04:02 INFO : subdir-not/subdir-not2: Making directory 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Connecting to FTP server 2026/08/31 04:04:02 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:02 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/08/31 04:04:02 INFO : subdir/subdirA: Making directory 2026/08/31 04:04:02 DEBUG : subdirX/subdirX1/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:02 DEBUG : subdirX/subdirX1/file30.txt: Need to transfer - File not found at Destination 2026/08/31 04:04:02 INFO : subdir/subdirB: Making directory 2026/08/31 04:04:02 DEBUG : subdir/subdirB/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:02 DEBUG : subdir/subdirB/file30.txt: Need to transfer - File not found at Destination 2026/08/31 04:04:02 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:02 DEBUG : subdir/subdirA/file30.txt: Need to transfer - File not found at Destination 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:47718->172.17.0.4:21, err= 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:47730->172.17.0.4:21, err= 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:47736->172.17.0.4:21, err= 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:02 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:47750->172.17.0.4:21, err= 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:32337") 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:42498->172.17.0.4:32337, err= 2026/08/31 04:04:08 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/08/31 04:04:08 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/08/31 04:04:08 INFO : RCLONE_TEST: Copied (new) 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:36319") 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:40050->172.17.0.4:36319, err= 2026/08/31 04:04:08 DEBUG : file4.txt.fbf05a9b.partial: size = 0 OK 2026/08/31 04:04:08 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2026/08/31 04:04:08 INFO : file4.txt: Copied (new) 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:34924") 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:56912->172.17.0.4:34924, err= 2026/08/31 04:04:08 DEBUG : subdirX/RCLONE_TEST.fd5b40a2.partial: size = 109 OK 2026/08/31 04:04:08 DEBUG : subdirX/RCLONE_TEST.fd5b40a2.partial: renamed to: subdirX/RCLONE_TEST 2026/08/31 04:04:08 INFO : subdirX/RCLONE_TEST: Copied (new) 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:30054") 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:60610->172.17.0.4:30054, err= 2026/08/31 04:04:08 DEBUG : subdirX/file20.txt.0c4add8a.partial: size = 0 OK 2026/08/31 04:04:08 DEBUG : subdirX/file20.txt.0c4add8a.partial: renamed to: subdirX/file20.txt 2026/08/31 04:04:08 INFO : subdirX/file20.txt: Copied (new) 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:31068") 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:41470->172.17.0.4:31068, err= 2026/08/31 04:04:08 DEBUG : subdir-not/RCLONE_TEST.16d95000.partial: size = 109 OK 2026/08/31 04:04:08 DEBUG : subdir-not/RCLONE_TEST.16d95000.partial: renamed to: subdir-not/RCLONE_TEST 2026/08/31 04:04:08 INFO : subdir-not/RCLONE_TEST: Copied (new) 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:38402") 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:55058->172.17.0.4:38402, err= 2026/08/31 04:04:08 DEBUG : subdir-not/file20.txt.e2b8d4dd.partial: size = 0 OK 2026/08/31 04:04:08 DEBUG : subdir-not/file20.txt.e2b8d4dd.partial: renamed to: subdir-not/file20.txt 2026/08/31 04:04:08 INFO : subdir-not/file20.txt: Copied (new) 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:36446") 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:41564->172.17.0.4:36446, err= 2026/08/31 04:04:08 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: size = 109 OK 2026/08/31 04:04:08 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: renamed to: subdir/RCLONE_TEST 2026/08/31 04:04:08 INFO : subdir/RCLONE_TEST: Copied (new) 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:35285") 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:34636->172.17.0.4:35285, err= 2026/08/31 04:04:08 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK 2026/08/31 04:04:08 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2026/08/31 04:04:08 INFO : subdir/file20.txt: Copied (new) 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:35356") 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:45696->172.17.0.4:35356, err= 2026/08/31 04:04:08 DEBUG : subdirX/subdirX1/RCLONE_TEST.09a85483.partial: size = 109 OK 2026/08/31 04:04:08 DEBUG : subdirX/subdirX1/RCLONE_TEST.09a85483.partial: renamed to: subdirX/subdirX1/RCLONE_TEST 2026/08/31 04:04:08 INFO : subdirX/subdirX1/RCLONE_TEST: Copied (new) 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:39821") 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:50070->172.17.0.4:39821, err= 2026/08/31 04:04:08 DEBUG : subdirX/subdirX1/file30.txt.0106cff7.partial: size = 0 OK 2026/08/31 04:04:08 DEBUG : subdirX/subdirX1/file30.txt.0106cff7.partial: renamed to: subdirX/subdirX1/file30.txt 2026/08/31 04:04:08 INFO : subdirX/subdirX1/file30.txt: Copied (new) 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:32768") 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:48104->172.17.0.4:32768, err= 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:30208") 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:47792->172.17.0.4:30208, err= 2026/08/31 04:04:08 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/08/31 04:04:08 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/08/31 04:04:08 INFO : file1.txt: Copied (new) 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:33410") 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:56854->172.17.0.4:33410, err= 2026/08/31 04:04:08 DEBUG : subdir/subdirB/RCLONE_TEST.37da2e99.partial: size = 109 OK 2026/08/31 04:04:08 DEBUG : subdir/subdirB/file30.txt.ca7c4d29.partial: size = 0 OK 2026/08/31 04:04:08 DEBUG : subdir/subdirB/file30.txt.ca7c4d29.partial: renamed to: subdir/subdirB/file30.txt 2026/08/31 04:04:08 INFO : subdir/subdirB/file30.txt: Copied (new) 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:32638") 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:52720->172.17.0.4:32638, err= 2026/08/31 04:04:08 DEBUG : subdir/subdirB/RCLONE_TEST.37da2e99.partial: renamed to: subdir/subdirB/RCLONE_TEST 2026/08/31 04:04:08 INFO : subdir/subdirB/RCLONE_TEST: Copied (new) 2026/08/31 04:04:08 DEBUG : subdir/subdirA/RCLONE_TEST.b780822c.partial: size = 109 OK 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:31162") 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:42224->172.17.0.4:31162, err= 2026/08/31 04:04:08 DEBUG : subdir/subdirA/file30.txt.03485624.partial: size = 0 OK 2026/08/31 04:04:08 DEBUG : subdir/subdirA/RCLONE_TEST.b780822c.partial: renamed to: subdir/subdirA/RCLONE_TEST 2026/08/31 04:04:08 INFO : subdir/subdirA/RCLONE_TEST: Copied (new) 2026/08/31 04:04:08 DEBUG : subdir/subdirA/file30.txt.03485624.partial: renamed to: subdir/subdirA/file30.txt 2026/08/31 04:04:08 INFO : subdir/subdirA/file30.txt: Copied (new) 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:34929") 2026/08/31 04:04:08 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:58632->172.17.0.4:34929, err= 2026/08/31 04:04:08 DEBUG : file2.txt.3230ad67.partial: size = 0 OK 2026/08/31 04:04:08 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2026/08/31 04:04:08 INFO : file2.txt: Copied (new) 2026/08/31 04:04:09 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:09 DEBUG : subdir-not/subdir-not2/file30.txt: Need to transfer - File not found at Destination 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Waiting for checks to finish 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Waiting for transfers to finish 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:37948") 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:46894->172.17.0.4:37948, err= 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:32307") 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:39652->172.17.0.4:32307, err= 2026/08/31 04:04:09 DEBUG : subdir-not/subdir-not2/file30.txt.e99a79ee.partial: size = 0 OK 2026/08/31 04:04:09 DEBUG : subdir-not/subdir-not2/file30.txt.e99a79ee.partial: renamed to: subdir-not/subdir-not2/file30.txt 2026/08/31 04:04:09 INFO : subdir-not/subdir-not2/file30.txt: Copied (new) 2026/08/31 04:04:09 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.51791ac5.partial: size = 109 OK 2026/08/31 04:04:09 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.51791ac5.partial: renamed to: subdir-not/subdir-not2/RCLONE_TEST 2026/08/31 04:04:09 INFO : subdir-not/subdir-not2/RCLONE_TEST: Copied (new) 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:32245") 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:60152->172.17.0.4:32245, err= 2026/08/31 04:04:09 DEBUG : file3.txt.a74079f2.partial: size = 0 OK 2026/08/31 04:04:09 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2026/08/31 04:04:09 INFO : file3.txt: Copied (new) 2026/08/31 04:04:09 NOTICE: checking path2 ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:33093") 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:60362->172.17.0.4:33093, err= 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:36788") 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:31912") 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:45788->172.17.0.4:36788, err= 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:38128") 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:38454->172.17.0.4:31912, err= 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:52386->172.17.0.4:38128, err= 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:31533") 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:31948") 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:60064->172.17.0.4:31533, err= 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:42796->172.17.0.4:31948, err= 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:36209") 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:39891") 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:46536->172.17.0.4:39891, err= 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:44284->172.17.0.4:36209, err= 2026/08/31 04:04:09 NOTICE: (01) : test check-access-filters 2026/08/31 04:04:09 NOTICE: (02) : test EXCLUDE - OTHER TESTS 2026/08/31 04:04:09 NOTICE: (03) : copy-file /tmp/040346cekojis5/datadir/test_check_access_filters-sojedac8/exclude-other-filtersfile.txt /tmp/040346cekojis5/workdir/ 2026/08/31 04:04:09 DEBUG : copyFile "/tmp/040346cekojis5/datadir/test_check_access_filters-sojedac8/exclude-other-filtersfile.txt" to "/tmp/040346cekojis5/workdir/" as "" 2026/08/31 04:04:09 DEBUG : Creating backend with remote "/tmp/040346cekojis5/datadir/test_check_access_filters-sojedac8/exclude-other-filtersfile.txt" 2026/08/31 04:04:09 DEBUG : Creating backend with remote "/tmp/040346cekojis5/workdir/" 2026/08/31 04:04:09 DEBUG : operations.CopyFile "exclude-other-filtersfile.txt" to "Local file system at /tmp/040346cekojis5/workdir" as "exclude-other-filtersfile.txt" 2026/08/31 04:04:09 DEBUG : exclude-other-filtersfile.txt: Need to transfer - File not found at Destination 2026/08/31 04:04:09 DEBUG : exclude-other-filtersfile.txt.955454a7.partial: size = 173 OK 2026/08/31 04:04:09 DEBUG : exclude-other-filtersfile.txt: md5 = 5fcc6205d7df1c2e9ed3a15a1356b345 OK 2026/08/31 04:04:09 DEBUG : exclude-other-filtersfile.txt.955454a7.partial: renamed to: exclude-other-filtersfile.txt 2026/08/31 04:04:09 INFO : exclude-other-filtersfile.txt: Copied (new) 2026/08/31 04:04:09 NOTICE: (04) : test resync to get the filters file md5 built. 2026/08/31 04:04:09 NOTICE: (05) : bisync resync filters-file=/tmp/040346cekojis5/workdir/exclude-other-filtersfile.txt 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:34147") 2026/08/31 04:04:09 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:44226->172.17.0.4:34147, err= 2026/08/31 04:04:11 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:33033") 2026/08/31 04:04:11 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:55858->172.17.0.4:33033, err= 2026/08/31 04:04:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:04:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:04:13 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/08/31 04:04:13 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2026/08/31 04:04:13 INFO : Synching Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" with Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:04:13 INFO : Using filters file /tmp/040346cekojis5/workdir/exclude-other-filtersfile.txt 2026/08/31 04:04:13 INFO : Storing filters file hash to /tmp/040346cekojis5/workdir/exclude-other-filtersfile.txt.md5 2026/08/31 04:04:13 INFO : Copying Path2 files to Path1 2026/08/31 04:04:13 INFO : - Path2 Resync is copying files to - Path1 2026/08/31 04:04:13 INFO : There was nothing to transfer 2026/08/31 04:04:13 INFO : - Path1 Resync is copying files to - Path2 2026/08/31 04:04:13 INFO : There was nothing to transfer 2026/08/31 04:04:13 INFO : Resync updating listings 2026/08/31 04:04:13 INFO : Validating listings for Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" vs Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:04:13 INFO : Bisync successful 2026/08/31 04:04:13 NOTICE: (06) : test EXCLUDE - test filters for check access 2026/08/31 04:04:13 NOTICE: (07) : bisync check-access filters-file=/tmp/040346cekojis5/workdir/exclude-other-filtersfile.txt 2026/08/31 04:04:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:30070") 2026/08/31 04:04:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:50158->172.17.0.4:30070, err= 2026/08/31 04:04:15 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:37853") 2026/08/31 04:04:15 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:55722->172.17.0.4:37853, err= 2026/08/31 04:04:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:04:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:04:17 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/08/31 04:04:17 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2026/08/31 04:04:17 INFO : Synching Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" with Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:04:17 INFO : Using filters file /tmp/040346cekojis5/workdir/exclude-other-filtersfile.txt 2026/08/31 04:04:17 INFO : Building Path1 and Path2 listings 2026/08/31 04:04:17 INFO : Path1 checking for diffs 2026/08/31 04:04:17 INFO : Path2 checking for diffs 2026/08/31 04:04:17 INFO : Checking access health 2026/08/31 04:04:17 INFO : Found 3 matching "RCLONE_TEST" files on both paths 2026/08/31 04:04:17 INFO : No changes found 2026/08/31 04:04:17 INFO : Updating listings 2026/08/31 04:04:17 INFO : Validating listings for Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" vs Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:04:17 INFO : Bisync successful 2026/08/31 04:04:17 NOTICE: (08) : copy-listings exclude-initial 2026/08/31 04:04:17 NOTICE: (09) : test EXCLUDE - delete RCLONE_TEST files in excluded directories 2026/08/31 04:04:17 NOTICE: (10) : delete-file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir/subdirA/RCLONE_TEST 2026/08/31 04:04:17 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir/subdirA/" 2026/08/31 04:04:17 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:04:17 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:04:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir/subdirA: Connecting to FTP server 2026/08/31 04:04:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir/subdirA: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir/subdirA: > dial: conn=172.17.0.1:58906->172.17.0.4:21, err= 2026/08/31 04:04:20 DEBUG : fs cache: renaming cache item "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir/subdirA/" to be canonical "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir/subdirA/" 2026/08/31 04:04:20 INFO : RCLONE_TEST: Deleted 2026/08/31 04:04:20 NOTICE: (11) : delete-file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir-not/RCLONE_TEST 2026/08/31 04:04:20 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir-not/" 2026/08/31 04:04:20 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:04:20 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:04:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir-not: Connecting to FTP server 2026/08/31 04:04:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir-not: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir-not: > dial: conn=172.17.0.1:58922->172.17.0.4:21, err= 2026/08/31 04:04:24 DEBUG : fs cache: renaming cache item "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir-not/" to be canonical "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir-not/" 2026/08/31 04:04:24 INFO : RCLONE_TEST: Deleted 2026/08/31 04:04:24 NOTICE: (12) : delete-file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir-not/subdir-not2/RCLONE_TEST 2026/08/31 04:04:24 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir-not/subdir-not2/" 2026/08/31 04:04:24 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:04:24 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:04:24 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir-not/subdir-not2: Connecting to FTP server 2026/08/31 04:04:24 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir-not/subdir-not2: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:24 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir-not/subdir-not2: > dial: conn=172.17.0.1:48018->172.17.0.4:21, err= 2026/08/31 04:04:27 DEBUG : fs cache: renaming cache item "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir-not/subdir-not2/" to be canonical "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir-not/subdir-not2/" 2026/08/31 04:04:27 INFO : RCLONE_TEST: Deleted 2026/08/31 04:04:27 NOTICE: (13) : delete-file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdirX/RCLONE_TEST 2026/08/31 04:04:27 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdirX/" 2026/08/31 04:04:27 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:04:27 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:04:27 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdirX: Connecting to FTP server 2026/08/31 04:04:27 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdirX: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:27 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdirX: > dial: conn=172.17.0.1:48034->172.17.0.4:21, err= 2026/08/31 04:04:29 DEBUG : fs cache: renaming cache item "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdirX/" to be canonical "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdirX/" 2026/08/31 04:04:29 INFO : RCLONE_TEST: Deleted 2026/08/31 04:04:29 NOTICE: (14) : test EXCLUDE - test should PASS 2026/08/31 04:04:29 NOTICE: (15) : bisync check-access filters-file=/tmp/040346cekojis5/workdir/exclude-other-filtersfile.txt 2026/08/31 04:04:29 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:37368") 2026/08/31 04:04:29 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:39036->172.17.0.4:37368, err= 2026/08/31 04:04:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:36232") 2026/08/31 04:04:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:38450->172.17.0.4:36232, err= 2026/08/31 04:04:33 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:04:33 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:04:33 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/08/31 04:04:33 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2026/08/31 04:04:33 INFO : Synching Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" with Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:04:33 INFO : Using filters file /tmp/040346cekojis5/workdir/exclude-other-filtersfile.txt 2026/08/31 04:04:33 INFO : Building Path1 and Path2 listings 2026/08/31 04:04:34 INFO : Path1 checking for diffs 2026/08/31 04:04:34 INFO : Path2 checking for diffs 2026/08/31 04:04:34 INFO : Checking access health 2026/08/31 04:04:34 INFO : Found 3 matching "RCLONE_TEST" files on both paths 2026/08/31 04:04:34 INFO : No changes found 2026/08/31 04:04:34 INFO : Updating listings 2026/08/31 04:04:34 INFO : Validating listings for Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" vs Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:04:34 INFO : Bisync successful 2026/08/31 04:04:34 NOTICE: (16) : copy-listings exclude-pass-run 2026/08/31 04:04:34 NOTICE: (17) : test EXCLUDE - delete RCLONE_TEST files in included directories 2026/08/31 04:04:34 NOTICE: (18) : delete-file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/RCLONE_TEST 2026/08/31 04:04:34 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:04:34 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:04:34 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:04:34 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Connecting to FTP server 2026/08/31 04:04:34 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:34 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:51048->172.17.0.4:21, err= 2026/08/31 04:04:37 DEBUG : fs cache: renaming cache item "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" to be canonical "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:04:37 INFO : RCLONE_TEST: Deleted 2026/08/31 04:04:37 NOTICE: (19) : delete-file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir/RCLONE_TEST 2026/08/31 04:04:37 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir/" 2026/08/31 04:04:37 DEBUG : Config file has changed externally - reloading 2026/08/31 04:04:37 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:04:37 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:04:37 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir: Connecting to FTP server 2026/08/31 04:04:37 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:37 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir: > dial: conn=172.17.0.1:51058->172.17.0.4:21, err= 2026/08/31 04:04:40 DEBUG : fs cache: renaming cache item "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir/" to be canonical "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir/" 2026/08/31 04:04:40 INFO : RCLONE_TEST: Deleted 2026/08/31 04:04:40 NOTICE: (20) : test EXCLUDE - test should ABORT 2026/08/31 04:04:40 NOTICE: (21) : bisync check-access filters-file=/tmp/040346cekojis5/workdir/exclude-other-filtersfile.txt 2026/08/31 04:04:40 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:39381") 2026/08/31 04:04:40 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:38072->172.17.0.4:39381, err= 2026/08/31 04:04:42 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:37814") 2026/08/31 04:04:42 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:39936->172.17.0.4:37814, err= 2026/08/31 04:04:44 DEBUG : ftp://172.17.0.4:21/rclone-test-molated8yusu: closing 1 unused connections 2026/08/31 04:04:44 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:04:44 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:04:44 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/08/31 04:04:44 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2026/08/31 04:04:44 INFO : Synching Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" with Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:04:44 INFO : Using filters file /tmp/040346cekojis5/workdir/exclude-other-filtersfile.txt 2026/08/31 04:04:44 INFO : Building Path1 and Path2 listings 2026/08/31 04:04:44 INFO : Path1 checking for diffs 2026/08/31 04:04:44 INFO : - Path1 File was deleted - subdir/RCLONE_TEST 2026/08/31 04:04:44 INFO : Path1: 1 changes:  0 new,  0 modified,  1 deleted 2026/08/31 04:04:44 INFO : Path2 checking for diffs 2026/08/31 04:04:44 INFO : - Path2 File was deleted - RCLONE_TEST 2026/08/31 04:04:44 INFO : Path2: 1 changes:  0 new,  0 modified,  1 deleted 2026/08/31 04:04:44 INFO : Checking access health 2026/08/31 04:04:44 ERROR : -  Access test failed: Path1 file not found in Path2 - RCLONE_TEST 2026/08/31 04:04:44 ERROR : -  Access test failed: Path2 file not found in Path1 - subdir/RCLONE_TEST 2026/08/31 04:04:44 ERROR : Bisync critical error: check file check failed 2026/08/31 04:04:44 ERROR : Bisync aborted. Must run --resync to recover. 2026/08/31 04:04:44 NOTICE: Bisync error: bisync aborted 2026/08/31 04:04:44 NOTICE: (22) : move-listings exclude-error-run 2026/08/31 04:04:44 NOTICE: (23) : test INCLUDE - OTHER TESTS 2026/08/31 04:04:44 NOTICE: (24) : test reset to the initial state 2026/08/31 04:04:44 NOTICE: (25) : copy-dir /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_access_filters/initial TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/ 2026/08/31 04:04:44 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" 2026/08/31 04:04:44 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:04:44 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:04:44 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Connecting to FTP server 2026/08/31 04:04:44 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:44 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:58250->172.17.0.4:21, err= 2026/08/31 04:04:47 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: closing 1 unused connections 2026/08/31 04:04:48 DEBUG : fs cache: renaming cache item "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" to be canonical "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" 2026/08/31 04:04:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:39596") 2026/08/31 04:04:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:41166->172.17.0.4:39596, err= 2026/08/31 04:04:48 DEBUG : RCLONE_TEST: size = 109 OK 2026/08/31 04:04:48 DEBUG : RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:48 DEBUG : RCLONE_TEST: Unchanged skipping 2026/08/31 04:04:48 DEBUG : file1.txt: size = 0 OK 2026/08/31 04:04:48 DEBUG : file1.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:48 DEBUG : file1.txt: Unchanged skipping 2026/08/31 04:04:48 DEBUG : file2.txt: size = 0 OK 2026/08/31 04:04:48 DEBUG : file2.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:48 DEBUG : file2.txt: Unchanged skipping 2026/08/31 04:04:48 DEBUG : file3.txt: size = 0 OK 2026/08/31 04:04:48 DEBUG : file3.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:48 DEBUG : file3.txt: Unchanged skipping 2026/08/31 04:04:48 DEBUG : file4.txt: size = 0 OK 2026/08/31 04:04:48 DEBUG : file4.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:48 DEBUG : file4.txt: Unchanged skipping 2026/08/31 04:04:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Connecting to FTP server 2026/08/31 04:04:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:58264->172.17.0.4:21, err= 2026/08/31 04:04:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Connecting to FTP server 2026/08/31 04:04:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:39101") 2026/08/31 04:04:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:36864->172.17.0.4:39101, err= 2026/08/31 04:04:48 DEBUG : subdirX/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:48 DEBUG : subdirX/file20.txt: size = 0 OK 2026/08/31 04:04:48 DEBUG : subdirX/file20.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:48 DEBUG : subdirX/file20.txt: Unchanged skipping 2026/08/31 04:04:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Connecting to FTP server 2026/08/31 04:04:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:36046") 2026/08/31 04:04:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:45290->172.17.0.4:36046, err= 2026/08/31 04:04:48 DEBUG : subdirX/subdirX1/RCLONE_TEST: size = 109 OK 2026/08/31 04:04:48 DEBUG : subdirX/subdirX1/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:48 DEBUG : subdirX/subdirX1/RCLONE_TEST: Unchanged skipping 2026/08/31 04:04:48 DEBUG : subdirX/subdirX1/file30.txt: size = 0 OK 2026/08/31 04:04:48 DEBUG : subdirX/subdirX1/file30.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:48 DEBUG : subdirX/subdirX1/file30.txt: Unchanged skipping 2026/08/31 04:04:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:58266->172.17.0.4:21, err= 2026/08/31 04:04:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:58268->172.17.0.4:21, err= 2026/08/31 04:04:50 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:34702") 2026/08/31 04:04:50 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:41046->172.17.0.4:34702, err= 2026/08/31 04:04:50 DEBUG : subdir-not/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:50 DEBUG : subdir-not/file20.txt: size = 0 OK 2026/08/31 04:04:50 DEBUG : subdir-not/file20.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:50 DEBUG : subdir-not/file20.txt: Unchanged skipping 2026/08/31 04:04:50 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:35445") 2026/08/31 04:04:50 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:36130->172.17.0.4:35445, err= 2026/08/31 04:04:50 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:38749") 2026/08/31 04:04:50 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:48734->172.17.0.4:38749, err= 2026/08/31 04:04:50 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: size = 109 OK 2026/08/31 04:04:51 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:51 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Unchanged skipping 2026/08/31 04:04:51 DEBUG : subdir-not/subdir-not2/file30.txt: size = 0 OK 2026/08/31 04:04:51 DEBUG : subdir-not/subdir-not2/file30.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:51 DEBUG : subdir-not/subdir-not2/file30.txt: Unchanged skipping 2026/08/31 04:04:51 DEBUG : subdir-not/RCLONE_TEST.16d95000.partial: size = 109 OK 2026/08/31 04:04:51 DEBUG : subdir-not/RCLONE_TEST.16d95000.partial: renamed to: subdir-not/RCLONE_TEST 2026/08/31 04:04:51 INFO : subdir-not/RCLONE_TEST: Copied (new) 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:39792") 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:42256->172.17.0.4:39792, err= 2026/08/31 04:04:51 DEBUG : subdir/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:31032") 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:37282->172.17.0.4:31032, err= 2026/08/31 04:04:51 DEBUG : subdir/subdirA/RCLONE_TEST: size = 109 OK 2026/08/31 04:04:51 DEBUG : subdir/file20.txt: size = 0 OK 2026/08/31 04:04:51 DEBUG : subdir/subdirA/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:51 DEBUG : subdir/file20.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:51 DEBUG : subdir/subdirA/RCLONE_TEST: Unchanged skipping 2026/08/31 04:04:51 DEBUG : subdir/file20.txt: Unchanged skipping 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:39874") 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:39245") 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:55570->172.17.0.4:39874, err= 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:44616->172.17.0.4:39245, err= 2026/08/31 04:04:51 DEBUG : subdir/subdirA/file30.txt: size = 0 OK 2026/08/31 04:04:51 DEBUG : subdir/subdirA/file30.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:51 DEBUG : subdir/subdirA/file30.txt: Unchanged skipping 2026/08/31 04:04:51 DEBUG : subdir/subdirB/RCLONE_TEST: size = 109 OK 2026/08/31 04:04:51 DEBUG : subdir/subdirB/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:51 DEBUG : subdir/subdirB/RCLONE_TEST: Unchanged skipping 2026/08/31 04:04:51 DEBUG : subdir/subdirB/file30.txt: size = 0 OK 2026/08/31 04:04:51 DEBUG : subdir/subdirB/file30.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:51 DEBUG : subdir/subdirB/file30.txt: Unchanged skipping 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Waiting for checks to finish 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Waiting for transfers to finish 2026/08/31 04:04:51 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: size = 109 OK 2026/08/31 04:04:51 DEBUG : subdir/RCLONE_TEST.e0d6433d.partial: renamed to: subdir/RCLONE_TEST 2026/08/31 04:04:51 INFO : subdir/RCLONE_TEST: Copied (new) 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:38273") 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:49380->172.17.0.4:38273, err= 2026/08/31 04:04:51 DEBUG : subdirX/RCLONE_TEST.fd5b40a2.partial: size = 109 OK 2026/08/31 04:04:51 DEBUG : subdirX/RCLONE_TEST.fd5b40a2.partial: renamed to: subdirX/RCLONE_TEST 2026/08/31 04:04:51 INFO : subdirX/RCLONE_TEST: Copied (new) 2026/08/31 04:04:51 NOTICE: (26) : sync-dir TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/ TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/ 2026/08/31 04:04:51 DEBUG : fs cache: switching user supplied name "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" for canonical name "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" 2026/08/31 04:04:51 DEBUG : fs cache: switching user supplied name "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" for canonical name "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:39868") 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:47618->172.17.0.4:39868, err= 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:36020") 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:59674->172.17.0.4:36020, err= 2026/08/31 04:04:51 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:51 DEBUG : file1.txt: size = 0 OK 2026/08/31 04:04:51 DEBUG : file1.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Connecting to FTP server 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:51 DEBUG : file2.txt: size = 0 OK 2026/08/31 04:04:51 DEBUG : file2.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:51 DEBUG : file2.txt: Unchanged skipping 2026/08/31 04:04:51 DEBUG : file3.txt: size = 0 OK 2026/08/31 04:04:51 DEBUG : file3.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:51 DEBUG : file3.txt: Unchanged skipping 2026/08/31 04:04:51 DEBUG : file4.txt: size = 0 OK 2026/08/31 04:04:51 DEBUG : file4.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:51 DEBUG : file4.txt: Unchanged skipping 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:32463") 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Connecting to FTP server 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:52796->172.17.0.4:32463, err= 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:48798->172.17.0.4:21, err= 2026/08/31 04:04:51 DEBUG : file1.txt: Unchanged skipping 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:36299") 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Connecting to FTP server 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:32079") 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:50084->172.17.0.4:36299, err= 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:32792") 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:44228->172.17.0.4:32079, err= 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:51378->172.17.0.4:32792, err= 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:34869") 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:52674->172.17.0.4:34869, err= 2026/08/31 04:04:51 DEBUG : subdirX/RCLONE_TEST: size = 109 OK 2026/08/31 04:04:51 DEBUG : subdirX/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:51 DEBUG : subdirX/RCLONE_TEST: Unchanged skipping 2026/08/31 04:04:51 DEBUG : subdirX/file20.txt: size = 0 OK 2026/08/31 04:04:51 DEBUG : subdirX/file20.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:51 DEBUG : subdirX/file20.txt: Unchanged skipping 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:37714") 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:44150->172.17.0.4:37714, err= 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:38914") 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:43992->172.17.0.4:38914, err= 2026/08/31 04:04:51 DEBUG : subdirX/subdirX1/RCLONE_TEST: size = 109 OK 2026/08/31 04:04:51 DEBUG : subdirX/subdirX1/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:51 DEBUG : subdirX/subdirX1/RCLONE_TEST: Unchanged skipping 2026/08/31 04:04:51 DEBUG : subdirX/subdirX1/file30.txt: size = 0 OK 2026/08/31 04:04:51 DEBUG : subdirX/subdirX1/file30.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:51 DEBUG : subdirX/subdirX1/file30.txt: Unchanged skipping 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:48804->172.17.0.4:21, err= 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:04:51 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:48812->172.17.0.4:21, err= 2026/08/31 04:04:52 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5: closing 1 unused connections 2026/08/31 04:04:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:30591") 2026/08/31 04:04:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:60586->172.17.0.4:30591, err= 2026/08/31 04:04:54 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/08/31 04:04:54 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/08/31 04:04:54 INFO : RCLONE_TEST: Copied (new) 2026/08/31 04:04:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:30515") 2026/08/31 04:04:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:36508->172.17.0.4:30515, err= 2026/08/31 04:04:54 DEBUG : subdir/RCLONE_TEST: size = 109 OK 2026/08/31 04:04:54 DEBUG : subdir/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:54 DEBUG : subdir/RCLONE_TEST: Unchanged skipping 2026/08/31 04:04:54 DEBUG : subdir/file20.txt: size = 0 OK 2026/08/31 04:04:54 DEBUG : subdir/file20.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:54 DEBUG : subdir/file20.txt: Unchanged skipping 2026/08/31 04:04:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:37117") 2026/08/31 04:04:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:41536->172.17.0.4:37117, err= 2026/08/31 04:04:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:35051") 2026/08/31 04:04:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:57728->172.17.0.4:35051, err= 2026/08/31 04:04:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:31716") 2026/08/31 04:04:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:60740->172.17.0.4:31716, err= 2026/08/31 04:04:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:33028") 2026/08/31 04:04:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:39448->172.17.0.4:33028, err= 2026/08/31 04:04:54 DEBUG : subdir/subdirA/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:54 DEBUG : subdir/subdirB/file30.txt: size = 0 OK 2026/08/31 04:04:54 DEBUG : subdir/subdirB/file30.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:54 DEBUG : subdir/subdirB/file30.txt: Unchanged skipping 2026/08/31 04:04:54 DEBUG : subdir/subdirA/file30.txt: size = 0 OK 2026/08/31 04:04:54 DEBUG : subdir/subdirA/file30.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:54 DEBUG : subdir/subdirA/file30.txt: Unchanged skipping 2026/08/31 04:04:54 DEBUG : subdir/subdirB/RCLONE_TEST: size = 109 OK 2026/08/31 04:04:54 DEBUG : subdir/subdirB/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:54 DEBUG : subdir/subdirB/RCLONE_TEST: Unchanged skipping 2026/08/31 04:04:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:35622") 2026/08/31 04:04:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:33102->172.17.0.4:35622, err= 2026/08/31 04:04:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:36553") 2026/08/31 04:04:54 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:38744->172.17.0.4:36553, err= 2026/08/31 04:04:54 DEBUG : subdir/subdirA/RCLONE_TEST.b780822c.partial: size = 109 OK 2026/08/31 04:04:54 DEBUG : subdir/subdirA/RCLONE_TEST.b780822c.partial: renamed to: subdir/subdirA/RCLONE_TEST 2026/08/31 04:04:54 INFO : subdir/subdirA/RCLONE_TEST: Copied (new) 2026/08/31 04:04:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:34500") 2026/08/31 04:04:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:59914->172.17.0.4:34500, err= 2026/08/31 04:04:55 DEBUG : subdir-not/RCLONE_TEST: size = 109 OK 2026/08/31 04:04:55 DEBUG : subdir-not/file20.txt: size = 0 OK 2026/08/31 04:04:55 DEBUG : subdir-not/file20.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:55 DEBUG : subdir-not/file20.txt: Unchanged skipping 2026/08/31 04:04:55 DEBUG : subdir-not/RCLONE_TEST: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:55 DEBUG : subdir-not/RCLONE_TEST: Unchanged skipping 2026/08/31 04:04:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:31053") 2026/08/31 04:04:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:39719") 2026/08/31 04:04:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:34648->172.17.0.4:39719, err= 2026/08/31 04:04:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:53374->172.17.0.4:31053, err= 2026/08/31 04:04:55 DEBUG : subdir-not/subdir-not2/RCLONE_TEST: Need to transfer - File not found at Destination 2026/08/31 04:04:55 DEBUG : subdir-not/subdir-not2/file30.txt: size = 0 OK 2026/08/31 04:04:55 DEBUG : subdir-not/subdir-not2/file30.txt: Size and modification time the same (differ by 0s, within tolerance 1s) 2026/08/31 04:04:55 DEBUG : subdir-not/subdir-not2/file30.txt: Unchanged skipping 2026/08/31 04:04:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Waiting for checks to finish 2026/08/31 04:04:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Waiting for transfers to finish 2026/08/31 04:04:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:38804") 2026/08/31 04:04:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:53980->172.17.0.4:38804, err= 2026/08/31 04:04:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:30207") 2026/08/31 04:04:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:36896->172.17.0.4:30207, err= 2026/08/31 04:04:55 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.51791ac5.partial: size = 109 OK 2026/08/31 04:04:55 DEBUG : subdir-not/subdir-not2/RCLONE_TEST.51791ac5.partial: renamed to: subdir-not/subdir-not2/RCLONE_TEST 2026/08/31 04:04:55 INFO : subdir-not/subdir-not2/RCLONE_TEST: Copied (new) 2026/08/31 04:04:55 DEBUG : Waiting for deletions to finish 2026/08/31 04:04:55 NOTICE: (27) : copy-file /tmp/040346cekojis5/datadir/test_check_access_filters-sojedac8/include-other-filtersfile.txt /tmp/040346cekojis5/workdir/ 2026/08/31 04:04:55 DEBUG : copyFile "/tmp/040346cekojis5/datadir/test_check_access_filters-sojedac8/include-other-filtersfile.txt" to "/tmp/040346cekojis5/workdir/" as "" 2026/08/31 04:04:55 DEBUG : Creating backend with remote "/tmp/040346cekojis5/datadir/test_check_access_filters-sojedac8/include-other-filtersfile.txt" 2026/08/31 04:04:55 DEBUG : Config file has changed externally - reloading 2026/08/31 04:04:55 DEBUG : Creating backend with remote "/tmp/040346cekojis5/workdir/" 2026/08/31 04:04:55 DEBUG : operations.CopyFile "include-other-filtersfile.txt" to "Local file system at /tmp/040346cekojis5/workdir" as "include-other-filtersfile.txt" 2026/08/31 04:04:55 DEBUG : include-other-filtersfile.txt: Need to transfer - File not found at Destination 2026/08/31 04:04:55 DEBUG : include-other-filtersfile.txt.8126a844.partial: size = 178 OK 2026/08/31 04:04:55 DEBUG : include-other-filtersfile.txt: md5 = 2ec13b2813141ed088e5978ef5a47b0e OK 2026/08/31 04:04:55 DEBUG : include-other-filtersfile.txt.8126a844.partial: renamed to: include-other-filtersfile.txt 2026/08/31 04:04:55 INFO : include-other-filtersfile.txt: Copied (new) 2026/08/31 04:04:55 NOTICE: (28) : bisync resync filters-file=/tmp/040346cekojis5/workdir/include-other-filtersfile.txt 2026/08/31 04:04:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:34335") 2026/08/31 04:04:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:52914->172.17.0.4:34335, err= 2026/08/31 04:04:57 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:38690") 2026/08/31 04:04:57 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:46722->172.17.0.4:38690, err= 2026/08/31 04:04:59 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:04:59 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:04:59 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/08/31 04:04:59 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2026/08/31 04:04:59 INFO : Synching Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" with Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:04:59 INFO : Using filters file /tmp/040346cekojis5/workdir/include-other-filtersfile.txt 2026/08/31 04:04:59 INFO : Storing filters file hash to /tmp/040346cekojis5/workdir/include-other-filtersfile.txt.md5 2026/08/31 04:04:59 INFO : Copying Path2 files to Path1 2026/08/31 04:04:59 INFO : - Path2 Resync is copying files to - Path1 2026/08/31 04:04:59 INFO : There was nothing to transfer 2026/08/31 04:04:59 INFO : - Path1 Resync is copying files to - Path2 2026/08/31 04:04:59 INFO : There was nothing to transfer 2026/08/31 04:04:59 INFO : Resync updating listings 2026/08/31 04:04:59 INFO : Validating listings for Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" vs Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:04:59 INFO : Bisync successful 2026/08/31 04:04:59 NOTICE: (29) : test INCLUDE - test include/exclude filters for check access 2026/08/31 04:04:59 NOTICE: (30) : bisync check-access filters-file=/tmp/040346cekojis5/workdir/include-other-filtersfile.txt 2026/08/31 04:04:59 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:39115") 2026/08/31 04:04:59 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:34558->172.17.0.4:39115, err= 2026/08/31 04:05:01 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:37624") 2026/08/31 04:05:01 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:48188->172.17.0.4:37624, err= 2026/08/31 04:05:03 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:05:03 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:05:03 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/08/31 04:05:03 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2026/08/31 04:05:03 INFO : Synching Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" with Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:05:03 INFO : Using filters file /tmp/040346cekojis5/workdir/include-other-filtersfile.txt 2026/08/31 04:05:03 INFO : Building Path1 and Path2 listings 2026/08/31 04:05:03 INFO : Path1 checking for diffs 2026/08/31 04:05:03 INFO : Path2 checking for diffs 2026/08/31 04:05:03 INFO : Checking access health 2026/08/31 04:05:03 INFO : Found 5 matching "RCLONE_TEST" files on both paths 2026/08/31 04:05:03 INFO : No changes found 2026/08/31 04:05:03 INFO : Updating listings 2026/08/31 04:05:03 INFO : Validating listings for Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" vs Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:05:03 INFO : Bisync successful 2026/08/31 04:05:03 NOTICE: (31) : copy-listings include-initial 2026/08/31 04:05:03 NOTICE: (32) : test INCLUDE - delete RCLONE_TEST files in excluded directories 2026/08/31 04:05:03 NOTICE: (33) : delete-file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir/subdirA/RCLONE_TEST 2026/08/31 04:05:03 DEBUG : fs cache: switching user supplied name "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir/subdirA/" for canonical name "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir/subdirA/" 2026/08/31 04:05:03 INFO : RCLONE_TEST: Deleted 2026/08/31 04:05:03 NOTICE: (34) : delete-file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir-not/RCLONE_TEST 2026/08/31 04:05:03 DEBUG : fs cache: switching user supplied name "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir-not/" for canonical name "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir-not/" 2026/08/31 04:05:03 INFO : RCLONE_TEST: Deleted 2026/08/31 04:05:03 NOTICE: (35) : delete-file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir-not/subdir-not2/RCLONE_TEST 2026/08/31 04:05:03 DEBUG : fs cache: switching user supplied name "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir-not/subdir-not2/" for canonical name "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir-not/subdir-not2/" 2026/08/31 04:05:03 INFO : RCLONE_TEST: Deleted 2026/08/31 04:05:03 NOTICE: (36) : test INCLUDE - test should PASS 2026/08/31 04:05:03 NOTICE: (37) : bisync check-access filters-file=/tmp/040346cekojis5/workdir/include-other-filtersfile.txt 2026/08/31 04:05:03 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:32396") 2026/08/31 04:05:03 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:54404->172.17.0.4:32396, err= 2026/08/31 04:05:05 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:31899") 2026/08/31 04:05:05 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:52618->172.17.0.4:31899, err= 2026/08/31 04:05:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:05:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:05:07 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/08/31 04:05:07 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2026/08/31 04:05:07 INFO : Synching Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" with Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:05:07 INFO : Using filters file /tmp/040346cekojis5/workdir/include-other-filtersfile.txt 2026/08/31 04:05:07 INFO : Building Path1 and Path2 listings 2026/08/31 04:05:07 INFO : Path1 checking for diffs 2026/08/31 04:05:07 INFO : Path2 checking for diffs 2026/08/31 04:05:07 INFO : Checking access health 2026/08/31 04:05:07 INFO : Found 5 matching "RCLONE_TEST" files on both paths 2026/08/31 04:05:07 INFO : No changes found 2026/08/31 04:05:07 INFO : Updating listings 2026/08/31 04:05:07 INFO : Validating listings for Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" vs Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:05:07 INFO : Bisync successful 2026/08/31 04:05:07 NOTICE: (38) : copy-listings include-pass-run 2026/08/31 04:05:07 NOTICE: (39) : test INCLUDE - delete RCLONE_TEST files in included directories 2026/08/31 04:05:07 NOTICE: (40) : delete-file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/RCLONE_TEST 2026/08/31 04:05:07 DEBUG : fs cache: switching user supplied name "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" for canonical name "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:05:07 INFO : RCLONE_TEST: Deleted 2026/08/31 04:05:07 NOTICE: (41) : delete-file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir/RCLONE_TEST 2026/08/31 04:05:07 DEBUG : fs cache: switching user supplied name "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir/" for canonical name "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir/" 2026/08/31 04:05:07 INFO : RCLONE_TEST: Deleted 2026/08/31 04:05:07 NOTICE: (42) : delete-file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdirX/subdirX1/RCLONE_TEST 2026/08/31 04:05:07 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdirX/subdirX1/" 2026/08/31 04:05:07 DEBUG : Config file has changed externally - reloading 2026/08/31 04:05:07 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:05:07 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:05:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdirX/subdirX1: Connecting to FTP server 2026/08/31 04:05:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdirX/subdirX1: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdirX/subdirX1: > dial: conn=172.17.0.1:38520->172.17.0.4:21, err= 2026/08/31 04:05:10 DEBUG : fs cache: renaming cache item "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdirX/subdirX1/" to be canonical "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdirX/subdirX1/" 2026/08/31 04:05:10 INFO : RCLONE_TEST: Deleted 2026/08/31 04:05:10 NOTICE: (43) : test INCLUDE - test should ABORT 2026/08/31 04:05:10 NOTICE: (44) : bisync check-access filters-file=/tmp/040346cekojis5/workdir/include-other-filtersfile.txt 2026/08/31 04:05:10 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:36586") 2026/08/31 04:05:10 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:44446->172.17.0.4:36586, err= 2026/08/31 04:05:12 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:37264") 2026/08/31 04:05:12 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:44286->172.17.0.4:37264, err= 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:05:14 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/08/31 04:05:14 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2026/08/31 04:05:14 INFO : Synching Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/" with Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/" 2026/08/31 04:05:14 INFO : Using filters file /tmp/040346cekojis5/workdir/include-other-filtersfile.txt 2026/08/31 04:05:14 INFO : Building Path1 and Path2 listings 2026/08/31 04:05:14 INFO : Path1 checking for diffs 2026/08/31 04:05:14 INFO : - Path1 File was deleted - subdir/RCLONE_TEST 2026/08/31 04:05:14 INFO : - Path1 File was deleted - subdirX/subdirX1/RCLONE_TEST 2026/08/31 04:05:14 INFO : Path1: 2 changes:  0 new,  0 modified,  2 deleted 2026/08/31 04:05:14 INFO : Path2 checking for diffs 2026/08/31 04:05:14 INFO : - Path2 File was deleted - RCLONE_TEST 2026/08/31 04:05:14 INFO : Path2: 1 changes:  0 new,  0 modified,  1 deleted 2026/08/31 04:05:14 INFO : Checking access health 2026/08/31 04:05:14 ERROR : Access test failed: Path1 count 3, Path2 count 4 - RCLONE_TEST 2026/08/31 04:05:14 ERROR : -  Access test failed: Path1 file not found in Path2 - RCLONE_TEST 2026/08/31 04:05:14 ERROR : -  Access test failed: Path2 file not found in Path1 - subdir/RCLONE_TEST 2026/08/31 04:05:14 ERROR : -  Access test failed: Path2 file not found in Path1 - subdirX/subdirX1/RCLONE_TEST 2026/08/31 04:05:14 ERROR : Bisync critical error: check file check failed 2026/08/31 04:05:14 ERROR : Bisync aborted. Must run --resync to recover. 2026/08/31 04:05:14 NOTICE: Bisync error: bisync aborted 2026/08/31 04:05:14 NOTICE: (45) : move-listings include-error-run 2026/08/31 04:05:14 DEBUG : Waiting for deletions to finish 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:32135") 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:44358->172.17.0.4:32135, err= 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Connecting to FTP server 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:36906->172.17.0.4:21, err= 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:36354") 2026/08/31 04:05:14 INFO : file4.txt: Deleted 2026/08/31 04:05:14 INFO : file3.txt: Deleted 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:35017") 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:48254->172.17.0.4:36354, err= 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:35717") 2026/08/31 04:05:14 INFO : file1.txt: Deleted 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:51862->172.17.0.4:35717, err= 2026/08/31 04:05:14 INFO : RCLONE_TEST: Deleted 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:41044->172.17.0.4:35017, err= 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Connecting to FTP server 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:33528") 2026/08/31 04:05:14 INFO : subdirX/RCLONE_TEST: Deleted 2026/08/31 04:05:14 INFO : subdirX/file20.txt: Deleted 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:40658->172.17.0.4:33528, err= 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:37217") 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:50712->172.17.0.4:37217, err= 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:38130") 2026/08/31 04:05:14 INFO : subdir/file20.txt: Deleted 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:39958->172.17.0.4:38130, err= 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:30326") 2026/08/31 04:05:14 INFO : subdirX/subdirX1/file30.txt: Deleted 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:44686->172.17.0.4:30326, err= 2026/08/31 04:05:14 INFO : subdir/subdirB/file30.txt: Deleted 2026/08/31 04:05:14 INFO : subdir/subdirB/RCLONE_TEST: Deleted 2026/08/31 04:05:14 INFO : subdir/subdirA/file30.txt: Deleted 2026/08/31 04:05:14 INFO : subdir-not/subdir-not2/RCLONE_TEST: Deleted 2026/08/31 04:05:14 INFO : subdir-not/subdir-not2/file30.txt: Deleted 2026/08/31 04:05:14 INFO : subdir/subdirA/RCLONE_TEST: Deleted 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:14 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:36912->172.17.0.4:21, err= 2026/08/31 04:05:17 INFO : file2.txt: Deleted 2026/08/31 04:05:17 INFO : subdir-not/file20.txt: Deleted 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:34868") 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:52616->172.17.0.4:34868, err= 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:37145") 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:31719") 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:30865") 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:39988->172.17.0.4:31719, err= 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:47710->172.17.0.4:37145, err= 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:55828->172.17.0.4:30865, err= 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:39021") 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:32150") 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:48306->172.17.0.4:39021, err= 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:34283") 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: dial("tcp","172.17.0.4:30614") 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:50786->172.17.0.4:32150, err= 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:39838->172.17.0.4:34283, err= 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: > dial: conn=172.17.0.1:35670->172.17.0.4:30614, err= 2026/08/31 04:05:17 DEBUG : removing 4 level 2 directories 2026/08/31 04:05:17 INFO : subdirX/subdirX1: Removing directory 2026/08/31 04:05:17 INFO : subdir-not/subdir-not2: Removing directory 2026/08/31 04:05:17 INFO : subdir/subdirA: Removing directory 2026/08/31 04:05:17 INFO : subdir/subdirB: Removing directory 2026/08/31 04:05:17 DEBUG : removing 3 level 1 directories 2026/08/31 04:05:17 INFO : subdirX: Removing directory 2026/08/31 04:05:17 INFO : subdir: Removing directory 2026/08/31 04:05:17 INFO : subdir-not: Removing directory 2026/08/31 04:05:17 DEBUG : removing 1 level 0 directories 2026/08/31 04:05:17 INFO : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: Removing directory 2026/08/31 04:05:17 DEBUG : Waiting for deletions to finish 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:31508") 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:51584->172.17.0.4:31508, err= 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Connecting to FTP server 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:31185") 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:53460->172.17.0.4:31185, err= 2026/08/31 04:05:17 INFO : file2.txt: Deleted 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:36920->172.17.0.4:21, err= 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:38247") 2026/08/31 04:05:17 INFO : file3.txt: Deleted 2026/08/31 04:05:17 INFO : file1.txt: Deleted 2026/08/31 04:05:17 INFO : file4.txt: Deleted 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:33715") 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:49626->172.17.0.4:38247, err= 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:57368->172.17.0.4:33715, err= 2026/08/31 04:05:17 INFO : subdirX/file20.txt: Deleted 2026/08/31 04:05:17 INFO : subdirX/RCLONE_TEST: Deleted 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:35582") 2026/08/31 04:05:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:46100->172.17.0.4:35582, err= 2026/08/31 04:05:17 INFO : subdir-not/RCLONE_TEST: Deleted 2026/08/31 04:05:17 INFO : subdir-not/file20.txt: Deleted 2026/08/31 04:05:17 INFO : subdirX/subdirX1/file30.txt: Deleted 2026/08/31 04:05:17 INFO : subdirX/subdirX1/RCLONE_TEST: Deleted 2026/08/31 04:05:17 INFO : subdir-not/subdir-not2/file30.txt: Deleted 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:30305") 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:56578->172.17.0.4:30305, err= 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:38034") 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:37030") 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:33838->172.17.0.4:38034, err= 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:46872->172.17.0.4:37030, err= 2026/08/31 04:05:20 INFO : subdir/file20.txt: Deleted 2026/08/31 04:05:20 INFO : subdir/RCLONE_TEST: Deleted 2026/08/31 04:05:20 INFO : subdir/subdirB/RCLONE_TEST: Deleted 2026/08/31 04:05:20 INFO : subdir/subdirA/file30.txt: Deleted 2026/08/31 04:05:20 INFO : subdir/subdirB/file30.txt: Deleted 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:38301") 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:44308->172.17.0.4:38301, err= 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:36482") 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:30077") 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:46172->172.17.0.4:36482, err= 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:44542->172.17.0.4:30077, err= 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:39877") 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:38907") 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:36121") 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:33163") 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:56254->172.17.0.4:38907, err= 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:60474->172.17.0.4:36121, err= 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:50742->172.17.0.4:39877, err= 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:55190->172.17.0.4:33163, err= 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: dial("tcp","172.17.0.4:36225") 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: > dial: conn=172.17.0.1:58408->172.17.0.4:36225, err= 2026/08/31 04:05:20 DEBUG : removing 4 level 2 directories 2026/08/31 04:05:20 INFO : subdirX/subdirX1: Removing directory 2026/08/31 04:05:20 INFO : subdir/subdirA: Removing directory 2026/08/31 04:05:20 INFO : subdir-not/subdir-not2: Removing directory 2026/08/31 04:05:20 INFO : subdir/subdirB: Removing directory 2026/08/31 04:05:20 DEBUG : removing 3 level 1 directories 2026/08/31 04:05:20 INFO : subdirX: Removing directory 2026/08/31 04:05:20 INFO : subdir: Removing directory 2026/08/31 04:05:20 INFO : subdir-not: Removing directory 2026/08/31 04:05:20 DEBUG : removing 1 level 0 directories 2026/08/31 04:05:20 INFO : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: Removing directory bisync_test.go:610: TEST check_access_filters PASSED === RUN TestBisyncRemoteRemote/check_filename 2026/08/31 04:05:20 DEBUG : fs cache: switching user supplied name "TestFTPPureftpd:rclone-test-tedetoz6cudi/040346cekojis5" for canonical name "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5" 2026/08/31 04:05:20 INFO : path1: Making directory 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5: Connecting to FTP server 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:20 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5: > dial: conn=172.17.0.1:36928->172.17.0.4:21, err= 2026/08/31 04:05:23 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1" 2026/08/31 04:05:23 DEBUG : Config file has changed externally - reloading 2026/08/31 04:05:23 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:05:23 DEBUG : Setting host=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/08/31 04:05:23 DEBUG : Setting user=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/08/31 04:05:23 DEBUG : Setting pass=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/08/31 04:05:23 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/08/31 04:05:23 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:05:23 DEBUG : Setting host=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/08/31 04:05:23 DEBUG : Setting user=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/08/31 04:05:23 DEBUG : Setting pass=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/08/31 04:05:23 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/08/31 04:05:23 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: Connecting to FTP server 2026/08/31 04:05:23 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:23 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:36318->172.17.0.4:21, err= 2026/08/31 04:05:25 DEBUG : fs cache: renaming cache item "TestFTPPureftpd:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1" to be canonical "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1" 2026/08/31 04:05:25 DEBUG : fs cache: switching user supplied name "TestFTPPureftpd:rclone-test-tedetoz6cudi/040346cekojis5" for canonical name "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5" 2026/08/31 04:05:25 INFO : path2: Making directory 2026/08/31 04:05:25 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2" 2026/08/31 04:05:25 DEBUG : Config file has changed externally - reloading 2026/08/31 04:05:25 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:05:25 DEBUG : Setting host=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/08/31 04:05:25 DEBUG : Setting user=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/08/31 04:05:25 DEBUG : Setting pass=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/08/31 04:05:25 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/08/31 04:05:25 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:05:25 DEBUG : Setting host=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/08/31 04:05:25 DEBUG : Setting user=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/08/31 04:05:25 DEBUG : Setting pass=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/08/31 04:05:25 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/08/31 04:05:25 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: Connecting to FTP server 2026/08/31 04:05:25 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:25 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:36332->172.17.0.4:21, err= 2026/08/31 04:05:27 DEBUG : fs cache: renaming cache item "TestFTPPureftpd:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2" to be canonical "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2" 2026/08/31 04:05:27 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_filename/initial" 2026/08/31 04:05:27 DEBUG : Creating backend with remote "/tmp/040346cekojis5/initdir/test_check_filename-layejix1" 2026/08/31 04:05:27 DEBUG : .chk_file: Need to transfer - File not found at Destination 2026/08/31 04:05:27 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/08/31 04:05:27 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/08/31 04:05:27 DEBUG : file3.txt: Need to transfer - File not found at Destination 2026/08/31 04:05:27 DEBUG : file4.txt: Need to transfer - File not found at Destination 2026/08/31 04:05:27 DEBUG : subdir: Making directory with metadata 2026/08/31 04:05:27 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2026/08/31 04:05:27 DEBUG : Added delayed dir = "subdir", newDst=subdir 2026/08/31 04:05:27 DEBUG : subdir/.chk_file: Need to transfer - File not found at Destination 2026/08/31 04:05:27 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/08/31 04:05:27 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/08/31 04:05:27 DEBUG : file2.txt.3230ad67.partial: size = 0 OK 2026/08/31 04:05:27 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/08/31 04:05:27 DEBUG : Local file system at /tmp/040346cekojis5/initdir/test_check_filename-layejix1: Waiting for checks to finish 2026/08/31 04:05:27 DEBUG : Local file system at /tmp/040346cekojis5/initdir/test_check_filename-layejix1: Waiting for transfers to finish 2026/08/31 04:05:27 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/08/31 04:05:27 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/08/31 04:05:27 INFO : file1.txt: Copied (new) 2026/08/31 04:05:27 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2026/08/31 04:05:27 INFO : file2.txt: Copied (new) 2026/08/31 04:05:27 DEBUG : .chk_file.b7f3f5bf.partial: size = 109 OK 2026/08/31 04:05:27 DEBUG : .chk_file: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/08/31 04:05:27 DEBUG : file4.txt.fbf05a9b.partial: size = 0 OK 2026/08/31 04:05:27 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/08/31 04:05:27 DEBUG : .chk_file.b7f3f5bf.partial: renamed to: .chk_file 2026/08/31 04:05:27 INFO : .chk_file: Copied (new) 2026/08/31 04:05:27 DEBUG : subdir/.chk_file.6dc50fe3.partial: size = 109 OK 2026/08/31 04:05:27 DEBUG : file3.txt.a74079f2.partial: size = 0 OK 2026/08/31 04:05:27 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2026/08/31 04:05:27 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/08/31 04:05:27 INFO : file4.txt: Copied (new) 2026/08/31 04:05:27 DEBUG : subdir/.chk_file: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/08/31 04:05:27 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2026/08/31 04:05:27 INFO : file3.txt: Copied (new) 2026/08/31 04:05:27 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK 2026/08/31 04:05:27 DEBUG : subdir/.chk_file.6dc50fe3.partial: renamed to: subdir/.chk_file 2026/08/31 04:05:27 INFO : subdir/.chk_file: Copied (new) 2026/08/31 04:05:27 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/08/31 04:05:27 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2026/08/31 04:05:27 INFO : subdir/file20.txt: Copied (new) 2026/08/31 04:05:27 INFO : subdir: Set directory modification time (using SetModTime) 2026/08/31 04:05:27 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_filename/modfiles" 2026/08/31 04:05:27 DEBUG : Creating backend with remote "/tmp/040346cekojis5/datadir/test_check_filename-fujeqof2" 2026/08/31 04:05:27 DEBUG : hold.txt: Need to transfer - File not found at Destination 2026/08/31 04:05:27 DEBUG : Local file system at /tmp/040346cekojis5/datadir/test_check_filename-fujeqof2: Waiting for checks to finish 2026/08/31 04:05:27 DEBUG : Local file system at /tmp/040346cekojis5/datadir/test_check_filename-fujeqof2: Waiting for transfers to finish 2026/08/31 04:05:27 DEBUG : hold.txt.83686dab.partial: size = 59 OK 2026/08/31 04:05:27 DEBUG : hold.txt: md5 = 628c2241b6ba4e313ef08bdfcf1cd964 OK 2026/08/31 04:05:27 DEBUG : hold.txt.83686dab.partial: renamed to: hold.txt 2026/08/31 04:05:27 INFO : hold.txt: Copied (new) 2026/08/31 04:05:27 DEBUG : Waiting for deletions to finish 2026/08/31 04:05:27 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:36379") 2026/08/31 04:05:27 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:52878->172.17.0.4:36379, err= 2026/08/31 04:05:27 ERROR : error listing: directory not found 2026/08/31 04:05:27 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:30215") 2026/08/31 04:05:27 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:60882->172.17.0.4:30215, err= 2026/08/31 04:05:27 ERROR : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: Failed to list "": directory not found 2026/08/31 04:05:27 DEBUG : removing 1 level 0 directories 2026/08/31 04:05:27 INFO : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: Removing directory 2026/08/31 04:05:27 ERROR : Failed to rmdir: directory not found 2026/08/31 04:05:27 DEBUG : Waiting for deletions to finish 2026/08/31 04:05:27 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:39068") 2026/08/31 04:05:27 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:52748->172.17.0.4:39068, err= 2026/08/31 04:05:27 ERROR : error listing: directory not found 2026/08/31 04:05:27 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:39007") 2026/08/31 04:05:27 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:42652->172.17.0.4:39007, err= 2026/08/31 04:05:27 ERROR : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: Failed to list "": directory not found 2026/08/31 04:05:27 DEBUG : removing 1 level 0 directories 2026/08/31 04:05:27 INFO : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: Removing directory 2026/08/31 04:05:27 ERROR : Failed to rmdir: directory not found 2026/08/31 04:05:27 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:30475") 2026/08/31 04:05:27 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:50648->172.17.0.4:30475, err= 2026/08/31 04:05:27 ERROR : error listing: directory not found 2026/08/31 04:05:27 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:30564") 2026/08/31 04:05:27 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:42046->172.17.0.4:30564, err= 2026/08/31 04:05:27 ERROR : error listing: directory not found 2026/08/31 04:05:27 NOTICE: checking initFs Local file system at /tmp/040346cekojis5/initdir/test_check_filename-layejix1 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:37991") 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:39708->172.17.0.4:37991, err= 2026/08/31 04:05:28 DEBUG : .chk_file: Need to transfer - File not found at Destination 2026/08/31 04:05:28 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/08/31 04:05:28 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/08/31 04:05:28 DEBUG : file3.txt: Need to transfer - File not found at Destination 2026/08/31 04:05:28 DEBUG : file4.txt: Need to transfer - File not found at Destination 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: Connecting to FTP server 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: Connecting to FTP server 2026/08/31 04:05:28 INFO : subdir: Making directory 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: Connecting to FTP server 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: Connecting to FTP server 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:36340->172.17.0.4:21, err= 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:38619") 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:44478->172.17.0.4:38619, err= 2026/08/31 04:05:28 DEBUG : .chk_file.b7f3f5bf.partial: size = 109 OK 2026/08/31 04:05:28 DEBUG : .chk_file.b7f3f5bf.partial: renamed to: .chk_file 2026/08/31 04:05:28 INFO : .chk_file: Copied (new) 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:37930") 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:45436->172.17.0.4:37930, err= 2026/08/31 04:05:28 DEBUG : file4.txt.fbf05a9b.partial: size = 0 OK 2026/08/31 04:05:28 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2026/08/31 04:05:28 INFO : file4.txt: Copied (new) 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:36352->172.17.0.4:21, err= 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:36366->172.17.0.4:21, err= 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:28 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:36376->172.17.0.4:21, err= 2026/08/31 04:05:29 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdirX: closing 1 unused connections 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:33052") 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:47468->172.17.0.4:33052, err= 2026/08/31 04:05:31 DEBUG : file2.txt.3230ad67.partial: size = 0 OK 2026/08/31 04:05:31 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2026/08/31 04:05:31 INFO : file2.txt: Copied (new) 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:34813") 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:39130->172.17.0.4:34813, err= 2026/08/31 04:05:31 DEBUG : file3.txt.a74079f2.partial: size = 0 OK 2026/08/31 04:05:31 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2026/08/31 04:05:31 INFO : file3.txt: Copied (new) 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:39373") 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:44470->172.17.0.4:39373, err= 2026/08/31 04:05:31 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/08/31 04:05:31 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/08/31 04:05:31 INFO : file1.txt: Copied (new) 2026/08/31 04:05:31 DEBUG : subdir/.chk_file: Need to transfer - File not found at Destination 2026/08/31 04:05:31 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: Waiting for checks to finish 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: Waiting for transfers to finish 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:34314") 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:55202->172.17.0.4:34314, err= 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:38416") 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:44228->172.17.0.4:38416, err= 2026/08/31 04:05:31 DEBUG : subdir/.chk_file.6dc50fe3.partial: size = 109 OK 2026/08/31 04:05:31 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK 2026/08/31 04:05:31 DEBUG : subdir/.chk_file.6dc50fe3.partial: renamed to: subdir/.chk_file 2026/08/31 04:05:31 INFO : subdir/.chk_file: Copied (new) 2026/08/31 04:05:31 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2026/08/31 04:05:31 INFO : subdir/file20.txt: Copied (new) 2026/08/31 04:05:31 NOTICE: checking Path1 ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:36519") 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:43680->172.17.0.4:36519, err= 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:34163") 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:52056->172.17.0.4:34163, err= 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:35152") 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:40054->172.17.0.4:35152, err= 2026/08/31 04:05:31 DEBUG : .chk_file: Need to transfer - File not found at Destination 2026/08/31 04:05:31 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/08/31 04:05:31 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/08/31 04:05:31 DEBUG : file3.txt: Need to transfer - File not found at Destination 2026/08/31 04:05:31 DEBUG : file4.txt: Need to transfer - File not found at Destination 2026/08/31 04:05:31 INFO : subdir: Making directory 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: Connecting to FTP server 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: Connecting to FTP server 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: Connecting to FTP server 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:35190->172.17.0.4:21, err= 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: Connecting to FTP server 2026/08/31 04:05:31 DEBUG : subdir/.chk_file: Need to transfer - File not found at Destination 2026/08/31 04:05:31 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: Waiting for checks to finish 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: Waiting for transfers to finish 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:35198->172.17.0.4:21, err= 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:35210->172.17.0.4:21, err= 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:31 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:35224->172.17.0.4:21, err= 2026/08/31 04:05:34 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:31214") 2026/08/31 04:05:34 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:38212->172.17.0.4:31214, err= 2026/08/31 04:05:34 DEBUG : file2.txt.3230ad67.partial: size = 0 OK 2026/08/31 04:05:34 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2026/08/31 04:05:34 INFO : file2.txt: Copied (new) 2026/08/31 04:05:34 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:32574") 2026/08/31 04:05:34 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:36214->172.17.0.4:32574, err= 2026/08/31 04:05:34 DEBUG : file4.txt.fbf05a9b.partial: size = 0 OK 2026/08/31 04:05:34 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2026/08/31 04:05:34 INFO : file4.txt: Copied (new) 2026/08/31 04:05:34 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:33035") 2026/08/31 04:05:34 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:46218->172.17.0.4:33035, err= 2026/08/31 04:05:34 DEBUG : subdir/.chk_file.6dc50fe3.partial: size = 109 OK 2026/08/31 04:05:34 DEBUG : subdir/.chk_file.6dc50fe3.partial: renamed to: subdir/.chk_file 2026/08/31 04:05:34 INFO : subdir/.chk_file: Copied (new) 2026/08/31 04:05:34 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:38851") 2026/08/31 04:05:34 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:57826->172.17.0.4:38851, err= 2026/08/31 04:05:34 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK 2026/08/31 04:05:34 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2026/08/31 04:05:34 INFO : subdir/file20.txt: Copied (new) 2026/08/31 04:05:34 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:35799") 2026/08/31 04:05:34 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:52948->172.17.0.4:35799, err= 2026/08/31 04:05:34 DEBUG : .chk_file.b7f3f5bf.partial: size = 109 OK 2026/08/31 04:05:34 DEBUG : .chk_file.b7f3f5bf.partial: renamed to: .chk_file 2026/08/31 04:05:34 INFO : .chk_file: Copied (new) 2026/08/31 04:05:34 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:39224") 2026/08/31 04:05:34 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:46904->172.17.0.4:39224, err= 2026/08/31 04:05:34 DEBUG : file3.txt.a74079f2.partial: size = 0 OK 2026/08/31 04:05:34 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2026/08/31 04:05:34 INFO : file3.txt: Copied (new) 2026/08/31 04:05:35 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:36651") 2026/08/31 04:05:35 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:33822->172.17.0.4:36651, err= 2026/08/31 04:05:35 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/08/31 04:05:35 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/08/31 04:05:35 INFO : file1.txt: Copied (new) 2026/08/31 04:05:35 NOTICE: checking path2 ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2 2026/08/31 04:05:35 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:37459") 2026/08/31 04:05:35 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:44950->172.17.0.4:37459, err= 2026/08/31 04:05:35 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:34499") 2026/08/31 04:05:35 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:43306->172.17.0.4:34499, err= 2026/08/31 04:05:35 NOTICE: (01) : test check-filename 2026/08/31 04:05:35 NOTICE: (02) : test initial bisync 2026/08/31 04:05:35 NOTICE: (03) : bisync resync 2026/08/31 04:05:35 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:39976") 2026/08/31 04:05:35 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:59442->172.17.0.4:39976, err= 2026/08/31 04:05:37 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:30881") 2026/08/31 04:05:37 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:42020->172.17.0.4:30881, err= 2026/08/31 04:05:39 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:05:39 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:05:39 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/08/31 04:05:39 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2026/08/31 04:05:39 INFO : Synching Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/" with Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/" 2026/08/31 04:05:39 INFO : Copying Path2 files to Path1 2026/08/31 04:05:39 INFO : - Path2 Resync is copying files to - Path1 2026/08/31 04:05:39 INFO : There was nothing to transfer 2026/08/31 04:05:39 INFO : - Path1 Resync is copying files to - Path2 2026/08/31 04:05:39 INFO : There was nothing to transfer 2026/08/31 04:05:39 INFO : Resync updating listings 2026/08/31 04:05:39 INFO : Validating listings for Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/" vs Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/" 2026/08/31 04:05:39 INFO : Bisync successful 2026/08/31 04:05:39 NOTICE: (04) : test 1. see that check-access passes with the initial setup 2026/08/31 04:05:39 NOTICE: (05) : bisync check-access check-filename=.chk_file 2026/08/31 04:05:39 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:37252") 2026/08/31 04:05:39 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:36476->172.17.0.4:37252, err= 2026/08/31 04:05:41 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:33314") 2026/08/31 04:05:41 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:60484->172.17.0.4:33314, err= 2026/08/31 04:05:43 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:05:43 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:05:43 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/08/31 04:05:43 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2026/08/31 04:05:43 INFO : Synching Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/" with Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/" 2026/08/31 04:05:43 INFO : Building Path1 and Path2 listings 2026/08/31 04:05:43 INFO : Path1 checking for diffs 2026/08/31 04:05:43 INFO : Path2 checking for diffs 2026/08/31 04:05:43 INFO : Checking access health 2026/08/31 04:05:43 INFO : Found 2 matching ".chk_file" files on both paths 2026/08/31 04:05:43 INFO : No changes found 2026/08/31 04:05:43 INFO : Updating listings 2026/08/31 04:05:43 INFO : Validating listings for Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/" vs Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/" 2026/08/31 04:05:43 INFO : Bisync successful 2026/08/31 04:05:43 NOTICE: (06) : copy-listings initial-pass 2026/08/31 04:05:43 NOTICE: (07) : test 2. delete the remote subdir .chk_file, run sync. should fail critical. 2026/08/31 04:05:43 NOTICE: (08) : delete-file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir/.chk_file 2026/08/31 04:05:43 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir/" 2026/08/31 04:05:43 DEBUG : Config file has changed externally - reloading 2026/08/31 04:05:43 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:05:43 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:05:43 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir: Connecting to FTP server 2026/08/31 04:05:43 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:43 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir: > dial: conn=172.17.0.1:38470->172.17.0.4:21, err= 2026/08/31 04:05:46 DEBUG : fs cache: renaming cache item "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir/" to be canonical "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir/" 2026/08/31 04:05:46 INFO : .chk_file: Deleted 2026/08/31 04:05:46 NOTICE: (09) : bisync check-access check-filename=.chk_file 2026/08/31 04:05:46 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:38132") 2026/08/31 04:05:46 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:58974->172.17.0.4:38132, err= 2026/08/31 04:05:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:37570") 2026/08/31 04:05:48 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:50454->172.17.0.4:37570, err= 2026/08/31 04:05:50 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:05:50 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:05:50 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/08/31 04:05:50 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2026/08/31 04:05:50 INFO : Synching Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/" with Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/" 2026/08/31 04:05:50 INFO : Building Path1 and Path2 listings 2026/08/31 04:05:50 INFO : Path1 checking for diffs 2026/08/31 04:05:50 INFO : Path2 checking for diffs 2026/08/31 04:05:50 INFO : - Path2 File was deleted - subdir/.chk_file 2026/08/31 04:05:50 INFO : Path2: 1 changes:  0 new,  0 modified,  1 deleted 2026/08/31 04:05:50 INFO : Checking access health 2026/08/31 04:05:50 ERROR : Access test failed: Path1 count 2, Path2 count 1 - .chk_file 2026/08/31 04:05:50 ERROR : -  Access test failed: Path1 file not found in Path2 - subdir/.chk_file 2026/08/31 04:05:50 ERROR : Bisync critical error: check file check failed 2026/08/31 04:05:50 ERROR : Bisync aborted. Must run --resync to recover. 2026/08/31 04:05:50 NOTICE: Bisync error: bisync aborted 2026/08/31 04:05:50 NOTICE: (10) : move-listings path2-missing 2026/08/31 04:05:50 NOTICE: (11) : test 3. put the remote subdir .chk_file back, run resync. 2026/08/31 04:05:50 NOTICE: (12) : copy-file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/subdir/.chk_file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir/ 2026/08/31 04:05:50 DEBUG : copyFile "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/subdir/.chk_file" to "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir/" as "" 2026/08/31 04:05:50 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/subdir/.chk_file" 2026/08/31 04:05:50 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:05:50 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:05:50 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/subdir/.chk_file: Connecting to FTP server 2026/08/31 04:05:50 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/subdir/.chk_file: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:50 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/subdir/.chk_file: > dial: conn=172.17.0.1:38472->172.17.0.4:21, err= 2026/08/31 04:05:53 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='IEzWn8y7R97U2MEvp8Kl8k8ZPGyIKpvn5UAcCf8HnEk',user='rclone':rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir/" 2026/08/31 04:05:53 DEBUG : Setting type=XXX for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/08/31 04:05:53 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7ULTW}" suffix to name 2026/08/31 04:05:53 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir: Connecting to FTP server 2026/08/31 04:05:53 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir: dial("tcp","172.17.0.4:21") 2026/08/31 04:05:53 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir: > dial: conn=172.17.0.1:52322->172.17.0.4:21, err= 2026/08/31 04:05:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: closing 4 unused connections 2026/08/31 04:05:55 DEBUG : operations.CopyFile ".chk_file" to "ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir" as ".chk_file" 2026/08/31 04:05:55 DEBUG : .chk_file: Need to transfer - File not found at Destination 2026/08/31 04:05:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/subdir/.chk_file: dial("tcp","172.17.0.4:33957") 2026/08/31 04:05:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/subdir/.chk_file: > dial: conn=172.17.0.1:49692->172.17.0.4:33957, err= 2026/08/31 04:05:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir: dial("tcp","172.17.0.4:34702") 2026/08/31 04:05:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir: > dial: conn=172.17.0.1:56386->172.17.0.4:34702, err= 2026/08/31 04:05:55 DEBUG : .chk_file.b7f3f5bf.partial: size = 109 OK 2026/08/31 04:05:55 DEBUG : .chk_file.b7f3f5bf.partial: renamed to: .chk_file 2026/08/31 04:05:55 INFO : .chk_file: Copied (new) 2026/08/31 04:05:55 NOTICE: (13) : bisync check-access resync check-filename=.chk_file 2026/08/31 04:05:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:33552") 2026/08/31 04:05:55 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:60598->172.17.0.4:33552, err= 2026/08/31 04:05:57 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:34118") 2026/08/31 04:05:57 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:45252->172.17.0.4:34118, err= 2026/08/31 04:05:59 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:05:59 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:05:59 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/08/31 04:05:59 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2026/08/31 04:05:59 INFO : Synching Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/" with Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/" 2026/08/31 04:05:59 INFO : Copying Path2 files to Path1 2026/08/31 04:05:59 INFO : Checking access health 2026/08/31 04:05:59 INFO : Found 2 matching ".chk_file" files on both paths 2026/08/31 04:05:59 INFO : - Path2 Resync is copying files to - Path1 2026/08/31 04:05:59 INFO : There was nothing to transfer 2026/08/31 04:05:59 INFO : - Path1 Resync is copying files to - Path2 2026/08/31 04:05:59 INFO : There was nothing to transfer 2026/08/31 04:05:59 INFO : Resync updating listings 2026/08/31 04:05:59 INFO : Validating listings for Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/" vs Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/" 2026/08/31 04:05:59 INFO : Bisync successful 2026/08/31 04:05:59 NOTICE: (14) : test 4. run sync with check-access. should pass. 2026/08/31 04:05:59 NOTICE: (15) : bisync check-access check-filename=.chk_file 2026/08/31 04:05:59 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:31392") 2026/08/31 04:05:59 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:48356->172.17.0.4:31392, err= 2026/08/31 04:06:01 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:31586") 2026/08/31 04:06:01 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:49968->172.17.0.4:31586, err= 2026/08/31 04:06:03 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir/subdirA: closing 1 unused connections 2026/08/31 04:06:03 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir-not: closing 1 unused connections 2026/08/31 04:06:03 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2/subdir-not/subdir-not2: closing 1 unused connections 2026/08/31 04:06:03 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:06:03 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/08/31 04:06:03 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/08/31 04:06:03 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2026/08/31 04:06:03 INFO : Synching Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/" with Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/" 2026/08/31 04:06:03 INFO : Building Path1 and Path2 listings 2026/08/31 04:06:03 INFO : Path1 checking for diffs 2026/08/31 04:06:03 INFO : Path2 checking for diffs 2026/08/31 04:06:03 INFO : Checking access health 2026/08/31 04:06:03 INFO : Found 2 matching ".chk_file" files on both paths 2026/08/31 04:06:03 INFO : No changes found 2026/08/31 04:06:03 INFO : Updating listings 2026/08/31 04:06:03 INFO : Validating listings for Path1 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1/" vs Path2 "TestFTPPureftpd{7ULTW}:rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/" 2026/08/31 04:06:03 INFO : Bisync successful 2026/08/31 04:06:03 DEBUG : Waiting for deletions to finish 2026/08/31 04:06:03 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:33021") 2026/08/31 04:06:03 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:49430->172.17.0.4:33021, err= 2026/08/31 04:06:03 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: Connecting to FTP server 2026/08/31 04:06:03 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:21") 2026/08/31 04:06:03 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:45682->172.17.0.4:21, err= 2026/08/31 04:06:03 INFO : file2.txt: Deleted 2026/08/31 04:06:03 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:31883") 2026/08/31 04:06:03 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:58824->172.17.0.4:31883, err= 2026/08/31 04:06:03 INFO : file3.txt: Deleted 2026/08/31 04:06:03 INFO : file1.txt: Deleted 2026/08/31 04:06:03 INFO : file4.txt: Deleted 2026/08/31 04:06:03 INFO : subdir/.chk_file: Deleted 2026/08/31 04:06:03 INFO : subdir/file20.txt: Deleted 2026/08/31 04:06:07 INFO : .chk_file: Deleted 2026/08/31 04:06:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:39730") 2026/08/31 04:06:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:49514->172.17.0.4:39730, err= 2026/08/31 04:06:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: dial("tcp","172.17.0.4:36390") 2026/08/31 04:06:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: > dial: conn=172.17.0.1:41444->172.17.0.4:36390, err= 2026/08/31 04:06:07 DEBUG : removing 1 level 1 directories 2026/08/31 04:06:07 INFO : subdir: Removing directory 2026/08/31 04:06:07 DEBUG : removing 1 level 0 directories 2026/08/31 04:06:07 INFO : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: Removing directory 2026/08/31 04:06:07 DEBUG : Waiting for deletions to finish 2026/08/31 04:06:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:36924") 2026/08/31 04:06:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:34062->172.17.0.4:36924, err= 2026/08/31 04:06:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: Connecting to FTP server 2026/08/31 04:06:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:21") 2026/08/31 04:06:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:45686->172.17.0.4:21, err= 2026/08/31 04:06:07 INFO : file4.txt: Deleted 2026/08/31 04:06:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:36512") 2026/08/31 04:06:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:38200->172.17.0.4:36512, err= 2026/08/31 04:06:07 INFO : file3.txt: Deleted 2026/08/31 04:06:07 INFO : file1.txt: Deleted 2026/08/31 04:06:07 INFO : .chk_file: Deleted 2026/08/31 04:06:07 INFO : subdir/.chk_file: Deleted 2026/08/31 04:06:07 INFO : subdir/file20.txt: Deleted 2026/08/31 04:06:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: closing 4 unused connections 2026/08/31 04:06:07 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdir: closing 1 unused connections 2026/08/31 04:06:10 INFO : file2.txt: Deleted 2026/08/31 04:06:10 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:32943") 2026/08/31 04:06:10 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:44654->172.17.0.4:32943, err= 2026/08/31 04:06:10 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: dial("tcp","172.17.0.4:34796") 2026/08/31 04:06:10 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: > dial: conn=172.17.0.1:47938->172.17.0.4:34796, err= 2026/08/31 04:06:10 DEBUG : removing 1 level 1 directories 2026/08/31 04:06:10 INFO : subdir: Removing directory 2026/08/31 04:06:10 DEBUG : removing 1 level 0 directories 2026/08/31 04:06:10 INFO : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: Removing directory bisync_test.go:610: TEST check_filename PASSED 2026/08/31 04:06:10 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: Connecting to FTP server 2026/08/31 04:06:10 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: dial("tcp","172.17.0.4:21") 2026/08/31 04:06:10 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: > dial: conn=172.17.0.1:45702->172.17.0.4:21, err= 2026/08/31 04:06:10 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1/subdirX/subdirX1: closing 1 unused connections 2026/08/31 04:06:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: dial("tcp","172.17.0.4:32810") 2026/08/31 04:06:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: > dial: conn=172.17.0.1:57246->172.17.0.4:32810, err= 2026/08/31 04:06:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: dial("tcp","172.17.0.4:38594") 2026/08/31 04:06:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: > dial: conn=172.17.0.1:48570->172.17.0.4:38594, err= 2026/08/31 04:06:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: Connecting to FTP server 2026/08/31 04:06:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: Connecting to FTP server 2026/08/31 04:06:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: Connecting to FTP server 2026/08/31 04:06:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: dial("tcp","172.17.0.4:21") 2026/08/31 04:06:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: dial("tcp","172.17.0.4:36716") 2026/08/31 04:06:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: > dial: conn=172.17.0.1:46160->172.17.0.4:21, err= 2026/08/31 04:06:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: > dial: conn=172.17.0.1:59558->172.17.0.4:36716, err= 2026/08/31 04:06:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: dial("tcp","172.17.0.4:21") 2026/08/31 04:06:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: > dial: conn=172.17.0.1:46164->172.17.0.4:21, err= 2026/08/31 04:06:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: dial("tcp","172.17.0.4:21") 2026/08/31 04:06:13 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: > dial: conn=172.17.0.1:46170->172.17.0.4:21, err= 2026/08/31 04:06:16 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: dial("tcp","172.17.0.4:38628") 2026/08/31 04:06:16 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: > dial: conn=172.17.0.1:44250->172.17.0.4:38628, err= 2026/08/31 04:06:16 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: dial("tcp","172.17.0.4:31654") 2026/08/31 04:06:16 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: > dial: conn=172.17.0.1:38630->172.17.0.4:31654, err= 2026/08/31 04:06:16 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: dial("tcp","172.17.0.4:34949") 2026/08/31 04:06:16 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: > dial: conn=172.17.0.1:49820->172.17.0.4:34949, err= 2026/08/31 04:06:16 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: Purge dir "040346cekojis5/path2" 2026/08/31 04:06:16 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: Purge dir "040346cekojis5/path1" 2026/08/31 04:06:16 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: Purge dir "040346cekojis5/check_filename" 2026/08/31 04:06:16 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: Purge dir "040346cekojis5/check_access_filters" 2026/08/31 04:06:16 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: Purge dir "040346cekojis5" 2026/08/31 04:06:16 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi: Purge dir "" --- PASS: TestBisyncRemoteRemote (152.50s) --- PASS: TestBisyncRemoteRemote/check_access_filters (93.23s) --- PASS: TestBisyncRemoteRemote/check_filename (50.18s) PASS 2026/08/31 04:06:16 DEBUG : ftp://172.17.0.4:21/rclone-test-molated8yusu: Connecting to FTP server 2026/08/31 04:06:16 DEBUG : ftp://172.17.0.4:21/rclone-test-molated8yusu: dial("tcp","172.17.0.4:21") 2026/08/31 04:06:16 DEBUG : ftp://172.17.0.4:21/rclone-test-molated8yusu: > dial: conn=172.17.0.1:46178->172.17.0.4:21, err= 2026/08/31 04:06:17 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path1: closing 9 unused connections 2026/08/31 04:06:19 DEBUG : ftp://172.17.0.4:21/rclone-test-molated8yusu: dial("tcp","172.17.0.4:30150") 2026/08/31 04:06:19 DEBUG : ftp://172.17.0.4:21/rclone-test-molated8yusu: > dial: conn=172.17.0.1:53462->172.17.0.4:30150, err= 2026/08/31 04:06:19 ERROR : error listing: directory not found 2026/08/31 04:06:19 DEBUG : ftp://172.17.0.4:21/rclone-test-molated8yusu: Purge dir "" 2026/08/31 04:06:19 NOTICE: purge failed to rmdir "": directory not found 2026/08/31 04:06:19 NOTICE: purge failed: directory not found 2026/08/31 04:06:19 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5: closing 1 unused connections 2026/08/31 04:06:19 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path1: closing 6 unused connections 2026/08/31 04:06:19 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2: closing 6 unused connections 2026/08/31 04:06:19 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_filename/path2/subdir: closing 1 unused connections 2026/08/31 04:06:19 DEBUG : ftp://172.17.0.4:21/rclone-test-tedetoz6cudi/040346cekojis5/check_access_filters/path2: closing 7 unused connections "./bisync.test -test.v -test.timeout 1h0m0s -remote TestFTPPureftpd: -verbose -test.run '^TestBisyncRemoteRemote$/^(check_access_filters|check_filename)$'" - Finished OK in 2m38.844342178s (try 2/5)