"./sync.test -test.v -test.timeout 1h0m0s -remote TestFTPProftpd: -verbose -test.run '^(TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs|TestServerSideMoveWithFilter|TestSyncOverlap|TestSyncOverlapWithFilter)$'" - Starting (try 2/5) 2025/03/24 01:01:30 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-gesofoj1rewi" 2025/03/24 01:01:30 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/03/24 01:01:30 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE 2025/03/24 01:01:30 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:30 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:30 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:30 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:30 DEBUG : TestFTPProftpd: detected overridden config - adding "{N5Xgg}" suffix to name 2025/03/24 01:01:30 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:30 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:30 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:30 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: Connecting to FTP server 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 DEBUG : Creating backend with remote "/tmp/rclone758894800" === RUN TestServerSideMove run.go:180: Remote "ftp://172.17.0.3:21/rclone-test-gesofoj1rewi", Local "Local file system at /tmp/rclone758894800", Modify Window "1s" 2025/03/24 01:01:30 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-bibituv7moji" 2025/03/24 01:01:30 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE 2025/03/24 01:01:30 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:30 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:30 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:30 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:30 DEBUG : TestFTPProftpd: detected overridden config - adding "{N5Xgg}" suffix to name 2025/03/24 01:01:30 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:30 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:30 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:30 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: Connecting to FTP server 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:23230") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:4668") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:15306") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:4364") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= sync_test.go:1705: Server side move (if possible) ftp://172.17.0.3:21/rclone-test-gesofoj1rewi -> ftp://172.17.0.3:21/rclone-test-bibituv7moji 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: dial("tcp","172.17.0.3:17823") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: dial("tcp","172.17.0.3:20351") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: dial("tcp","172.17.0.3:60959") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: Using server-side directory move 2025/03/24 01:01:30 INFO : ftp://172.17.0.3:21/rclone-test-bibituv7moji: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: dial("tcp","172.17.0.3:46594") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:21760") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/24 01:01:30 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1s) 2025/03/24 01:01:30 DEBUG : empty space: Unchanged skipping 2025/03/24 01:01:30 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: Waiting for checks to finish 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: Connecting to FTP server 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 INFO : empty space: Deleted 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: Waiting for transfers to finish 2025/03/24 01:01:30 INFO : potato2: Moved (server-side) 2025/03/24 01:01:30 INFO : potato3: Deleted 2025/03/24 01:01:30 INFO : potato3: Moved (server-side) 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:5289") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: dial("tcp","172.17.0.3:34103") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-hegibiy3suse" 2025/03/24 01:01:30 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE 2025/03/24 01:01:30 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:30 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:30 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:30 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:30 DEBUG : TestFTPProftpd: detected overridden config - adding "{N5Xgg}" suffix to name 2025/03/24 01:01:30 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:30 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:30 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:30 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-hegibiy3suse: Connecting to FTP server 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-hegibiy3suse: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-hegibiy3suse: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-hegibiy3suse: Using server-side directory move 2025/03/24 01:01:30 INFO : ftp://172.17.0.3:21/rclone-test-hegibiy3suse: Server side directory move succeeded 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-hegibiy3suse: dial("tcp","172.17.0.3:27170") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-hegibiy3suse: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: dial("tcp","172.17.0.3:11693") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 ERROR : : error listing: directory not found 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-hegibiy3suse: dial("tcp","172.17.0.3:37985") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-hegibiy3suse: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-hegibiy3suse: Purge object "empty space" 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-hegibiy3suse: Purge object "potato2" 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-hegibiy3suse: Purge object "potato3" 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-hegibiy3suse: Purge dir "" 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: dial("tcp","172.17.0.3:33310") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 ERROR : : error listing: directory not found 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-bibituv7moji: Purge dir "" 2025/03/24 01:01:30 NOTICE: purge failed to rmdir "": directory not found 2025/03/24 01:01:30 NOTICE: purge failed: directory not found 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:30709") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:8041") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= --- PASS: TestServerSideMove (0.19s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "ftp://172.17.0.3:21/rclone-test-gesofoj1rewi", Local "Local file system at /tmp/rclone758894800", Modify Window "1s" 2025/03/24 01:01:30 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-konosog1kosa" 2025/03/24 01:01:30 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE 2025/03/24 01:01:30 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:30 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:30 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:30 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:30 DEBUG : TestFTPProftpd: detected overridden config - adding "{N5Xgg}" suffix to name 2025/03/24 01:01:30 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:30 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:30 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:30 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: Connecting to FTP server 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:30 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:9448") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:55078") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:58054") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:55420") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= sync_test.go:1705: Server side move (if possible) ftp://172.17.0.3:21/rclone-test-gesofoj1rewi -> ftp://172.17.0.3:21/rclone-test-konosog1kosa 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: dial("tcp","172.17.0.3:59384") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: dial("tcp","172.17.0.3:26876") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: dial("tcp","172.17.0.3:57218") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: dial("tcp","172.17.0.3:64876") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:56257") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : empty space: Excluded (Size Filter) 2025/03/24 01:01:31 DEBUG : empty space: Excluded 2025/03/24 01:01:31 DEBUG : empty space: Excluded (Size Filter) 2025/03/24 01:01:31 DEBUG : empty space: Excluded 2025/03/24 01:01:31 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/24 01:01:31 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: Waiting for checks to finish 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: Connecting to FTP server 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: Waiting for transfers to finish 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 INFO : potato2: Moved (server-side) 2025/03/24 01:01:31 INFO : potato3: Deleted 2025/03/24 01:01:31 INFO : potato3: Moved (server-side) 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:45282") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: dial("tcp","172.17.0.3:41140") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-zepoxec1qura" 2025/03/24 01:01:31 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE 2025/03/24 01:01:31 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:31 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:31 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:31 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:31 DEBUG : TestFTPProftpd: detected overridden config - adding "{N5Xgg}" suffix to name 2025/03/24 01:01:31 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:31 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:31 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:31 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: Connecting to FTP server 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: dial("tcp","172.17.0.3:37726") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: dial("tcp","172.17.0.3:5703") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : empty space: Excluded (Size Filter) 2025/03/24 01:01:31 DEBUG : empty space: Excluded 2025/03/24 01:01:31 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/24 01:01:31 DEBUG : potato3: Need to transfer - File not found at Destination 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: Waiting for checks to finish 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: Connecting to FTP server 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: Waiting for transfers to finish 2025/03/24 01:01:31 INFO : potato2: Moved (server-side) 2025/03/24 01:01:31 INFO : potato3: Moved (server-side) 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: dial("tcp","172.17.0.3:35525") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: dial("tcp","172.17.0.3:46577") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: dial("tcp","172.17.0.3:46699") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: Purge object "potato2" 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: Purge object "potato3" 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-zepoxec1qura: Purge dir "" 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: dial("tcp","172.17.0.3:54017") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: Purge object "empty space" 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-konosog1kosa: Purge dir "" 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:2256") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:51990") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= --- PASS: TestServerSideMoveWithFilter (0.26s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "ftp://172.17.0.3:21/rclone-test-gesofoj1rewi", Local "Local file system at /tmp/rclone758894800", Modify Window "1s" 2025/03/24 01:01:31 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-foyihux1humo" 2025/03/24 01:01:31 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE 2025/03/24 01:01:31 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:31 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:31 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:31 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:31 DEBUG : TestFTPProftpd: detected overridden config - adding "{N5Xgg}" suffix to name 2025/03/24 01:01:31 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:31 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:31 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:31 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: Connecting to FTP server 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:21635") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:36529") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:40759") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 INFO : tomatoDir: Making directory 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:63721") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:59824") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= sync_test.go:1705: Server side move (if possible) ftp://172.17.0.3:21/rclone-test-gesofoj1rewi -> ftp://172.17.0.3:21/rclone-test-foyihux1humo 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: dial("tcp","172.17.0.3:24209") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: dial("tcp","172.17.0.3:3073") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: dial("tcp","172.17.0.3:9595") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: Using server-side directory move 2025/03/24 01:01:31 INFO : ftp://172.17.0.3:21/rclone-test-foyihux1humo: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: dial("tcp","172.17.0.3:23659") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:32210") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:55589") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1s) 2025/03/24 01:01:31 DEBUG : empty space: Unchanged skipping 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: Connecting to FTP server 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:31 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: Connecting to FTP server 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 INFO : potato2: Moved (server-side) 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: Waiting for checks to finish 2025/03/24 01:01:31 INFO : potato3: Deleted 2025/03/24 01:01:31 INFO : potato3: Moved (server-side) 2025/03/24 01:01:31 INFO : empty space: Deleted 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: Waiting for transfers to finish 2025/03/24 01:01:31 INFO : tomatoDir: Removing directory 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: deleted 1 directories 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:47513") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:46318") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: dial("tcp","172.17.0.3:28003") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-nufuyoj7cemu" 2025/03/24 01:01:31 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE 2025/03/24 01:01:31 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:31 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:31 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:31 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:31 DEBUG : TestFTPProftpd: detected overridden config - adding "{N5Xgg}" suffix to name 2025/03/24 01:01:31 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:31 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:31 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:31 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: Connecting to FTP server 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 INFO : tomatoDir: Making directory 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: Using server-side directory move 2025/03/24 01:01:31 INFO : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: Server side directory move succeeded 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: dial("tcp","172.17.0.3:33354") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: dial("tcp","172.17.0.3:7438") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: dial("tcp","172.17.0.3:62090") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 ERROR : : error listing: directory not found 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: dial("tcp","172.17.0.3:56456") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 ERROR : : error listing: directory not found 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: dial("tcp","172.17.0.3:46855") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: Purge object "empty space" 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: Purge object "potato2" 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: Purge object "potato3" 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: dial("tcp","172.17.0.3:27987") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: Purge dir "tomatoDir" 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-nufuyoj7cemu: Purge dir "" 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: dial("tcp","172.17.0.3:45806") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 ERROR : : error listing: directory not found 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-foyihux1humo: Purge dir "" 2025/03/24 01:01:31 NOTICE: purge failed to rmdir "": directory not found 2025/03/24 01:01:31 NOTICE: purge failed: directory not found 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:35288") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:7090") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= --- PASS: TestServerSideMoveDeleteEmptySourceDirs (0.19s) === RUN TestSyncOverlap run.go:180: Remote "ftp://172.17.0.3:21/rclone-test-gesofoj1rewi", Local "Local file system at /tmp/rclone758894800", Modify Window "1s" 2025/03/24 01:01:31 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-gesofoj1rewi/rclone-sync-test" 2025/03/24 01:01:31 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE 2025/03/24 01:01:31 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:31 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:31 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:31 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:31 DEBUG : TestFTPProftpd: detected overridden config - adding "{N5Xgg}" suffix to name 2025/03/24 01:01:31 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:31 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:31 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:31 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: Connecting to FTP server 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : pacer: low level retry 1/10 (error EOF) 2025/03/24 01:01:31 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : pacer: low level retry 2/10 (error EOF) 2025/03/24 01:01:31 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : pacer: low level retry 3/10 (error EOF) 2025/03/24 01:01:31 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : pacer: low level retry 4/10 (error EOF) 2025/03/24 01:01:31 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : pacer: low level retry 5/10 (error EOF) 2025/03/24 01:01:31 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:31 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:31 DEBUG : pacer: low level retry 6/10 (error EOF) 2025/03/24 01:01:31 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2025/03/24 01:01:32 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:32 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:32 DEBUG : pacer: low level retry 7/10 (error EOF) 2025/03/24 01:01:32 DEBUG : pacer: Rate limited, increasing sleep to 1.28s 2025/03/24 01:01:32 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:32 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:32 DEBUG : pacer: low level retry 8/10 (error EOF) 2025/03/24 01:01:32 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/03/24 01:01:33 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:33 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:33 DEBUG : pacer: low level retry 9/10 (error EOF) 2025/03/24 01:01:35 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:35 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:35 DEBUG : pacer: low level retry 10/10 (error EOF) sync_test.go:1945: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1945 Error: Received unexpected error: NewFs: failed to make FTP connection to "172.17.0.3:21": EOF Test: TestSyncOverlap 2025/03/24 01:01:35 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:44991") 2025/03/24 01:01:35 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:35 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:44908") 2025/03/24 01:01:35 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= --- FAIL: TestSyncOverlap (4.57s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "ftp://172.17.0.3:21/rclone-test-gesofoj1rewi", Local "Local file system at /tmp/rclone758894800", Modify Window "1s" 2025/03/24 01:01:35 DEBUG : Creating backend with remote "TestFTPProftpd:rclone-test-gesofoj1rewi/rclone-sync-test" 2025/03/24 01:01:35 DEBUG : Setting type="ftp" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_TYPE 2025/03/24 01:01:35 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:35 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:35 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:35 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:35 DEBUG : TestFTPProftpd: detected overridden config - adding "{N5Xgg}" suffix to name 2025/03/24 01:01:35 DEBUG : Setting host="172.17.0.3" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_HOST 2025/03/24 01:01:35 DEBUG : Setting user="rclone" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_USER 2025/03/24 01:01:35 DEBUG : Setting pass="EUHOTljuNwgHICWBDfW9DTg-NAfh0cZYWIujdM3etaD_Qw" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_PASS 2025/03/24 01:01:35 DEBUG : Setting encoding="Asterisk,Ctl,Dot,Slash" for "TestFTPProftpd" from environment variable RCLONE_CONFIG_TESTFTPPROFTPD_ENCODING 2025/03/24 01:01:35 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: Connecting to FTP server 2025/03/24 01:01:35 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:35 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:35 DEBUG : pacer: low level retry 1/10 (error EOF) 2025/03/24 01:01:35 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2025/03/24 01:01:35 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:35 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:35 DEBUG : pacer: low level retry 2/10 (error EOF) 2025/03/24 01:01:35 DEBUG : pacer: Rate limited, increasing sleep to 40ms 2025/03/24 01:01:36 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:36 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:36 DEBUG : pacer: low level retry 3/10 (error EOF) 2025/03/24 01:01:36 DEBUG : pacer: Rate limited, increasing sleep to 80ms 2025/03/24 01:01:36 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:36 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:36 DEBUG : pacer: low level retry 4/10 (error EOF) 2025/03/24 01:01:36 DEBUG : pacer: Rate limited, increasing sleep to 160ms 2025/03/24 01:01:36 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:36 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:36 DEBUG : pacer: low level retry 5/10 (error EOF) 2025/03/24 01:01:36 DEBUG : pacer: Rate limited, increasing sleep to 320ms 2025/03/24 01:01:36 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:36 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:36 DEBUG : pacer: low level retry 6/10 (error EOF) 2025/03/24 01:01:36 DEBUG : pacer: Rate limited, increasing sleep to 640ms 2025/03/24 01:01:36 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:36 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:36 DEBUG : pacer: low level retry 7/10 (error EOF) 2025/03/24 01:01:36 DEBUG : pacer: Rate limited, increasing sleep to 1.28s 2025/03/24 01:01:37 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:37 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:37 DEBUG : pacer: low level retry 8/10 (error EOF) 2025/03/24 01:01:37 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/03/24 01:01:38 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:38 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:38 DEBUG : pacer: low level retry 9/10 (error EOF) 2025/03/24 01:01:40 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: dial("tcp","172.17.0.3:21") 2025/03/24 01:01:40 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi/rclone-sync-test: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:40 DEBUG : pacer: low level retry 10/10 (error EOF) 2025/03/24 01:01:40 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:35731") 2025/03/24 01:01:40 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= 2025/03/24 01:01:40 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: dial("tcp","172.17.0.3:62682") 2025/03/24 01:01:40 DEBUG : ftp://172.17.0.3:21/rclone-test-gesofoj1rewi: > dial: conn=*fshttp.timeoutConn, err= --- FAIL: TestSyncOverlapWithFilter (4.57s) panic: runtime error: invalid memory address or nil pointer dereference [recovered] panic: runtime error: invalid memory address or nil pointer dereference [signal SIGSEGV: segmentation violation code=0x1 addr=0x30 pc=0x1e8d57e] goroutine 580 [running]: testing.tRunner.func1.2({0x2162500, 0x3c731e0}) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/testing/testing.go:1632 +0x230 testing.tRunner.func1() /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/testing/testing.go:1635 +0x35e panic({0x2162500?, 0x3c731e0?}) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/runtime/panic.go:785 +0x132 github.com/rclone/rclone/fs/sync.TestSyncOverlapWithFilter(0xc0005a0b60) /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1981 +0x1de testing.tRunner(0xc0005a0b60, 0x270ece8) /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/testing/testing.go:1690 +0xf4 created by testing.(*T).Run in goroutine 1 /home/rclone/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.0.linux-amd64/src/testing/testing.go:1743 +0x390 "./sync.test -test.v -test.timeout 1h0m0s -remote TestFTPProftpd: -verbose -test.run '^(TestServerSideMove|TestServerSideMoveDeleteEmptySourceDirs|TestServerSideMoveWithFilter|TestSyncOverlap|TestSyncOverlapWithFilter)$'" - Finished ERROR in 9.910451762s (try 2/5): exit status 2: Failed [TestSyncOverlap TestSyncOverlapWithFilter]