"./bisync.test -test.v -test.timeout 1h0m0s -remote TestFTPProftpd: -verbose" - Starting (try 1/5) 2026/04/30 05:40:14 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-qesajud8five" 2026/04/30 05:40:14 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/04/30 05:40:14 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE 2026/04/30 05:40:14 DEBUG : Setting host="172.17.0.4" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2026/04/30 05:40:14 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2026/04/30 05:40:14 DEBUG : Setting pass="IUkwnytnB_eUiYBvUdjCvJBRmdWclT-iwId0BhY4NK7y7g" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2026/04/30 05:40:14 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2026/04/30 05:40:14 DEBUG : TestFTPProftpd: detected overridden config - adding "{zHO13}" suffix to name 2026/04/30 05:40:14 DEBUG : Setting host="172.17.0.4" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2026/04/30 05:40:14 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2026/04/30 05:40:14 DEBUG : Setting pass="IUkwnytnB_eUiYBvUdjCvJBRmdWclT-iwId0BhY4NK7y7g" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2026/04/30 05:40:14 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-qesajud8five: Connecting to FTP server 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-qesajud8five: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-qesajud8five: > dial: conn=172.17.0.1:45570->172.17.0.4:21, err= 2026/04/30 05:40:14 DEBUG : Creating backend with remote "/tmp/rclone3918168223" === RUN TestLockfileIsExpired_UnreadableWithMaxLock 2026/04/30 05:40:14 INFO : /tmp/TestLockfileIsExpired_UnreadableWithMaxLock43000632/001/test.lck: Lock file is unreadable (decode error: invalid character 'o' in literal null (expecting 'u')) and --max-lock is set. Treating as expired. --- PASS: TestLockfileIsExpired_UnreadableWithMaxLock (0.00s) === RUN TestLockfileIsExpired_UnreadableWithoutMaxLock 2026/04/30 05:40:14 ERROR : /tmp/TestLockfileIsExpired_UnreadableWithoutMaxLock2469979493/001/test.lck: Lock file exists, but contents are unreadable. (decode error: invalid character 'o' in literal null (expecting 'u')) --- PASS: TestLockfileIsExpired_UnreadableWithoutMaxLock (0.00s) === RUN TestLockfileIsExpired_ValidExpired 2026/04/30 05:40:14 INFO : /tmp/TestLockfileIsExpired_ValidExpired2574346609/001/test.lck: Lock file found, but it expired at 2026-04-30 05:35:14.908716145 +0000 UTC. Will delete it and proceed. --- PASS: TestLockfileIsExpired_ValidExpired (0.00s) === RUN TestLockfileIsExpired_ValidNotExpired 2026/04/30 05:40:14 INFO : /tmp/TestLockfileIsExpired_ValidNotExpired398962766/001/test.lck: Valid lock file found. Expires at 2026-04-30 05:50:14.910168101 +0000 UTC. (10m0s from now) 2026/04/30 05:40:14 INFO : Lockfile info: { "Session": "test", "PID": "12345", "TimeRenewed": "2026-04-30T05:40:14.910168021Z", "TimeExpires": "2026-04-30T05:50:14.910168101Z" } --- PASS: TestLockfileIsExpired_ValidNotExpired (0.00s) === RUN TestBisyncRemoteLocal 2026/04/30 05:40:14 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-peyubav3tidu" 2026/04/30 05:40:14 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE 2026/04/30 05:40:14 DEBUG : Setting host="172.17.0.4" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2026/04/30 05:40:14 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2026/04/30 05:40:14 DEBUG : Setting pass="IUkwnytnB_eUiYBvUdjCvJBRmdWclT-iwId0BhY4NK7y7g" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2026/04/30 05:40:14 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2026/04/30 05:40:14 DEBUG : TestFTPProftpd: detected overridden config - adding "{zHO13}" suffix to name 2026/04/30 05:40:14 DEBUG : Setting host="172.17.0.4" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2026/04/30 05:40:14 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2026/04/30 05:40:14 DEBUG : Setting pass="IUkwnytnB_eUiYBvUdjCvJBRmdWclT-iwId0BhY4NK7y7g" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2026/04/30 05:40:14 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu: Connecting to FTP server 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu: > dial: conn=172.17.0.1:45574->172.17.0.4:21, err= 2026/04/30 05:40:14 NOTICE: remote: TestFTPProftpd:rclone-test-peyubav3tidu === RUN TestBisyncRemoteLocal/all_changed 2026/04/30 05:40:14 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-peyubav3tidu/054014yofizef0" 2026/04/30 05:40:14 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE 2026/04/30 05:40:14 DEBUG : Setting host="172.17.0.4" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2026/04/30 05:40:14 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2026/04/30 05:40:14 DEBUG : Setting pass="IUkwnytnB_eUiYBvUdjCvJBRmdWclT-iwId0BhY4NK7y7g" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2026/04/30 05:40:14 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2026/04/30 05:40:14 DEBUG : TestFTPProftpd: detected overridden config - adding "{zHO13}" suffix to name 2026/04/30 05:40:14 DEBUG : Setting host="172.17.0.4" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2026/04/30 05:40:14 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2026/04/30 05:40:14 DEBUG : Setting pass="IUkwnytnB_eUiYBvUdjCvJBRmdWclT-iwId0BhY4NK7y7g" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2026/04/30 05:40:14 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0: Connecting to FTP server 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0: > dial: conn=172.17.0.1:45580->172.17.0.4:21, err= 2026/04/30 05:40:14 DEBUG : fs cache: renaming cache item "TestFTPProftpd:rclone-test-peyubav3tidu/054014yofizef0" to be canonical "TestFTPProftpd{zHO13}:rclone-test-peyubav3tidu/054014yofizef0" 2026/04/30 05:40:14 INFO : path1: Making directory 2026/04/30 05:40:14 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1" 2026/04/30 05:40:14 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE 2026/04/30 05:40:14 DEBUG : Setting host="172.17.0.4" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2026/04/30 05:40:14 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2026/04/30 05:40:14 DEBUG : Setting pass="IUkwnytnB_eUiYBvUdjCvJBRmdWclT-iwId0BhY4NK7y7g" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2026/04/30 05:40:14 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2026/04/30 05:40:14 DEBUG : TestFTPProftpd: detected overridden config - adding "{zHO13}" suffix to name 2026/04/30 05:40:14 DEBUG : Setting host="172.17.0.4" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2026/04/30 05:40:14 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2026/04/30 05:40:14 DEBUG : Setting pass="IUkwnytnB_eUiYBvUdjCvJBRmdWclT-iwId0BhY4NK7y7g" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2026/04/30 05:40:14 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: Connecting to FTP server 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:45584->172.17.0.4:21, err= 2026/04/30 05:40:14 DEBUG : fs cache: renaming cache item "TestFTPProftpd:rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1" to be canonical "TestFTPProftpd{zHO13}:rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1" 2026/04/30 05:40:14 DEBUG : Creating backend with remote "/tmp/054014yofizef0" 2026/04/30 05:40:14 DEBUG : Creating backend with remote "/tmp/054014yofizef0/all_changed/path2" 2026/04/30 05:40:14 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_all_changed/initial" 2026/04/30 05:40:14 DEBUG : Creating backend with remote "/tmp/054014yofizef0/initdir/test_all_changed-mabawaz5" 2026/04/30 05:40:14 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/04/30 05:40:14 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:14 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:14 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:14 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:14 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:14 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:14 DEBUG : subdir: Making directory with metadata 2026/04/30 05:40:14 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2026/04/30 05:40:14 DEBUG : Added delayed dir = "subdir", newDst=subdir 2026/04/30 05:40:14 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:14 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/04/30 05:40:14 DEBUG : file1.copy1.txt.21b8fa2b.partial: size = 0 OK 2026/04/30 05:40:14 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/04/30 05:40:14 DEBUG : file1.copy3.txt.d0285540.partial: size = 0 OK 2026/04/30 05:40:14 DEBUG : Local file system at /tmp/054014yofizef0/initdir/test_all_changed-mabawaz5: Waiting for checks to finish 2026/04/30 05:40:14 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/30 05:40:14 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/30 05:40:14 DEBUG : file1.copy1.txt.21b8fa2b.partial: renamed to: file1.copy1.txt 2026/04/30 05:40:14 INFO : file1.copy1.txt: Copied (new) 2026/04/30 05:40:14 DEBUG : Local file system at /tmp/054014yofizef0/initdir/test_all_changed-mabawaz5: Waiting for transfers to finish 2026/04/30 05:40:14 DEBUG : file1.copy3.txt.d0285540.partial: renamed to: file1.copy3.txt 2026/04/30 05:40:14 INFO : file1.copy3.txt: Copied (new) 2026/04/30 05:40:14 DEBUG : file1.copy2.txt.455881d5.partial: size = 0 OK 2026/04/30 05:40:14 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/30 05:40:14 DEBUG : file1.copy2.txt.455881d5.partial: renamed to: file1.copy2.txt 2026/04/30 05:40:14 INFO : file1.copy2.txt: Copied (new) 2026/04/30 05:40:14 DEBUG : file1.copy4.txt.8c987629.partial: size = 0 OK 2026/04/30 05:40:14 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/30 05:40:14 DEBUG : file1.copy5.txt.19e8a2bc.partial: size = 0 OK 2026/04/30 05:40:14 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/04/30 05:40:14 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/30 05:40:14 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/30 05:40:14 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/04/30 05:40:14 INFO : file1.txt: Copied (new) 2026/04/30 05:40:14 DEBUG : file1.copy5.txt.19e8a2bc.partial: renamed to: file1.copy5.txt 2026/04/30 05:40:14 INFO : file1.copy5.txt: Copied (new) 2026/04/30 05:40:14 DEBUG : file1.copy4.txt.8c987629.partial: renamed to: file1.copy4.txt 2026/04/30 05:40:14 INFO : file1.copy4.txt: Copied (new) 2026/04/30 05:40:14 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK 2026/04/30 05:40:14 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/30 05:40:14 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2026/04/30 05:40:14 INFO : subdir/file20.txt: Copied (new) 2026/04/30 05:40:14 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/04/30 05:40:14 INFO : RCLONE_TEST: Copied (new) 2026/04/30 05:40:14 INFO : subdir: Set directory modification time (using SetModTime) 2026/04/30 05:40:14 DEBUG : Waiting for deletions to finish 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:27572") 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:38444->172.17.0.4:27572, err= 2026/04/30 05:40:14 ERROR : error listing: directory not found 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:33721") 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:56360->172.17.0.4:33721, err= 2026/04/30 05:40:14 ERROR : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: Failed to list "": directory not found 2026/04/30 05:40:14 DEBUG : removing 1 level 0 directories 2026/04/30 05:40:14 INFO : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: Removing directory 2026/04/30 05:40:14 ERROR : Failed to rmdir: directory not found 2026/04/30 05:40:14 DEBUG : Waiting for deletions to finish 2026/04/30 05:40:14 ERROR : error listing: directory not found 2026/04/30 05:40:14 ERROR : Local file system at /tmp/054014yofizef0/all_changed/path2: Failed to list "": directory not found 2026/04/30 05:40:14 DEBUG : removing 1 level 0 directories 2026/04/30 05:40:14 INFO : Local file system at /tmp/054014yofizef0/all_changed/path2: Removing directory 2026/04/30 05:40:14 ERROR : Failed to rmdir: stat /tmp/054014yofizef0/all_changed/path2: no such file or directory 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:59876") 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:49116->172.17.0.4:59876, err= 2026/04/30 05:40:14 ERROR : error listing: directory not found 2026/04/30 05:40:14 ERROR : error listing: directory not found 2026/04/30 05:40:14 NOTICE: checking initFs Local file system at /tmp/054014yofizef0/initdir/test_all_changed-mabawaz5 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:4089") 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:36220->172.17.0.4:4089, err= 2026/04/30 05:40:14 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/04/30 05:40:14 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:14 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:14 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: Connecting to FTP server 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: Connecting to FTP server 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:45598->172.17.0.4:21, err= 2026/04/30 05:40:14 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:14 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:14 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: Connecting to FTP server 2026/04/30 05:40:14 INFO : subdir: Making directory 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: Connecting to FTP server 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:37946") 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:43046->172.17.0.4:37946, err= 2026/04/30 05:40:14 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/04/30 05:40:14 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/04/30 05:40:14 INFO : RCLONE_TEST: Copied (new) 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:52309") 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:56040->172.17.0.4:52309, err= 2026/04/30 05:40:14 DEBUG : file1.copy4.txt.8c987629.partial: size = 0 OK 2026/04/30 05:40:14 DEBUG : file1.copy4.txt.8c987629.partial: renamed to: file1.copy4.txt 2026/04/30 05:40:14 INFO : file1.copy4.txt: Copied (new) 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:53010") 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:49064->172.17.0.4:53010, err= 2026/04/30 05:40:14 DEBUG : file1.copy5.txt.19e8a2bc.partial: size = 0 OK 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:45608->172.17.0.4:21, err= 2026/04/30 05:40:14 DEBUG : file1.copy5.txt.19e8a2bc.partial: renamed to: file1.copy5.txt 2026/04/30 05:40:14 INFO : file1.copy5.txt: Copied (new) 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:33874") 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:39232->172.17.0.4:33874, err= 2026/04/30 05:40:14 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/04/30 05:40:14 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/04/30 05:40:14 INFO : file1.txt: Copied (new) 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:14 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:45612->172.17.0.4:21, err= 2026/04/30 05:40:15 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:15 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:45614->172.17.0.4:21, err= 2026/04/30 05:40:15 DEBUG : pacer: low level retry 1/10 (error EOF) 2026/04/30 05:40:15 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/04/30 05:40:15 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:15 DEBUG : pacer: low level retry 1/10 (error EOF) 2026/04/30 05:40:15 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/04/30 05:40:15 DEBUG : pacer: low level retry 1/10 (error EOF) 2026/04/30 05:40:15 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2026/04/30 05:40:15 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:45628->172.17.0.4:21, err= 2026/04/30 05:40:15 DEBUG : pacer: low level retry 2/10 (error EOF) 2026/04/30 05:40:15 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2026/04/30 05:40:15 DEBUG : pacer: Reducing sleep to 120ms 2026/04/30 05:40:15 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:6982") 2026/04/30 05:40:15 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:39258->172.17.0.4:6982, err= 2026/04/30 05:40:15 DEBUG : file1.copy1.txt.21b8fa2b.partial: size = 0 OK 2026/04/30 05:40:15 DEBUG : file1.copy1.txt.21b8fa2b.partial: renamed to: file1.copy1.txt 2026/04/30 05:40:15 INFO : file1.copy1.txt: Copied (new) 2026/04/30 05:40:15 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:15 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:45642->172.17.0.4:21, err= 2026/04/30 05:40:15 DEBUG : pacer: low level retry 2/10 (error EOF) 2026/04/30 05:40:15 DEBUG : pacer: Rate limited, increasing sleep to 240ms 2026/04/30 05:40:15 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:15 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:45662->172.17.0.4:21, err= 2026/04/30 05:40:15 DEBUG : pacer: low level retry 2/10 (error EOF) 2026/04/30 05:40:15 DEBUG : pacer: Rate limited, increasing sleep to 480ms 2026/04/30 05:40:15 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:15 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:45688->172.17.0.4:21, err= 2026/04/30 05:40:15 DEBUG : pacer: low level retry 3/10 (error EOF) 2026/04/30 05:40:15 DEBUG : pacer: Rate limited, increasing sleep to 960ms 2026/04/30 05:40:16 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:16 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:45700->172.17.0.4:21, err= 2026/04/30 05:40:16 DEBUG : pacer: low level retry 3/10 (error EOF) 2026/04/30 05:40:16 DEBUG : pacer: Rate limited, increasing sleep to 1.92s 2026/04/30 05:40:16 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:16 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:45712->172.17.0.4:21, err= 2026/04/30 05:40:16 DEBUG : pacer: low level retry 3/10 (error EOF) 2026/04/30 05:40:16 DEBUG : pacer: Rate limited, increasing sleep to 2s 2026/04/30 05:40:18 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:18 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:45728->172.17.0.4:21, err= 2026/04/30 05:40:18 DEBUG : pacer: low level retry 4/10 (error EOF) 2026/04/30 05:40:20 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:20 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:45822->172.17.0.4:21, err= 2026/04/30 05:40:20 DEBUG : pacer: low level retry 4/10 (error EOF) 2026/04/30 05:40:22 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:22 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:34114->172.17.0.4:21, err= 2026/04/30 05:40:22 DEBUG : pacer: low level retry 4/10 (error EOF) 2026/04/30 05:40:24 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:24 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:34188->172.17.0.4:21, err= 2026/04/30 05:40:24 DEBUG : pacer: low level retry 5/10 (error EOF) 2026/04/30 05:40:26 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:26 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:34218->172.17.0.4:21, err= 2026/04/30 05:40:26 DEBUG : pacer: low level retry 5/10 (error EOF) 2026/04/30 05:40:28 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:28 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:34242->172.17.0.4:21, err= 2026/04/30 05:40:28 DEBUG : pacer: low level retry 5/10 (error EOF) 2026/04/30 05:40:30 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:30 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:34326->172.17.0.4:21, err= 2026/04/30 05:40:30 DEBUG : pacer: low level retry 6/10 (error EOF) 2026/04/30 05:40:32 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:32 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:60842->172.17.0.4:21, err= 2026/04/30 05:40:32 DEBUG : pacer: low level retry 6/10 (error EOF) 2026/04/30 05:40:34 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:34 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:60958->172.17.0.4:21, err= 2026/04/30 05:40:34 DEBUG : pacer: low level retry 6/10 (error EOF) 2026/04/30 05:40:36 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:36 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:60976->172.17.0.4:21, err= 2026/04/30 05:40:36 DEBUG : pacer: low level retry 7/10 (error EOF) 2026/04/30 05:40:38 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:38 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:32820->172.17.0.4:21, err= 2026/04/30 05:40:38 DEBUG : pacer: low level retry 7/10 (error EOF) 2026/04/30 05:40:40 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:40 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:32864->172.17.0.4:21, err= 2026/04/30 05:40:40 DEBUG : pacer: low level retry 7/10 (error EOF) 2026/04/30 05:40:42 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:42 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:50764->172.17.0.4:21, err= 2026/04/30 05:40:42 DEBUG : pacer: low level retry 8/10 (error EOF) 2026/04/30 05:40:44 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:44 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:50776->172.17.0.4:21, err= 2026/04/30 05:40:44 DEBUG : pacer: low level retry 8/10 (error EOF) 2026/04/30 05:40:46 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:46 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:50802->172.17.0.4:21, err= 2026/04/30 05:40:46 DEBUG : pacer: low level retry 8/10 (error EOF) 2026/04/30 05:40:48 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:48 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:50824->172.17.0.4:21, err= 2026/04/30 05:40:48 DEBUG : pacer: low level retry 9/10 (error EOF) 2026/04/30 05:40:50 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:50 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:50850->172.17.0.4:21, err= 2026/04/30 05:40:50 DEBUG : pacer: low level retry 9/10 (error EOF) 2026/04/30 05:40:52 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:52 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:46300->172.17.0.4:21, err= 2026/04/30 05:40:52 DEBUG : pacer: low level retry 9/10 (error EOF) 2026/04/30 05:40:54 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:54 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:46322->172.17.0.4:21, err= 2026/04/30 05:40:54 DEBUG : pacer: low level retry 10/10 (error EOF) 2026/04/30 05:40:54 DEBUG : file1.copy2.txt: Received error: Put mkParentDir failed: mkdir "rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1" failed: findItem: failed to make FTP connection to "172.17.0.4:21": EOF - low level retry 0/10 2026/04/30 05:40:54 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:6857") 2026/04/30 05:40:54 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:47312->172.17.0.4:6857, err= 2026/04/30 05:40:54 DEBUG : file1.copy2.txt.455881d5.partial: size = 0 OK 2026/04/30 05:40:54 DEBUG : file1.copy2.txt.455881d5.partial: renamed to: file1.copy2.txt 2026/04/30 05:40:54 INFO : file1.copy2.txt: Copied (new) 2026/04/30 05:40:56 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:56 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:46334->172.17.0.4:21, err= 2026/04/30 05:40:56 DEBUG : pacer: low level retry 10/10 (error EOF) 2026/04/30 05:40:56 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:56 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: Waiting for checks to finish 2026/04/30 05:40:56 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: Waiting for transfers to finish 2026/04/30 05:40:56 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:10480") 2026/04/30 05:40:56 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:38122->172.17.0.4:10480, err= 2026/04/30 05:40:56 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK 2026/04/30 05:40:56 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2026/04/30 05:40:56 INFO : subdir/file20.txt: Copied (new) 2026/04/30 05:40:58 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:40:58 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:46352->172.17.0.4:21, err= 2026/04/30 05:40:58 DEBUG : pacer: low level retry 10/10 (error EOF) 2026/04/30 05:40:58 DEBUG : file1.copy3.txt: Received error: Put mkParentDir failed: mkdir "rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1" failed: findItem: failed to make FTP connection to "172.17.0.4:21": EOF - low level retry 0/10 2026/04/30 05:40:58 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:26335") 2026/04/30 05:40:58 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:52502->172.17.0.4:26335, err= 2026/04/30 05:40:58 DEBUG : file1.copy3.txt.d0285540.partial: size = 0 OK 2026/04/30 05:40:58 DEBUG : file1.copy3.txt.d0285540.partial: renamed to: file1.copy3.txt 2026/04/30 05:40:58 INFO : file1.copy3.txt: Copied (new) bisync_test.go:2015: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:2015 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:508 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:407 Error: Received unexpected error: mkdir "rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1/subdir" failed: findItem: failed to make FTP connection to "172.17.0.4:21": EOF Test: TestBisyncRemoteLocal/all_changed Messages: setting up path1 2026/04/30 05:40:58 NOTICE: checking Path1 ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1 2026/04/30 05:40:58 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:63299") 2026/04/30 05:40:58 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:46346->172.17.0.4:63299, err= 2026/04/30 05:40:58 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:4144") 2026/04/30 05:40:58 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:46098->172.17.0.4:4144, err= 2026/04/30 05:40:58 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination 2026/04/30 05:40:58 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:58 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:58 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:58 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:58 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:58 DEBUG : file1.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:58 DEBUG : subdir: Making directory with metadata 2026/04/30 05:40:58 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z) 2026/04/30 05:40:58 DEBUG : Added delayed dir = "subdir", newDst=subdir 2026/04/30 05:40:58 DEBUG : file1.copy1.txt.21b8fa2b.partial: size = 0 OK 2026/04/30 05:40:58 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination 2026/04/30 05:40:58 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK 2026/04/30 05:40:58 DEBUG : Local file system at /tmp/054014yofizef0/all_changed/path2: Waiting for checks to finish 2026/04/30 05:40:58 DEBUG : Local file system at /tmp/054014yofizef0/all_changed/path2: Waiting for transfers to finish 2026/04/30 05:40:58 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK 2026/04/30 05:40:58 DEBUG : file1.copy3.txt.d0285540.partial: size = 0 OK 2026/04/30 05:40:58 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST 2026/04/30 05:40:58 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/30 05:40:58 INFO : RCLONE_TEST: Copied (new) 2026/04/30 05:40:58 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/30 05:40:58 DEBUG : file1.copy3.txt.d0285540.partial: renamed to: file1.copy3.txt 2026/04/30 05:40:58 INFO : file1.copy3.txt: Copied (new) 2026/04/30 05:40:58 DEBUG : file1.copy1.txt.21b8fa2b.partial: renamed to: file1.copy1.txt 2026/04/30 05:40:58 INFO : file1.copy1.txt: Copied (new) 2026/04/30 05:40:58 DEBUG : file1.copy2.txt.455881d5.partial: size = 0 OK 2026/04/30 05:40:58 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/30 05:40:58 DEBUG : file1.txt.56d0d699.partial: size = 0 OK 2026/04/30 05:40:58 DEBUG : file1.copy5.txt.19e8a2bc.partial: size = 0 OK 2026/04/30 05:40:58 DEBUG : file1.copy2.txt.455881d5.partial: renamed to: file1.copy2.txt 2026/04/30 05:40:58 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/30 05:40:58 INFO : file1.copy2.txt: Copied (new) 2026/04/30 05:40:58 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/30 05:40:58 DEBUG : file1.copy5.txt.19e8a2bc.partial: renamed to: file1.copy5.txt 2026/04/30 05:40:58 INFO : file1.copy5.txt: Copied (new) 2026/04/30 05:40:58 DEBUG : file1.copy4.txt.8c987629.partial: size = 0 OK 2026/04/30 05:40:58 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/30 05:40:58 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK 2026/04/30 05:40:58 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK 2026/04/30 05:40:58 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt 2026/04/30 05:40:58 INFO : subdir/file20.txt: Copied (new) 2026/04/30 05:40:58 DEBUG : file1.copy4.txt.8c987629.partial: renamed to: file1.copy4.txt 2026/04/30 05:40:58 INFO : file1.copy4.txt: Copied (new) 2026/04/30 05:40:58 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt 2026/04/30 05:40:58 INFO : file1.txt: Copied (new) 2026/04/30 05:40:58 INFO : subdir: Set directory modification time (using SetModTime) 2026/04/30 05:40:58 NOTICE: checking path2 Local file system at /tmp/054014yofizef0/all_changed/path2 2026/04/30 05:40:58 NOTICE: (01) : test all-changed 2026/04/30 05:40:58 NOTICE: (02) : test initial bisync 2026/04/30 05:40:58 NOTICE: (03) : bisync resync 2026/04/30 05:40:58 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:7955") 2026/04/30 05:40:58 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:38486->172.17.0.4:7955, err= 2026/04/30 05:41:00 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: Skipping jamDirTimes as remote does not support DirSetModTime or MkdirMetadata 2026/04/30 05:41:00 INFO : subdir: Set directory modification time (using SetModTime) 2026/04/30 05:41:00 INFO : Setting --ignore-listing-checksum as neither --checksum nor --compare checksum are set. 2026/04/30 05:41: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/04/30 05:41:00 INFO : Synching Path1 "TestFTPProftpd{zHO13}:rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1/" with Path2 "/tmp/054014yofizef0/all_changed/path2/" 2026/04/30 05:41:00 INFO : Copying Path2 files to Path1 2026/04/30 05:41:00 INFO : - Path2 Resync is copying files to - Path1 2026/04/30 05:41:00 INFO : There was nothing to transfer 2026/04/30 05:41:00 INFO : - Path1 Resync is copying files to - Path2 2026/04/30 05:41:00 INFO : subdir: Set directory modification time (using SetModTime) 2026/04/30 05:41:00 INFO : There was nothing to transfer 2026/04/30 05:41:00 INFO : Resync updating listings 2026/04/30 05:41:00 INFO : Validating listings for Path1 "TestFTPProftpd{zHO13}:rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1/" vs Path2 "/tmp/054014yofizef0/all_changed/path2/" 2026/04/30 05:41:00 INFO : Bisync successful 2026/04/30 05:41:00 NOTICE: (04) : test change timestamp on all files except RCLONE_TEST 2026/04/30 05:41:00 NOTICE: (05) : touch-glob 2005-01-02 TestFTPProftpd,encoding='Asterisk,Ctl,Dot,Slash',host='172.17.0.4',pass='IUkwnytnB_eUiYBvUdjCvJBRmdWclT-iwId0BhY4NK7y7g',user='rclone':rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1/ file* 2026/04/30 05:41:00 DEBUG : Creating backend with remote "TestFTPProftpd,encoding='Asterisk,Ctl,Dot,Slash',host='172.17.0.4',pass='IUkwnytnB_eUiYBvUdjCvJBRmdWclT-iwId0BhY4NK7y7g',user='rclone':rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1/" 2026/04/30 05:41:00 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE 2026/04/30 05:41:00 DEBUG : TestFTPProftpd: detected overridden config - adding "{zHO13}" suffix to name 2026/04/30 05:41:00 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: Connecting to FTP server 2026/04/30 05:41:00 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:00 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:46376->172.17.0.4:21, err= 2026/04/30 05:41:00 DEBUG : pacer: low level retry 1/10 (error EOF) 2026/04/30 05:41:00 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/04/30 05:41:00 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:00 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:46380->172.17.0.4:21, err= 2026/04/30 05:41:00 DEBUG : pacer: low level retry 2/10 (error EOF) 2026/04/30 05:41:00 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/04/30 05:41:00 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:00 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:46388->172.17.0.4:21, err= 2026/04/30 05:41:00 DEBUG : pacer: low level retry 3/10 (error EOF) 2026/04/30 05:41:00 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2026/04/30 05:41:01 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:01 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:46396->172.17.0.4:21, err= 2026/04/30 05:41:01 DEBUG : pacer: low level retry 4/10 (error EOF) 2026/04/30 05:41:01 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2026/04/30 05:41:01 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:01 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:46410->172.17.0.4:21, err= 2026/04/30 05:41:01 DEBUG : pacer: low level retry 5/10 (error EOF) 2026/04/30 05:41:01 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2026/04/30 05:41:01 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:01 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:46414->172.17.0.4:21, err= 2026/04/30 05:41:01 DEBUG : pacer: low level retry 6/10 (error EOF) 2026/04/30 05:41:01 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2026/04/30 05:41:01 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:01 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:51816->172.17.0.4:21, err= 2026/04/30 05:41:01 DEBUG : pacer: low level retry 7/10 (error EOF) 2026/04/30 05:41:01 DEBUG : pacer: Rate limited, increasing sleep to 1.28s 2026/04/30 05:41:02 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:02 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:51822->172.17.0.4:21, err= 2026/04/30 05:41:02 DEBUG : pacer: low level retry 8/10 (error EOF) 2026/04/30 05:41:02 DEBUG : pacer: Rate limited, increasing sleep to 2s 2026/04/30 05:41:03 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:03 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:51852->172.17.0.4:21, err= 2026/04/30 05:41:03 DEBUG : pacer: low level retry 9/10 (error EOF) 2026/04/30 05:41:05 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:05 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/all_changed/path1: > dial: conn=172.17.0.1:51876->172.17.0.4:21, err= 2026/04/30 05:41:05 DEBUG : pacer: low level retry 10/10 (error EOF) bisync_test.go:545: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:545 /usr/local/go/src/strings/iter.go:54 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:527 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:407 Error: test step failed Test: TestBisyncRemoteLocal/all_changed Messages: step 5 failed: NewFs: failed to make FTP connection to "172.17.0.4:21": EOF === RUN TestBisyncRemoteLocal/backupdir 2026/04/30 05:41:05 DEBUG : fs cache: switching user supplied name "TestFTPProftpd:rclone-test-peyubav3tidu/054014yofizef0" for canonical name "TestFTPProftpd{zHO13}:rclone-test-peyubav3tidu/054014yofizef0" 2026/04/30 05:41:05 INFO : path1: Making directory 2026/04/30 05:41:05 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1" 2026/04/30 05:41:05 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE 2026/04/30 05:41:05 DEBUG : Setting host="172.17.0.4" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2026/04/30 05:41:05 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2026/04/30 05:41:05 DEBUG : Setting pass="IUkwnytnB_eUiYBvUdjCvJBRmdWclT-iwId0BhY4NK7y7g" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2026/04/30 05:41:05 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2026/04/30 05:41:05 DEBUG : TestFTPProftpd: detected overridden config - adding "{zHO13}" suffix to name 2026/04/30 05:41:05 DEBUG : Setting host="172.17.0.4" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2026/04/30 05:41:05 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2026/04/30 05:41:05 DEBUG : Setting pass="IUkwnytnB_eUiYBvUdjCvJBRmdWclT-iwId0BhY4NK7y7g" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2026/04/30 05:41:05 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2026/04/30 05:41:05 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: Connecting to FTP server 2026/04/30 05:41:05 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:05 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: > dial: conn=172.17.0.1:51892->172.17.0.4:21, err= 2026/04/30 05:41:05 DEBUG : pacer: low level retry 1/10 (error EOF) 2026/04/30 05:41:05 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/04/30 05:41:05 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:05 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: > dial: conn=172.17.0.1:51902->172.17.0.4:21, err= 2026/04/30 05:41:05 DEBUG : pacer: low level retry 2/10 (error EOF) 2026/04/30 05:41:05 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2026/04/30 05:41:05 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:05 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: > dial: conn=172.17.0.1:51906->172.17.0.4:21, err= 2026/04/30 05:41:05 DEBUG : pacer: low level retry 3/10 (error EOF) 2026/04/30 05:41:05 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2026/04/30 05:41:05 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:05 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: > dial: conn=172.17.0.1:51910->172.17.0.4:21, err= 2026/04/30 05:41:05 DEBUG : pacer: low level retry 4/10 (error EOF) 2026/04/30 05:41:05 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2026/04/30 05:41:05 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:05 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: > dial: conn=172.17.0.1:51914->172.17.0.4:21, err= 2026/04/30 05:41:05 DEBUG : pacer: low level retry 5/10 (error EOF) 2026/04/30 05:41:05 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2026/04/30 05:41:05 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:05 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: > dial: conn=172.17.0.1:51918->172.17.0.4:21, err= 2026/04/30 05:41:05 DEBUG : pacer: low level retry 6/10 (error EOF) 2026/04/30 05:41:05 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2026/04/30 05:41:06 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:06 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: > dial: conn=172.17.0.1:51924->172.17.0.4:21, err= 2026/04/30 05:41:06 DEBUG : pacer: low level retry 7/10 (error EOF) 2026/04/30 05:41:06 DEBUG : pacer: Rate limited, increasing sleep to 1.28s 2026/04/30 05:41:06 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:06 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: > dial: conn=172.17.0.1:51928->172.17.0.4:21, err= 2026/04/30 05:41:06 DEBUG : pacer: low level retry 8/10 (error EOF) 2026/04/30 05:41:06 DEBUG : pacer: Rate limited, increasing sleep to 2s 2026/04/30 05:41:08 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:08 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: > dial: conn=172.17.0.1:51952->172.17.0.4:21, err= 2026/04/30 05:41:08 DEBUG : pacer: low level retry 9/10 (error EOF) 2026/04/30 05:41:10 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: dial("tcp","172.17.0.4:21") 2026/04/30 05:41:10 DEBUG : ftp://172.17.0.4:21/rclone-test-peyubav3tidu/054014yofizef0/backupdir/path1: > dial: conn=172.17.0.1:51968->172.17.0.4:21, err= 2026/04/30 05:41:10 DEBUG : pacer: low level retry 10/10 (error EOF) bisync_test.go:2015: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:2015 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:648 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:434 /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:407 Error: Received unexpected error: NewFs: failed to make FTP connection to "172.17.0.4:21": EOF Test: TestBisyncRemoteLocal/backupdir Messages: parsing remote/subdir TestFTPProftpd:rclone-test-peyubav3tidu/054014yofizef0/path1 --- FAIL: TestBisyncRemoteLocal (55.16s) --- FAIL: TestBisyncRemoteLocal/all_changed (50.59s) --- FAIL: TestBisyncRemoteLocal/backupdir (4.56s) panic: runtime error: invalid memory address or nil pointer dereference [recovered, repanicked] [signal SIGSEGV: segmentation violation code=0x1 addr=0x28 pc=0xb15b9c] goroutine 381 [running]: testing.tRunner.func1.2({0x25646c0, 0x4697760}) /usr/local/go/src/testing/testing.go:1974 +0x232 testing.tRunner.func1() /usr/local/go/src/testing/testing.go:1977 +0x349 panic({0x25646c0?, 0x4697760?}) /usr/local/go/src/runtime/panic.go:860 +0x13a github.com/rclone/rclone/cmd/bisync/bilib.FsPath({0x0, 0x0}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bilib/canonical.go:18 +0x1c github.com/rclone/rclone/cmd/bisync_test.(*bisyncTest).makeTempRemote(0x29f924ae81c0, {0x2c53ac0, 0x29f924595200}, {0x29f924b9def0, 0x27}, {0x2a68cf4, 0x5}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:649 +0x698 github.com/rclone/rclone/cmd/bisync_test.(*bisyncTest).runTestCase(0x29f924ae81c0, {0x2c53ac0, 0x29f924595200}, 0x29f9249f86c8?, {0x29f9249968d5?, 0x9?}) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:434 +0xa9 github.com/rclone/rclone/cmd/bisync_test.testBisync.func4(0x29f9249f86c8) /home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:407 +0x265 testing.tRunner(0x29f9249f86c8, 0x29f924cdf260) /usr/local/go/src/testing/testing.go:2036 +0xea created by testing.(*T).Run in goroutine 72 /usr/local/go/src/testing/testing.go:2101 +0x4c5 "./bisync.test -test.v -test.timeout 1h0m0s -remote TestFTPProftpd: -verbose" - Finished ERROR in 55.395713243s (try 1/5): exit status 2: Failed [TestBisyncRemoteLocal/all_changed TestBisyncRemoteLocal/backupdir]