"./operations.test -test.v -test.timeout 1h0m0s -remote TestFTPRclone: -verbose -test.run '^TestIndexChangedDirTime$'" - Starting (try 4/5) 2026/09/30 02:51:10 DEBUG : Creating backend with remote "TestFTPRclone:rclone-test-cugobub4mise" 2026/09/30 02:51:10 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/09/30 02:51:10 DEBUG : Setting type=XXX for "TestFTPRclone" from environment variable RCLONE_CONFIG_TESTFTPRCLONE_TYPE 2026/09/30 02:51:10 DEBUG : Setting host=XXX for "TestFTPRclone" from environment variable RCLONE_CONFIG_TESTFTPRCLONE_HOST 2026/09/30 02:51:10 DEBUG : Setting user=XXX for "TestFTPRclone" from environment variable RCLONE_CONFIG_TESTFTPRCLONE_USER 2026/09/30 02:51:10 DEBUG : Setting port="28622" for "TestFTPRclone" from environment variable RCLONE_CONFIG_TESTFTPRCLONE_PORT 2026/09/30 02:51:10 DEBUG : Setting pass=XXX for "TestFTPRclone" from environment variable RCLONE_CONFIG_TESTFTPRCLONE_PASS 2026/09/30 02:51:10 DEBUG : TestFTPRclone: detected overridden config - adding "{C-iaI}" suffix to name 2026/09/30 02:51:10 DEBUG : Setting host=XXX for "TestFTPRclone" from environment variable RCLONE_CONFIG_TESTFTPRCLONE_HOST 2026/09/30 02:51:10 DEBUG : Setting user=XXX for "TestFTPRclone" from environment variable RCLONE_CONFIG_TESTFTPRCLONE_USER 2026/09/30 02:51:10 DEBUG : Setting pass=XXX for "TestFTPRclone" from environment variable RCLONE_CONFIG_TESTFTPRCLONE_PASS 2026/09/30 02:51:10 DEBUG : Setting port="28622" for "TestFTPRclone" from environment variable RCLONE_CONFIG_TESTFTPRCLONE_PORT 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: Connecting to FTP server 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:28622") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:55314->127.0.0.1:28622, err= 2026/09/30 02:51:10 DEBUG : Creating backend with remote "/tmp/rclone3073560318" === RUN TestIndexChangedDirTime run.go:198: Remote "ftp://127.0.0.1:28622/rclone-test-cugobub4mise", Local "Local file system at /tmp/rclone3073560318", Modify Window "876000h0m0s" 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30873") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:51900->127.0.0.1:30873, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: SetModTime is not supported 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:31664") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:40712->127.0.0.1:31664, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: SetModTime is not supported 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:31978") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:38286->127.0.0.1:31978, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: SetModTime is not supported 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:31017") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:43150->127.0.0.1:31017, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: SetModTime is not supported 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30443") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:49974->127.0.0.1:30443, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: Connecting to FTP server 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:28622") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:55326->127.0.0.1:28622, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:31166") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:57292->127.0.0.1:31166, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:31468") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30592") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:46888->127.0.0.1:31468, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:33840->127.0.0.1:30592, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: Connecting to FTP server 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: Connecting to FTP server 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30499") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30592") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:45310->127.0.0.1:30499, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:33850->127.0.0.1:30592, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: SetModTime is not supported 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: SetModTime is not supported 2026/09/30 02:51:10 DEBUG : other/index.json.30a00cb7.partial: size = 140 OK 2026/09/30 02:51:10 DEBUG : index.json.918f7b51.partial: size = 371 OK 2026/09/30 02:51:10 DEBUG : index.json.918f7b51.partial: renamed to: index.json 2026/09/30 02:51:10 INFO : index.json: Copied (new) 2026/09/30 02:51:10 DEBUG : other/index.json.30a00cb7.partial: renamed to: other/index.json 2026/09/30 02:51:10 INFO : other/index.json: Copied (new) 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:28622") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:55340->127.0.0.1:28622, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30750") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:35814->127.0.0.1:30750, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: SetModTime is not supported 2026/09/30 02:51:10 DEBUG : sub/deep/index.json.fef9fa11.partial: size = 139 OK 2026/09/30 02:51:10 DEBUG : sub/deep/index.json.fef9fa11.partial: renamed to: sub/deep/index.json 2026/09/30 02:51:10 INFO : sub/deep/index.json: Copied (new) 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:28622") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:55356->127.0.0.1:28622, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30231") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:39078->127.0.0.1:30231, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: SetModTime is not supported 2026/09/30 02:51:10 DEBUG : sub/index.json.1fb91a8c.partial: size = 255 OK 2026/09/30 02:51:10 DEBUG : sub/index.json.1fb91a8c.partial: renamed to: sub/index.json 2026/09/30 02:51:10 INFO : sub/index.json: Copied (new) 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30655") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:35596->127.0.0.1:30655, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: SetModTime is not supported 2026/09/30 02:51:10 INFO : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: Partial index: listing 3 directories and walking 0 changed directories 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30448") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:33362->127.0.0.1:30448, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30936") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:36984->127.0.0.1:30936, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30363") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:36584->127.0.0.1:30363, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30349") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:50282->127.0.0.1:30349, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30741") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:43824->127.0.0.1:30741, err= 2026/09/30 02:51:10 DEBUG : sub/index.json: Unchanged skipping 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: SetModTime is not supported 2026/09/30 02:51:10 DEBUG : sub/deep/index.json.233275cb.partial: size = 275 OK 2026/09/30 02:51:10 DEBUG : sub/deep/index.json.233275cb.partial: renamed to: sub/deep/index.json 2026/09/30 02:51:10 INFO : sub/deep/index.json: Copied (replaced existing) 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30281") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:43228->127.0.0.1:30281, err= 2026/09/30 02:51:10 DEBUG : index.json: Unchanged skipping index_test.go:540: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/index_test.go:540 Error: Not equal: expected: 3 actual : 1 Test: TestIndexChangedDirTime 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:31318") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:35850->127.0.0.1:31318, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30439") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:57480->127.0.0.1:30439, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30486") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30249") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:37012->127.0.0.1:30486, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:46212->127.0.0.1:30249, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:31053") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:48500->127.0.0.1:31053, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30811") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:48350->127.0.0.1:30811, err= --- FAIL: TestIndexChangedDirTime (0.07s) FAIL 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: dial("tcp","127.0.0.1:30368") 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: > dial: conn=127.0.0.1:48460->127.0.0.1:30368, err= 2026/09/30 02:51:10 DEBUG : ftp://127.0.0.1:28622/rclone-test-cugobub4mise: Purge dir "" "./operations.test -test.v -test.timeout 1h0m0s -remote TestFTPRclone: -verbose -test.run '^TestIndexChangedDirTime$'" - Finished ERROR in 153.924312ms (try 4/5): exit status 1: Failed [TestIndexChangedDirTime]