"./bisync.test -test.v -test.timeout 1h0m0s -remote TestInternxt: -list-retries 5 -verbose -test.run '^TestBisyncRemoteLocal$/^normalization$'" - Starting (try 3/5)
2026/06/11 08:13:37 DEBUG : Creating backend with remote "TestInternxt:rclone-test-qibazow2bebo"
2026/06/11 08:13:37 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/06/11 08:13:37 DEBUG : User info: rootFolderId=2661cf64-e104-478b-b737-48c3ac8984d2, bucket=697358bf16ceabcf39af85f2
2026/06/11 08:13:38 DEBUG : Creating backend with remote "/tmp/rclone2415238645"
=== RUN   TestBisyncRemoteLocal
2026/06/11 08:13:38 DEBUG : Creating backend with remote "TestInternxt:rclone-test-yupumis4gudo"
2026/06/11 08:13:38 DEBUG : User info: rootFolderId=2661cf64-e104-478b-b737-48c3ac8984d2, bucket=697358bf16ceabcf39af85f2
2026/06/11 08:13:38 NOTICE: remote: TestInternxt:rclone-test-yupumis4gudo
=== RUN   TestBisyncRemoteLocal/normalization
2026/06/11 08:13:38 DEBUG : Creating backend with remote "TestInternxt:rclone-test-yupumis4gudo/081338lewifay5"
2026/06/11 08:13:39 DEBUG : User info: rootFolderId=2661cf64-e104-478b-b737-48c3ac8984d2, bucket=697358bf16ceabcf39af85f2
2026/06/11 08:13:39 INFO  : path1: Making directory
2026/06/11 08:13:46 DEBUG : Creating backend with remote "TestInternxt:rclone-test-yupumis4gudo/081338lewifay5/normalization/path1"
2026/06/11 08:13:46 DEBUG : User info: rootFolderId=2661cf64-e104-478b-b737-48c3ac8984d2, bucket=697358bf16ceabcf39af85f2
2026/06/11 08:13:47 DEBUG : Creating backend with remote "/tmp/081338lewifay5"
2026/06/11 08:13:47 DEBUG : Creating backend with remote "/tmp/081338lewifay5/normalization/path2"
2026/06/11 08:13:47 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_normalization/initial"
2026/06/11 08:13:47 DEBUG : Creating backend with remote "/tmp/081338lewifay5/initdir/test_normalization-watofaz3"
2026/06/11 08:13:47 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2026/06/11 08:13:47 DEBUG : file1.txt: Need to transfer - File not found at Destination
2026/06/11 08:13:47 DEBUG : 測試_Русский_ _ _ě_áñ: Making directory with metadata
2026/06/11 08:13:47 INFO  : 測試_Русский_ _ _ě_áñ: Made directory with metadata (mtime=2024-01-25T05:00:02.874776175Z)
2026/06/11 08:13:47 DEBUG : Added delayed dir = "測試_Русский_ _ _ě_áñ", newDst=測試_Русский_ _ _ě_áñ
2026/06/11 08:13:47 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK
2026/06/11 08:13:47 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Need to transfer - File not found at Destination
2026/06/11 08:13:47 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2026/06/11 08:13:47 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Need to transfer - File not found at Destination
2026/06/11 08:13:47 DEBUG : file1.txt.56d0d699.partial: size = 0 OK
2026/06/11 08:13:47 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: Need to transfer - File not found at Destination
2026/06/11 08:13:47 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST
2026/06/11 08:13:47 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/11 08:13:47 INFO  : RCLONE_TEST: Copied (new)
2026/06/11 08:13:47 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt
2026/06/11 08:13:47 INFO  : file1.txt: Copied (new)
2026/06/11 08:13:47 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt.b8f49a2a.partial: size = 272 OK
2026/06/11 08:13:47 DEBUG : Local file system at /tmp/081338lewifay5/initdir/test_normalization-watofaz3: Waiting for checks to finish
2026/06/11 08:13:47 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: md5 = 0033328434f9662a7dae0d1aee7768b6 OK
2026/06/11 08:13:47 DEBUG : Local file system at /tmp/081338lewifay5/initdir/test_normalization-watofaz3: Waiting for transfers to finish
2026/06/11 08:13:47 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt.b8f49a2a.partial: renamed to: 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt
2026/06/11 08:13:47 INFO  : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Copied (new)
2026/06/11 08:13:47 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file.062d4dd7.partial: size = 0 OK
2026/06/11 08:13:47 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt.24b96bc5.partial: size = 272 OK
2026/06/11 08:13:47 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/11 08:13:47 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: md5 = 0033328434f9662a7dae0d1aee7768b6 OK
2026/06/11 08:13:47 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file.062d4dd7.partial: renamed to: 測試_Русский_ _ _ě_áñ/測試_check file
2026/06/11 08:13:47 INFO  : 測試_Русский_ _ _ě_áñ/測試_check file: Copied (new)
2026/06/11 08:13:47 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt.24b96bc5.partial: renamed to: 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt
2026/06/11 08:13:47 INFO  : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Copied (new)
2026/06/11 08:13:47 INFO  : 測試_Русский_ _ _ě_áñ: Set directory modification time (using SetModTime)
2026/06/11 08:13:47 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_normalization/modfiles"
2026/06/11 08:13:47 DEBUG : Creating backend with remote "/tmp/081338lewifay5/datadir/test_normalization-pudaros0"
2026/06/11 08:13:47 DEBUG : file1.txt: Need to transfer - File not found at Destination
2026/06/11 08:13:47 DEBUG : 測試_filtersfile.txt: Need to transfer - File not found at Destination
2026/06/11 08:13:47 DEBUG : Local file system at /tmp/081338lewifay5/datadir/test_normalization-pudaros0: Waiting for checks to finish
2026/06/11 08:13:47 DEBUG : Local file system at /tmp/081338lewifay5/datadir/test_normalization-pudaros0: Waiting for transfers to finish
2026/06/11 08:13:47 DEBUG : file1.txt.75b77f44.partial: size = 19 OK
2026/06/11 08:13:47 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK
2026/06/11 08:13:47 DEBUG : 測試_filtersfile.txt.3ada41b4.partial: size = 254 OK
2026/06/11 08:13:47 DEBUG : file1.txt.75b77f44.partial: renamed to: file1.txt
2026/06/11 08:13:47 INFO  : file1.txt: Copied (new)
2026/06/11 08:13:47 DEBUG : 測試_filtersfile.txt: md5 = 1cec24a8ae7c33c49693a14d53fd6a96 OK
2026/06/11 08:13:47 DEBUG : 測試_filtersfile.txt.3ada41b4.partial: renamed to: 測試_filtersfile.txt
2026/06/11 08:13:47 INFO  : 測試_filtersfile.txt: Copied (new)
2026/06/11 08:13:47 DEBUG : Waiting for deletions to finish
2026/06/11 08:13:48 ERROR : error listing: directory not found
2026/06/11 08:13:48 ERROR : Internxt root 'rclone-test-yupumis4gudo/081338lewifay5/normalization/path1': Failed to list "": directory not found
2026/06/11 08:13:48 DEBUG : removing 1 level 0 directories
2026/06/11 08:13:48 INFO  : Internxt root 'rclone-test-yupumis4gudo/081338lewifay5/normalization/path1': Removing directory
2026/06/11 08:13:48 ERROR : Failed to rmdir: directory not found
2026/06/11 08:13:48 DEBUG : Waiting for deletions to finish
2026/06/11 08:13:48 ERROR : error listing: directory not found
2026/06/11 08:13:48 ERROR : Local file system at /tmp/081338lewifay5/normalization/path2: Failed to list "": directory not found
2026/06/11 08:13:48 DEBUG : removing 1 level 0 directories
2026/06/11 08:13:48 INFO  : Local file system at /tmp/081338lewifay5/normalization/path2: Removing directory
2026/06/11 08:13:48 ERROR : Failed to rmdir: stat /tmp/081338lewifay5/normalization/path2: no such file or directory
2026/06/11 08:13:48 ERROR : error listing: directory not found
2026/06/11 08:13:48 ERROR : error listing: directory not found
2026/06/11 08:13:48 NOTICE: checking initFs Local file system at /tmp/081338lewifay5/initdir/test_normalization-watofaz3
2026/06/11 08:13:48 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2026/06/11 08:13:48 DEBUG : file1.txt: Need to transfer - File not found at Destination
2026/06/11 08:13:48 INFO  : 測試_Русский_ _ _ě_áñ: Making directory
2026/06/11 08:13:51 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Need to transfer - File not found at Destination
2026/06/11 08:13:51 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Need to transfer - File not found at Destination
2026/06/11 08:13:51 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: Need to transfer - File not found at Destination
2026/06/11 08:13:51 DEBUG : Internxt root 'rclone-test-yupumis4gudo/081338lewifay5/normalization/path1': Waiting for checks to finish
2026/06/11 08:13:51 DEBUG : Internxt root 'rclone-test-yupumis4gudo/081338lewifay5/normalization/path1': Waiting for transfers to finish
2026/06/11 08:13:56 DEBUG : file1.txt: size = 0 OK
2026/06/11 08:13:56 INFO  : file1.txt: Copied (new)
2026/06/11 08:13:57 DEBUG : RCLONE_TEST: size = 109 OK
2026/06/11 08:13:57 INFO  : RCLONE_TEST: Copied (new)
2026/06/11 08:13:57 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: size = 272 OK
2026/06/11 08:13:57 INFO  : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Copied (new)
2026/06/11 08:13:58 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: size = 272 OK
2026/06/11 08:13:58 INFO  : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Copied (new)
2026/06/11 08:14:03 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: size = 0 OK
2026/06/11 08:14:03 INFO  : 測試_Русский_ _ _ě_áñ/測試_check file: Copied (new)
2026/06/11 08:14:03 NOTICE: checking Path1 Internxt root 'rclone-test-yupumis4gudo/081338lewifay5/normalization/path1'
2026/06/11 08:14:04 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2026/06/11 08:14:04 DEBUG : file1.txt: Need to transfer - File not found at Destination
2026/06/11 08:14:04 DEBUG : 測試_Русский_ _ _ě_áñ: Making directory with metadata
2026/06/11 08:14:04 INFO  : 測試_Русский_ _ _ě_áñ: Made directory with metadata (mtime=2024-01-25T05:00:02.874776175Z)
2026/06/11 08:14:04 DEBUG : Added delayed dir = "測試_Русский_ _ _ě_áñ", newDst=測試_Русский_ _ _ě_áñ
2026/06/11 08:14:04 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK
2026/06/11 08:14:04 DEBUG : file1.txt.56d0d699.partial: size = 0 OK
2026/06/11 08:14:04 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2026/06/11 08:14:04 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Need to transfer - File not found at Destination
2026/06/11 08:14:04 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Need to transfer - File not found at Destination
2026/06/11 08:14:04 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/11 08:14:04 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: Need to transfer - File not found at Destination
2026/06/11 08:14:04 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST
2026/06/11 08:14:04 INFO  : RCLONE_TEST: Copied (new)
2026/06/11 08:14:04 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt
2026/06/11 08:14:04 INFO  : file1.txt: Copied (new)
2026/06/11 08:14:04 DEBUG : Local file system at /tmp/081338lewifay5/normalization/path2: Waiting for checks to finish
2026/06/11 08:14:04 DEBUG : Local file system at /tmp/081338lewifay5/normalization/path2: Waiting for transfers to finish
2026/06/11 08:14:04 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file.062d4dd7.partial: size = 0 OK
2026/06/11 08:14:04 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/11 08:14:04 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt.b8f49a2a.partial: size = 272 OK
2026/06/11 08:14:04 DEBUG : 測試_Русский_ _ _ě_áñ/測試_check file.062d4dd7.partial: renamed to: 測試_Русский_ _ _ě_áñ/測試_check file
2026/06/11 08:14:04 INFO  : 測試_Русский_ _ _ě_áñ/測試_check file: Copied (new)
2026/06/11 08:14:04 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: md5 = 0033328434f9662a7dae0d1aee7768b6 OK
2026/06/11 08:14:04 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt.b8f49a2a.partial: renamed to: 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt
2026/06/11 08:14:04 INFO  : 測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt: Copied (new)
2026/06/11 08:14:04 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt.24b96bc5.partial: size = 272 OK
2026/06/11 08:14:04 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: md5 = 0033328434f9662a7dae0d1aee7768b6 OK
2026/06/11 08:14:04 DEBUG : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt.24b96bc5.partial: renamed to: 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt
2026/06/11 08:14:04 INFO  : 測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt: Copied (new)
2026/06/11 08:14:04 INFO  : 測試_Русский_ _ _ě_áñ: Set directory modification time (using SetModTime)
2026/06/11 08:14:04 NOTICE: checking path2 Local file system at /tmp/081338lewifay5/normalization/path2
2026/06/11 08:14:04 NOTICE: (01)  : test normalization
2026/06/11 08:14:04 NOTICE: (02)  : touch-copy 2001-01-02 /tmp/081338lewifay5/datadir/test_normalization-pudaros0/file1.txt /tmp/081338lewifay5/normalization/path2/
2026/06/11 08:14:04 DEBUG : Creating backend with remote "/tmp/081338lewifay5/datadir/test_normalization-pudaros0/"
2026/06/11 08:14:04 DEBUG : fs cache: renaming cache item "/tmp/081338lewifay5/datadir/test_normalization-pudaros0/" to be canonical "/tmp/081338lewifay5/datadir/test_normalization-pudaros0"
2026/06/11 08:14:04 DEBUG : file1.txt: Set modification time 2001-01-02
2026/06/11 08:14:04 DEBUG : copyFile "/tmp/081338lewifay5/datadir/test_normalization-pudaros0/file1.txt" to "/tmp/081338lewifay5/normalization/path2/" as ""
2026/06/11 08:14:04 DEBUG : Creating backend with remote "/tmp/081338lewifay5/datadir/test_normalization-pudaros0/file1.txt"
2026/06/11 08:14:04 DEBUG : Creating backend with remote "/tmp/081338lewifay5/normalization/path2/"
2026/06/11 08:14:04 DEBUG : operations.CopyFile "file1.txt" to "Local file system at /tmp/081338lewifay5/normalization/path2" as "file1.txt"
2026/06/11 08:14:04 DEBUG : file1.txt: size = 19 (Local file system at /tmp/081338lewifay5/datadir/test_normalization-pudaros0)
2026/06/11 08:14:04 DEBUG : file1.txt: size = 0 (Local file system at /tmp/081338lewifay5/normalization/path2)
2026/06/11 08:14:04 DEBUG : file1.txt: Sizes differ
2026/06/11 08:14:04 DEBUG : file1.txt.75b77f44.partial: size = 19 OK
2026/06/11 08:14:04 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK
2026/06/11 08:14:04 DEBUG : file1.txt.75b77f44.partial: renamed to: file1.txt
2026/06/11 08:14:04 INFO  : file1.txt: Copied (replaced existing)
2026/06/11 08:14:04 NOTICE: (03)  : test initial bisync
2026/06/11 08:14:04 NOTICE: (04)  : bisync resync
    bisync_test.go:1017: skipping test as at least one remote does not support setting modtime
