"./bisync.test -test.v -test.timeout 1h0m0s -remote TestFTPProftpd: -verbose -test.run '^TestBisyncRemoteLocal$/^check_sync$'" - Starting (try 2/5)
2025/03/25 03:43:08 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-xofakuv5nori"
2025/03/25 03:43:08 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/25 03:43:08 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE
2025/03/25 03:43:08 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST
2025/03/25 03:43:08 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER
2025/03/25 03:43:08 DEBUG : Setting pass="1pnWvJMGSeMzVjE0Y2tH6oHhL9hfLa9vOb3P4ea_9c8waw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS
2025/03/25 03:43:08 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING
2025/03/25 03:43:08 DEBUG : TestFTPProftpd: detected overridden config - adding "{c0p9p}" suffix to name
2025/03/25 03:43:08 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST
2025/03/25 03:43:08 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER
2025/03/25 03:43:08 DEBUG : Setting pass="1pnWvJMGSeMzVjE0Y2tH6oHhL9hfLa9vOb3P4ea_9c8waw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS
2025/03/25 03:43:08 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-xofakuv5nori: Connecting to FTP server
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-xofakuv5nori: dial("tcp","172.17.0.3:21")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-xofakuv5nori: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : Creating backend with remote "/tmp/rclone1875249687"
=== RUN TestBisyncRemoteLocal
2025/03/25 03:43:08 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-pinedax2zequ"
2025/03/25 03:43:08 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE
2025/03/25 03:43:08 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST
2025/03/25 03:43:08 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER
2025/03/25 03:43:08 DEBUG : Setting pass="1pnWvJMGSeMzVjE0Y2tH6oHhL9hfLa9vOb3P4ea_9c8waw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS
2025/03/25 03:43:08 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING
2025/03/25 03:43:08 DEBUG : TestFTPProftpd: detected overridden config - adding "{c0p9p}" suffix to name
2025/03/25 03:43:08 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST
2025/03/25 03:43:08 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER
2025/03/25 03:43:08 DEBUG : Setting pass="1pnWvJMGSeMzVjE0Y2tH6oHhL9hfLa9vOb3P4ea_9c8waw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS
2025/03/25 03:43:08 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: Connecting to FTP server
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: dial("tcp","172.17.0.3:21")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 NOTICE: remote: TestFTPProftpd:rclone-test-pinedax2zequ
=== RUN TestBisyncRemoteLocal/check_sync
2025/03/25 03:43:08 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-pinedax2zequ/034308fa"
2025/03/25 03:43:08 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/03/25 03:43:08 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE
2025/03/25 03:43:08 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST
2025/03/25 03:43:08 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER
2025/03/25 03:43:08 DEBUG : Setting pass="1pnWvJMGSeMzVjE0Y2tH6oHhL9hfLa9vOb3P4ea_9c8waw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS
2025/03/25 03:43:08 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING
2025/03/25 03:43:08 DEBUG : TestFTPProftpd: detected overridden config - adding "{c0p9p}" suffix to name
2025/03/25 03:43:08 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST
2025/03/25 03:43:08 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER
2025/03/25 03:43:08 DEBUG : Setting pass="1pnWvJMGSeMzVjE0Y2tH6oHhL9hfLa9vOb3P4ea_9c8waw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS
2025/03/25 03:43:08 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa: Connecting to FTP server
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa: dial("tcp","172.17.0.3:21")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : fs cache: renaming cache item "TestFTPProftpd:rclone-test-pinedax2zequ/034308fa" to be canonical "TestFTPProftpd{c0p9p}:rclone-test-pinedax2zequ/034308fa"
2025/03/25 03:43:08 INFO : path1: Making directory
2025/03/25 03:43:08 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-pinedax2zequ/034308fa/check_sync/path1"
2025/03/25 03:43:08 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE
2025/03/25 03:43:08 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST
2025/03/25 03:43:08 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER
2025/03/25 03:43:08 DEBUG : Setting pass="1pnWvJMGSeMzVjE0Y2tH6oHhL9hfLa9vOb3P4ea_9c8waw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS
2025/03/25 03:43:08 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING
2025/03/25 03:43:08 DEBUG : TestFTPProftpd: detected overridden config - adding "{c0p9p}" suffix to name
2025/03/25 03:43:08 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST
2025/03/25 03:43:08 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER
2025/03/25 03:43:08 DEBUG : Setting pass="1pnWvJMGSeMzVjE0Y2tH6oHhL9hfLa9vOb3P4ea_9c8waw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS
2025/03/25 03:43:08 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: Connecting to FTP server
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: dial("tcp","172.17.0.3:21")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : fs cache: renaming cache item "TestFTPProftpd:rclone-test-pinedax2zequ/034308fa/check_sync/path1" to be canonical "TestFTPProftpd{c0p9p}:rclone-test-pinedax2zequ/034308fa/check_sync/path1"
2025/03/25 03:43:08 DEBUG : Creating backend with remote "/tmp/034308fa"
2025/03/25 03:43:08 DEBUG : Creating backend with remote "/tmp/034308fa/check_sync/path2"
2025/03/25 03:43:08 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_sync/initial"
2025/03/25 03:43:08 DEBUG : Creating backend with remote "/tmp/034308fa/initdir/test_check_sync-foyapan2"
2025/03/25 03:43:08 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/03/25 03:43:08 DEBUG : file5.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file8.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/03/25 03:43:08 DEBUG : Local file system at /tmp/034308fa/initdir/test_check_sync-foyapan2: Waiting for checks to finish
2025/03/25 03:43:08 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST
2025/03/25 03:43:08 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/03/25 03:43:08 INFO : RCLONE_TEST: Copied (new)
2025/03/25 03:43:08 DEBUG : file3.txt.5028a97.partial: renamed to: file3.txt
2025/03/25 03:43:08 INFO : file3.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : Local file system at /tmp/034308fa/initdir/test_check_sync-foyapan2: Waiting for transfers to finish
2025/03/25 03:43:08 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/03/25 03:43:08 DEBUG : file4.txt.5028a97.partial: renamed to: file4.txt
2025/03/25 03:43:08 INFO : file4.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/03/25 03:43:08 DEBUG : file5.txt.5028a97.partial: renamed to: file5.txt
2025/03/25 03:43:08 INFO : file5.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/03/25 03:43:08 DEBUG : file6.txt.5028a97.partial: renamed to: file6.txt
2025/03/25 03:43:08 INFO : file6.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/03/25 03:43:08 DEBUG : file7.txt.5028a97.partial: renamed to: file7.txt
2025/03/25 03:43:08 INFO : file7.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/03/25 03:43:08 DEBUG : file8.txt.5028a97.partial: renamed to: file8.txt
2025/03/25 03:43:08 INFO : file8.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt
2025/03/25 03:43:08 INFO : file1.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/03/25 03:43:08 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt
2025/03/25 03:43:08 INFO : file2.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_check_sync/modfiles"
2025/03/25 03:43:08 DEBUG : Creating backend with remote "/tmp/034308fa/datadir/test_check_sync-waxotaj1"
2025/03/25 03:43:08 DEBUG : _testdir_path1.._testdir_path2.path1.lst: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : _testdir_path1.._testdir_path2.path2.lst: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : Local file system at /tmp/034308fa/datadir/test_check_sync-waxotaj1: Waiting for checks to finish
2025/03/25 03:43:08 DEBUG : Local file system at /tmp/034308fa/datadir/test_check_sync-waxotaj1: Waiting for transfers to finish
2025/03/25 03:43:08 DEBUG : _testdir_path1.._testdir_path2.path1.lst: md5 = fdb18e0dff6961813e12c57227d2e854 OK
2025/03/25 03:43:08 DEBUG : _testdir_path1.._testdir_path2.path1.lst.c670fe74.partial: renamed to: _testdir_path1.._testdir_path2.path1.lst
2025/03/25 03:43:08 INFO : _testdir_path1.._testdir_path2.path1.lst: Copied (new)
2025/03/25 03:43:08 DEBUG : _testdir_path1.._testdir_path2.path2.lst: md5 = d6ce44a26af9c2110b1750fe88dc4b69 OK
2025/03/25 03:43:08 DEBUG : _testdir_path1.._testdir_path2.path2.lst.c670fe74.partial: renamed to: _testdir_path1.._testdir_path2.path2.lst
2025/03/25 03:43:08 INFO : _testdir_path1.._testdir_path2.path2.lst: Copied (new)
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: dial("tcp","172.17.0.3:20169")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 ERROR : : error listing: directory not found
2025/03/25 03:43:08 ERROR : : error listing: directory not found
2025/03/25 03:43:08 NOTICE: checking initFs Local file system at /tmp/034308fa/initdir/test_check_sync-foyapan2
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: dial("tcp","172.17.0.3:17498")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file5.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file8.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: Waiting for checks to finish
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: Connecting to FTP server
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: dial("tcp","172.17.0.3:21")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: Connecting to FTP server
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: Waiting for transfers to finish
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: Connecting to FTP server
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: dial("tcp","172.17.0.3:26963")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST
2025/03/25 03:43:08 INFO : RCLONE_TEST: Copied (new)
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: dial("tcp","172.17.0.3:18225")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: dial("tcp","172.17.0.3:21")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: dial("tcp","172.17.0.3:5181")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt
2025/03/25 03:43:08 INFO : file1.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: dial("tcp","172.17.0.3:57398")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : file4.txt.5028a97.partial: renamed to: file4.txt
2025/03/25 03:43:08 INFO : file4.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: dial("tcp","172.17.0.3:19943")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : file5.txt.5028a97.partial: renamed to: file5.txt
2025/03/25 03:43:08 INFO : file5.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: dial("tcp","172.17.0.3:21")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: dial("tcp","172.17.0.3:26118")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : file6.txt.5028a97.partial: renamed to: file6.txt
2025/03/25 03:43:08 INFO : file6.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : file7.txt.5028a97.partial: renamed to: file7.txt
2025/03/25 03:43:08 INFO : file7.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: dial("tcp","172.17.0.3:29968")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: dial("tcp","172.17.0.3:37853")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt
2025/03/25 03:43:08 INFO : file2.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : file8.txt.5028a97.partial: renamed to: file8.txt
2025/03/25 03:43:08 INFO : file8.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: dial("tcp","172.17.0.3:24195")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : file3.txt.5028a97.partial: renamed to: file3.txt
2025/03/25 03:43:08 INFO : file3.txt: Copied (new)
2025/03/25 03:43:08 NOTICE: checking Path1 ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: dial("tcp","172.17.0.3:22705")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/03/25 03:43:08 DEBUG : file1.txt.5028a97.partial: renamed to: file1.txt
2025/03/25 03:43:08 INFO : file1.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/03/25 03:43:08 DEBUG : file2.txt.5028a97.partial: renamed to: file2.txt
2025/03/25 03:43:08 INFO : file2.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file5.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file8.txt: Need to transfer - File not found at Destination
2025/03/25 03:43:08 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/03/25 03:43:08 DEBUG : file4.txt.5028a97.partial: renamed to: file4.txt
2025/03/25 03:43:08 INFO : file4.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/03/25 03:43:08 DEBUG : file5.txt.5028a97.partial: renamed to: file5.txt
2025/03/25 03:43:08 INFO : file5.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : Local file system at /tmp/034308fa/check_sync/path2: Waiting for checks to finish
2025/03/25 03:43:08 DEBUG : Local file system at /tmp/034308fa/check_sync/path2: Waiting for transfers to finish
2025/03/25 03:43:08 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/03/25 03:43:08 DEBUG : file7.txt.5028a97.partial: renamed to: file7.txt
2025/03/25 03:43:08 INFO : file7.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/03/25 03:43:08 DEBUG : file8.txt.5028a97.partial: renamed to: file8.txt
2025/03/25 03:43:08 INFO : file8.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/03/25 03:43:08 DEBUG : RCLONE_TEST.cf9a93ac.partial: renamed to: RCLONE_TEST
2025/03/25 03:43:08 INFO : RCLONE_TEST: Copied (new)
2025/03/25 03:43:08 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/03/25 03:43:08 DEBUG : file3.txt.5028a97.partial: renamed to: file3.txt
2025/03/25 03:43:08 INFO : file3.txt: Copied (new)
2025/03/25 03:43:08 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/03/25 03:43:08 DEBUG : file6.txt.5028a97.partial: renamed to: file6.txt
2025/03/25 03:43:08 INFO : file6.txt: Copied (new)
2025/03/25 03:43:08 NOTICE: checking path2 Local file system at /tmp/034308fa/check_sync/path2
2025/03/25 03:43:08 NOTICE: [36m(01) :[0m [34mtest check-sync[0m
2025/03/25 03:43:08 NOTICE: [36m(02) :[0m [34mtest initial bisync[0m
2025/03/25 03:43:08 NOTICE: [36m(03) :[0m [34mbisync resync[0m
2025/03/25 03:43:08 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m
2025/03/25 03:43:08 INFO : Bisyncing with Comparison Settings:
{
"Modtime": true,
"Size": true,
"Checksum": false,
"HashType1": 0,
"HashType2": 0,
"NoSlowHash": false,
"SlowHashSyncOnly": false,
"SlowHashDetected": true,
"DownloadHash": false
}
2025/03/25 03:43:08 INFO : Synching Path1 "TestFTPProftpd{c0p9p}:rclone-test-pinedax2zequ/034308fa/check_sync/path1/" with Path2 "/tmp/034308fa/check_sync/path2/"
2025/03/25 03:43:08 INFO : Copying Path2 files to Path1
2025/03/25 03:43:08 INFO : - [34mPath2[0m [35mResync is copying files to[0m - [36mPath1[0m
2025/03/25 03:43:08 INFO : - [36mPath1[0m [35mResync is copying files to[0m - [36mPath2[0m
2025/03/25 03:43:08 INFO : Resync updating listings
2025/03/25 03:43:08 INFO : Validating listings for Path1 "TestFTPProftpd{c0p9p}:rclone-test-pinedax2zequ/034308fa/check_sync/path1/" vs Path2 "/tmp/034308fa/check_sync/path2/"
2025/03/25 03:43:08 INFO : [32mBisync successful[0m
2025/03/25 03:43:08 NOTICE: [36m(04) :[0m [34mtest 1. run check-sync-only on a clean sync[0m
2025/03/25 03:43:08 NOTICE: [36m(05) :[0m [34mbisync check-sync-only[0m
2025/03/25 03:43:08 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m
2025/03/25 03:43:08 INFO : Bisyncing with Comparison Settings:
{
"Modtime": true,
"Size": true,
"Checksum": false,
"HashType1": 0,
"HashType2": 0,
"NoSlowHash": false,
"SlowHashSyncOnly": false,
"SlowHashDetected": true,
"DownloadHash": false
}
2025/03/25 03:43:08 INFO : Validating listings for Path1 "TestFTPProftpd{c0p9p}:rclone-test-pinedax2zequ/034308fa/check_sync/path1/" vs Path2 "/tmp/034308fa/check_sync/path2/"
2025/03/25 03:43:08 INFO : [32mBisync successful[0m
2025/03/25 03:43:08 NOTICE: [36m(06) :[0m [34mtest 2. inject modified listings into the workdir[0m
2025/03/25 03:43:08 NOTICE: [36m(07) :[0m [34mcopy-as /tmp/034308fa/datadir/test_check_sync-waxotaj1/_testdir_path1.._testdir_path2.path1.lst /tmp/034308fa/workdir/ TestFTPProftpd_rclone-test-pinedax2zequ_034308fa_check_sync_path1..tmp_034308fa_check_sync_path2.path1.lst[0m
2025/03/25 03:43:08 INFO : _testdir_path1.._testdir_path2.path1.lst: Copied (replaced existing) to: TestFTPProftpd_rclone-test-pinedax2zequ_034308fa_check_sync_path1..tmp_034308fa_check_sync_path2.path1.lst
2025/03/25 03:43:08 NOTICE: [36m(08) :[0m [34mcopy-as /tmp/034308fa/datadir/test_check_sync-waxotaj1/_testdir_path1.._testdir_path2.path2.lst /tmp/034308fa/workdir/ TestFTPProftpd_rclone-test-pinedax2zequ_034308fa_check_sync_path1..tmp_034308fa_check_sync_path2.path2.lst[0m
2025/03/25 03:43:08 INFO : _testdir_path1.._testdir_path2.path2.lst: Copied (replaced existing) to: TestFTPProftpd_rclone-test-pinedax2zequ_034308fa_check_sync_path1..tmp_034308fa_check_sync_path2.path2.lst
2025/03/25 03:43:08 NOTICE: [36m(09) :[0m [34mtest 3. run check-sync-only on modified listings[0m
2025/03/25 03:43:08 NOTICE: [36m(10) :[0m [34mbisync check-sync-only[0m
2025/03/25 03:43:08 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m
2025/03/25 03:43:08 INFO : Bisyncing with Comparison Settings:
{
"Modtime": true,
"Size": true,
"Checksum": false,
"HashType1": 0,
"HashType2": 0,
"NoSlowHash": false,
"SlowHashSyncOnly": false,
"SlowHashDetected": true,
"DownloadHash": false
}
2025/03/25 03:43:08 INFO : Validating listings for Path1 "TestFTPProftpd{c0p9p}:rclone-test-pinedax2zequ/034308fa/check_sync/path1/" vs Path2 "/tmp/034308fa/check_sync/path2/"
2025/03/25 03:43:08 ERROR : - [34m[0m [35mPath1 file not found in Path2[0m - [36mfile2.txt[0m
2025/03/25 03:43:08 ERROR : - [34m[0m [35mPath2 file not found in Path1[0m - [36mfile1.txt[0m
2025/03/25 03:43:08 ERROR : [31mBisync critical error: path1 and path2 are out of sync, run --resync to recover[0m
2025/03/25 03:43:08 ERROR : [31mBisync aborted. Must run --resync to recover.[0m
2025/03/25 03:43:08 NOTICE: Bisync error: bisync aborted
2025/03/25 03:43:08 NOTICE: [36m(11) :[0m [34mcopy-listings check-sync-only[0m
2025/03/25 03:43:08 NOTICE: [36m(12) :[0m [34mtest 4. run normal sync to check that it aborts[0m
2025/03/25 03:43:08 NOTICE: [36m(13) :[0m [34mbisync[0m
2025/03/25 03:43:08 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m
2025/03/25 03:43:08 INFO : Bisyncing with Comparison Settings:
{
"Modtime": true,
"Size": true,
"Checksum": false,
"HashType1": 0,
"HashType2": 0,
"NoSlowHash": false,
"SlowHashSyncOnly": false,
"SlowHashDetected": true,
"DownloadHash": false
}
2025/03/25 03:43:08 INFO : Synching Path1 "TestFTPProftpd{c0p9p}:rclone-test-pinedax2zequ/034308fa/check_sync/path1/" with Path2 "/tmp/034308fa/check_sync/path2/"
2025/03/25 03:43:08 ERROR : [31mBisync critical error: cannot find prior Path1 or Path2 listings, likely due to critical error on prior run
[35mTip: here are the filenames we were looking for. Do they exist?
[0m[36mPath1: [94m/tmp/034308fa/workdir/TestFTPProftpd_rclone-test-pinedax2zequ_034308fa_check_sync_path1..tmp_034308fa_check_sync_path2.path1.lst[0m
[0m[36mPath2: [94m/tmp/034308fa/workdir/TestFTPProftpd_rclone-test-pinedax2zequ_034308fa_check_sync_path1..tmp_034308fa_check_sync_path2.path2.lst[0m
[0m[35mTry running this command to inspect the work dir:
[0m[96mrclone lsl "/tmp/034308fa/workdir"[0m[0m
2025/03/25 03:43:08 ERROR : [31mBisync aborted. Must run --resync to recover.[0m
2025/03/25 03:43:08 NOTICE: Bisync error: bisync aborted
2025/03/25 03:43:08 NOTICE: [36m(14) :[0m [34mtest 5. prune failure listings after critical abort[0m
2025/03/25 03:43:08 NOTICE: [36m(15) :[0m [34mdelete-glob /tmp/034308fa/workdir/ *.lst[0m
2025/03/25 03:43:08 NOTICE: [36m(16) :[0m [34mdelete-glob /tmp/034308fa/workdir/ *.lst-err[0m
2025/03/25 03:43:08 INFO : TestFTPProftpd_rclone-test-pinedax2zequ_034308fa_check_sync_path1..tmp_034308fa_check_sync_path2.path1.lst-err: Deleted
2025/03/25 03:43:08 INFO : TestFTPProftpd_rclone-test-pinedax2zequ_034308fa_check_sync_path1..tmp_034308fa_check_sync_path2.path2.lst-err: Deleted
2025/03/25 03:43:08 NOTICE: [36m(17) :[0m [34mdelete-glob /tmp/034308fa/workdir/ *.lst-new[0m
2025/03/25 03:43:08 INFO : TestFTPProftpd_rclone-test-pinedax2zequ_034308fa_check_sync_path1..tmp_034308fa_check_sync_path2.path1.lst-new: Deleted
2025/03/25 03:43:08 INFO : TestFTPProftpd_rclone-test-pinedax2zequ_034308fa_check_sync_path1..tmp_034308fa_check_sync_path2.path2.lst-new: Deleted
2025/03/25 03:43:08 NOTICE: [36m(18) :[0m [34mtest 6. run resync[0m
2025/03/25 03:43:08 NOTICE: [36m(19) :[0m [34mbisync resync[0m
2025/03/25 03:43:08 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m
2025/03/25 03:43:08 INFO : Bisyncing with Comparison Settings:
{
"Modtime": true,
"Size": true,
"Checksum": false,
"HashType1": 0,
"HashType2": 0,
"NoSlowHash": false,
"SlowHashSyncOnly": false,
"SlowHashDetected": true,
"DownloadHash": false
}
2025/03/25 03:43:08 INFO : Synching Path1 "TestFTPProftpd{c0p9p}:rclone-test-pinedax2zequ/034308fa/check_sync/path1/" with Path2 "/tmp/034308fa/check_sync/path2/"
2025/03/25 03:43:08 INFO : Copying Path2 files to Path1
2025/03/25 03:43:08 INFO : - [34mPath2[0m [35mResync is copying files to[0m - [36mPath1[0m
2025/03/25 03:43:08 INFO : - [36mPath1[0m [35mResync is copying files to[0m - [36mPath2[0m
2025/03/25 03:43:08 INFO : Resync updating listings
2025/03/25 03:43:08 INFO : Validating listings for Path1 "TestFTPProftpd{c0p9p}:rclone-test-pinedax2zequ/034308fa/check_sync/path1/" vs Path2 "/tmp/034308fa/check_sync/path2/"
2025/03/25 03:43:08 INFO : [32mBisync successful[0m
2025/03/25 03:43:08 NOTICE: [36m(20) :[0m [34mtest 7. run normal sync with check-sync enabled (default)[0m
2025/03/25 03:43:08 NOTICE: [36m(21) :[0m [34mbisync[0m
2025/03/25 03:43:08 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m
2025/03/25 03:43:08 INFO : Bisyncing with Comparison Settings:
{
"Modtime": true,
"Size": true,
"Checksum": false,
"HashType1": 0,
"HashType2": 0,
"NoSlowHash": false,
"SlowHashSyncOnly": false,
"SlowHashDetected": true,
"DownloadHash": false
}
2025/03/25 03:43:08 INFO : Synching Path1 "TestFTPProftpd{c0p9p}:rclone-test-pinedax2zequ/034308fa/check_sync/path1/" with Path2 "/tmp/034308fa/check_sync/path2/"
2025/03/25 03:43:08 INFO : Building Path1 and Path2 listings
2025/03/25 03:43:08 INFO : Path1 checking for diffs
2025/03/25 03:43:08 INFO : Path2 checking for diffs
2025/03/25 03:43:08 INFO : No changes found
2025/03/25 03:43:08 INFO : Updating listings
2025/03/25 03:43:08 INFO : Validating listings for Path1 "TestFTPProftpd{c0p9p}:rclone-test-pinedax2zequ/034308fa/check_sync/path1/" vs Path2 "/tmp/034308fa/check_sync/path2/"
2025/03/25 03:43:08 INFO : [32mBisync successful[0m
2025/03/25 03:43:08 NOTICE: [36m(22) :[0m [34mtest 8. run normal sync with no-check-sync[0m
2025/03/25 03:43:08 NOTICE: [36m(23) :[0m [34mbisync no-check-sync[0m
2025/03/25 03:43:08 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m
2025/03/25 03:43:08 INFO : Bisyncing with Comparison Settings:
{
"Modtime": true,
"Size": true,
"Checksum": false,
"HashType1": 0,
"HashType2": 0,
"NoSlowHash": false,
"SlowHashSyncOnly": false,
"SlowHashDetected": true,
"DownloadHash": false
}
2025/03/25 03:43:08 INFO : Synching Path1 "TestFTPProftpd{c0p9p}:rclone-test-pinedax2zequ/034308fa/check_sync/path1/" with Path2 "/tmp/034308fa/check_sync/path2/"
2025/03/25 03:43:08 INFO : Building Path1 and Path2 listings
2025/03/25 03:43:08 INFO : Path1 checking for diffs
2025/03/25 03:43:08 INFO : Path2 checking for diffs
2025/03/25 03:43:08 INFO : No changes found
2025/03/25 03:43:08 INFO : Updating listings
2025/03/25 03:43:08 INFO : [32mBisync successful[0m
bisync_test.go:560: [32mTEST check_sync PASSED[0m
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: dial("tcp","172.17.0.3:55923")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: dial("tcp","172.17.0.3:40646")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: Connecting to FTP server
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: dial("tcp","172.17.0.3:21")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: dial("tcp","172.17.0.3:55704")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: dial("tcp","172.17.0.3:28540")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: Purge dir "034308fa/path1"
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: Purge dir "034308fa/check_sync"
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: Purge dir "034308fa"
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ: Purge dir ""
--- PASS: TestBisyncRemoteLocal (0.28s)
--- PASS: TestBisyncRemoteLocal/check_sync (0.25s)
PASS
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-xofakuv5nori: dial("tcp","172.17.0.3:18721")
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-xofakuv5nori: > dial: conn=*fshttp.timeoutConn, err=<nil>
2025/03/25 03:43:08 ERROR : : error listing: directory not found
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-xofakuv5nori: Purge dir ""
2025/03/25 03:43:08 NOTICE: purge failed to rmdir "": directory not found
2025/03/25 03:43:08 NOTICE: purge failed: directory not found
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa: closing 1 unused connections
2025/03/25 03:43:08 DEBUG : ftp://172.17.0.3:21/rclone-test-pinedax2zequ/034308fa/check_sync/path1: closing 4 unused connections
"./bisync.test -test.v -test.timeout 1h0m0s -remote TestFTPProftpd: -verbose -test.run '^TestBisyncRemoteLocal$/^check_sync$'" - Finished OK in 511.063296ms (try 2/5)