"./bisync.test -test.v -test.timeout 1h0m0s -remote TestFTPPureftpd: -verbose -test.run '^TestBisyncLocalRemote$/^normalization$|^TestBisyncRemoteLocal$/^(equal|resync)$|^TestBisyncRemoteRemote$/^basic$'" - Starting (try 2/5) 2026/03/31 04:47:53 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-camedud4veye" 2026/03/31 04:47:53 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/03/31 04:47:53 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:47:53 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:47:53 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:47:53 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:47:53 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:47:53 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:47:53 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:47:53 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:47:53 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:47:53 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-camedud4veye: Connecting to FTP server 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-camedud4veye: dial("tcp","172.17.0.4:21") 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-camedud4veye: > dial: conn=172.17.0.1:58796->172.17.0.4:21, err= 2026/03/31 04:47:53 DEBUG : Creating backend with remote "/tmp/rclone3826305146" === RUN TestBisyncRemoteLocal 2026/03/31 04:47:53 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-mikotiz8vugo" 2026/03/31 04:47:53 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:47:53 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:47:53 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:47:53 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:47:53 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:47:53 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:47:53 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:47:53 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:47:53 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:47:53 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: Connecting to FTP server 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: dial("tcp","172.17.0.4:21") 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: > dial: conn=172.17.0.1:58798->172.17.0.4:21, err= 2026/03/31 04:47:53 NOTICE: remote: TestFTPPureftpd:rclone-test-mikotiz8vugo === RUN TestBisyncRemoteLocal/equal 2026/03/31 04:47:53 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-mikotiz8vugo/044753me" 2026/03/31 04:47:53 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:47:53 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:47:53 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:47:53 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:47:53 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:47:53 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:47:53 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:47:53 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:47:53 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:47:53 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me: Connecting to FTP server 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me: dial("tcp","172.17.0.4:21") 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me: > dial: conn=172.17.0.1:58802->172.17.0.4:21, err= 2026/03/31 04:47:53 DEBUG : fs cache: renaming cache item "TestFTPPureftpd:rclone-test-mikotiz8vugo/044753me" to be canonical "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me" 2026/03/31 04:47:53 INFO : path1: Making directory 2026/03/31 04:47:53 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-mikotiz8vugo/044753me/equal/path1" 2026/03/31 04:47:53 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:47:53 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:47:53 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:47:53 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:47:53 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:47:53 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:47:53 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:47:53 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:47:53 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:47:53 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: Connecting to FTP server 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:58816->172.17.0.4:21, err= 2026/03/31 04:47:53 DEBUG : fs cache: renaming cache item "TestFTPPureftpd:rclone-test-mikotiz8vugo/044753me/equal/path1" to be canonical "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/equal/path1" 2026/03/31 04:47:53 DEBUG : Creating backend with remote "/tmp/044753me" 2026/03/31 04:47:53 DEBUG : Creating backend with remote "/tmp/044753me/equal/path2" 2026/03/31 04:47:53 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_equal/initial" 2026/03/31 04:47:53 DEBUG : Creating backend with remote "/tmp/044753me/initdir/test_equal-guzohaw1" 2026/03/31 04:47:53 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/03/31 04:47:53 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:53 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:53 DEBUG : Local file system at /tmp/044753me/initdir/test_equal-guzohaw1: Waiting for checks to finish 2026/03/31 04:47:53 DEBUG : Local file system at /tmp/044753me/initdir/test_equal-guzohaw1: Waiting for transfers to finish 2026/03/31 04:47:53 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/03/31 04:47:53 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/03/31 04:47:53 DEBUG : file2.txt.3230ad67.partial: size = 0 OK 2026/03/31 04:47:53 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:53 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:53 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/03/31 04:47:53 INFO : file1.txt: Copied (new) 2026/03/31 04:47:53 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2026/03/31 04:47:53 INFO : file2.txt: Copied (new) 2026/03/31 04:47:53 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/03/31 04:47:53 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/03/31 04:47:53 INFO : RCLONE_TEST: Copied (new) 2026/03/31 04:47:53 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_equal/modfiles" 2026/03/31 04:47:53 DEBUG : Creating backend with remote "/tmp/044753me/datadir/test_equal-biqoguw1" 2026/03/31 04:47:53 DEBUG : file1L.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:53 DEBUG : file1R.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:53 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:53 DEBUG : file1R.txt.df7bff44.partial: size = 33 OK 2026/03/31 04:47:53 DEBUG : file1R.txt: md5 = 2b4975bb20f7be674e66d78570ba2fb1 OK 2026/03/31 04:47:53 DEBUG : file2.txt.467c795f.partial: size = 37 OK 2026/03/31 04:47:53 DEBUG : Local file system at /tmp/044753me/datadir/test_equal-biqoguw1: Waiting for checks to finish 2026/03/31 04:47:53 DEBUG : file1R.txt.df7bff44.partial: renamed to: file1R.txt 2026/03/31 04:47:53 DEBUG : file2.txt: md5 = 9fe822ddd1cb81d83aae00fa48239bd3 OK 2026/03/31 04:47:53 INFO : file1R.txt: Copied (new) 2026/03/31 04:47:53 DEBUG : Local file system at /tmp/044753me/datadir/test_equal-biqoguw1: Waiting for transfers to finish 2026/03/31 04:47:53 DEBUG : file1L.txt.bc963e7b.partial: size = 33 OK 2026/03/31 04:47:53 DEBUG : file2.txt.467c795f.partial: renamed to: file2.txt 2026/03/31 04:47:53 INFO : file2.txt: Copied (new) 2026/03/31 04:47:53 DEBUG : file1L.txt: md5 = ea683c03f780b76a62405456b08ae6fd OK 2026/03/31 04:47:53 DEBUG : file1L.txt.bc963e7b.partial: renamed to: file1L.txt 2026/03/31 04:47:53 INFO : file1L.txt: Copied (new) 2026/03/31 04:47:53 DEBUG : Waiting for deletions to finish 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:35989") 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:51006->172.17.0.4:35989, err= 2026/03/31 04:47:53 ERROR : error listing: directory not found 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:38665") 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:60098->172.17.0.4:38665, err= 2026/03/31 04:47:53 ERROR : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: Failed to list "": directory not found 2026/03/31 04:47:53 DEBUG : removing 1 level 0 directories 2026/03/31 04:47:53 INFO : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: Removing directory 2026/03/31 04:47:53 ERROR : Failed to rmdir: directory not found 2026/03/31 04:47:53 DEBUG : Waiting for deletions to finish 2026/03/31 04:47:53 ERROR : error listing: directory not found 2026/03/31 04:47:53 ERROR : Local file system at /tmp/044753me/equal/path2: Failed to list "": directory not found 2026/03/31 04:47:53 DEBUG : removing 1 level 0 directories 2026/03/31 04:47:53 INFO : Local file system at /tmp/044753me/equal/path2: Removing directory 2026/03/31 04:47:53 ERROR : Failed to rmdir: stat /tmp/044753me/equal/path2: no such file or directory 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:31207") 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:45922->172.17.0.4:31207, err= 2026/03/31 04:47:53 ERROR : error listing: directory not found 2026/03/31 04:47:53 ERROR : error listing: directory not found 2026/03/31 04:47:53 NOTICE: checking initFs Local file system at /tmp/044753me/initdir/test_equal-guzohaw1 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:34381") 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:36528->172.17.0.4:34381, err= 2026/03/31 04:47:53 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/03/31 04:47:53 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:53 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: Connecting to FTP server 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: Waiting for checks to finish 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: Connecting to FTP server 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: Waiting for transfers to finish 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:58832->172.17.0.4:21, err= 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:36727") 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:57714->172.17.0.4:36727, err= 2026/03/31 04:47:53 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/03/31 04:47:53 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/03/31 04:47:53 INFO : file1.txt: Copied (new) 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:58842->172.17.0.4:21, err= 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:37640") 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:45952->172.17.0.4:37640, err= 2026/03/31 04:47:53 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/03/31 04:47:53 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/03/31 04:47:53 INFO : RCLONE_TEST: Copied (new) 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:32544") 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:52510->172.17.0.4:32544, err= 2026/03/31 04:47:53 DEBUG : file2.txt.3230ad67.partial: size = 0 OK 2026/03/31 04:47:53 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2026/03/31 04:47:53 INFO : file2.txt: Copied (new) 2026/03/31 04:47:53 NOTICE: checking Path1 ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:37400") 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:52806->172.17.0.4:37400, err= 2026/03/31 04:47:53 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/03/31 04:47:53 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:53 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:53 DEBUG : Local file system at /tmp/044753me/equal/path2: Waiting for checks to finish 2026/03/31 04:47:53 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/03/31 04:47:53 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/03/31 04:47:53 DEBUG : Local file system at /tmp/044753me/equal/path2: Waiting for transfers to finish 2026/03/31 04:47:53 DEBUG : file2.txt.3230ad67.partial: size = 0 OK 2026/03/31 04:47:53 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:53 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/03/31 04:47:53 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:53 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/03/31 04:47:53 INFO : file1.txt: Copied (new) 2026/03/31 04:47:53 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2026/03/31 04:47:53 INFO : file2.txt: Copied (new) 2026/03/31 04:47:53 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/03/31 04:47:53 INFO : RCLONE_TEST: Copied (new) 2026/03/31 04:47:53 NOTICE: checking path2 Local file system at /tmp/044753me/equal/path2 2026/03/31 04:47:53 NOTICE: (01) : test equal 2026/03/31 04:47:53 NOTICE: (02) : test initial bisync 2026/03/31 04:47:53 NOTICE: (03) : bisync resync 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:37953") 2026/03/31 04:47:53 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:40314->172.17.0.4:37953, err= 2026/03/31 04:47:55 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/03/31 04:47:55 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/03/31 04:47:55 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2026/03/31 04:47:55 INFO : Synching Path1 "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/equal/path1/" with Path2 "/tmp/044753me/equal/path2/" 2026/03/31 04:47:55 INFO : Copying Path2 files to Path1 2026/03/31 04:47:55 INFO : - Path2 Resync is copying files to - Path1 2026/03/31 04:47:55 INFO : There was nothing to transfer 2026/03/31 04:47:55 INFO : - Path1 Resync is copying files to - Path2 2026/03/31 04:47:55 INFO : There was nothing to transfer 2026/03/31 04:47:55 INFO : Resync updating listings 2026/03/31 04:47:55 INFO : Validating listings for Path1 "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/equal/path1/" vs Path2 "/tmp/044753me/equal/path2/" 2026/03/31 04:47:55 INFO : Bisync successful 2026/03/31 04:47:55 NOTICE: (04) : test changed on both paths and NOT identical - file1 (file1R, file1L) 2026/03/31 04:47:55 NOTICE: (05) : touch-glob 2001-01-02 /tmp/044753me/datadir/test_equal-biqoguw1/ file1R.txt 2026/03/31 04:47:55 DEBUG : Creating backend with remote "/tmp/044753me/datadir/test_equal-biqoguw1/" 2026/03/31 04:47:55 DEBUG : fs cache: renaming cache item "/tmp/044753me/datadir/test_equal-biqoguw1/" to be canonical "/tmp/044753me/datadir/test_equal-biqoguw1" 2026/03/31 04:47:55 DEBUG : file1R.txt: Set modification time 2001-01-02 2026/03/31 04:47:55 NOTICE: (06) : copy-as /tmp/044753me/datadir/test_equal-biqoguw1/file1R.txt /tmp/044753me/equal/path2/ file1.txt 2026/03/31 04:47:55 DEBUG : copyFile "/tmp/044753me/datadir/test_equal-biqoguw1/file1R.txt" to "/tmp/044753me/equal/path2/" as "file1.txt" 2026/03/31 04:47:55 DEBUG : Creating backend with remote "/tmp/044753me/datadir/test_equal-biqoguw1/file1R.txt" 2026/03/31 04:47:55 DEBUG : Creating backend with remote "/tmp/044753me/equal/path2/" 2026/03/31 04:47:55 DEBUG : operations.CopyFile "file1R.txt" to "Local file system at /tmp/044753me/equal/path2" as "file1.txt" 2026/03/31 04:47:55 DEBUG : file1R.txt: size = 33 (Local file system at /tmp/044753me/datadir/test_equal-biqoguw1) 2026/03/31 04:47:55 DEBUG : file1.txt: size = 0 (Local file system at /tmp/044753me/equal/path2) 2026/03/31 04:47:55 DEBUG : file1R.txt: Sizes differ 2026/03/31 04:47:55 DEBUG : file1.txt.2782e57b.partial: size = 33 OK 2026/03/31 04:47:55 DEBUG : file1R.txt: md5 = 2b4975bb20f7be674e66d78570ba2fb1 OK 2026/03/31 04:47:55 DEBUG : file1.txt.2782e57b.partial: renamed to: file1.txt 2026/03/31 04:47:55 INFO : file1R.txt: Copied (replaced existing) to: file1.txt 2026/03/31 04:47:55 NOTICE: (07) : touch-glob 2001-03-04 /tmp/044753me/datadir/test_equal-biqoguw1/ file1L.txt 2026/03/31 04:47:55 DEBUG : fs cache: switching user supplied name "/tmp/044753me/datadir/test_equal-biqoguw1/" for canonical name "/tmp/044753me/datadir/test_equal-biqoguw1" 2026/03/31 04:47:55 DEBUG : file1L.txt: Set modification time 2001-03-04 2026/03/31 04:47:55 NOTICE: (08) : copy-as /tmp/044753me/datadir/test_equal-biqoguw1/file1L.txt TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-mikotiz8vugo/044753me/equal/path1/ file1.txt 2026/03/31 04:47:55 DEBUG : copyFile "/tmp/044753me/datadir/test_equal-biqoguw1/file1L.txt" to "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-mikotiz8vugo/044753me/equal/path1/" as "file1.txt" 2026/03/31 04:47:55 DEBUG : Creating backend with remote "/tmp/044753me/datadir/test_equal-biqoguw1/file1L.txt" 2026/03/31 04:47:55 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-mikotiz8vugo/044753me/equal/path1/" 2026/03/31 04:47:55 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:47:55 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:47:55 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: Connecting to FTP server 2026/03/31 04:47:55 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:47:55 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:58856->172.17.0.4:21, err= 2026/03/31 04:47:55 DEBUG : operations.CopyFile "file1L.txt" to "ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1" as "file1.txt" 2026/03/31 04:47:55 DEBUG : file1L.txt: size = 33 (Local file system at /tmp/044753me/datadir/test_equal-biqoguw1) 2026/03/31 04:47:55 DEBUG : file1.txt: size = 0 (ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1) 2026/03/31 04:47:55 DEBUG : file1L.txt: Sizes differ 2026/03/31 04:47:55 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:33883") 2026/03/31 04:47:55 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:57960->172.17.0.4:33883, err= 2026/03/31 04:47:55 DEBUG : file1.txt.4e37ab47.partial: size = 33 OK 2026/03/31 04:47:55 DEBUG : file1.txt.4e37ab47.partial: renamed to: file1.txt 2026/03/31 04:47:55 INFO : file1L.txt: Copied (replaced existing) to: file1.txt 2026/03/31 04:47:55 NOTICE: (09) : test changed on both paths and identical - file2 2026/03/31 04:47:55 NOTICE: (10) : touch-glob 2001-01-02 /tmp/044753me/datadir/test_equal-biqoguw1/ file2.txt 2026/03/31 04:47:55 DEBUG : fs cache: switching user supplied name "/tmp/044753me/datadir/test_equal-biqoguw1/" for canonical name "/tmp/044753me/datadir/test_equal-biqoguw1" 2026/03/31 04:47:55 DEBUG : file2.txt: Set modification time 2001-01-02 2026/03/31 04:47:55 NOTICE: (11) : copy-as /tmp/044753me/datadir/test_equal-biqoguw1/file2.txt TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-mikotiz8vugo/044753me/equal/path1/ file2.txt 2026/03/31 04:47:55 DEBUG : copyFile "/tmp/044753me/datadir/test_equal-biqoguw1/file2.txt" to "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-mikotiz8vugo/044753me/equal/path1/" as "file2.txt" 2026/03/31 04:47:55 DEBUG : Creating backend with remote "/tmp/044753me/datadir/test_equal-biqoguw1/file2.txt" 2026/03/31 04:47:55 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-mikotiz8vugo/044753me/equal/path1/" 2026/03/31 04:47:55 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:47:55 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:47:55 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: Connecting to FTP server 2026/03/31 04:47:55 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:47:55 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:58866->172.17.0.4:21, err= 2026/03/31 04:47:55 DEBUG : operations.CopyFile "file2.txt" to "ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1" as "file2.txt" 2026/03/31 04:47:55 DEBUG : file2.txt: size = 37 (Local file system at /tmp/044753me/datadir/test_equal-biqoguw1) 2026/03/31 04:47:55 DEBUG : file2.txt: size = 0 (ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1) 2026/03/31 04:47:55 DEBUG : file2.txt: Sizes differ 2026/03/31 04:47:55 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:31196") 2026/03/31 04:47:55 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:33570->172.17.0.4:31196, err= 2026/03/31 04:47:55 DEBUG : file2.txt.467c795f.partial: size = 37 OK 2026/03/31 04:47:55 DEBUG : file2.txt.467c795f.partial: renamed to: file2.txt 2026/03/31 04:47:55 INFO : file2.txt: Copied (replaced existing) 2026/03/31 04:47:55 NOTICE: (12) : copy-as /tmp/044753me/datadir/test_equal-biqoguw1/file2.txt /tmp/044753me/equal/path2/ file2.txt 2026/03/31 04:47:55 DEBUG : copyFile "/tmp/044753me/datadir/test_equal-biqoguw1/file2.txt" to "/tmp/044753me/equal/path2/" as "file2.txt" 2026/03/31 04:47:55 DEBUG : Creating backend with remote "/tmp/044753me/datadir/test_equal-biqoguw1/file2.txt" 2026/03/31 04:47:55 DEBUG : Creating backend with remote "/tmp/044753me/equal/path2/" 2026/03/31 04:47:55 DEBUG : operations.CopyFile "file2.txt" to "Local file system at /tmp/044753me/equal/path2" as "file2.txt" 2026/03/31 04:47:55 DEBUG : file2.txt: size = 37 (Local file system at /tmp/044753me/datadir/test_equal-biqoguw1) 2026/03/31 04:47:55 DEBUG : file2.txt: size = 0 (Local file system at /tmp/044753me/equal/path2) 2026/03/31 04:47:55 DEBUG : file2.txt: Sizes differ 2026/03/31 04:47:55 DEBUG : file2.txt.467c795f.partial: size = 37 OK 2026/03/31 04:47:55 DEBUG : file2.txt: md5 = 9fe822ddd1cb81d83aae00fa48239bd3 OK 2026/03/31 04:47:55 DEBUG : file2.txt.467c795f.partial: renamed to: file2.txt 2026/03/31 04:47:55 INFO : file2.txt: Copied (replaced existing) 2026/03/31 04:47:55 NOTICE: (13) : test bisync run 2026/03/31 04:47:55 NOTICE: (14) : bisync 2026/03/31 04:47:55 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:35156") 2026/03/31 04:47:55 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:56802->172.17.0.4:35156, err= 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/03/31 04:47:57 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/03/31 04:47:57 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2026/03/31 04:47:57 INFO : Synching Path1 "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/equal/path1/" with Path2 "/tmp/044753me/equal/path2/" 2026/03/31 04:47:57 INFO : Building Path1 and Path2 listings 2026/03/31 04:47:57 INFO : Path1 checking for diffs 2026/03/31 04:47:57 INFO : - Path1 File changed: size (larger), time (newer) - file1.txt 2026/03/31 04:47:57 INFO : - Path1 File changed: size (larger), time (newer) - file2.txt 2026/03/31 04:47:57 INFO : Path1: 2 changes:  0 new,  2 modified,  0 deleted 2026/03/31 04:47:57 INFO : (Modified:  2 newer,  0 older,  2 larger,  0 smaller) 2026/03/31 04:47:57 INFO : Path2 checking for diffs 2026/03/31 04:47:57 INFO : - Path2 File changed: size (larger), time (newer) - file1.txt 2026/03/31 04:47:57 INFO : - Path2 File changed: size (larger), time (newer) - file2.txt 2026/03/31 04:47:57 INFO : Path2: 2 changes:  0 new,  2 modified,  0 deleted 2026/03/31 04:47:57 INFO : (Modified:  2 newer,  0 older,  2 larger,  0 smaller) 2026/03/31 04:47:57 INFO : Applying changes 2026/03/31 04:47:57 INFO : Can't compare hashes, so using check --download for safety. (Use --size-only or --ignore-checksum to disable) 2026/03/31 04:47:57 INFO : Checking potential conflicts... 2026/03/31 04:47:57 NOTICE: Local file system at /tmp/044753me/equal/path2: 1 differences found 2026/03/31 04:47:57 NOTICE: Local file system at /tmp/044753me/equal/path2: 1 errors while checking 2026/03/31 04:47:57 NOTICE: Local file system at /tmp/044753me/equal/path2: 1 matching files 2026/03/31 04:47:57 INFO : Finished checking the potential conflicts. 1 differences found 2026/03/31 04:47:57 NOTICE: - WARNING New or changed in both paths - file1.txt 2026/03/31 04:47:57 NOTICE: - Path1 Renaming Path1 copy - TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/equal/path1/file1.txt.conflict1 2026/03/31 04:47:57 INFO : file1.txt: Moved (server-side) to: file1.txt.conflict1 2026/03/31 04:47:57 NOTICE: - Path1 Queue copy to Path2 - /tmp/044753me/equal/path2/file1.txt.conflict1 2026/03/31 04:47:57 NOTICE: - Path2 Renaming Path2 copy - /tmp/044753me/equal/path2/file1.txt.conflict2 2026/03/31 04:47:57 INFO : file1.txt: Moved (server-side) to: file1.txt.conflict2 2026/03/31 04:47:57 NOTICE: - Path2 Queue copy to Path1 - TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/equal/path1/file1.txt.conflict2 2026/03/31 04:47:57 NOTICE: - WARNING New or changed in both paths - file2.txt 2026/03/31 04:47:57 INFO : Files are equal! Skipping: file2.txt 2026/03/31 04:47:57 INFO : - Path2 Do queued copies to - Path1 2026/03/31 04:47:57 INFO : file1.txt.conflict2: Copied (new) 2026/03/31 04:47:57 INFO : - Path1 Do queued copies to - Path2 2026/03/31 04:47:57 INFO : file1.txt.conflict1: Copied (new) 2026/03/31 04:47:57 INFO : Updating listings 2026/03/31 04:47:57 INFO : Can't compare hashes, so using check --download for safety. (Use --size-only or --ignore-checksum to disable) 2026/03/31 04:47:57 INFO : Can't compare hashes, so using check --download for safety. (Use --size-only or --ignore-checksum to disable) 2026/03/31 04:47:57 INFO : Validating listings for Path1 "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/equal/path1/" vs Path2 "/tmp/044753me/equal/path2/" 2026/03/31 04:47:57 INFO : Bisync successful 2026/03/31 04:47:57 DEBUG : Waiting for deletions to finish 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:31697") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:43286->172.17.0.4:31697, err= 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: Connecting to FTP server 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:58880->172.17.0.4:21, err= 2026/03/31 04:47:57 INFO : RCLONE_TEST: Deleted 2026/03/31 04:47:57 INFO : file1.txt.conflict1: Deleted 2026/03/31 04:47:57 INFO : file1.txt.conflict2: Deleted 2026/03/31 04:47:57 INFO : file2.txt: Deleted 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: dial("tcp","172.17.0.4:37895") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: > dial: conn=172.17.0.1:51800->172.17.0.4:37895, err= 2026/03/31 04:47:57 DEBUG : removing 1 level 0 directories 2026/03/31 04:47:57 INFO : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: Removing directory 2026/03/31 04:47:57 DEBUG : Waiting for deletions to finish 2026/03/31 04:47:57 INFO : RCLONE_TEST: Deleted 2026/03/31 04:47:57 INFO : file1.txt.conflict1: Deleted 2026/03/31 04:47:57 INFO : file2.txt: Deleted 2026/03/31 04:47:57 INFO : file1.txt.conflict2: Deleted 2026/03/31 04:47:57 DEBUG : removing 1 level 0 directories 2026/03/31 04:47:57 INFO : Local file system at /tmp/044753me/equal/path2: Removing directory bisync_test.go:608: TEST equal PASSED === RUN TestBisyncRemoteLocal/resync 2026/03/31 04:47:57 DEBUG : fs cache: switching user supplied name "TestFTPPureftpd:rclone-test-mikotiz8vugo/044753me" for canonical name "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me" 2026/03/31 04:47:57 INFO : path1: Making directory 2026/03/31 04:47:57 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-mikotiz8vugo/044753me/resync/path1" 2026/03/31 04:47:57 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:47:57 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:47:57 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:47:57 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:47:57 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:47:57 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:47:57 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:47:57 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:47:57 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:47:57 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Connecting to FTP server 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:58896->172.17.0.4:21, err= 2026/03/31 04:47:57 DEBUG : fs cache: renaming cache item "TestFTPPureftpd:rclone-test-mikotiz8vugo/044753me/resync/path1" to be canonical "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/resync/path1" 2026/03/31 04:47:57 DEBUG : Creating backend with remote "/tmp/044753me/resync/path2" 2026/03/31 04:47:57 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_resync/initial" 2026/03/31 04:47:57 DEBUG : Creating backend with remote "/tmp/044753me/initdir/test_resync-torozaf9" 2026/03/31 04:47:57 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : file3.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : file4.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : file5.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : file6.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : file7.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : Local file system at /tmp/044753me/initdir/test_resync-torozaf9: Waiting for checks to finish 2026/03/31 04:47:57 DEBUG : Local file system at /tmp/044753me/initdir/test_resync-torozaf9: Waiting for transfers to finish 2026/03/31 04:47:57 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/03/31 04:47:57 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/03/31 04:47:57 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/03/31 04:47:57 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/03/31 04:47:57 INFO : RCLONE_TEST: Copied (new) 2026/03/31 04:47:57 DEBUG : file2.txt.3230ad67.partial: size = 0 OK 2026/03/31 04:47:57 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:57 DEBUG : file4.txt.fbf05a9b.partial: size = 0 OK 2026/03/31 04:47:57 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:57 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2026/03/31 04:47:57 INFO : file2.txt: Copied (new) 2026/03/31 04:47:57 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/03/31 04:47:57 INFO : file1.txt: Copied (new) 2026/03/31 04:47:57 DEBUG : file5.txt.6e808e0e.partial: size = 0 OK 2026/03/31 04:47:57 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:57 DEBUG : file6.txt.0a60f5f0.partial: size = 0 OK 2026/03/31 04:47:57 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:57 DEBUG : file5.txt.6e808e0e.partial: renamed to: file5.txt 2026/03/31 04:47:57 INFO : file5.txt: Copied (new) 2026/03/31 04:47:57 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2026/03/31 04:47:57 INFO : file4.txt: Copied (new) 2026/03/31 04:47:57 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:57 DEBUG : file7.txt.9f102165.partial: size = 0 OK 2026/03/31 04:47:57 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:57 DEBUG : file7.txt.9f102165.partial: renamed to: file7.txt 2026/03/31 04:47:57 INFO : file7.txt: Copied (new) 2026/03/31 04:47:57 DEBUG : file6.txt.0a60f5f0.partial: renamed to: file6.txt 2026/03/31 04:47:57 INFO : file6.txt: Copied (new) 2026/03/31 04:47:57 DEBUG : file3.txt.a74079f2.partial: size = 0 OK 2026/03/31 04:47:57 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:57 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2026/03/31 04:47:57 INFO : file3.txt: Copied (new) 2026/03/31 04:47:57 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_resync/modfiles" 2026/03/31 04:47:57 DEBUG : Creating backend with remote "/tmp/044753me/datadir/test_resync-wekuxaq6" 2026/03/31 04:47:57 DEBUG : fileA.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : fileB.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : Local file system at /tmp/044753me/datadir/test_resync-wekuxaq6: Waiting for checks to finish 2026/03/31 04:47:57 DEBUG : Local file system at /tmp/044753me/datadir/test_resync-wekuxaq6: Waiting for transfers to finish 2026/03/31 04:47:57 DEBUG : fileA.txt.04c13af3.partial: size = 19 OK 2026/03/31 04:47:57 DEBUG : fileA.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2026/03/31 04:47:57 DEBUG : fileA.txt.04c13af3.partial: renamed to: fileA.txt 2026/03/31 04:47:57 INFO : fileA.txt: Copied (new) 2026/03/31 04:47:57 DEBUG : fileB.txt.b8ec97e6.partial: size = 19 OK 2026/03/31 04:47:57 DEBUG : fileB.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2026/03/31 04:47:57 DEBUG : fileB.txt.b8ec97e6.partial: renamed to: fileB.txt 2026/03/31 04:47:57 INFO : fileB.txt: Copied (new) 2026/03/31 04:47:57 DEBUG : Waiting for deletions to finish 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:38419") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:60554->172.17.0.4:38419, err= 2026/03/31 04:47:57 ERROR : error listing: directory not found 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:31686") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:49176->172.17.0.4:31686, err= 2026/03/31 04:47:57 ERROR : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Failed to list "": directory not found 2026/03/31 04:47:57 DEBUG : removing 1 level 0 directories 2026/03/31 04:47:57 INFO : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Removing directory 2026/03/31 04:47:57 ERROR : Failed to rmdir: directory not found 2026/03/31 04:47:57 DEBUG : Waiting for deletions to finish 2026/03/31 04:47:57 ERROR : error listing: directory not found 2026/03/31 04:47:57 ERROR : Local file system at /tmp/044753me/resync/path2: Failed to list "": directory not found 2026/03/31 04:47:57 DEBUG : removing 1 level 0 directories 2026/03/31 04:47:57 INFO : Local file system at /tmp/044753me/resync/path2: Removing directory 2026/03/31 04:47:57 ERROR : Failed to rmdir: stat /tmp/044753me/resync/path2: no such file or directory 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:31505") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:35252->172.17.0.4:31505, err= 2026/03/31 04:47:57 ERROR : error listing: directory not found 2026/03/31 04:47:57 ERROR : error listing: directory not found 2026/03/31 04:47:57 NOTICE: checking initFs Local file system at /tmp/044753me/initdir/test_resync-torozaf9 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:33188") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:60424->172.17.0.4:33188, err= 2026/03/31 04:47:57 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : file3.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : file4.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : file5.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : file6.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : file7.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Connecting to FTP server 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Waiting for checks to finish 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Connecting to FTP server 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Waiting for transfers to finish 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Connecting to FTP server 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:32210") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:58910->172.17.0.4:21, err= 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:46694->172.17.0.4:32210, err= 2026/03/31 04:47:57 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/03/31 04:47:57 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/03/31 04:47:57 INFO : RCLONE_TEST: Copied (new) 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:33828") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:36094->172.17.0.4:33828, err= 2026/03/31 04:47:57 DEBUG : file4.txt.fbf05a9b.partial: size = 0 OK 2026/03/31 04:47:57 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2026/03/31 04:47:57 INFO : file4.txt: Copied (new) 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:38516") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:52938->172.17.0.4:38516, err= 2026/03/31 04:47:57 DEBUG : file5.txt.6e808e0e.partial: size = 0 OK 2026/03/31 04:47:57 DEBUG : file5.txt.6e808e0e.partial: renamed to: file5.txt 2026/03/31 04:47:57 INFO : file5.txt: Copied (new) 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:30154") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:52362->172.17.0.4:30154, err= 2026/03/31 04:47:57 DEBUG : file6.txt.0a60f5f0.partial: size = 0 OK 2026/03/31 04:47:57 DEBUG : file6.txt.0a60f5f0.partial: renamed to: file6.txt 2026/03/31 04:47:57 INFO : file6.txt: Copied (new) 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:36647") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:52236->172.17.0.4:36647, err= 2026/03/31 04:47:57 DEBUG : file7.txt.9f102165.partial: size = 0 OK 2026/03/31 04:47:57 DEBUG : file7.txt.9f102165.partial: renamed to: file7.txt 2026/03/31 04:47:57 INFO : file7.txt: Copied (new) 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:58912->172.17.0.4:21, err= 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:37384") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:53764->172.17.0.4:37384, err= 2026/03/31 04:47:57 DEBUG : file2.txt.3230ad67.partial: size = 0 OK 2026/03/31 04:47:57 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2026/03/31 04:47:57 INFO : file2.txt: Copied (new) 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:58926->172.17.0.4:21, err= 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:34398") 2026/03/31 04:47:57 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:33724->172.17.0.4:34398, err= 2026/03/31 04:47:57 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/03/31 04:47:57 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/03/31 04:47:57 INFO : file1.txt: Copied (new) 2026/03/31 04:47:58 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:32684") 2026/03/31 04:47:58 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:35808->172.17.0.4:32684, err= 2026/03/31 04:47:58 DEBUG : file3.txt.a74079f2.partial: size = 0 OK 2026/03/31 04:47:58 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2026/03/31 04:47:58 INFO : file3.txt: Copied (new) 2026/03/31 04:47:58 NOTICE: checking Path1 ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1 2026/03/31 04:47:58 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:31094") 2026/03/31 04:47:58 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:35032->172.17.0.4:31094, err= 2026/03/31 04:47:58 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/03/31 04:47:58 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:58 DEBUG : file2.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:58 DEBUG : file3.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:58 DEBUG : file4.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:58 DEBUG : file5.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:58 DEBUG : file6.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:58 DEBUG : file7.txt: Need to transfer - File not found at Destination 2026/03/31 04:47:58 DEBUG : Local file system at /tmp/044753me/resync/path2: Waiting for checks to finish 2026/03/31 04:47:58 DEBUG : Local file system at /tmp/044753me/resync/path2: Waiting for transfers to finish 2026/03/31 04:47:58 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/03/31 04:47:58 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/03/31 04:47:58 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:58 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/03/31 04:47:58 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/03/31 04:47:58 DEBUG : file2.txt.3230ad67.partial: size = 0 OK 2026/03/31 04:47:58 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/03/31 04:47:58 INFO : file1.txt: Copied (new) 2026/03/31 04:47:58 INFO : RCLONE_TEST: Copied (new) 2026/03/31 04:47:58 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:58 DEBUG : file3.txt.a74079f2.partial: size = 0 OK 2026/03/31 04:47:58 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt 2026/03/31 04:47:58 DEBUG : file5.txt.6e808e0e.partial: size = 0 OK 2026/03/31 04:47:58 INFO : file2.txt: Copied (new) 2026/03/31 04:47:58 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:58 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt 2026/03/31 04:47:58 INFO : file3.txt: Copied (new) 2026/03/31 04:47:58 DEBUG : file6.txt.0a60f5f0.partial: size = 0 OK 2026/03/31 04:47:58 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:58 DEBUG : file7.txt.9f102165.partial: size = 0 OK 2026/03/31 04:47:58 DEBUG : file5.txt.6e808e0e.partial: renamed to: file5.txt 2026/03/31 04:47:58 INFO : file5.txt: Copied (new) 2026/03/31 04:47:58 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:58 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:58 DEBUG : file7.txt.9f102165.partial: renamed to: file7.txt 2026/03/31 04:47:58 INFO : file7.txt: Copied (new) 2026/03/31 04:47:58 DEBUG : file6.txt.0a60f5f0.partial: renamed to: file6.txt 2026/03/31 04:47:58 INFO : file6.txt: Copied (new) 2026/03/31 04:47:58 DEBUG : file4.txt.fbf05a9b.partial: size = 0 OK 2026/03/31 04:47:58 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:47:58 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt 2026/03/31 04:47:58 INFO : file4.txt: Copied (new) 2026/03/31 04:47:58 NOTICE: checking path2 Local file system at /tmp/044753me/resync/path2 2026/03/31 04:47:58 NOTICE: (01) : test resync 2026/03/31 04:47:58 NOTICE: (02) : test 1. resync with empty path1, resulting in copying all content from path2. 2026/03/31 04:47:58 NOTICE: (03) : purge-children TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-mikotiz8vugo/044753me/resync/path1/ 2026/03/31 04:47:58 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:35228") 2026/03/31 04:47:58 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:52256->172.17.0.4:35228, err= 2026/03/31 04:47:58 DEBUG : RCLONE_TEST: Remove file 2026/03/31 04:47:58 DEBUG : file1.txt: Remove file 2026/03/31 04:47:58 DEBUG : file2.txt: Remove file 2026/03/31 04:47:58 DEBUG : file3.txt: Remove file 2026/03/31 04:47:58 DEBUG : file4.txt: Remove file 2026/03/31 04:47:58 DEBUG : file5.txt: Remove file 2026/03/31 04:47:58 DEBUG : file6.txt: Remove file 2026/03/31 04:47:58 DEBUG : file7.txt: Remove file 2026/03/31 04:47:58 NOTICE: (04) : bisync resync 2026/03/31 04:47:58 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:31506") 2026/03/31 04:47:58 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:35432->172.17.0.4:31506, err= 2026/03/31 04:48:00 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/03/31 04:48:00 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/03/31 04:48:00 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2026/03/31 04:48:00 INFO : Synching Path1 "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/resync/path1/" with Path2 "/tmp/044753me/resync/path2/" 2026/03/31 04:48:00 INFO : Copying Path2 files to Path1 2026/03/31 04:48:00 INFO : - Path2 Resync is copying files to - Path1 2026/03/31 04:48:00 INFO : file3.txt: Copied (new) 2026/03/31 04:48:00 INFO : RCLONE_TEST: Copied (new) 2026/03/31 04:48:00 INFO : file2.txt: Copied (new) 2026/03/31 04:48:00 INFO : file1.txt: Copied (new) 2026/03/31 04:48:00 INFO : file5.txt: Copied (new) 2026/03/31 04:48:00 INFO : file4.txt: Copied (new) 2026/03/31 04:48:00 INFO : file6.txt: Copied (new) 2026/03/31 04:48:00 INFO : file7.txt: Copied (new) 2026/03/31 04:48:00 INFO : - Path1 Resync is copying files to - Path2 2026/03/31 04:48:00 INFO : Resync updating listings 2026/03/31 04:48:00 INFO : Validating listings for Path1 "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/resync/path1/" vs Path2 "/tmp/044753me/resync/path2/" 2026/03/31 04:48:00 INFO : Bisync successful 2026/03/31 04:48:00 NOTICE: (05) : move-listings empty-path1 2026/03/31 04:48:00 NOTICE: (06) : test 2. resync with empty path2, resulting in syncing all content to path2. 2026/03/31 04:48:00 NOTICE: (07) : purge-children /tmp/044753me/resync/path2/ 2026/03/31 04:48:00 DEBUG : file6.txt: Remove file 2026/03/31 04:48:00 DEBUG : file4.txt: Remove file 2026/03/31 04:48:00 DEBUG : file1.txt: Remove file 2026/03/31 04:48:00 DEBUG : file3.txt: Remove file 2026/03/31 04:48:00 DEBUG : RCLONE_TEST: Remove file 2026/03/31 04:48:00 DEBUG : file5.txt: Remove file 2026/03/31 04:48:00 DEBUG : file7.txt: Remove file 2026/03/31 04:48:00 DEBUG : file2.txt: Remove file 2026/03/31 04:48:00 NOTICE: (08) : bisync resync 2026/03/31 04:48:00 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:32154") 2026/03/31 04:48:00 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:57934->172.17.0.4:32154, err= 2026/03/31 04:48:02 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/03/31 04:48:02 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/03/31 04:48:02 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2026/03/31 04:48:02 INFO : Synching Path1 "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/resync/path1/" with Path2 "/tmp/044753me/resync/path2/" 2026/03/31 04:48:02 INFO : Copying Path2 files to Path1 2026/03/31 04:48:02 INFO : - Path2 Resync is copying files to - Path1 2026/03/31 04:48:02 INFO : There was nothing to transfer 2026/03/31 04:48:02 INFO : - Path1 Resync is copying files to - Path2 2026/03/31 04:48:02 INFO : RCLONE_TEST: Copied (new) 2026/03/31 04:48:02 INFO : file1.txt: Copied (new) 2026/03/31 04:48:02 INFO : file2.txt: Copied (new) 2026/03/31 04:48:02 INFO : file3.txt: Copied (new) 2026/03/31 04:48:02 INFO : file4.txt: Copied (new) 2026/03/31 04:48:02 INFO : file5.txt: Copied (new) 2026/03/31 04:48:02 INFO : file6.txt: Copied (new) 2026/03/31 04:48:02 INFO : file7.txt: Copied (new) 2026/03/31 04:48:02 INFO : Resync updating listings 2026/03/31 04:48:02 INFO : Validating listings for Path1 "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/resync/path1/" vs Path2 "/tmp/044753me/resync/path2/" 2026/03/31 04:48:02 INFO : Bisync successful 2026/03/31 04:48:02 NOTICE: (09) : move-listings empty-path2 2026/03/31 04:48:02 NOTICE: (10) : test 3. exercise all of the various file difference scenarios during a resync. 2026/03/31 04:48:02 NOTICE: (11) : touch-glob 2002-02-02 /tmp/044753me/datadir/test_resync-wekuxaq6/ fileA.txt 2026/03/31 04:48:02 DEBUG : Creating backend with remote "/tmp/044753me/datadir/test_resync-wekuxaq6/" 2026/03/31 04:48:02 DEBUG : fs cache: renaming cache item "/tmp/044753me/datadir/test_resync-wekuxaq6/" to be canonical "/tmp/044753me/datadir/test_resync-wekuxaq6" 2026/03/31 04:48:02 DEBUG : fileA.txt: Set modification time 2002-02-02 2026/03/31 04:48:02 NOTICE: (12) : touch-glob 1999-09-09 /tmp/044753me/datadir/test_resync-wekuxaq6/ fileB.txt 2026/03/31 04:48:02 DEBUG : fs cache: switching user supplied name "/tmp/044753me/datadir/test_resync-wekuxaq6/" for canonical name "/tmp/044753me/datadir/test_resync-wekuxaq6" 2026/03/31 04:48:02 DEBUG : fileB.txt: Set modification time 1999-09-09 2026/03/31 04:48:02 NOTICE: (13) : test = file - path1 - path2 - expected action - who wins 2026/03/31 04:48:02 NOTICE: (14) : test - file1.txt - exists - missing - sync path1 > path2 - path1 2026/03/31 04:48:02 NOTICE: (15) : delete-file /tmp/044753me/resync/path2/file1.txt 2026/03/31 04:48:02 DEBUG : Creating backend with remote "/tmp/044753me/resync/path2/" 2026/03/31 04:48:02 DEBUG : fs cache: renaming cache item "/tmp/044753me/resync/path2/" to be canonical "/tmp/044753me/resync/path2" 2026/03/31 04:48:02 INFO : file1.txt: Deleted 2026/03/31 04:48:02 NOTICE: (16) : test - file2.txt - missing - exists - copy path2 > path1 - path2 2026/03/31 04:48:02 NOTICE: (17) : delete-file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-mikotiz8vugo/044753me/resync/path1/file2.txt 2026/03/31 04:48:02 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-mikotiz8vugo/044753me/resync/path1/" 2026/03/31 04:48:02 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:48:02 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:48:02 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Connecting to FTP server 2026/03/31 04:48:02 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:02 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:58160->172.17.0.4:21, err= 2026/03/31 04:48:02 DEBUG : fs cache: renaming cache item "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-mikotiz8vugo/044753me/resync/path1/" to be canonical "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/resync/path1/" 2026/03/31 04:48:02 INFO : file2.txt: Deleted 2026/03/31 04:48:02 NOTICE: (18) : test - file3.txt - exists - newer date - sync path1 > path2 - path1 2026/03/31 04:48:02 NOTICE: (19) : copy-as /tmp/044753me/datadir/test_resync-wekuxaq6/fileA.txt /tmp/044753me/resync/path2/ file3.txt 2026/03/31 04:48:02 DEBUG : copyFile "/tmp/044753me/datadir/test_resync-wekuxaq6/fileA.txt" to "/tmp/044753me/resync/path2/" as "file3.txt" 2026/03/31 04:48:02 DEBUG : Creating backend with remote "/tmp/044753me/datadir/test_resync-wekuxaq6/fileA.txt" 2026/03/31 04:48:02 DEBUG : Creating backend with remote "/tmp/044753me/resync/path2/" 2026/03/31 04:48:02 DEBUG : operations.CopyFile "fileA.txt" to "Local file system at /tmp/044753me/resync/path2" as "file3.txt" 2026/03/31 04:48:02 DEBUG : fileA.txt: size = 19 (Local file system at /tmp/044753me/datadir/test_resync-wekuxaq6) 2026/03/31 04:48:02 DEBUG : file3.txt: size = 0 (Local file system at /tmp/044753me/resync/path2) 2026/03/31 04:48:02 DEBUG : fileA.txt: Sizes differ 2026/03/31 04:48:02 DEBUG : file3.txt.2b9483fe.partial: size = 19 OK 2026/03/31 04:48:02 DEBUG : fileA.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2026/03/31 04:48:02 DEBUG : file3.txt.2b9483fe.partial: renamed to: file3.txt 2026/03/31 04:48:02 INFO : fileA.txt: Copied (replaced existing) to: file3.txt 2026/03/31 04:48:02 NOTICE: (20) : test - file4.txt - missing - newer date - copy path2 > path1 - path2 2026/03/31 04:48:02 NOTICE: (21) : delete-file TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-mikotiz8vugo/044753me/resync/path1/file4.txt 2026/03/31 04:48:02 DEBUG : fs cache: switching user supplied name "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-mikotiz8vugo/044753me/resync/path1/" for canonical name "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/resync/path1/" 2026/03/31 04:48:02 INFO : file4.txt: Deleted 2026/03/31 04:48:02 NOTICE: (22) : copy-as /tmp/044753me/datadir/test_resync-wekuxaq6/fileA.txt /tmp/044753me/resync/path2/ file4.txt 2026/03/31 04:48:02 DEBUG : copyFile "/tmp/044753me/datadir/test_resync-wekuxaq6/fileA.txt" to "/tmp/044753me/resync/path2/" as "file4.txt" 2026/03/31 04:48:02 DEBUG : Creating backend with remote "/tmp/044753me/datadir/test_resync-wekuxaq6/fileA.txt" 2026/03/31 04:48:02 DEBUG : Creating backend with remote "/tmp/044753me/resync/path2/" 2026/03/31 04:48:02 DEBUG : operations.CopyFile "fileA.txt" to "Local file system at /tmp/044753me/resync/path2" as "file4.txt" 2026/03/31 04:48:02 DEBUG : fileA.txt: size = 19 (Local file system at /tmp/044753me/datadir/test_resync-wekuxaq6) 2026/03/31 04:48:02 DEBUG : file4.txt: size = 0 (Local file system at /tmp/044753me/resync/path2) 2026/03/31 04:48:02 DEBUG : fileA.txt: Sizes differ 2026/03/31 04:48:02 DEBUG : file4.txt.1fa6ea21.partial: size = 19 OK 2026/03/31 04:48:02 DEBUG : fileA.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2026/03/31 04:48:02 DEBUG : file4.txt.1fa6ea21.partial: renamed to: file4.txt 2026/03/31 04:48:02 INFO : fileA.txt: Copied (replaced existing) to: file4.txt 2026/03/31 04:48:02 NOTICE: (23) : test - file5.txt - exists - older date - sync path1 > path2 - path1 2026/03/31 04:48:02 NOTICE: (24) : copy-as /tmp/044753me/datadir/test_resync-wekuxaq6/fileB.txt /tmp/044753me/resync/path2/ file5.txt 2026/03/31 04:48:02 DEBUG : copyFile "/tmp/044753me/datadir/test_resync-wekuxaq6/fileB.txt" to "/tmp/044753me/resync/path2/" as "file5.txt" 2026/03/31 04:48:02 DEBUG : Creating backend with remote "/tmp/044753me/datadir/test_resync-wekuxaq6/fileB.txt" 2026/03/31 04:48:02 DEBUG : Creating backend with remote "/tmp/044753me/resync/path2/" 2026/03/31 04:48:02 DEBUG : operations.CopyFile "fileB.txt" to "Local file system at /tmp/044753me/resync/path2" as "file5.txt" 2026/03/31 04:48:02 DEBUG : fileB.txt: size = 19 (Local file system at /tmp/044753me/datadir/test_resync-wekuxaq6) 2026/03/31 04:48:02 DEBUG : file5.txt: size = 0 (Local file system at /tmp/044753me/resync/path2) 2026/03/31 04:48:02 DEBUG : fileB.txt: Sizes differ 2026/03/31 04:48:02 DEBUG : file5.txt.791a6f4b.partial: size = 19 OK 2026/03/31 04:48:02 DEBUG : fileB.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2026/03/31 04:48:02 DEBUG : file5.txt.791a6f4b.partial: renamed to: file5.txt 2026/03/31 04:48:02 INFO : fileB.txt: Copied (replaced existing) to: file5.txt 2026/03/31 04:48:02 NOTICE: (25) : test - file6.txt - older date - newer date - sync path1 > path2 - path1 2026/03/31 04:48:02 NOTICE: (26) : copy-as /tmp/044753me/datadir/test_resync-wekuxaq6/fileB.txt TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-mikotiz8vugo/044753me/resync/path1/ file6.txt 2026/03/31 04:48:02 DEBUG : copyFile "/tmp/044753me/datadir/test_resync-wekuxaq6/fileB.txt" to "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-mikotiz8vugo/044753me/resync/path1/" as "file6.txt" 2026/03/31 04:48:02 DEBUG : Creating backend with remote "/tmp/044753me/datadir/test_resync-wekuxaq6/fileB.txt" 2026/03/31 04:48:02 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-mikotiz8vugo/044753me/resync/path1/" 2026/03/31 04:48:02 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:48:02 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:48:02 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Connecting to FTP server 2026/03/31 04:48:02 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:02 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:58172->172.17.0.4:21, err= 2026/03/31 04:48:02 DEBUG : operations.CopyFile "fileB.txt" to "ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1" as "file6.txt" 2026/03/31 04:48:02 DEBUG : fileB.txt: size = 19 (Local file system at /tmp/044753me/datadir/test_resync-wekuxaq6) 2026/03/31 04:48:02 DEBUG : file6.txt: size = 0 (ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1) 2026/03/31 04:48:02 DEBUG : fileB.txt: Sizes differ 2026/03/31 04:48:02 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:32389") 2026/03/31 04:48:02 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:35824->172.17.0.4:32389, err= 2026/03/31 04:48:02 DEBUG : file6.txt.237b502b.partial: size = 19 OK 2026/03/31 04:48:02 DEBUG : file6.txt.237b502b.partial: renamed to: file6.txt 2026/03/31 04:48:02 INFO : fileB.txt: Copied (replaced existing) to: file6.txt 2026/03/31 04:48:02 NOTICE: (27) : copy-as /tmp/044753me/datadir/test_resync-wekuxaq6/fileA.txt /tmp/044753me/resync/path2/ file6.txt 2026/03/31 04:48:02 DEBUG : copyFile "/tmp/044753me/datadir/test_resync-wekuxaq6/fileA.txt" to "/tmp/044753me/resync/path2/" as "file6.txt" 2026/03/31 04:48:02 DEBUG : Creating backend with remote "/tmp/044753me/datadir/test_resync-wekuxaq6/fileA.txt" 2026/03/31 04:48:02 DEBUG : Creating backend with remote "/tmp/044753me/resync/path2/" 2026/03/31 04:48:02 DEBUG : operations.CopyFile "fileA.txt" to "Local file system at /tmp/044753me/resync/path2" as "file6.txt" 2026/03/31 04:48:02 DEBUG : fileA.txt: size = 19 (Local file system at /tmp/044753me/datadir/test_resync-wekuxaq6) 2026/03/31 04:48:02 DEBUG : file6.txt: size = 0 (Local file system at /tmp/044753me/resync/path2) 2026/03/31 04:48:02 DEBUG : fileA.txt: Sizes differ 2026/03/31 04:48:02 DEBUG : file6.txt.c537c25e.partial: size = 19 OK 2026/03/31 04:48:02 DEBUG : fileA.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2026/03/31 04:48:02 DEBUG : file6.txt.c537c25e.partial: renamed to: file6.txt 2026/03/31 04:48:02 INFO : fileA.txt: Copied (replaced existing) to: file6.txt 2026/03/31 04:48:02 NOTICE: (28) : test - file7.txt - exists - exists (same) - none - same 2026/03/31 04:48:02 NOTICE: (29) : test run bisync with resync 2026/03/31 04:48:02 NOTICE: (30) : bisync resync 2026/03/31 04:48:02 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:37625") 2026/03/31 04:48:02 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:54556->172.17.0.4:37625, err= 2026/03/31 04:48:04 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/03/31 04:48:04 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/03/31 04:48:04 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2026/03/31 04:48:04 INFO : Synching Path1 "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/resync/path1/" with Path2 "/tmp/044753me/resync/path2/" 2026/03/31 04:48:04 INFO : Copying Path2 files to Path1 2026/03/31 04:48:04 INFO : - Path2 Resync is copying files to - Path1 2026/03/31 04:48:04 INFO : file4.txt: Copied (new) 2026/03/31 04:48:04 INFO : file2.txt: Copied (new) 2026/03/31 04:48:04 INFO : - Path1 Resync is copying files to - Path2 2026/03/31 04:48:04 INFO : file1.txt: Copied (new) 2026/03/31 04:48:04 INFO : file3.txt: Copied (replaced existing) 2026/03/31 04:48:04 INFO : file5.txt: Copied (replaced existing) 2026/03/31 04:48:04 INFO : file6.txt: Copied (replaced existing) 2026/03/31 04:48:04 INFO : Resync updating listings 2026/03/31 04:48:04 INFO : Validating listings for Path1 "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/resync/path1/" vs Path2 "/tmp/044753me/resync/path2/" 2026/03/31 04:48:04 INFO : Bisync successful 2026/03/31 04:48:04 NOTICE: (31) : copy-listings mixed-diffs 2026/03/31 04:48:04 NOTICE: (32) : test run normal bisync 2026/03/31 04:48:04 NOTICE: (33) : bisync 2026/03/31 04:48:04 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:39779") 2026/03/31 04:48:04 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:58426->172.17.0.4:39779, err= 2026/03/31 04:48:06 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/03/31 04:48:06 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/03/31 04:48:06 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2026/03/31 04:48:06 INFO : Synching Path1 "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/resync/path1/" with Path2 "/tmp/044753me/resync/path2/" 2026/03/31 04:48:06 INFO : Building Path1 and Path2 listings 2026/03/31 04:48:06 INFO : Path1 checking for diffs 2026/03/31 04:48:06 INFO : Path2 checking for diffs 2026/03/31 04:48:06 INFO : No changes found 2026/03/31 04:48:06 INFO : Updating listings 2026/03/31 04:48:06 INFO : Validating listings for Path1 "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/resync/path1/" vs Path2 "/tmp/044753me/resync/path2/" 2026/03/31 04:48:06 INFO : Bisync successful 2026/03/31 04:48:06 NOTICE: (34) : test 4. confirm critical error on normal sync of empty path. 2026/03/31 04:48:06 NOTICE: (35) : purge-children /tmp/044753me/resync/path2/ 2026/03/31 04:48:06 DEBUG : file6.txt: Remove file 2026/03/31 04:48:06 DEBUG : file4.txt: Remove file 2026/03/31 04:48:06 DEBUG : file1.txt: Remove file 2026/03/31 04:48:06 DEBUG : file3.txt: Remove file 2026/03/31 04:48:06 DEBUG : RCLONE_TEST: Remove file 2026/03/31 04:48:06 DEBUG : file5.txt: Remove file 2026/03/31 04:48:06 DEBUG : file7.txt: Remove file 2026/03/31 04:48:06 DEBUG : file2.txt: Remove file 2026/03/31 04:48:06 NOTICE: (36) : bisync 2026/03/31 04:48:06 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:33760") 2026/03/31 04:48:06 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:36872->172.17.0.4:33760, err= 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/03/31 04:48:08 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/03/31 04:48:08 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": true, "DownloadHash": false } 2026/03/31 04:48:08 INFO : Synching Path1 "TestFTPPureftpd{MtW45}:rclone-test-mikotiz8vugo/044753me/resync/path1/" with Path2 "/tmp/044753me/resync/path2/" 2026/03/31 04:48:08 INFO : Building Path1 and Path2 listings 2026/03/31 04:48:08 INFO : Path1 checking for diffs 2026/03/31 04:48:08 INFO : Path2 checking for diffs 2026/03/31 04:48:08 ERROR : Empty current Path2 listing. Cannot sync to an empty directory: /tmp/044753me/workdir/TestFTPPureftpd_rclone-test-mikotiz8vugo_044753me_resync_path1..tmp_044753me_resync_path2.path2.lst-new 2026/03/31 04:48:08 ERROR : Bisync critical error: empty current Path2 listing: /tmp/044753me/workdir/TestFTPPureftpd_rclone-test-mikotiz8vugo_044753me_resync_path1..tmp_044753me_resync_path2.path2.lst-new 2026/03/31 04:48:08 ERROR : Bisync aborted. Must run --resync to recover. 2026/03/31 04:48:08 NOTICE: Bisync error: bisync aborted 2026/03/31 04:48:08 DEBUG : Waiting for deletions to finish 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:31533") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:49352->172.17.0.4:31533, err= 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Connecting to FTP server 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Connecting to FTP server 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Connecting to FTP server 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Connecting to FTP server 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:58182->172.17.0.4:21, err= 2026/03/31 04:48:08 INFO : file3.txt: Deleted 2026/03/31 04:48:08 INFO : RCLONE_TEST: Deleted 2026/03/31 04:48:08 INFO : file2.txt: Deleted 2026/03/31 04:48:08 INFO : file7.txt: Deleted 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:58184->172.17.0.4:21, err= 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:58188->172.17.0.4:21, err= 2026/03/31 04:48:08 INFO : file6.txt: Deleted 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:58194->172.17.0.4:21, err= 2026/03/31 04:48:08 INFO : file4.txt: Deleted 2026/03/31 04:48:08 INFO : file5.txt: Deleted 2026/03/31 04:48:08 INFO : file1.txt: Deleted 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: dial("tcp","172.17.0.4:31254") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: > dial: conn=172.17.0.1:45420->172.17.0.4:31254, err= 2026/03/31 04:48:08 DEBUG : removing 1 level 0 directories 2026/03/31 04:48:08 INFO : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: Removing directory 2026/03/31 04:48:08 DEBUG : Waiting for deletions to finish 2026/03/31 04:48:08 DEBUG : removing 1 level 0 directories 2026/03/31 04:48:08 INFO : Local file system at /tmp/044753me/resync/path2: Removing directory bisync_test.go:608: TEST resync PASSED 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: dial("tcp","172.17.0.4:38928") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: > dial: conn=172.17.0.1:45672->172.17.0.4:38928, err= 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: dial("tcp","172.17.0.4:32936") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: > dial: conn=172.17.0.1:58644->172.17.0.4:32936, err= 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: Connecting to FTP server 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: dial("tcp","172.17.0.4:31838") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: Connecting to FTP server 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: > dial: conn=172.17.0.1:58200->172.17.0.4:21, err= 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: > dial: conn=172.17.0.1:52774->172.17.0.4:31838, err= 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: > dial: conn=172.17.0.1:58210->172.17.0.4:21, err= 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: dial("tcp","172.17.0.4:37853") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: > dial: conn=172.17.0.1:46444->172.17.0.4:37853, err= 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: dial("tcp","172.17.0.4:30415") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: > dial: conn=172.17.0.1:54640->172.17.0.4:30415, err= 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: Purge dir "044753me/resync" 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: Purge dir "044753me/path1" 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: Purge dir "044753me/equal" 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: Purge dir "044753me" 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo: Purge dir "" --- PASS: TestBisyncRemoteLocal (14.75s) --- PASS: TestBisyncRemoteLocal/equal (4.27s) --- PASS: TestBisyncRemoteLocal/resync (10.41s) === RUN TestBisyncLocalRemote 2026/03/31 04:48:08 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-nazavet2mofu" 2026/03/31 04:48:08 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:48:08 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:48:08 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:48:08 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:48:08 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:48:08 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:48:08 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:48:08 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:48:08 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:48:08 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: Connecting to FTP server 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: > dial: conn=172.17.0.1:58212->172.17.0.4:21, err= 2026/03/31 04:48:08 NOTICE: remote: TestFTPPureftpd:rclone-test-nazavet2mofu === RUN TestBisyncLocalRemote/normalization 2026/03/31 04:48:08 DEBUG : Creating backend with remote "/tmp/044808ma" 2026/03/31 04:48:08 DEBUG : Creating backend with remote "/tmp/044808ma/normalization/path1" 2026/03/31 04:48:08 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-nazavet2mofu/044808ma" 2026/03/31 04:48:08 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:48:08 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:48:08 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:48:08 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:48:08 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:48:08 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:48:08 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:48:08 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:48:08 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:48:08 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma: Connecting to FTP server 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma: > dial: conn=172.17.0.1:58226->172.17.0.4:21, err= 2026/03/31 04:48:08 DEBUG : fs cache: renaming cache item "TestFTPPureftpd:rclone-test-nazavet2mofu/044808ma" to be canonical "TestFTPPureftpd{MtW45}:rclone-test-nazavet2mofu/044808ma" 2026/03/31 04:48:08 INFO : path2: Making directory 2026/03/31 04:48:08 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-nazavet2mofu/044808ma/normalization/path2" 2026/03/31 04:48:08 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:48:08 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:48:08 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:48:08 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:48:08 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:48:08 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:48:08 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:48:08 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:48:08 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:48:08 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: Connecting to FTP server 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:58240->172.17.0.4:21, err= 2026/03/31 04:48:08 DEBUG : fs cache: renaming cache item "TestFTPPureftpd:rclone-test-nazavet2mofu/044808ma/normalization/path2" to be canonical "TestFTPPureftpd{MtW45}:rclone-test-nazavet2mofu/044808ma/normalization/path2" 2026/03/31 04:48:08 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_normalization/initial" 2026/03/31 04:48:08 DEBUG : Creating backend with remote "/tmp/044808ma/initdir/test_normalization-fosoxog9" 2026/03/31 04:48:08 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/03/31 04:48:08 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ: Making directory with metadata 2026/03/31 04:48:08 INFO : 測試_Русский_ _ _ě_áñ: Made directory with metadata (mtime=2024-01-25T05:00:02.874776175Z) 2026/03/31 04:48:08 DEBUG : Added delayed dir = "測試_Русский_ _ _ě_áñ", newDst=測試_Русский_ _ _ě_áñ 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: Need to transfer - File not found at Destination 2026/03/31 04:48:08 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/03/31 04:48:08 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:48:08 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt.b8f49a2a.partial: size = 272 OK 2026/03/31 04:48:08 INFO : file1.txt: Copied (new) 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file.062d4dd7.partial: size = 0 OK 2026/03/31 04:48:08 DEBUG : Local file system at /tmp/044808ma/initdir/test_normalization-fosoxog9: Waiting for checks to finish 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: md5 = 0033328434f9662a7dae0d1aee7768b6 OK 2026/03/31 04:48:08 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt.b8f49a2a.partial: renamed to: 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt 2026/03/31 04:48:08 INFO : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Copied (new) 2026/03/31 04:48:08 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt.24b96bc5.partial: size = 272 OK 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:48:08 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/03/31 04:48:08 INFO : RCLONE_TEST: Copied (new) 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file.062d4dd7.partial: renamed to: 測試_Русский_ _ _ě_áñ/測試_check file 2026/03/31 04:48:08 INFO : 測試_Русский_ _ _ě_áñ/測試_check file: Copied (new) 2026/03/31 04:48:08 DEBUG : Local file system at /tmp/044808ma/initdir/test_normalization-fosoxog9: Waiting for transfers to finish 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: md5 = 0033328434f9662a7dae0d1aee7768b6 OK 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt.24b96bc5.partial: renamed to: 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt 2026/03/31 04:48:08 INFO : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Copied (new) 2026/03/31 04:48:08 INFO : 測試_Русский_ _ _ě_áñ: Set directory modification time (using SetModTime) 2026/03/31 04:48:08 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_normalization/modfiles" 2026/03/31 04:48:08 DEBUG : Creating backend with remote "/tmp/044808ma/datadir/test_normalization-fonewab9" 2026/03/31 04:48:08 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:08 DEBUG : 測試_filtersfile.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:08 DEBUG : Local file system at /tmp/044808ma/datadir/test_normalization-fonewab9: Waiting for checks to finish 2026/03/31 04:48:08 DEBUG : Local file system at /tmp/044808ma/datadir/test_normalization-fonewab9: Waiting for transfers to finish 2026/03/31 04:48:08 DEBUG : 測試_filtersfile.txt.3ada41b4.partial: size = 254 OK 2026/03/31 04:48:08 DEBUG : 測試_filtersfile.txt: md5 = 1cec24a8ae7c33c49693a14d53fd6a96 OK 2026/03/31 04:48:08 DEBUG : 測試_filtersfile.txt.3ada41b4.partial: renamed to: 測試_filtersfile.txt 2026/03/31 04:48:08 INFO : 測試_filtersfile.txt: Copied (new) 2026/03/31 04:48:08 DEBUG : file1.txt.75b77f44.partial: size = 19 OK 2026/03/31 04:48:08 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2026/03/31 04:48:08 DEBUG : file1.txt.75b77f44.partial: renamed to: file1.txt 2026/03/31 04:48:08 INFO : file1.txt: Copied (new) 2026/03/31 04:48:08 DEBUG : Waiting for deletions to finish 2026/03/31 04:48:08 ERROR : error listing: directory not found 2026/03/31 04:48:08 ERROR : Local file system at /tmp/044808ma/normalization/path1: Failed to list "": directory not found 2026/03/31 04:48:08 DEBUG : removing 1 level 0 directories 2026/03/31 04:48:08 INFO : Local file system at /tmp/044808ma/normalization/path1: Removing directory 2026/03/31 04:48:08 ERROR : Failed to rmdir: stat /tmp/044808ma/normalization/path1: no such file or directory 2026/03/31 04:48:08 DEBUG : Waiting for deletions to finish 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:34383") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:33610->172.17.0.4:34383, err= 2026/03/31 04:48:08 ERROR : error listing: directory not found 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:32830") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:50052->172.17.0.4:32830, err= 2026/03/31 04:48:08 ERROR : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: Failed to list "": directory not found 2026/03/31 04:48:08 DEBUG : removing 1 level 0 directories 2026/03/31 04:48:08 INFO : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: Removing directory 2026/03/31 04:48:08 ERROR : Failed to rmdir: directory not found 2026/03/31 04:48:08 ERROR : error listing: directory not found 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:33718") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:47578->172.17.0.4:33718, err= 2026/03/31 04:48:08 ERROR : error listing: directory not found 2026/03/31 04:48:08 NOTICE: checking initFs Local file system at /tmp/044808ma/initdir/test_normalization-fosoxog9 2026/03/31 04:48:08 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/03/31 04:48:08 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ: Making directory with metadata 2026/03/31 04:48:08 INFO : 測試_Русский_ _ _ě_áñ: Made directory with metadata (mtime=2024-01-25T05:00:02.874776175Z) 2026/03/31 04:48:08 DEBUG : Added delayed dir = "測試_Русский_ _ _ě_áñ", newDst=測試_Русский_ _ _ě_áñ 2026/03/31 04:48:08 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/03/31 04:48:08 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: Need to transfer - File not found at Destination 2026/03/31 04:48:08 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/03/31 04:48:08 INFO : RCLONE_TEST: Copied (new) 2026/03/31 04:48:08 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt.b8f49a2a.partial: size = 272 OK 2026/03/31 04:48:08 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:48:08 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/03/31 04:48:08 INFO : file1.txt: Copied (new) 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: md5 = 0033328434f9662a7dae0d1aee7768b6 OK 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt.b8f49a2a.partial: renamed to: 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt 2026/03/31 04:48:08 INFO : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Copied (new) 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt.24b96bc5.partial: size = 272 OK 2026/03/31 04:48:08 DEBUG : Local file system at /tmp/044808ma/normalization/path1: Waiting for checks to finish 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: md5 = 0033328434f9662a7dae0d1aee7768b6 OK 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file.062d4dd7.partial: size = 0 OK 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:48:08 DEBUG : Local file system at /tmp/044808ma/normalization/path1: Waiting for transfers to finish 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt.24b96bc5.partial: renamed to: 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt 2026/03/31 04:48:08 INFO : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Copied (new) 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file.062d4dd7.partial: renamed to: 測試_Русский_ _ _ě_áñ/測試_check file 2026/03/31 04:48:08 INFO : 測試_Русский_ _ _ě_áñ/測試_check file: Copied (new) 2026/03/31 04:48:08 INFO : 測試_Русский_ _ _ě_áñ: Set directory modification time (using SetModTime) 2026/03/31 04:48:08 NOTICE: checking Path1 Local file system at /tmp/044808ma/normalization/path1 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:32716") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:41072->172.17.0.4:32716, err= 2026/03/31 04:48:08 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/03/31 04:48:08 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:08 INFO : 測試_Русский_ _ _ě_áñ: Making directory 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: Connecting to FTP server 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: Connecting to FTP server 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:58250->172.17.0.4:21, err= 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: Need to transfer - File not found at Destination 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: Connecting to FTP server 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: Waiting for checks to finish 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: Waiting for transfers to finish 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:37022") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:34436->172.17.0.4:37022, err= 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt.b8f49a2a.partial: size = 272 OK 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt.b8f49a2a.partial: renamed to: 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt 2026/03/31 04:48:08 INFO : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Copied (new) 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:33821") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:50512->172.17.0.4:33821, err= 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file.062d4dd7.partial: size = 0 OK 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file.062d4dd7.partial: renamed to: 測試_Русский_ _ _ě_áñ/測試_check file 2026/03/31 04:48:08 INFO : 測試_Русский_ _ _ě_áñ/測試_check file: Copied (new) 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:58260->172.17.0.4:21, err= 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:58276->172.17.0.4:21, err= 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:34660") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:47526->172.17.0.4:34660, err= 2026/03/31 04:48:08 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:31479") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:52946->172.17.0.4:31479, err= 2026/03/31 04:48:08 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/03/31 04:48:08 INFO : RCLONE_TEST: Copied (new) 2026/03/31 04:48:08 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/03/31 04:48:08 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/03/31 04:48:08 INFO : file1.txt: Copied (new) 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:31560") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:55730->172.17.0.4:31560, err= 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt.24b96bc5.partial: size = 272 OK 2026/03/31 04:48:08 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt.24b96bc5.partial: renamed to: 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt 2026/03/31 04:48:08 INFO : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Copied (new) 2026/03/31 04:48:08 NOTICE: checking path2 ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:33836") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:39316->172.17.0.4:33836, err= 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:34465") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:40150->172.17.0.4:34465, err= 2026/03/31 04:48:08 NOTICE: (01) : test normalization 2026/03/31 04:48:08 NOTICE: (02) : touch-copy 2001-01-02 /tmp/044808ma/datadir/test_normalization-fonewab9/file1.txt TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-nazavet2mofu/044808ma/normalization/path2/ 2026/03/31 04:48:08 DEBUG : Creating backend with remote "/tmp/044808ma/datadir/test_normalization-fonewab9/" 2026/03/31 04:48:08 DEBUG : fs cache: renaming cache item "/tmp/044808ma/datadir/test_normalization-fonewab9/" to be canonical "/tmp/044808ma/datadir/test_normalization-fonewab9" 2026/03/31 04:48:08 DEBUG : file1.txt: Set modification time 2001-01-02 2026/03/31 04:48:08 DEBUG : copyFile "/tmp/044808ma/datadir/test_normalization-fonewab9/file1.txt" to "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-nazavet2mofu/044808ma/normalization/path2/" as "" 2026/03/31 04:48:08 DEBUG : Creating backend with remote "/tmp/044808ma/datadir/test_normalization-fonewab9/file1.txt" 2026/03/31 04:48:08 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-nazavet2mofu/044808ma/normalization/path2/" 2026/03/31 04:48:08 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:48:08 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: Connecting to FTP server 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:58286->172.17.0.4:21, err= 2026/03/31 04:48:08 DEBUG : operations.CopyFile "file1.txt" to "ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2" as "file1.txt" 2026/03/31 04:48:08 DEBUG : file1.txt: size = 19 (Local file system at /tmp/044808ma/datadir/test_normalization-fonewab9) 2026/03/31 04:48:08 DEBUG : file1.txt: size = 0 (ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2) 2026/03/31 04:48:08 DEBUG : file1.txt: Sizes differ 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:35000") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:45484->172.17.0.4:35000, err= 2026/03/31 04:48:08 DEBUG : file1.txt.75b77f44.partial: size = 19 OK 2026/03/31 04:48:08 DEBUG : file1.txt.75b77f44.partial: renamed to: file1.txt 2026/03/31 04:48:08 INFO : file1.txt: Copied (replaced existing) 2026/03/31 04:48:08 NOTICE: (03) : test initial bisync 2026/03/31 04:48:08 NOTICE: (04) : bisync resync 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:32328") 2026/03/31 04:48:08 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:59086->172.17.0.4:32328, err= 2026/03/31 04:48:10 NOTICE: Local file system at /tmp/044808ma/normalization/path1: Replacing invalid UTF-8 characters in "ě\x81\xfe áñhࢺ_測試Рускийěáñ👸🏼🧝🏾\u200d♀️💆🏿\u200d♂️🐨🤙🏼🤮🧑🏻\u200d🔧🧑\u200d🔬éö" 2026/03/31 04:48:10 DEBUG : ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍🔧.1c6c2e43.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍🔧🧑‍🔬éö: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:48:10 DEBUG : ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍🔧.1c6c2e43.partial: renamed to: ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍🔧🧑‍🔬éö 2026/03/31 04:48:10 INFO : ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍🔧🧑‍🔬éö: Copied (new) 2026/03/31 04:48:10 NOTICE: Local file system at /tmp/044808ma/normalization/path1: Replacing invalid UTF-8 characters in "ě\x81\xfe áñhࢺ_測試Рускийěáñ👸🏼🧝🏾\u200d♀️💆🏿\u200d♂️🐨🤙🏼🤮🧑🏻\u200d🔧🧑\u200d🔬éö" 2026/03/31 04:48:10 DEBUG : ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍.a79ff014.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍🔧🧑‍🔬éö: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:48:10 DEBUG : ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍.a79ff014.partial: renamed to: ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍🔧🧑‍🔬éö 2026/03/31 04:48:10 INFO : ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍🔧🧑‍🔬éö: Copied (new) 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:38420") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:44730->172.17.0.4:38420, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:34350") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:57872->172.17.0.4:34350, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:34481") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:48432->172.17.0.4:34481, err= 2026/03/31 04:48:10 DEBUG : ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍🔧.1c6c2e43.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍🔧.1c6c2e43.partial: renamed to: ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍🔧🧑‍🔬éö 2026/03/31 04:48:10 INFO : ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍🔧🧑‍🔬éö: Copied (new) 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:30807") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:40656->172.17.0.4:30807, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:39179") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:51120->172.17.0.4:39179, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: dial("tcp","172.17.0.4:32932") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: > dial: conn=172.17.0.1:47930->172.17.0.4:32932, err= 2026/03/31 04:48:10 DEBUG : ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍.a79ff014.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍.a79ff014.partial: renamed to: ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍🔧🧑‍🔬éö 2026/03/31 04:48:10 INFO : ě�� áñhࢺ_測試рускийěáñ👸🏼🧝🏾‍♀️💆🏿‍♂️🐨🤙🏼🤮🧑🏻‍🔧🧑‍🔬éö: Copied (new) bisync_test.go:1094: Fs is incapable of running test as the paths produce different results, skipping: normalization (path1: 測試_Русский_ _ _ě_áñ測試_Русский_ _ _ě_áñ (NFC) path2: RCLONE_TESTRCLONE_TEST (RCLONE_TESTRCLONE_TEST)) (fs1: Local file system at /tmp/044808ma/normalization/path1 fs2: ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2) @@ -1 +1 @@ -測試_Русский_ _ _ě_áñ測試_Русский_ _ _ě_áñ+RCLONE_TESTRCLONE_TEST 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: dial("tcp","172.17.0.4:30903") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: > dial: conn=172.17.0.1:53166->172.17.0.4:30903, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: dial("tcp","172.17.0.4:38276") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: > dial: conn=172.17.0.1:56638->172.17.0.4:38276, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: Connecting to FTP server 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: dial("tcp","172.17.0.4:35027") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: > dial: conn=172.17.0.1:43444->172.17.0.4:35027, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: > dial: conn=172.17.0.1:58302->172.17.0.4:21, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: dial("tcp","172.17.0.4:30595") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: > dial: conn=172.17.0.1:48140->172.17.0.4:30595, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: dial("tcp","172.17.0.4:34920") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: > dial: conn=172.17.0.1:42368->172.17.0.4:34920, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: Purge object "044808ma/normalization/path2/RCLONE_TEST" 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: Purge object "044808ma/normalization/path2/file1.txt" 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: dial("tcp","172.17.0.4:35193") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: > dial: conn=172.17.0.1:38224->172.17.0.4:35193, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: Purge object "044808ma/normalization/path2/測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt" 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: Purge object "044808ma/normalization/path2/測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt" 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: Purge object "044808ma/normalization/path2/測試_Русский_ _ _ě_áñ/測試_check file" 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: Purge dir "044808ma/path2" 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: Purge dir "044808ma/normalization/path2/測試_Русский_ _ _ě_áñ" 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: Purge dir "044808ma/normalization/path2" 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: Purge dir "044808ma/normalization" 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: Purge dir "044808ma" 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu: Purge dir "" --- PASS: TestBisyncLocalRemote (2.22s) --- SKIP: TestBisyncLocalRemote/normalization (2.18s) === RUN TestBisyncRemoteRemote 2026/03/31 04:48:10 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-zuwafed0zecu" 2026/03/31 04:48:10 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:48:10 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:48:10 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:48:10 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:48:10 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:48:10 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:48:10 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:48:10 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:48:10 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:48:10 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: Connecting to FTP server 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: > dial: conn=172.17.0.1:58314->172.17.0.4:21, err= 2026/03/31 04:48:10 NOTICE: remote: TestFTPPureftpd:rclone-test-zuwafed0zecu === RUN TestBisyncRemoteRemote/basic 2026/03/31 04:48:10 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-zuwafed0zecu/044810xu" 2026/03/31 04:48:10 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:48:10 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:48:10 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:48:10 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:48:10 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:48:10 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:48:10 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:48:10 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:48:10 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:48:10 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu: Connecting to FTP server 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu: > dial: conn=172.17.0.1:58328->172.17.0.4:21, err= 2026/03/31 04:48:10 DEBUG : fs cache: renaming cache item "TestFTPPureftpd:rclone-test-zuwafed0zecu/044810xu" to be canonical "TestFTPPureftpd{MtW45}:rclone-test-zuwafed0zecu/044810xu" 2026/03/31 04:48:10 INFO : path1: Making directory 2026/03/31 04:48:10 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-zuwafed0zecu/044810xu/basic/path1" 2026/03/31 04:48:10 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:48:10 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:48:10 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:48:10 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:48:10 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:48:10 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:48:10 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:48:10 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:48:10 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:48:10 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: Connecting to FTP server 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:58334->172.17.0.4:21, err= 2026/03/31 04:48:10 DEBUG : fs cache: renaming cache item "TestFTPPureftpd:rclone-test-zuwafed0zecu/044810xu/basic/path1" to be canonical "TestFTPPureftpd{MtW45}:rclone-test-zuwafed0zecu/044810xu/basic/path1" 2026/03/31 04:48:10 DEBUG : fs cache: switching user supplied name "TestFTPPureftpd:rclone-test-zuwafed0zecu/044810xu" for canonical name "TestFTPPureftpd{MtW45}:rclone-test-zuwafed0zecu/044810xu" 2026/03/31 04:48:10 INFO : path2: Making directory 2026/03/31 04:48:10 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-zuwafed0zecu/044810xu/basic/path2" 2026/03/31 04:48:10 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:48:10 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:48:10 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:48:10 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:48:10 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:48:10 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:48:10 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2026/03/31 04:48:10 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2026/03/31 04:48:10 DEBUG : Setting pass="CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2026/03/31 04:48:10 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: Connecting to FTP server 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:58336->172.17.0.4:21, err= 2026/03/31 04:48:10 DEBUG : fs cache: renaming cache item "TestFTPPureftpd:rclone-test-zuwafed0zecu/044810xu/basic/path2" to be canonical "TestFTPPureftpd{MtW45}:rclone-test-zuwafed0zecu/044810xu/basic/path2" 2026/03/31 04:48:10 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_basic/initial" 2026/03/31 04:48:10 DEBUG : Creating backend with remote "/tmp/044810xu/initdir/test_basic-monalok7" 2026/03/31 04:48:10 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : subdir: Making directory with metadata 2026/03/31 04:48:10 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2026/03/31 04:48:10 DEBUG : Added delayed dir = "subdir", newDst=subdir 2026/03/31 04:48:10 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : Local file system at /tmp/044810xu/initdir/test_basic-monalok7: Waiting for checks to finish 2026/03/31 04:48:10 DEBUG : file1.copy1.txt.21b8fa2b.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : Local file system at /tmp/044810xu/initdir/test_basic-monalok7: Waiting for transfers to finish 2026/03/31 04:48:10 DEBUG : file1.copy2.txt.455881d5.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:48:10 DEBUG : file1.copy1.txt.21b8fa2b.partial: renamed to: file1.copy1.txt 2026/03/31 04:48:10 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:48:10 INFO : file1.copy1.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : file1.copy3.txt.d0285540.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : file1.copy4.txt.8c987629.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : file1.copy2.txt.455881d5.partial: renamed to: file1.copy2.txt 2026/03/31 04:48:10 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:48:10 INFO : file1.copy2.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : file1.copy3.txt.d0285540.partial: renamed to: file1.copy3.txt 2026/03/31 04:48:10 INFO : file1.copy3.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/03/31 04:48:10 DEBUG : file1.copy5.txt.19e8a2bc.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/03/31 04:48:10 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:48:10 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:48:10 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/03/31 04:48:10 INFO : RCLONE_TEST: Copied (new) 2026/03/31 04:48:10 DEBUG : file1.copy4.txt.8c987629.partial: renamed to: file1.copy4.txt 2026/03/31 04:48:10 INFO : file1.copy4.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : file1.copy5.txt.19e8a2bc.partial: renamed to: file1.copy5.txt 2026/03/31 04:48:10 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:48:10 INFO : file1.copy5.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/03/31 04:48:10 INFO : file1.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/03/31 04:48:10 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2026/03/31 04:48:10 INFO : subdir/file20.txt: Copied (new) 2026/03/31 04:48:10 INFO : subdir: Set directory modification time (using SetModTime) 2026/03/31 04:48:10 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_basic/modfiles" 2026/03/31 04:48:10 DEBUG : Creating backend with remote "/tmp/044810xu/datadir/test_basic-cuhirun9" 2026/03/31 04:48:10 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.txt.75b77f44.partial: size = 19 OK 2026/03/31 04:48:10 DEBUG : Local file system at /tmp/044810xu/datadir/test_basic-cuhirun9: Waiting for checks to finish 2026/03/31 04:48:10 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK 2026/03/31 04:48:10 DEBUG : file1.txt.75b77f44.partial: renamed to: file1.txt 2026/03/31 04:48:10 INFO : file1.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : Local file system at /tmp/044810xu/datadir/test_basic-cuhirun9: Waiting for transfers to finish 2026/03/31 04:48:10 DEBUG : Waiting for deletions to finish 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:30507") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:37118->172.17.0.4:30507, err= 2026/03/31 04:48:10 ERROR : error listing: directory not found 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:37064") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:58014->172.17.0.4:37064, err= 2026/03/31 04:48:10 ERROR : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: Failed to list "": directory not found 2026/03/31 04:48:10 DEBUG : removing 1 level 0 directories 2026/03/31 04:48:10 INFO : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: Removing directory 2026/03/31 04:48:10 ERROR : Failed to rmdir: directory not found 2026/03/31 04:48:10 DEBUG : Waiting for deletions to finish 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:32415") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:33048->172.17.0.4:32415, err= 2026/03/31 04:48:10 ERROR : error listing: directory not found 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:30406") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:37360->172.17.0.4:30406, err= 2026/03/31 04:48:10 ERROR : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: Failed to list "": directory not found 2026/03/31 04:48:10 DEBUG : removing 1 level 0 directories 2026/03/31 04:48:10 INFO : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: Removing directory 2026/03/31 04:48:10 ERROR : Failed to rmdir: directory not found 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:32153") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:50226->172.17.0.4:32153, err= 2026/03/31 04:48:10 ERROR : error listing: directory not found 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:38453") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:60452->172.17.0.4:38453, err= 2026/03/31 04:48:10 ERROR : error listing: directory not found 2026/03/31 04:48:10 NOTICE: checking initFs Local file system at /tmp/044810xu/initdir/test_basic-monalok7 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:39501") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:55802->172.17.0.4:39501, err= 2026/03/31 04:48:10 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 INFO : subdir: Making directory 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: Connecting to FTP server 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: Connecting to FTP server 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: Connecting to FTP server 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: Connecting to FTP server 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:58352->172.17.0.4:21, err= 2026/03/31 04:48:10 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: Waiting for checks to finish 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: Waiting for transfers to finish 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:58354->172.17.0.4:21, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:32369") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:32802->172.17.0.4:32369, err= 2026/03/31 04:48:10 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/03/31 04:48:10 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/03/31 04:48:10 INFO : RCLONE_TEST: Copied (new) 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:38534") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:58356->172.17.0.4:21, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:44578->172.17.0.4:38534, err= 2026/03/31 04:48:10 DEBUG : file1.copy4.txt.8c987629.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : file1.copy4.txt.8c987629.partial: renamed to: file1.copy4.txt 2026/03/31 04:48:10 INFO : file1.copy4.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:34767") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:47596->172.17.0.4:34767, err= 2026/03/31 04:48:10 DEBUG : file1.copy5.txt.19e8a2bc.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : file1.copy5.txt.19e8a2bc.partial: renamed to: file1.copy5.txt 2026/03/31 04:48:10 INFO : file1.copy5.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:37027") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:52798->172.17.0.4:37027, err= 2026/03/31 04:48:10 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/03/31 04:48:10 INFO : file1.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:30110") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:46216->172.17.0.4:30110, err= 2026/03/31 04:48:10 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:58360->172.17.0.4:21, err= 2026/03/31 04:48:10 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2026/03/31 04:48:10 INFO : subdir/file20.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:37058") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:56730->172.17.0.4:37058, err= 2026/03/31 04:48:10 DEBUG : file1.copy1.txt.21b8fa2b.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : file1.copy1.txt.21b8fa2b.partial: renamed to: file1.copy1.txt 2026/03/31 04:48:10 INFO : file1.copy1.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:39314") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:51946->172.17.0.4:39314, err= 2026/03/31 04:48:10 DEBUG : file1.copy2.txt.455881d5.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : file1.copy2.txt.455881d5.partial: renamed to: file1.copy2.txt 2026/03/31 04:48:10 INFO : file1.copy2.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:39582") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:51924->172.17.0.4:39582, err= 2026/03/31 04:48:10 DEBUG : file1.copy3.txt.d0285540.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : file1.copy3.txt.d0285540.partial: renamed to: file1.copy3.txt 2026/03/31 04:48:10 INFO : file1.copy3.txt: Copied (new) 2026/03/31 04:48:10 NOTICE: checking Path1 ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:34432") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:47264->172.17.0.4:34432, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:31151") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:38398->172.17.0.4:31151, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:32308") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:60360->172.17.0.4:32308, err= 2026/03/31 04:48:10 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 INFO : subdir: Making directory 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: Connecting to FTP server 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: Connecting to FTP server 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: Connecting to FTP server 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: Connecting to FTP server 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:58376->172.17.0.4:21, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:35798") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:38828->172.17.0.4:35798, err= 2026/03/31 04:48:10 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/03/31 04:48:10 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/03/31 04:48:10 INFO : RCLONE_TEST: Copied (new) 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:34155") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:43304->172.17.0.4:34155, err= 2026/03/31 04:48:10 DEBUG : file1.copy4.txt.8c987629.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : file1.copy4.txt.8c987629.partial: renamed to: file1.copy4.txt 2026/03/31 04:48:10 INFO : file1.copy4.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:30524") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:37420->172.17.0.4:30524, err= 2026/03/31 04:48:10 DEBUG : file1.copy5.txt.19e8a2bc.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : file1.copy5.txt.19e8a2bc.partial: renamed to: file1.copy5.txt 2026/03/31 04:48:10 INFO : file1.copy5.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:34997") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:39270->172.17.0.4:34997, err= 2026/03/31 04:48:10 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:58390->172.17.0.4:21, err= 2026/03/31 04:48:10 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/03/31 04:48:10 INFO : file1.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:58404->172.17.0.4:21, err= 2026/03/31 04:48:10 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: Waiting for checks to finish 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: Waiting for transfers to finish 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:31786") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:35667") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:57894->172.17.0.4:31786, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:46830->172.17.0.4:35667, err= 2026/03/31 04:48:10 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2026/03/31 04:48:10 INFO : subdir/file20.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : file1.copy1.txt.21b8fa2b.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : file1.copy1.txt.21b8fa2b.partial: renamed to: file1.copy1.txt 2026/03/31 04:48:10 INFO : file1.copy1.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:58416->172.17.0.4:21, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:34326") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:50346->172.17.0.4:34326, err= 2026/03/31 04:48:10 DEBUG : file1.copy3.txt.d0285540.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : file1.copy3.txt.d0285540.partial: renamed to: file1.copy3.txt 2026/03/31 04:48:10 INFO : file1.copy3.txt: Copied (new) 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:36480") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:48374->172.17.0.4:36480, err= 2026/03/31 04:48:10 DEBUG : file1.copy2.txt.455881d5.partial: size = 0 OK 2026/03/31 04:48:10 DEBUG : file1.copy2.txt.455881d5.partial: renamed to: file1.copy2.txt 2026/03/31 04:48:10 INFO : file1.copy2.txt: Copied (new) 2026/03/31 04:48:10 NOTICE: checking path2 ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:30348") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:39962->172.17.0.4:30348, err= 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:38648") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:47966->172.17.0.4:38648, err= 2026/03/31 04:48:10 NOTICE: (01) : test basic 2026/03/31 04:48:10 NOTICE: (02) : test initial bisync 2026/03/31 04:48:10 NOTICE: (03) : bisync resync 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:32198") 2026/03/31 04:48:10 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:58146->172.17.0.4:32198, err= 2026/03/31 04:48:12 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:35070") 2026/03/31 04:48:12 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:41034->172.17.0.4:35070, err= 2026/03/31 04:48:14 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/03/31 04:48:14 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/03/31 04:48:14 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/03/31 04:48: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/03/31 04:48:14 INFO : Synching Path1 "TestFTPPureftpd{MtW45}:rclone-test-zuwafed0zecu/044810xu/basic/path1/" with Path2 "TestFTPPureftpd{MtW45}:rclone-test-zuwafed0zecu/044810xu/basic/path2/" 2026/03/31 04:48:14 INFO : Copying Path2 files to Path1 2026/03/31 04:48:14 INFO : - Path2 Resync is copying files to - Path1 2026/03/31 04:48:14 INFO : There was nothing to transfer 2026/03/31 04:48:14 INFO : - Path1 Resync is copying files to - Path2 2026/03/31 04:48:14 INFO : There was nothing to transfer 2026/03/31 04:48:14 INFO : Resync updating listings 2026/03/31 04:48:14 INFO : Validating listings for Path1 "TestFTPPureftpd{MtW45}:rclone-test-zuwafed0zecu/044810xu/basic/path1/" vs Path2 "TestFTPPureftpd{MtW45}:rclone-test-zuwafed0zecu/044810xu/basic/path2/" 2026/03/31 04:48:14 INFO : Bisync successful 2026/03/31 04:48:14 NOTICE: (04) : test place newer files on both paths 2026/03/31 04:48:14 NOTICE: (05) : touch-copy 2001-01-02 /tmp/044810xu/datadir/test_basic-cuhirun9/file1.txt TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-zuwafed0zecu/044810xu/basic/path2/ 2026/03/31 04:48:14 DEBUG : Creating backend with remote "/tmp/044810xu/datadir/test_basic-cuhirun9/" 2026/03/31 04:48:14 DEBUG : Config file has changed externally - reloading 2026/03/31 04:48:14 DEBUG : fs cache: renaming cache item "/tmp/044810xu/datadir/test_basic-cuhirun9/" to be canonical "/tmp/044810xu/datadir/test_basic-cuhirun9" 2026/03/31 04:48:14 DEBUG : file1.txt: Set modification time 2001-01-02 2026/03/31 04:48:14 DEBUG : copyFile "/tmp/044810xu/datadir/test_basic-cuhirun9/file1.txt" to "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-zuwafed0zecu/044810xu/basic/path2/" as "" 2026/03/31 04:48:14 DEBUG : Creating backend with remote "/tmp/044810xu/datadir/test_basic-cuhirun9/file1.txt" 2026/03/31 04:48:14 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-zuwafed0zecu/044810xu/basic/path2/" 2026/03/31 04:48:14 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:48:14 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:48:14 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: Connecting to FTP server 2026/03/31 04:48:14 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:14 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:34668->172.17.0.4:21, err= 2026/03/31 04:48:14 DEBUG : operations.CopyFile "file1.txt" to "ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2" as "file1.txt" 2026/03/31 04:48:14 DEBUG : file1.txt: size = 19 (Local file system at /tmp/044810xu/datadir/test_basic-cuhirun9) 2026/03/31 04:48:14 DEBUG : file1.txt: size = 0 (ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2) 2026/03/31 04:48:14 DEBUG : file1.txt: Sizes differ 2026/03/31 04:48:14 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:33981") 2026/03/31 04:48:14 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:41688->172.17.0.4:33981, err= 2026/03/31 04:48:14 DEBUG : file1.txt.75b77f44.partial: size = 19 OK 2026/03/31 04:48:14 DEBUG : file1.txt.75b77f44.partial: renamed to: file1.txt 2026/03/31 04:48:14 INFO : file1.txt: Copied (replaced existing) 2026/03/31 04:48:14 NOTICE: (06) : copy-as /tmp/044810xu/datadir/test_basic-cuhirun9/file1.txt TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-zuwafed0zecu/044810xu/basic/path1/subdir file20.txt 2026/03/31 04:48:14 DEBUG : copyFile "/tmp/044810xu/datadir/test_basic-cuhirun9/file1.txt" to "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-zuwafed0zecu/044810xu/basic/path1/subdir" as "file20.txt" 2026/03/31 04:48:14 DEBUG : Creating backend with remote "/tmp/044810xu/datadir/test_basic-cuhirun9/file1.txt" 2026/03/31 04:48:14 DEBUG : Creating backend with remote "TestFTPPureftpd,encoding='BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket',host='172.17.0.4',pass='CW13l6W2XNXM0YbuLZpnSiUFbwvyDsZT42wMWrac1BM',user='rclone':rclone-test-zuwafed0zecu/044810xu/basic/path1/subdir" 2026/03/31 04:48:14 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2026/03/31 04:48:14 DEBUG : TestFTPPureftpd: detected overridden config - adding "{MtW45}" suffix to name 2026/03/31 04:48:14 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1/subdir: Connecting to FTP server 2026/03/31 04:48:14 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1/subdir: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:14 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1/subdir: > dial: conn=172.17.0.1:34676->172.17.0.4:21, err= 2026/03/31 04:48:14 DEBUG : operations.CopyFile "file1.txt" to "ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1/subdir" as "file20.txt" 2026/03/31 04:48:14 DEBUG : file1.txt: size = 19 (Local file system at /tmp/044810xu/datadir/test_basic-cuhirun9) 2026/03/31 04:48:14 DEBUG : file20.txt: size = 0 (ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1/subdir) 2026/03/31 04:48:14 DEBUG : file1.txt: Sizes differ 2026/03/31 04:48:14 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1/subdir: dial("tcp","172.17.0.4:37837") 2026/03/31 04:48:14 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1/subdir: > dial: conn=172.17.0.1:52962->172.17.0.4:37837, err= 2026/03/31 04:48:14 DEBUG : file20.txt.8dcf80ac.partial: size = 19 OK 2026/03/31 04:48:14 DEBUG : file20.txt.8dcf80ac.partial: renamed to: file20.txt 2026/03/31 04:48:14 INFO : file1.txt: Copied (replaced existing) to: file20.txt 2026/03/31 04:48:14 NOTICE: (07) : test bisync run 2026/03/31 04:48:14 NOTICE: (08) : bisync 2026/03/31 04:48:14 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:34197") 2026/03/31 04:48:14 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:48842->172.17.0.4:34197, err= 2026/03/31 04:48:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:31924") 2026/03/31 04:48:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:53920->172.17.0.4:31924, err= 2026/03/31 04:48:18 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/03/31 04:48:18 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/03/31 04:48:18 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/03/31 04:48:18 INFO : Bisyncing with Comparison Settings: { "Modtime": true, "Size": true, "Checksum": false, "HashType1": 0, "HashType2": 0, "NoSlowHash": false, "SlowHashSyncOnly": false, "SlowHashDetected": false, "DownloadHash": false } 2026/03/31 04:48:18 INFO : Synching Path1 "TestFTPPureftpd{MtW45}:rclone-test-zuwafed0zecu/044810xu/basic/path1/" with Path2 "TestFTPPureftpd{MtW45}:rclone-test-zuwafed0zecu/044810xu/basic/path2/" 2026/03/31 04:48:18 INFO : Building Path1 and Path2 listings 2026/03/31 04:48:18 INFO : Path1 checking for diffs 2026/03/31 04:48:18 INFO : - Path1 File changed: size (larger), time (newer) - subdir/file20.txt 2026/03/31 04:48:18 INFO : Path1: 1 changes:  0 new,  1 modified,  0 deleted 2026/03/31 04:48:18 INFO : (Modified:  1 newer,  0 older,  1 larger,  0 smaller) 2026/03/31 04:48:18 INFO : Path2 checking for diffs 2026/03/31 04:48:18 INFO : - Path2 File changed: size (larger), time (newer) - file1.txt 2026/03/31 04:48:18 INFO : Path2: 1 changes:  0 new,  1 modified,  0 deleted 2026/03/31 04:48:18 INFO : (Modified:  1 newer,  0 older,  1 larger,  0 smaller) 2026/03/31 04:48:18 INFO : Applying changes 2026/03/31 04:48:18 INFO : - Path1 Queue copy to Path2 - TestFTPPureftpd{MtW45}:rclone-test-zuwafed0zecu/044810xu/basic/path2/subdir/file20.txt 2026/03/31 04:48:18 INFO : - Path2 Queue copy to Path1 - TestFTPPureftpd{MtW45}:rclone-test-zuwafed0zecu/044810xu/basic/path1/file1.txt 2026/03/31 04:48:18 INFO : - Path2 Do queued copies to - Path1 2026/03/31 04:48:18 INFO : file1.txt: Copied (replaced existing) 2026/03/31 04:48:18 INFO : - Path1 Do queued copies to - Path2 2026/03/31 04:48:18 INFO : subdir/file20.txt: Copied (replaced existing) 2026/03/31 04:48:18 INFO : Updating listings 2026/03/31 04:48:18 INFO : Validating listings for Path1 "TestFTPPureftpd{MtW45}:rclone-test-zuwafed0zecu/044810xu/basic/path1/" vs Path2 "TestFTPPureftpd{MtW45}:rclone-test-zuwafed0zecu/044810xu/basic/path2/" 2026/03/31 04:48:18 INFO : Bisync successful 2026/03/31 04:48:18 DEBUG : Waiting for deletions to finish 2026/03/31 04:48:18 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:33100") 2026/03/31 04:48:18 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:39092->172.17.0.4:33100, err= 2026/03/31 04:48:18 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: Connecting to FTP server 2026/03/31 04:48:18 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: Connecting to FTP server 2026/03/31 04:48:18 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:18 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: Connecting to FTP server 2026/03/31 04:48:18 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:34438") 2026/03/31 04:48:18 INFO : file1.copy3.txt: Deleted 2026/03/31 04:48:18 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:53772->172.17.0.4:34438, err= 2026/03/31 04:48:18 INFO : file1.copy1.txt: Deleted 2026/03/31 04:48:18 INFO : RCLONE_TEST: Deleted 2026/03/31 04:48:18 INFO : file1.copy4.txt: Deleted 2026/03/31 04:48:18 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:34680->172.17.0.4:21, err= 2026/03/31 04:48:18 INFO : subdir/file20.txt: Deleted 2026/03/31 04:48:18 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:18 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:34682->172.17.0.4:21, err= 2026/03/31 04:48:18 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:19 INFO : file1.copy5.txt: Deleted 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:34688->172.17.0.4:21, err= 2026/03/31 04:48:19 INFO : file1.copy2.txt: Deleted 2026/03/31 04:48:19 INFO : file1.txt: Deleted 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:32078") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:38294->172.17.0.4:32078, err= 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: dial("tcp","172.17.0.4:30909") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: > dial: conn=172.17.0.1:39908->172.17.0.4:30909, err= 2026/03/31 04:48:19 DEBUG : removing 1 level 1 directories 2026/03/31 04:48:19 INFO : subdir: Removing directory 2026/03/31 04:48:19 DEBUG : removing 1 level 0 directories 2026/03/31 04:48:19 INFO : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: Removing directory 2026/03/31 04:48:19 DEBUG : Waiting for deletions to finish 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:38638") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:42910->172.17.0.4:38638, err= 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: Connecting to FTP server 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: Connecting to FTP server 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:34696->172.17.0.4:21, err= 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:31562") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: Connecting to FTP server 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:34800->172.17.0.4:31562, err= 2026/03/31 04:48:19 INFO : file1.txt: Deleted 2026/03/31 04:48:19 INFO : RCLONE_TEST: Deleted 2026/03/31 04:48:19 INFO : file1.copy3.txt: Deleted 2026/03/31 04:48:19 INFO : file1.copy5.txt: Deleted 2026/03/31 04:48:19 INFO : subdir/file20.txt: Deleted 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:34712->172.17.0.4:21, err= 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:34720->172.17.0.4:21, err= 2026/03/31 04:48:19 INFO : file1.copy4.txt: Deleted 2026/03/31 04:48:19 INFO : file1.copy1.txt: Deleted 2026/03/31 04:48:19 INFO : file1.copy2.txt: Deleted 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:31744") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:54126->172.17.0.4:31744, err= 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: dial("tcp","172.17.0.4:35344") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: > dial: conn=172.17.0.1:48496->172.17.0.4:35344, err= 2026/03/31 04:48:19 DEBUG : removing 1 level 1 directories 2026/03/31 04:48:19 INFO : subdir: Removing directory 2026/03/31 04:48:19 DEBUG : removing 1 level 0 directories 2026/03/31 04:48:19 INFO : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: Removing directory bisync_test.go:608: TEST basic PASSED 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: dial("tcp","172.17.0.4:32705") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: > dial: conn=172.17.0.1:51790->172.17.0.4:32705, err= 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: dial("tcp","172.17.0.4:34364") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: > dial: conn=172.17.0.1:37948->172.17.0.4:34364, err= 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: Connecting to FTP server 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: Connecting to FTP server 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: > dial: conn=172.17.0.1:34722->172.17.0.4:21, err= 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: dial("tcp","172.17.0.4:35095") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: > dial: conn=172.17.0.1:58334->172.17.0.4:35095, err= 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: > dial: conn=172.17.0.1:34738->172.17.0.4:21, err= 2026/03/31 04:48:19 DEBUG : pacer: low level retry 1/10 (error 421 50 users (the maximum) are already logged in, sorry) 2026/03/31 04:48:19 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: > dial: conn=172.17.0.1:34740->172.17.0.4:21, err= 2026/03/31 04:48:19 DEBUG : pacer: low level retry 2/10 (error 421 50 users (the maximum) are already logged in, sorry) 2026/03/31 04:48:19 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/03/31 04:48:19 DEBUG : pacer: Reducing sleep to 30ms 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: dial("tcp","172.17.0.4:39651") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: > dial: conn=172.17.0.1:38424->172.17.0.4:39651, err= 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: > dial: conn=172.17.0.1:34744->172.17.0.4:21, err= 2026/03/31 04:48:19 DEBUG : pacer: low level retry 3/10 (error 421 50 users (the maximum) are already logged in, sorry) 2026/03/31 04:48:19 DEBUG : pacer: Rate limited, increasing sleep to 60ms 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: > dial: conn=172.17.0.1:34754->172.17.0.4:21, err= 2026/03/31 04:48:19 DEBUG : pacer: low level retry 4/10 (error 421 50 users (the maximum) are already logged in, sorry) 2026/03/31 04:48:19 DEBUG : pacer: Rate limited, increasing sleep to 120ms 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: > dial: conn=172.17.0.1:34764->172.17.0.4:21, err= 2026/03/31 04:48:19 DEBUG : pacer: low level retry 5/10 (error 421 50 users (the maximum) are already logged in, sorry) 2026/03/31 04:48:19 DEBUG : pacer: Rate limited, increasing sleep to 240ms 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: > dial: conn=172.17.0.1:34776->172.17.0.4:21, err= 2026/03/31 04:48:19 DEBUG : pacer: low level retry 6/10 (error 421 50 users (the maximum) are already logged in, sorry) 2026/03/31 04:48:19 DEBUG : pacer: Rate limited, increasing sleep to 480ms 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:19 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: > dial: conn=172.17.0.1:34782->172.17.0.4:21, err= 2026/03/31 04:48:19 DEBUG : pacer: low level retry 7/10 (error 421 50 users (the maximum) are already logged in, sorry) 2026/03/31 04:48:19 DEBUG : pacer: Rate limited, increasing sleep to 960ms 2026/03/31 04:48:20 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:20 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: > dial: conn=172.17.0.1:34786->172.17.0.4:21, err= 2026/03/31 04:48:20 DEBUG : pacer: low level retry 8/10 (error 421 50 users (the maximum) are already logged in, sorry) 2026/03/31 04:48:20 DEBUG : pacer: Rate limited, increasing sleep to 1.92s 2026/03/31 04:48:21 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:21 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: > dial: conn=172.17.0.1:34798->172.17.0.4:21, err= 2026/03/31 04:48:21 DEBUG : pacer: low level retry 9/10 (error 421 50 users (the maximum) are already logged in, sorry) 2026/03/31 04:48:21 DEBUG : pacer: Rate limited, increasing sleep to 2s 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: dial("tcp","172.17.0.4:21") 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: > dial: conn=172.17.0.1:47958->172.17.0.4:21, err= 2026/03/31 04:48:22 DEBUG : pacer: low level retry 10/10 (error 421 50 users (the maximum) are already logged in, sorry) 2026/03/31 04:48:22 ERROR : 044810xu/path1: error listing: list: failed to make FTP connection to "172.17.0.4:21": 421 50 users (the maximum) are already logged in, sorry 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: Purge dir "044810xu/path2" 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: Purge dir "044810xu/path1" 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: Purge dir "044810xu/basic" 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: Purge dir "044810xu" 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu: Purge dir "" 2026/03/31 04:48:22 NOTICE: purge failed: list: failed to make FTP connection to "172.17.0.4:21": 421 50 users (the maximum) are already logged in, sorry --- PASS: TestBisyncRemoteRemote (12.34s) --- PASS: TestBisyncRemoteRemote/basic (8.45s) PASS 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-camedud4veye: dial("tcp","172.17.0.4:32065") 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-camedud4veye: > dial: conn=172.17.0.1:48520->172.17.0.4:32065, err= 2026/03/31 04:48:22 ERROR : error listing: directory not found 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-camedud4veye: Purge dir "" 2026/03/31 04:48:22 NOTICE: purge failed to rmdir "": directory not found 2026/03/31 04:48:22 NOTICE: purge failed: directory not found 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: closing 8 unused connections 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path1: closing 8 unused connections 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu/basic/path2: closing 8 unused connections 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/resync/path1: closing 1 unused connections 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma: closing 1 unused connections 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-zuwafed0zecu/044810xu: closing 1 unused connections 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me: closing 1 unused connections 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-mikotiz8vugo/044753me/equal/path1: closing 4 unused connections 2026/03/31 04:48:22 DEBUG : ftp://172.17.0.4:21/rclone-test-nazavet2mofu/044808ma/normalization/path2: closing 4 unused connections "./bisync.test -test.v -test.timeout 1h0m0s -remote TestFTPPureftpd: -verbose -test.run '^TestBisyncLocalRemote$/^normalization$|^TestBisyncRemoteLocal$/^(equal|resync)$|^TestBisyncRemoteRemote$/^basic$'" - Finished OK in 29.424714119s (try 2/5)