"./sync.test -test.v -test.timeout 1h0m0s -remote TestFTPPureftpd: -verbose -test.run '^TestServerSideMoveDeleteEmptySourceDirs$'" - Starting (try 2/5)
2026/04/21 05:34:15 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-jusemod3nepe"
2026/04/21 05:34:15 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/04/21 05:34:15 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE
2026/04/21 05:34:15 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST
2026/04/21 05:34:15 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER
2026/04/21 05:34:15 DEBUG : Setting pass="JwWM98EGUIJSX7W3e-ilDO2tjZHQ_y2obeexasiyxxA" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS
2026/04/21 05:34:15 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING
2026/04/21 05:34:15 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7XE8O}" suffix to name
2026/04/21 05:34:15 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST
2026/04/21 05:34:15 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER
2026/04/21 05:34:15 DEBUG : Setting pass="JwWM98EGUIJSX7W3e-ilDO2tjZHQ_y2obeexasiyxxA" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS
2026/04/21 05:34:15 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING
2026/04/21 05:34:15 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: Connecting to FTP server
2026/04/21 05:34:15 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: dial("tcp","172.17.0.4:21")
2026/04/21 05:34:15 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: > dial: conn=172.17.0.1:56800->172.17.0.4:21, err=<nil>
2026/04/21 05:34:17 DEBUG : Creating backend with remote "/tmp/rclone4247749649"
=== RUN   TestServerSideMoveDeleteEmptySourceDirs
    run.go:185: Remote "ftp://172.17.0.4:21/rclone-test-jusemod3nepe", Local "Local file system at /tmp/rclone4247749649", Modify Window "1s"
