"go test -v -timeout 1h0m0s -remote TestFTPVsftpd: -verbose -test.run '^TestIntegration$/^FsMkdir$/^FsRootCollapse$'" - Starting (try 2/5)
=== RUN   TestIntegration
    fstests.go:438: Using remote "TestFTPVsftpd:"
2026/04/11 01:08:55 NOTICE: TestFTPVsftpd: Starting server
2026/04/11 01:08:56 NOTICE: TestFTPVsftpd: Attempting to connect to "172.17.0.7:21" try 1/100
2026/04/11 01:08:56 DEBUG : TestFTPVsftpd: Read 1, error: <nil>
2026/04/11 01:08:56 NOTICE: TestFTPVsftpd: Started server and connected to "172.17.0.7:21"
2026/04/11 01:08:56 DEBUG : Creating backend with remote "TestFTPVsftpd:rclone-test-lurigoh0pati"
2026/04/11 01:08:56 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/04/11 01:08:56 DEBUG : Setting type="ftp" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_TYPE
2026/04/11 01:08:56 DEBUG : Setting host="172.17.0.7" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_HOST
2026/04/11 01:08:56 DEBUG : Setting user="rclone" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_USER
2026/04/11 01:08:56 DEBUG : Setting pass="HCPOKr3Nrepj5jmt8ip3QcYZKMNJoVHF1Gz-9bYZoXtL" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_PASS
2026/04/11 01:08:56 DEBUG : Setting writing_mdtm="true" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_WRITING_MDTM
2026/04/11 01:08:56 DEBUG : Setting encoding="Ctl,LeftPeriod,Slash" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_ENCODING
2026/04/11 01:08:56 DEBUG : TestFTPVsftpd: detected overridden config - adding "{HoW4i}" suffix to name
2026/04/11 01:08:56 DEBUG : Setting host="172.17.0.7" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_HOST
2026/04/11 01:08:56 DEBUG : Setting user="rclone" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_USER
2026/04/11 01:08:56 DEBUG : Setting pass="HCPOKr3Nrepj5jmt8ip3QcYZKMNJoVHF1Gz-9bYZoXtL" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_PASS
2026/04/11 01:08:56 DEBUG : Setting writing_mdtm="true" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_WRITING_MDTM
2026/04/11 01:08:56 DEBUG : Setting encoding="Ctl,LeftPeriod,Slash" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_ENCODING
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: Connecting to FTP server
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:50708->172.17.0.7:21, err=<nil>
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21108")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:59114->172.17.0.7:21108, err=<nil>
2026/04/11 01:08:56 DEBUG : Setting type="ftp" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_TYPE
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21107")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:38228->172.17.0.7:21107, err=<nil>
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21104")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:36068->172.17.0.7:21104, err=<nil>
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21103")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:44276->172.17.0.7:21103, err=<nil>
=== RUN   TestIntegration/FsMkdir
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21102")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:58868->172.17.0.7:21102, err=<nil>
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21110")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:37716->172.17.0.7:21110, err=<nil>
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21110")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:37724->172.17.0.7:21110, err=<nil>
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21102")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:58872->172.17.0.7:21102, err=<nil>
=== RUN   TestIntegration/FsMkdir/FsRootCollapse
2026/04/11 01:08:56 DEBUG : Creating backend with remote "TestFTPVsftpd:rclone-test-lurigoh0pati/deeper/nonexisting/directory"
2026/04/11 01:08:56 DEBUG : Setting type="ftp" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_TYPE
2026/04/11 01:08:56 DEBUG : Setting host="172.17.0.7" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_HOST
2026/04/11 01:08:56 DEBUG : Setting user="rclone" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_USER
2026/04/11 01:08:56 DEBUG : Setting pass="HCPOKr3Nrepj5jmt8ip3QcYZKMNJoVHF1Gz-9bYZoXtL" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_PASS
2026/04/11 01:08:56 DEBUG : Setting writing_mdtm="true" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_WRITING_MDTM
2026/04/11 01:08:56 DEBUG : Setting encoding="Ctl,LeftPeriod,Slash" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_ENCODING
2026/04/11 01:08:56 DEBUG : TestFTPVsftpd: detected overridden config - adding "{HoW4i}" suffix to name
2026/04/11 01:08:56 DEBUG : Setting host="172.17.0.7" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_HOST
2026/04/11 01:08:56 DEBUG : Setting user="rclone" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_USER
2026/04/11 01:08:56 DEBUG : Setting pass="HCPOKr3Nrepj5jmt8ip3QcYZKMNJoVHF1Gz-9bYZoXtL" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_PASS
2026/04/11 01:08:56 DEBUG : Setting writing_mdtm="true" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_WRITING_MDTM
2026/04/11 01:08:56 DEBUG : Setting encoding="Ctl,LeftPeriod,Slash" for "TestFTPVsftpd" from environment variable RCLONE_CONFIG_TESTFTPVSFTPD_ENCODING
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati/deeper/nonexisting/directory: Connecting to FTP server
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati/deeper/nonexisting/directory: dial("tcp","172.17.0.7:21")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati/deeper/nonexisting/directory: > dial: conn=172.17.0.1:50724->172.17.0.7:21, err=<nil>
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati/deeper/nonexisting/directory: dial("tcp","172.17.0.7:21106")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati/deeper/nonexisting/directory: > dial: conn=172.17.0.1:45008->172.17.0.7:21106, err=<nil>
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati/deeper/nonexisting/directory: dial("tcp","172.17.0.7:21104")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati/deeper/nonexisting/directory: > dial: conn=172.17.0.1:36076->172.17.0.7:21104, err=<nil>
2026/04/11 01:08:56 DEBUG : Waiting for deletions to finish
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21108")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:59116->172.17.0.7:21108, err=<nil>
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21109")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:53980->172.17.0.7:21109, err=<nil>
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21100")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:33836->172.17.0.7:21100, err=<nil>
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21104")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:36078->172.17.0.7:21104, err=<nil>
2026/04/11 01:08:56 DEBUG : removing 1 level 0 directories
2026/04/11 01:08:56 INFO  : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: Removing directory
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21106")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:45020->172.17.0.7:21106, err=<nil>
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21106")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:45026->172.17.0.7:21106, err=<nil>
2026/04/11 01:08:56 ERROR : error listing: directory not found
2026/04/11 01:08:56 DEBUG : Waiting for deletions to finish
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21102")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:58874->172.17.0.7:21102, err=<nil>
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21103")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:44288->172.17.0.7:21103, err=<nil>
2026/04/11 01:08:56 ERROR : error listing: directory not found
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21109")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:53988->172.17.0.7:21109, err=<nil>
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: dial("tcp","172.17.0.7:21100")
2026/04/11 01:08:56 DEBUG : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: > dial: conn=172.17.0.1:33852->172.17.0.7:21100, err=<nil>
2026/04/11 01:08:56 ERROR : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: Failed to list "": directory not found
2026/04/11 01:08:56 DEBUG : removing 1 level 0 directories
2026/04/11 01:08:56 INFO  : ftp://172.17.0.7:21/rclone-test-lurigoh0pati: Removing directory
2026/04/11 01:08:56 ERROR : Failed to rmdir: directory not found
2026/04/11 01:08:56 NOTICE: TestFTPVsftpd: Stopping server
--- PASS: TestIntegration (1.10s)
    --- PASS: TestIntegration/FsMkdir (0.03s)
        --- PASS: TestIntegration/FsMkdir/FsRootCollapse (0.02s)
PASS
ok  	github.com/rclone/rclone/backend/ftp	1.120s
"go test -v -timeout 1h0m0s -remote TestFTPVsftpd: -verbose -test.run '^TestIntegration$/^FsMkdir$/^FsRootCollapse$'" - Finished OK in 1.857480941s (try 2/5)