"./sync.test -test.v -test.timeout 1h0m0s -remote TestFTPPureftpd: -verbose -test.run '^(TestServerSideMoveDeleteEmptySourceDirs|TestServerSideMoveWithFilter|TestSyncIgnoreErrors)$'" - Starting (try 2/5) 2025/08/16 01:22:15 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-povuzoq3fata" 2025/08/16 01:22:15 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/08/16 01:22:15 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2025/08/16 01:22:15 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2025/08/16 01:22:15 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2025/08/16 01:22:15 DEBUG : Setting pass="ReMZIIXnoiIJnYfiSH9ZBBKpErVv_6rt05TqGNzvAXE" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2025/08/16 01:22:15 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2025/08/16 01:22:15 DEBUG : TestFTPPureftpd: detected overridden config - adding "{1lujX}" suffix to name 2025/08/16 01:22:15 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2025/08/16 01:22:15 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2025/08/16 01:22:15 DEBUG : Setting pass="ReMZIIXnoiIJnYfiSH9ZBBKpErVv_6rt05TqGNzvAXE" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2025/08/16 01:22:15 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: Connecting to FTP server 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:21") 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:34748->172.17.0.4:21, err= 2025/08/16 01:22:15 DEBUG : Creating backend with remote "/tmp/rclone1918295062" === RUN TestSyncIgnoreErrors run.go:180: Remote "ftp://172.17.0.4:21/rclone-test-povuzoq3fata", Local "Local file system at /tmp/rclone1918295062", Modify Window "1s" 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:33918") 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:55656->172.17.0.4:33918, err= 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:36936") 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:47434->172.17.0.4:36936, err= 2025/08/16 01:22:15 INFO : d: Making directory 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:35699") 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:54892->172.17.0.4:35699, err= 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: Connecting to FTP server 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:21") 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: Connecting to FTP server 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:34754->172.17.0.4:21, err= 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:37351") 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:46706->172.17.0.4:37351, err= 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:21") 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:34770->172.17.0.4:21, err= 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:35512") 2025/08/16 01:22:15 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:60986->172.17.0.4:35512, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:35579") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:33472->172.17.0.4:35579, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:38886") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:34990->172.17.0.4:38886, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:37837") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:35272") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:51250->172.17.0.4:37837, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:51514->172.17.0.4:35272, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:36508") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:55384->172.17.0.4:36508, err= 2025/08/16 01:22:16 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/08/16 01:22:16 DEBUG : c/non empty space: Size and modification time the same (differ by -123.456789ms, within tolerance 1s) 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: Waiting for checks to finish 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:36852") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:40192->172.17.0.4:36852, err= 2025/08/16 01:22:16 DEBUG : c/non empty space: Unchanged skipping 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: Waiting for transfers to finish 2025/08/16 01:22:16 DEBUG : a/potato2.94a2530c.partial: renamed to: a/potato2 2025/08/16 01:22:16 INFO : a/potato2: Copied (new) 2025/08/16 01:22:16 DEBUG : Waiting for deletions to finish 2025/08/16 01:22:16 INFO : b/potato: Deleted 2025/08/16 01:22:16 INFO : d: Removing directory 2025/08/16 01:22:16 INFO : b: Removing directory 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: deleted 2 directories 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:34176") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:45720->172.17.0.4:34176, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:31238") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:59540->172.17.0.4:31238, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:33549") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:60040->172.17.0.4:33549, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:32434") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:39288->172.17.0.4:32434, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:39543") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:41332->172.17.0.4:39543, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:30088") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:36544->172.17.0.4:30088, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:38613") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:56252->172.17.0.4:38613, err= --- PASS: TestSyncIgnoreErrors (0.08s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "ftp://172.17.0.4:21/rclone-test-povuzoq3fata", Local "Local file system at /tmp/rclone1918295062", Modify Window "1s" 2025/08/16 01:22:16 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-fahucoj6rapa" 2025/08/16 01:22:16 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2025/08/16 01:22:16 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2025/08/16 01:22:16 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2025/08/16 01:22:16 DEBUG : Setting pass="ReMZIIXnoiIJnYfiSH9ZBBKpErVv_6rt05TqGNzvAXE" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2025/08/16 01:22:16 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2025/08/16 01:22:16 DEBUG : TestFTPPureftpd: detected overridden config - adding "{1lujX}" suffix to name 2025/08/16 01:22:16 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2025/08/16 01:22:16 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2025/08/16 01:22:16 DEBUG : Setting pass="ReMZIIXnoiIJnYfiSH9ZBBKpErVv_6rt05TqGNzvAXE" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2025/08/16 01:22:16 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: Connecting to FTP server 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: dial("tcp","172.17.0.4:21") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: > dial: conn=172.17.0.1:34772->172.17.0.4:21, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:37395") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:35838->172.17.0.4:37395, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:39256") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:33890->172.17.0.4:39256, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:37904") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:53848->172.17.0.4:37904, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:32203") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:53960->172.17.0.4:32203, err= sync_test.go:1735: Server side move (if possible) ftp://172.17.0.4:21/rclone-test-povuzoq3fata -> ftp://172.17.0.4:21/rclone-test-fahucoj6rapa 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: dial("tcp","172.17.0.4:30954") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: > dial: conn=172.17.0.1:37494->172.17.0.4:30954, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: dial("tcp","172.17.0.4:34907") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: > dial: conn=172.17.0.1:60018->172.17.0.4:34907, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: dial("tcp","172.17.0.4:35948") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: > dial: conn=172.17.0.1:47182->172.17.0.4:35948, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: dial("tcp","172.17.0.4:34977") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: > dial: conn=172.17.0.1:56028->172.17.0.4:34977, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:36819") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:45114->172.17.0.4:36819, err= 2025/08/16 01:22:16 DEBUG : empty space: Excluded (Size Filter) 2025/08/16 01:22:16 DEBUG : empty space: Excluded 2025/08/16 01:22:16 DEBUG : empty space: Excluded (Size Filter) 2025/08/16 01:22:16 DEBUG : empty space: Excluded 2025/08/16 01:22:16 DEBUG : potato2: Need to transfer - File not found at Destination 2025/08/16 01:22:16 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: Connecting to FTP server 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: dial("tcp","172.17.0.4:21") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: > dial: conn=172.17.0.1:34788->172.17.0.4:21, err= 2025/08/16 01:22:16 INFO : potato2: Moved (server-side) 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: Waiting for checks to finish 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: Waiting for transfers to finish 2025/08/16 01:22:16 INFO : potato3: Deleted 2025/08/16 01:22:16 INFO : potato3: Moved (server-side) 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:37509") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:51948->172.17.0.4:37509, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: dial("tcp","172.17.0.4:39294") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: > dial: conn=172.17.0.1:56076->172.17.0.4:39294, err= 2025/08/16 01:22:16 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-viwimuz3wexo" 2025/08/16 01:22:16 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2025/08/16 01:22:16 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2025/08/16 01:22:16 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2025/08/16 01:22:16 DEBUG : Setting pass="ReMZIIXnoiIJnYfiSH9ZBBKpErVv_6rt05TqGNzvAXE" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2025/08/16 01:22:16 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2025/08/16 01:22:16 DEBUG : TestFTPPureftpd: detected overridden config - adding "{1lujX}" suffix to name 2025/08/16 01:22:16 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2025/08/16 01:22:16 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2025/08/16 01:22:16 DEBUG : Setting pass="ReMZIIXnoiIJnYfiSH9ZBBKpErVv_6rt05TqGNzvAXE" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2025/08/16 01:22:16 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: Connecting to FTP server 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: dial("tcp","172.17.0.4:21") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: > dial: conn=172.17.0.1:34804->172.17.0.4:21, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: dial("tcp","172.17.0.4:37295") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: > dial: conn=172.17.0.1:37608->172.17.0.4:37295, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: dial("tcp","172.17.0.4:34915") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: > dial: conn=172.17.0.1:56230->172.17.0.4:34915, err= 2025/08/16 01:22:16 DEBUG : empty space: Excluded (Size Filter) 2025/08/16 01:22:16 DEBUG : empty space: Excluded 2025/08/16 01:22:16 DEBUG : potato2: Need to transfer - File not found at Destination 2025/08/16 01:22:16 DEBUG : potato3: Need to transfer - File not found at Destination 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: Waiting for checks to finish 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: Waiting for transfers to finish 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: Connecting to FTP server 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: dial("tcp","172.17.0.4:21") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: > dial: conn=172.17.0.1:34810->172.17.0.4:21, err= 2025/08/16 01:22:16 INFO : potato2: Moved (server-side) 2025/08/16 01:22:16 INFO : potato3: Moved (server-side) 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: dial("tcp","172.17.0.4:33831") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: > dial: conn=172.17.0.1:49722->172.17.0.4:33831, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: dial("tcp","172.17.0.4:38213") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: > dial: conn=172.17.0.1:58510->172.17.0.4:38213, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: dial("tcp","172.17.0.4:39271") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: > dial: conn=172.17.0.1:33862->172.17.0.4:39271, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: Purge object "potato2" 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: Purge object "potato3" 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-viwimuz3wexo: Purge dir "" 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: dial("tcp","172.17.0.4:39549") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: > dial: conn=172.17.0.1:46742->172.17.0.4:39549, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: Purge object "empty space" 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-fahucoj6rapa: Purge dir "" 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:32821") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:39254->172.17.0.4:32821, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:32475") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:40302->172.17.0.4:32475, err= --- PASS: TestServerSideMoveWithFilter (0.11s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "ftp://172.17.0.4:21/rclone-test-povuzoq3fata", Local "Local file system at /tmp/rclone1918295062", Modify Window "1s" 2025/08/16 01:22:16 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-nizesed5kece" 2025/08/16 01:22:16 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2025/08/16 01:22:16 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2025/08/16 01:22:16 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2025/08/16 01:22:16 DEBUG : Setting pass="ReMZIIXnoiIJnYfiSH9ZBBKpErVv_6rt05TqGNzvAXE" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2025/08/16 01:22:16 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2025/08/16 01:22:16 DEBUG : TestFTPPureftpd: detected overridden config - adding "{1lujX}" suffix to name 2025/08/16 01:22:16 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2025/08/16 01:22:16 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2025/08/16 01:22:16 DEBUG : Setting pass="ReMZIIXnoiIJnYfiSH9ZBBKpErVv_6rt05TqGNzvAXE" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2025/08/16 01:22:16 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: Connecting to FTP server 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: dial("tcp","172.17.0.4:21") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: > dial: conn=172.17.0.1:34814->172.17.0.4:21, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:36042") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:40166->172.17.0.4:36042, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:32718") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:46362->172.17.0.4:32718, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:39323") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:51108->172.17.0.4:39323, err= 2025/08/16 01:22:16 INFO : tomatoDir: Making directory 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:36142") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:45348->172.17.0.4:36142, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:33457") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:48766->172.17.0.4:33457, err= sync_test.go:1735: Server side move (if possible) ftp://172.17.0.4:21/rclone-test-povuzoq3fata -> ftp://172.17.0.4:21/rclone-test-nizesed5kece 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: dial("tcp","172.17.0.4:37966") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: > dial: conn=172.17.0.1:35806->172.17.0.4:37966, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: dial("tcp","172.17.0.4:32189") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: > dial: conn=172.17.0.1:43380->172.17.0.4:32189, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: dial("tcp","172.17.0.4:33560") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: > dial: conn=172.17.0.1:33036->172.17.0.4:33560, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: Using server-side directory move 2025/08/16 01:22:16 INFO : ftp://172.17.0.4:21/rclone-test-nizesed5kece: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: dial("tcp","172.17.0.4:38622") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:33203") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: > dial: conn=172.17.0.1:33208->172.17.0.4:38622, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:42800->172.17.0.4:33203, err= 2025/08/16 01:22:16 DEBUG : potato2: Need to transfer - File not found at Destination 2025/08/16 01:22:16 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1s) 2025/08/16 01:22:16 DEBUG : empty space: Unchanged skipping 2025/08/16 01:22:16 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: Connecting to FTP server 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: dial("tcp","172.17.0.4:21") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:34051") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: > dial: conn=172.17.0.1:34820->172.17.0.4:21, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:59996->172.17.0.4:34051, err= 2025/08/16 01:22:16 INFO : empty space: Deleted 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: Waiting for checks to finish 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: Waiting for transfers to finish 2025/08/16 01:22:16 INFO : potato2: Moved (server-side) 2025/08/16 01:22:16 INFO : potato3: Deleted 2025/08/16 01:22:16 INFO : potato3: Moved (server-side) 2025/08/16 01:22:16 INFO : tomatoDir: Removing directory 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: deleted 1 directories 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:31953") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:39192->172.17.0.4:31953, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:33390") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:57342->172.17.0.4:33390, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: dial("tcp","172.17.0.4:31030") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: > dial: conn=172.17.0.1:39858->172.17.0.4:31030, err= 2025/08/16 01:22:16 DEBUG : Creating backend with remote "TestFTPPureftpd:rclone-test-zequwig3keze" 2025/08/16 01:22:16 DEBUG : Setting type="ftp" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_TYPE 2025/08/16 01:22:16 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2025/08/16 01:22:16 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2025/08/16 01:22:16 DEBUG : Setting pass="ReMZIIXnoiIJnYfiSH9ZBBKpErVv_6rt05TqGNzvAXE" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2025/08/16 01:22:16 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2025/08/16 01:22:16 DEBUG : TestFTPPureftpd: detected overridden config - adding "{1lujX}" suffix to name 2025/08/16 01:22:16 DEBUG : Setting host="172.17.0.4" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_HOST 2025/08/16 01:22:16 DEBUG : Setting user="rclone" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_USER 2025/08/16 01:22:16 DEBUG : Setting pass="ReMZIIXnoiIJnYfiSH9ZBBKpErVv_6rt05TqGNzvAXE" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_PASS 2025/08/16 01:22:16 DEBUG : Setting encoding="BackSlash,Ctl,Del,Dot,RightSpace,Slash,SquareBracket" for "TestFTPPureftpd" from environment variable RCLONE_CONFIG_TESTFTPPUREFTPD_ENCODING 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: Connecting to FTP server 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: dial("tcp","172.17.0.4:21") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: > dial: conn=172.17.0.1:34830->172.17.0.4:21, err= 2025/08/16 01:22:16 INFO : tomatoDir: Making directory 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: Using server-side directory move 2025/08/16 01:22:16 INFO : ftp://172.17.0.4:21/rclone-test-zequwig3keze: Server side directory move succeeded 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: dial("tcp","172.17.0.4:34057") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: > dial: conn=172.17.0.1:34774->172.17.0.4:34057, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: dial("tcp","172.17.0.4:36851") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: > dial: conn=172.17.0.1:53604->172.17.0.4:36851, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: dial("tcp","172.17.0.4:34738") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: > dial: conn=172.17.0.1:56882->172.17.0.4:34738, err= 2025/08/16 01:22:16 ERROR : error listing: directory not found 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: dial("tcp","172.17.0.4:33244") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: > dial: conn=172.17.0.1:51388->172.17.0.4:33244, err= 2025/08/16 01:22:16 ERROR : error listing: directory not found 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: dial("tcp","172.17.0.4:37277") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: > dial: conn=172.17.0.1:41840->172.17.0.4:37277, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: Purge object "empty space" 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: Purge object "potato2" 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: Purge object "potato3" 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: dial("tcp","172.17.0.4:38559") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: > dial: conn=172.17.0.1:41282->172.17.0.4:38559, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: Purge dir "tomatoDir" 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-zequwig3keze: Purge dir "" 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: dial("tcp","172.17.0.4:30299") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: > dial: conn=172.17.0.1:60950->172.17.0.4:30299, err= 2025/08/16 01:22:16 ERROR : error listing: directory not found 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-nizesed5kece: Purge dir "" 2025/08/16 01:22:16 NOTICE: purge failed to rmdir "": directory not found 2025/08/16 01:22:16 NOTICE: purge failed: directory not found 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:38975") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:45986->172.17.0.4:38975, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:32380") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:40464->172.17.0.4:32380, err= --- PASS: TestServerSideMoveDeleteEmptySourceDirs (0.10s) PASS 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: dial("tcp","172.17.0.4:37883") 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: > dial: conn=172.17.0.1:46360->172.17.0.4:37883, err= 2025/08/16 01:22:16 DEBUG : ftp://172.17.0.4:21/rclone-test-povuzoq3fata: Purge dir "" "./sync.test -test.v -test.timeout 1h0m0s -remote TestFTPPureftpd: -verbose -test.run '^(TestServerSideMoveDeleteEmptySourceDirs|TestServerSideMoveWithFilter|TestSyncIgnoreErrors)$'" - Finished OK in 352.998453ms (try 2/5)