"./bisync.test -test.v -test.timeout 2h0m0s -remote TestInternxt: -list-retries 5 -verbose -test.run '^TestBisyncRemoteLocal$/^normalization$'" - Starting (try 3/5)
2026/09/14 06:43:21 DEBUG : Creating backend with remote "TestInternxt:rclone-test-zeqopod2fija"
2026/09/14 06:43:21 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/09/14 06:43:25 DEBUG : User info: rootFolderId=2661cf64-e104-478b-b737-48c3ac8984d2, bucket=697358bf16ceabcf39af85f2
2026/09/14 06:43:25 DEBUG : Saving config "token" in section "TestInternxt" of the config file
2026/09/14 06:43:25 DEBUG : TestInternxt: Saved new token in config file
2026/09/14 06:43:25 DEBUG : Internxt root 'rclone-test-zeqopod2fija': Persisted rotated token from user info, expiry: 2026-09-21 06:43:22 +0000 UTC
2026/09/14 06:43:41 DEBUG : Creating backend with remote "/tmp/rclone1588261398"
=== RUN   TestBisyncRemoteLocal
2026/09/14 06:43:41 DEBUG : Creating backend with remote "TestInternxt:rclone-test-kovuqiy4zaha"
2026/09/14 06:43:41 DEBUG : User info: rootFolderId=2661cf64-e104-478b-b737-48c3ac8984d2, bucket=697358bf16ceabcf39af85f2
2026/09/14 06:43:41 DEBUG : Saving config "token" in section "TestInternxt" of the config file
2026/09/14 06:43:41 DEBUG : TestInternxt: Saved new token in config file
2026/09/14 06:43:41 DEBUG : Internxt root 'rclone-test-kovuqiy4zaha': Persisted rotated token from user info, expiry: 2026-09-21 06:43:41 +0000 UTC
2026/09/14 06:43:53 NOTICE: remote: TestInternxt:rclone-test-kovuqiy4zaha
=== RUN   TestBisyncRemoteLocal/normalization
2026/09/14 06:43:53 DEBUG : Creating backend with remote "TestInternxt:rclone-test-kovuqiy4zaha/064353qixumes1"
2026/09/14 06:43:58 DEBUG : User info: rootFolderId=2661cf64-e104-478b-b737-48c3ac8984d2, bucket=697358bf16ceabcf39af85f2
2026/09/14 06:43:58 DEBUG : Saving config "token" in section "TestInternxt" of the config file
2026/09/14 06:43:58 DEBUG : TestInternxt: Saved new token in config file
2026/09/14 06:43:58 DEBUG : Internxt root 'rclone-test-kovuqiy4zaha/064353qixumes1': Persisted rotated token from user info, expiry: 2026-09-21 06:43:56 +0000 UTC
2026/09/14 06:44:09 INFO  : path1: Making directory
2026/09/14 06:46:24 DEBUG : Creating backend with remote "TestInternxt:rclone-test-kovuqiy4zaha/064353qixumes1/normalization/path1"
2026/09/14 06:46:24 DEBUG : Config file has changed externally - reloading
2026/09/14 06:46:29 DEBUG : User info: rootFolderId=2661cf64-e104-478b-b737-48c3ac8984d2, bucket=697358bf16ceabcf39af85f2
2026/09/14 06:46:29 DEBUG : Saving config "token" in section "TestInternxt" of the config file
2026/09/14 06:46:29 DEBUG : TestInternxt: Saved new token in config file
2026/09/14 06:46:29 DEBUG : Internxt root 'rclone-test-kovuqiy4zaha/064353qixumes1/normalization/path1': Persisted rotated token from user info, expiry: 2026-09-21 06:46:26 +0000 UTC
2026/09/14 06:47:11 DEBUG : Creating backend with remote "/tmp/064353qixumes1"
2026/09/14 06:47:11 DEBUG : Creating backend with remote "/tmp/064353qixumes1/normalization/path2"
2026/09/14 06:47:11 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_normalization/initial"
2026/09/14 06:47:11 DEBUG : Creating backend with remote "/tmp/064353qixumes1/initdir/test_normalization-zijikih4"
2026/09/14 06:47:11 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2026/09/14 06:47:11 DEBUG : file1.txt: Need to transfer - File not found at Destination
2026/09/14 06:47:11 DEBUG : 測試_Русский_ _ _ě_áñ: Making directory with metadata
2026/09/14 06:47:11 INFO  : 測試_Русский_ _ _ě_áñ: Made directory with metadata (mtime=2024-01-25T05:00:02.874776175Z)
2026/09/14 06:47:11 DEBUG : Added delayed dir = "測試_Русский_ _ _ě_áñ", newDst=測試_Русский_ _ _ě_áñ
2026/09/14 06:47:11 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK
2026/09/14 06:47:11 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2026/09/14 06:47:11 DEBUG : file1.txt.56d0d699.partial: size = 0 OK
2026/09/14 06:47:11 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/09/14 06:47:11 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST
2026/09/14 06:47:11 INFO  : RCLONE_TEST: Copied (new)
2026/09/14 06:47:11 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt
2026/09/14 06:47:11 INFO  : file1.txt: Copied (new)
2026/09/14 06:47:11 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Need to transfer - File not found at Destination
2026/09/14 06:47:11 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Need to transfer - File not found at Destination
2026/09/14 06:47:11 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: Need to transfer - File not found at Destination
2026/09/14 06:47:11 DEBUG : Local file system at /tmp/064353qixumes1/initdir/test_normalization-zijikih4: Waiting for checks to finish
2026/09/14 06:47:11 DEBUG : Local file system at /tmp/064353qixumes1/initdir/test_normalization-zijikih4: Waiting for transfers to finish
2026/09/14 06:47:11 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file.062d4dd7.partial: size = 0 OK
2026/09/14 06:47:11 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt.b8f49a2a.partial: size = 272 OK
2026/09/14 06:47:11 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/09/14 06:47:11 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt.24b96bc5.partial: size = 272 OK
2026/09/14 06:47:11 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: md5 = 0033328434f9662a7dae0d1aee7768b6 OK
2026/09/14 06:47:11 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file.062d4dd7.partial: renamed to: 測試_Русский_ _ _ě_áñ/測試_check file
2026/09/14 06:47:11 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: md5 = 0033328434f9662a7dae0d1aee7768b6 OK
2026/09/14 06:47:11 INFO  : 測試_Русский_ _ _ě_áñ/測試_check file: Copied (new)
2026/09/14 06:47:11 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt.24b96bc5.partial: renamed to: 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt
2026/09/14 06:47:11 INFO  : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Copied (new)
2026/09/14 06:47:11 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt.b8f49a2a.partial: renamed to: 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt
2026/09/14 06:47:11 INFO  : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Copied (new)
2026/09/14 06:47:11 INFO  : 測試_Русский_ _ _ě_áñ: Set directory modification time (using SetModTime)
2026/09/14 06:47:11 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_normalization/modfiles"
2026/09/14 06:47:11 DEBUG : Creating backend with remote "/tmp/064353qixumes1/datadir/test_normalization-fozusit9"
2026/09/14 06:47:11 DEBUG : file1.txt: Need to transfer - File not found at Destination
2026/09/14 06:47:11 DEBUG : 測試_filtersfile.txt: Need to transfer - File not found at Destination
2026/09/14 06:47:11 DEBUG : Local file system at /tmp/064353qixumes1/datadir/test_normalization-fozusit9: Waiting for checks to finish
2026/09/14 06:47:11 DEBUG : Local file system at /tmp/064353qixumes1/datadir/test_normalization-fozusit9: Waiting for transfers to finish
2026/09/14 06:47:11 DEBUG : file1.txt.75b77f44.partial: size = 19 OK
2026/09/14 06:47:11 DEBUG : 測試_filtersfile.txt.3ada41b4.partial: size = 254 OK
2026/09/14 06:47:11 DEBUG : 測試_filtersfile.txt: md5 = 1cec24a8ae7c33c49693a14d53fd6a96 OK
2026/09/14 06:47:11 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK
2026/09/14 06:47:11 DEBUG : file1.txt.75b77f44.partial: renamed to: file1.txt
2026/09/14 06:47:11 INFO  : file1.txt: Copied (new)
2026/09/14 06:47:11 DEBUG : 測試_filtersfile.txt.3ada41b4.partial: renamed to: 測試_filtersfile.txt
2026/09/14 06:47:11 INFO  : 測試_filtersfile.txt: Copied (new)
2026/09/14 06:47:11 DEBUG : Waiting for deletions to finish
2026/09/14 06:47:18 ERROR : error listing: directory not found
2026/09/14 06:47:24 ERROR : Internxt root 'rclone-test-kovuqiy4zaha/064353qixumes1/normalization/path1': Failed to list "": directory not found
2026/09/14 06:47:24 DEBUG : removing 1 level 0 directories
2026/09/14 06:47:24 INFO  : Internxt root 'rclone-test-kovuqiy4zaha/064353qixumes1/normalization/path1': Removing directory
2026/09/14 06:47:26 ERROR : Failed to rmdir: directory not found
2026/09/14 06:47:26 DEBUG : Waiting for deletions to finish
2026/09/14 06:47:26 ERROR : error listing: directory not found
2026/09/14 06:47:26 ERROR : Local file system at /tmp/064353qixumes1/normalization/path2: Failed to list "": directory not found
2026/09/14 06:47:26 DEBUG : removing 1 level 0 directories
2026/09/14 06:47:26 INFO  : Local file system at /tmp/064353qixumes1/normalization/path2: Removing directory
2026/09/14 06:47:26 ERROR : Failed to rmdir: stat /tmp/064353qixumes1/normalization/path2: no such file or directory
2026/09/14 06:47:30 ERROR : error listing: directory not found
2026/09/14 06:47:30 ERROR : error listing: directory not found
2026/09/14 06:47:30 NOTICE: checking initFs Local file system at /tmp/064353qixumes1/initdir/test_normalization-zijikih4
2026/09/14 06:47:35 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2026/09/14 06:47:35 DEBUG : file1.txt: Need to transfer - File not found at Destination
2026/09/14 06:47:35 INFO  : 測試_Русский_ _ _ě_áñ: Making directory
2026/09/14 06:47:58 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Need to transfer - File not found at Destination
2026/09/14 06:47:58 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Need to transfer - File not found at Destination
2026/09/14 06:47:58 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: Need to transfer - File not found at Destination
2026/09/14 06:47:58 DEBUG : Internxt root 'rclone-test-kovuqiy4zaha/064353qixumes1/normalization/path1': Waiting for checks to finish
2026/09/14 06:47:58 DEBUG : Internxt root 'rclone-test-kovuqiy4zaha/064353qixumes1/normalization/path1': Waiting for transfers to finish
FileLimitsResponse {
  "maxUploadFileSize": 107374182400,
  "versioning": {
    "enabled": true,
    "maxFileSize": 20971520,
    "retentionDays": 30,
    "maxVersions": 20
  }
}
2026/09/14 06:48:12 DEBUG : file1.txt: size = 0 OK
2026/09/14 06:48:12 INFO  : file1.txt: Copied (new)
2026/09/14 06:48:13 DEBUG : RCLONE_TEST: size = 109 OK
2026/09/14 06:48:13 INFO  : RCLONE_TEST: Copied (new)
2026/09/14 06:48:14 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: size = 272 OK
2026/09/14 06:48:14 INFO  : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Copied (new)
2026/09/14 06:48:14 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: size = 272 OK
2026/09/14 06:48:14 INFO  : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Copied (new)
2026/09/14 06:48:23 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: size = 0 OK
2026/09/14 06:48:23 INFO  : 測試_Русский_ _ _ě_áñ/測試_check file: Copied (new)
2026/09/14 06:48:23 NOTICE: checking Path1 Internxt root 'rclone-test-kovuqiy4zaha/064353qixumes1/normalization/path1'
2026/09/14 06:48:38 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2026/09/14 06:48:38 DEBUG : file1.txt: Need to transfer - File not found at Destination
2026/09/14 06:48:38 DEBUG : 測試_Русский_ _ _ě_áñ: Making directory with metadata
2026/09/14 06:48:38 INFO  : 測試_Русский_ _ _ě_áñ: Made directory with metadata (mtime=2024-01-25T05:00:02.874776175Z)
2026/09/14 06:48:38 DEBUG : Added delayed dir = "測試_Русский_ _ _ě_áñ", newDst=測試_Русский_ _ _ě_áñ
2026/09/14 06:48:38 DEBUG : file1.txt.56d0d699.partial: size = 0 OK
2026/09/14 06:48:38 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/09/14 06:48:38 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt
2026/09/14 06:48:38 INFO  : file1.txt: Copied (new)
2026/09/14 06:48:38 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK
2026/09/14 06:48:38 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Need to transfer - File not found at Destination
2026/09/14 06:48:38 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2026/09/14 06:48:38 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Need to transfer - File not found at Destination
2026/09/14 06:48:38 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: Need to transfer - File not found at Destination
2026/09/14 06:48:38 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST
2026/09/14 06:48:38 INFO  : RCLONE_TEST: Copied (new)
2026/09/14 06:48:38 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt.b8f49a2a.partial: size = 272 OK
2026/09/14 06:48:38 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: md5 = 0033328434f9662a7dae0d1aee7768b6 OK
2026/09/14 06:48:38 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file.062d4dd7.partial: size = 0 OK
2026/09/14 06:48:38 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt.24b96bc5.partial: size = 272 OK
2026/09/14 06:48:38 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/09/14 06:48:38 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt.b8f49a2a.partial: renamed to: 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt
2026/09/14 06:48:38 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: md5 = 0033328434f9662a7dae0d1aee7768b6 OK
2026/09/14 06:48:38 INFO  : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Copied (new)
2026/09/14 06:48:38 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file.062d4dd7.partial: renamed to: 測試_Русский_ _ _ě_áñ/測試_check file
2026/09/14 06:48:38 INFO  : 測試_Русский_ _ _ě_áñ/測試_check file: Copied (new)
2026/09/14 06:48:38 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt.24b96bc5.partial: renamed to: 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt
2026/09/14 06:48:38 INFO  : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Copied (new)
2026/09/14 06:48:38 DEBUG : Local file system at /tmp/064353qixumes1/normalization/path2: Waiting for checks to finish
2026/09/14 06:48:38 DEBUG : Local file system at /tmp/064353qixumes1/normalization/path2: Waiting for transfers to finish
2026/09/14 06:48:38 INFO  : 測試_Русский_ _ _ě_áñ: Set directory modification time (using SetModTime)
2026/09/14 06:48:38 NOTICE: checking path2 Local file system at /tmp/064353qixumes1/normalization/path2
2026/09/14 06:48:38 NOTICE: (01)  : test normalization
2026/09/14 06:48:38 NOTICE: (02)  : touch-copy 2001-01-02 /tmp/064353qixumes1/datadir/test_normalization-fozusit9/file1.txt /tmp/064353qixumes1/normalization/path2/
2026/09/14 06:48:38 DEBUG : Creating backend with remote "/tmp/064353qixumes1/datadir/test_normalization-fozusit9/"
2026/09/14 06:48:38 DEBUG : Config file has changed externally - reloading
2026/09/14 06:48:38 DEBUG : fs cache: renaming cache item "/tmp/064353qixumes1/datadir/test_normalization-fozusit9/" to be canonical "/tmp/064353qixumes1/datadir/test_normalization-fozusit9"
2026/09/14 06:48:38 DEBUG : file1.txt: Set modification time 2001-01-02
2026/09/14 06:48:38 DEBUG : copyFile "/tmp/064353qixumes1/datadir/test_normalization-fozusit9/file1.txt" to "/tmp/064353qixumes1/normalization/path2/" as ""
2026/09/14 06:48:38 DEBUG : Creating backend with remote "/tmp/064353qixumes1/datadir/test_normalization-fozusit9/file1.txt"
2026/09/14 06:48:38 DEBUG : Creating backend with remote "/tmp/064353qixumes1/normalization/path2/"
2026/09/14 06:48:38 DEBUG : operations.CopyFile "file1.txt" to "Local file system at /tmp/064353qixumes1/normalization/path2" as "file1.txt"
2026/09/14 06:48:38 DEBUG : file1.txt: size = 19 (Local file system at /tmp/064353qixumes1/datadir/test_normalization-fozusit9)
2026/09/14 06:48:38 DEBUG : file1.txt: size = 0 (Local file system at /tmp/064353qixumes1/normalization/path2)
2026/09/14 06:48:38 DEBUG : file1.txt: Sizes differ
2026/09/14 06:48:38 DEBUG : file1.txt.75b77f44.partial: size = 19 OK
2026/09/14 06:48:38 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK
2026/09/14 06:48:38 DEBUG : file1.txt.75b77f44.partial: renamed to: file1.txt
2026/09/14 06:48:38 INFO  : file1.txt: Copied (replaced existing)
2026/09/14 06:48:38 NOTICE: (03)  : test initial bisync
2026/09/14 06:48:38 NOTICE: (04)  : bisync resync
    bisync_test.go:1017: skipping test as at least one remote does not support setting modtime