2026/04/21 05:34:17 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-qesogef8jigu"
2026/04/21 05:34:17 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE
2026/04/21 05:34:17 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST
2026/04/21 05:34:17 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER
2026/04/21 05:34:17 DEBUG : Setting pass="JwWM98EGUIJSX7W3e-ilDO2tjZHQ_y2obeexasiyxxA" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS
2026/04/21 05:34:17 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING
2026/04/21 05:34:17 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7XE8O}" suffix to name
2026/04/21 05:34:17 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST
2026/04/21 05:34:17 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER
2026/04/21 05:34:17 DEBUG : Setting pass="JwWM98EGUIJSX7W3e-ilDO2tjZHQ_y2obeexasiyxxA" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS
2026/04/21 05:34:17 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING
2026/04/21 05:34:17 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: Connecting to FTP server
2026/04/21 05:34:17 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: dial("tcp","172.17.0.4:21")
2026/04/21 05:34:17 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: > dial: conn=172.17.0.1:56820->172.17.0.4:21, err=<nil>
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: dial("tcp","172.17.0.4:33389")
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: > dial: conn=172.17.0.1:45004->172.17.0.4:33389, err=<nil>
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: dial("tcp","172.17.0.4:39067")
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: > dial: conn=172.17.0.1:52012->172.17.0.4:39067, err=<nil>
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: dial("tcp","172.17.0.4:34056")
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: > dial: conn=172.17.0.1:44782->172.17.0.4:34056, err=<nil>
2026/04/21 05:34:19 INFO  : tomatoDir: Making directory
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: dial("tcp","172.17.0.4:37827")
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: > dial: conn=172.17.0.1:33350->172.17.0.4:37827, err=<nil>
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: dial("tcp","172.17.0.4:34755")
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: > dial: conn=172.17.0.1:45994->172.17.0.4:34755, err=<nil>
    sync_test.go:1736: Server side move (if possible) ftp://172.17.0.4:21/rclone-test-jusemod3nepe -> ftp://172.17.0.4:21/rclone-test-qesogef8jigu
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: dial("tcp","172.17.0.4:31719")
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: > dial: conn=172.17.0.1:49000->172.17.0.4:31719, err=<nil>
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: dial("tcp","172.17.0.4:37240")
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: > dial: conn=172.17.0.1:46376->172.17.0.4:37240, err=<nil>
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: dial("tcp","172.17.0.4:38207")
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: > dial: conn=172.17.0.1:46866->172.17.0.4:38207, err=<nil>
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: Using server-side directory move
2026/04/21 05:34:19 INFO  : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: dial("tcp","172.17.0.4:39524")
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: dial("tcp","172.17.0.4:30253")
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: > dial: conn=172.17.0.1:57582->172.17.0.4:39524, err=<nil>
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: > dial: conn=172.17.0.1:45584->172.17.0.4:30253, err=<nil>
2026/04/21 05:34:19 DEBUG : potato2: Need to transfer - File not found at Destination
2026/04/21 05:34:19 DEBUG : empty space: size = 1 OK
2026/04/21 05:34:19 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1s)
2026/04/21 05:34:19 DEBUG : empty space: Unchanged skipping
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: Connecting to FTP server
2026/04/21 05:34:19 DEBUG : potato3: size = 68 (ftp://172.17.0.4:21/rclone-test-jusemod3nepe)
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: dial("tcp","172.17.0.4:21")
2026/04/21 05:34:19 DEBUG : potato3: size = 60 (ftp://172.17.0.4:21/rclone-test-qesogef8jigu)
2026/04/21 05:34:19 DEBUG : potato3: Sizes differ
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: Connecting to FTP server
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: dial("tcp","172.17.0.4:21")
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: > dial: conn=172.17.0.1:56852->172.17.0.4:21, err=<nil>
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: > dial: conn=172.17.0.1:56866->172.17.0.4:21, err=<nil>
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: dial("tcp","172.17.0.4:33971")
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: > dial: conn=172.17.0.1:49656->172.17.0.4:33971, err=<nil>
2026/04/21 05:34:19 INFO  : potato2: Moved (server-side)
2026/04/21 05:34:19 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: Waiting for checks to finish
2026/04/21 05:34:22 INFO  : empty space: Deleted
2026/04/21 05:34:22 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: Waiting for transfers to finish
2026/04/21 05:34:22 INFO  : potato3: Deleted
2026/04/21 05:34:22 INFO  : potato3: Moved (server-side)
2026/04/21 05:34:22 INFO  : tomatoDir: Removing directory
2026/04/21 05:34:22 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: deleted 1 directories
2026/04/21 05:34:22 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: dial("tcp","172.17.0.4:34296")
2026/04/21 05:34:22 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: > dial: conn=172.17.0.1:45134->172.17.0.4:34296, err=<nil>
2026/04/21 05:34:22 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: dial("tcp","172.17.0.4:33032")
2026/04/21 05:34:22 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: > dial: conn=172.17.0.1:42850->172.17.0.4:33032, err=<nil>
2026/04/21 05:34:22 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: dial("tcp","172.17.0.4:39604")
2026/04/21 05:34:22 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: > dial: conn=172.17.0.1:40462->172.17.0.4:39604, err=<nil>
2026/04/21 05:34:22 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-catuwuw3tamo"
2026/04/21 05:34:22 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE
2026/04/21 05:34:22 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST
2026/04/21 05:34:22 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER
2026/04/21 05:34:22 DEBUG : Setting pass="JwWM98EGUIJSX7W3e-ilDO2tjZHQ_y2obeexasiyxxA" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS
2026/04/21 05:34:22 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING
2026/04/21 05:34:22 DEBUG : TestFTPPureftpd: detected overridden config - adding "{7XE8O}" suffix to name
2026/04/21 05:34:22 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST
2026/04/21 05:34:22 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER
2026/04/21 05:34:22 DEBUG : Setting pass="JwWM98EGUIJSX7W3e-ilDO2tjZHQ_y2obeexasiyxxA" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS
2026/04/21 05:34:22 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING
2026/04/21 05:34:22 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: Connecting to FTP server
2026/04/21 05:34:22 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: dial("tcp","172.17.0.4:21")
2026/04/21 05:34:22 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: > dial: conn=172.17.0.1:45216->172.17.0.4:21, err=<nil>
2026/04/21 05:34:25 INFO  : tomatoDir: Making directory
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: Using server-side directory move
2026/04/21 05:34:25 INFO  : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: Server side directory move succeeded
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: dial("tcp","172.17.0.4:37590")
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: > dial: conn=172.17.0.1:35370->172.17.0.4:37590, err=<nil>
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: dial("tcp","172.17.0.4:30463")
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: > dial: conn=172.17.0.1:55090->172.17.0.4:30463, err=<nil>
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: dial("tcp","172.17.0.4:38405")
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: > dial: conn=172.17.0.1:34106->172.17.0.4:38405, err=<nil>
2026/04/21 05:34:25 ERROR : error listing: directory not found
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: dial("tcp","172.17.0.4:35521")
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: > dial: conn=172.17.0.1:54970->172.17.0.4:35521, err=<nil>
2026/04/21 05:34:25 ERROR : error listing: directory not found
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: dial("tcp","172.17.0.4:31261")
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: > dial: conn=172.17.0.1:44804->172.17.0.4:31261, err=<nil>
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: Purge object "empty space"
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: Purge object "potato2"
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: Purge object "potato3"
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: dial("tcp","172.17.0.4:34970")
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: > dial: conn=172.17.0.1:49858->172.17.0.4:34970, err=<nil>
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: Purge dir "tomatoDir"
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-catuwuw3tamo: Purge dir ""
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: dial("tcp","172.17.0.4:37168")
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: > dial: conn=172.17.0.1:49396->172.17.0.4:37168, err=<nil>
2026/04/21 05:34:25 ERROR : error listing: directory not found
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-qesogef8jigu: Purge dir ""
2026/04/21 05:34:25 NOTICE: purge failed to rmdir "": directory not found
2026/04/21 05:34:25 NOTICE: purge failed: directory not found
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: dial("tcp","172.17.0.4:32794")
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: > dial: conn=172.17.0.1:38154->172.17.0.4:32794, err=<nil>
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: dial("tcp","172.17.0.4:32601")
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: > dial: conn=172.17.0.1:57762->172.17.0.4:32601, err=<nil>
--- PASS: TestServerSideMoveDeleteEmptySourceDirs (7.62s)
PASS
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: dial("tcp","172.17.0.4:37732")
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: > dial: conn=172.17.0.1:40694->172.17.0.4:37732, err=<nil>
2026/04/21 05:34:25 DEBUG : ftp://172.17.0.4:21/rclone-test-jusemod3nepe: Purge dir ""
"./sync.test -test.v -test.timeout 1h0m0s -remote TestFTPPureftpd: -verbose -test.run '^TestServerSideMoveDeleteEmptySourceDirs$'" - Finished OK in 9.972522192s (try 2/5)