2026/06/11 08:14:11 DEBUG : Internxt root 'rclone-test-yupumis4gudo': Purge object "081338lewifay5/normalization/path1/RCLONE_TEST"
2026/06/11 08:14:12 DEBUG : Internxt root 'rclone-test-yupumis4gudo': Purge object "081338lewifay5/normalization/path1/file1.txt"
2026/06/11 08:14:13 DEBUG : Internxt root 'rclone-test-yupumis4gudo': Purge object "081338lewifay5/normalization/path1/測試_Русский_ _ _ě_áñ/filename_contains_ě_.txt"
2026/06/11 08:14:13 DEBUG : Internxt root 'rclone-test-yupumis4gudo': Purge object "081338lewifay5/normalization/path1/測試_Русский_ _ _ě_áñ/filename_contains_ࢺ_.txt"
2026/06/11 08:14:14 DEBUG : Internxt root 'rclone-test-yupumis4gudo': Purge object "081338lewifay5/normalization/path1/測試_Русский_ _ _ě_áñ/測試_check file"
2026/06/11 08:14:14 DEBUG : Internxt root 'rclone-test-yupumis4gudo': Purge dir "081338lewifay5/path1"
2026/06/11 08:14:15 DEBUG : Internxt root 'rclone-test-yupumis4gudo': Purge dir "081338lewifay5/normalization/path1/測試_Русский_ _ _ě_áñ"
2026/06/11 08:14:15 DEBUG : Internxt root 'rclone-test-yupumis4gudo': Purge dir "081338lewifay5/normalization/path1"
2026/06/11 08:14:16 DEBUG : Internxt root 'rclone-test-yupumis4gudo': Purge dir "081338lewifay5/normalization"
2026/06/11 08:14:18 DEBUG : Internxt root 'rclone-test-yupumis4gudo': Purge dir "081338lewifay5"
2026/06/11 08:14:19 DEBUG : Internxt root 'rclone-test-yupumis4gudo': Purge dir ""
--- PASS: TestBisyncRemoteLocal (41.84s)
    --- SKIP: TestBisyncRemoteLocal/normalization (26.01s)
PASS
2026/06/11 08:14:20 ERROR : error listing: directory not found
2026/06/11 08:14:20 DEBUG : Internxt root 'rclone-test-qibazow2bebo': Purge dir ""
2026/06/11 08:14:20 NOTICE: purge failed to rmdir "": directory not found
2026/06/11 08:14:20 NOTICE: purge failed: directory not found
"./bisync.test -test.v -test.timeout 1h0m0s -remote TestInternxt: -list-retries 5 -verbose -test.run '^TestBisyncRemoteLocal$/^normalization$'" - Finished OK in 43.053634448s (try 3/5)