2026/09/14 06:49:46 DEBUG : Internxt root 'rclone-test-kovuqiy4zaha': Purge object "064353qixumes1/normalization/path1/RCLONE_TEST"
2026/09/14 06:49:46 DEBUG : Internxt root 'rclone-test-kovuqiy4zaha': Purge object "064353qixumes1/normalization/path1/file1.txt"
2026/09/14 06:49:58 DEBUG : Internxt root 'rclone-test-kovuqiy4zaha': Purge object "064353qixumes1/normalization/path1/測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt"
2026/09/14 06:50:00 DEBUG : Internxt root 'rclone-test-kovuqiy4zaha': Purge object "064353qixumes1/normalization/path1/測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt"
2026/09/14 06:50:01 DEBUG : Internxt root 'rclone-test-kovuqiy4zaha': Purge object "064353qixumes1/normalization/path1/測試_Русский_ _ _ě_áñ/測試_check file"
2026/09/14 06:50:07 DEBUG : Internxt root 'rclone-test-kovuqiy4zaha': Purge dir "064353qixumes1/path1"
2026/09/14 06:50:21 DEBUG : Internxt root 'rclone-test-kovuqiy4zaha': Purge dir "064353qixumes1/normalization/path1/測試_Русский_ _ _ě_áñ"
2026/09/14 06:50:32 DEBUG : Internxt root 'rclone-test-kovuqiy4zaha': Purge dir "064353qixumes1/normalization/path1"
2026/09/14 06:50:44 DEBUG : Internxt root 'rclone-test-kovuqiy4zaha': Purge dir "064353qixumes1/normalization"
2026/09/14 06:50:56 DEBUG : Internxt root 'rclone-test-kovuqiy4zaha': Purge dir "064353qixumes1"
2026/09/14 06:51:09 DEBUG : Internxt root 'rclone-test-kovuqiy4zaha': Purge dir ""
--- PASS: TestBisyncRemoteLocal (455.91s)
    --- SKIP: TestBisyncRemoteLocal/normalization (285.08s)
PASS
2026/09/14 06:51:21 ERROR : error listing: directory not found
2026/09/14 06:51:21 DEBUG : Internxt root 'rclone-test-zeqopod2fija': Purge dir ""
2026/09/14 06:51:27 NOTICE: purge failed to rmdir "": directory not found
2026/09/14 06:51:27 NOTICE: purge failed: directory not found
"./bisync.test -test.v -test.timeout 2h0m0s -remote TestInternxt: -list-retries 5 -verbose -test.run '^TestBisyncRemoteLocal$/^normalization$'" - Finished OK in 8m6.189285947s (try 3/5)