"./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestMoveOverSelf|TestNothingToTransferWithEmptyDirs|TestNothingToTransferWithoutEmptyDirs|TestSyncWithTrackRenames)$'" - Starting (try 2/5)
2025/10/15 01:30:23 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-wexewob0suzu"
2025/10/15 01:30:23 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/10/15 01:30:24 DEBUG : Creating backend with remote "/tmp/rclone2603177803"
=== RUN   TestMoveOverSelf
    run.go:180: Remote "files root 'rclone-test-wexewob0suzu'", Local "Local file system at /tmp/rclone2603177803", Modify Window "1s"
2025/10/15 01:30:27 DEBUG : sub dir: Directory modification time the same (differ by -978.362228ms, within tolerance 1s)
2025/10/15 01:30:27 DEBUG : Added delayed dir = "sub dir", newDst=sub dir
2025/10/15 01:30:27 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11)
2025/10/15 01:30:27 DEBUG : files root 'rclone-test-wexewob0suzu': Waiting for checks to finish
2025/10/15 01:30:27 DEBUG : files root 'rclone-test-wexewob0suzu': Waiting for transfers to finish
2025/10/15 01:30:28 DEBUG : sub dir/hello world: Dst hash empty - aborting Src hash check
2025/10/15 01:30:28 INFO  : sub dir/hello world: Copied (replaced existing)
2025/10/15 01:30:28 INFO  : sub dir/hello world: Deleted
2025/10/15 01:30:28 INFO  : sub dir: Set directory modification time (using DirSetModTime)
--- PASS: TestMoveOverSelf (4.99s)
=== RUN   TestSyncWithTrackRenames
    run.go:180: Remote "files root 'rclone-test-wexewob0suzu'", Local "Local file system at /tmp/rclone2603177803", Modify Window "1s"
    sync_test.go:1568: Can track renames: true
2025/10/15 01:30:29 INFO  : files root 'rclone-test-wexewob0suzu': Making map for --track-renames
2025/10/15 01:30:29 INFO  : files root 'rclone-test-wexewob0suzu': Finished making map for --track-renames
2025/10/15 01:30:29 DEBUG : files root 'rclone-test-wexewob0suzu': Waiting for checks to finish
2025/10/15 01:30:29 DEBUG : potato: Need to transfer - No matching file found at Destination
2025/10/15 01:30:29 DEBUG : yam: Need to transfer - No matching file found at Destination
2025/10/15 01:30:29 DEBUG : files root 'rclone-test-wexewob0suzu': Waiting for renames to finish
2025/10/15 01:30:29 DEBUG : files root 'rclone-test-wexewob0suzu': Waiting for transfers to finish
2025/10/15 01:30:30 DEBUG : potato: Dst hash empty - aborting Src hash check
2025/10/15 01:30:30 INFO  : potato: Copied (new)
2025/10/15 01:30:30 DEBUG : yam: Dst hash empty - aborting Src hash check
2025/10/15 01:30:30 INFO  : yam: Copied (new)
2025/10/15 01:30:30 DEBUG : Waiting for deletions to finish
2025/10/15 01:30:30 DEBUG : potato: Size and modification time the same (differ by -499.999999ms, within tolerance 1s)
2025/10/15 01:30:30 INFO  : files root 'rclone-test-wexewob0suzu': Making map for --track-renames
2025/10/15 01:30:30 INFO  : files root 'rclone-test-wexewob0suzu': Finished making map for --track-renames
2025/10/15 01:30:30 DEBUG : files root 'rclone-test-wexewob0suzu': Waiting for checks to finish
2025/10/15 01:30:30 DEBUG : potato: Unchanged skipping
2025/10/15 01:30:30 DEBUG : files root 'rclone-test-wexewob0suzu': Waiting for renames to finish
2025/10/15 01:30:30 DEBUG : yaml: Need to transfer - No matching file found at Destination
2025/10/15 01:30:30 DEBUG : files root 'rclone-test-wexewob0suzu': Waiting for transfers to finish
2025/10/15 01:30:31 DEBUG : yaml: Dst hash empty - aborting Src hash check
2025/10/15 01:30:31 INFO  : yaml: Copied (new)
2025/10/15 01:30:31 DEBUG : Waiting for deletions to finish
2025/10/15 01:30:31 INFO  : yam: Deleted
    sync_test.go:1594: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:1594
        	Error:      	Not equal: 
        	            	expected: true
        	            	actual  : false
        	Test:       	TestSyncWithTrackRenames
        	Messages:   	canTrackRenames=true, renames=0
--- FAIL: TestSyncWithTrackRenames (2.95s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:180: Remote "files root 'rclone-test-wexewob0suzu'", Local "Local file system at /tmp/rclone2603177803", Modify Window "1s"
2025/10/15 01:30:32 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/10/15 01:30:32 INFO  : sub dir: Making directory
2025/10/15 01:30:32 INFO  : sub dir: Made directory with modification time 2011-12-30 12:59:59 +0000 UTC
2025/10/15 01:30:42 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/10/15 01:30:42 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/10/15 01:30:42 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/10/15 01:30:42 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
2025/10/15 01:30:48 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dirEmpty not empty`)
2025/10/15 01:30:48 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/10/15 01:30:48 DEBUG : pacer: Reducing sleep to 15ms
2025/10/15 01:30:49 DEBUG : pacer: Reducing sleep to 11.25ms
2025/10/15 01:30:49 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dir2/very/very/very/very/very/nested not empty`)
2025/10/15 01:30:49 DEBUG : pacer: Rate limited, increasing sleep to 22.5ms
2025/10/15 01:30:49 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dir2/very/very/very/very/very/nested not empty`)
2025/10/15 01:30:49 DEBUG : pacer: Rate limited, increasing sleep to 45ms
2025/10/15 01:30:49 DEBUG : pacer: Reducing sleep to 33.75ms
2025/10/15 01:30:49 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dir2/very/very/very/very/very not empty`)
2025/10/15 01:30:49 DEBUG : pacer: Rate limited, increasing sleep to 67.5ms
2025/10/15 01:30:49 DEBUG : pacer: Reducing sleep to 50.625ms
2025/10/15 01:30:49 DEBUG : pacer: Reducing sleep to 37.96875ms
2025/10/15 01:30:50 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dir2/very/very/very not empty`)
2025/10/15 01:30:50 DEBUG : pacer: Rate limited, increasing sleep to 75.9375ms
2025/10/15 01:30:50 DEBUG : pacer: Reducing sleep to 56.953125ms
2025/10/15 01:30:50 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dir2/very/very not empty`)
2025/10/15 01:30:50 DEBUG : pacer: Rate limited, increasing sleep to 113.90625ms
2025/10/15 01:30:50 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dir2/very/very not empty`)
2025/10/15 01:30:50 DEBUG : pacer: Rate limited, increasing sleep to 227.8125ms
2025/10/15 01:30:50 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dir2/very/very not empty`)
2025/10/15 01:30:50 DEBUG : pacer: Rate limited, increasing sleep to 455.625ms
2025/10/15 01:30:50 DEBUG : pacer: Reducing sleep to 341.71875ms
2025/10/15 01:30:51 DEBUG : pacer: Reducing sleep to 256.289062ms
2025/10/15 01:30:51 DEBUG : pacer: Reducing sleep to 192.216796ms
2025/10/15 01:30:51 DEBUG : pacer: Reducing sleep to 144.162597ms
2025/10/15 01:30:52 DEBUG : pacer: Reducing sleep to 108.121947ms
2025/10/15 01:30:52 DEBUG : pacer: Reducing sleep to 81.09146ms
--- PASS: TestNothingToTransferWithEmptyDirs (19.88s)
=== RUN   TestNothingToTransferWithoutEmptyDirs
    run.go:180: Remote "files root 'rclone-test-wexewob0suzu'", Local "Local file system at /tmp/rclone2603177803", Modify Window "1s"
2025/10/15 01:30:52 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2025/10/15 01:30:52 INFO  : sub dir: Making directory
2025/10/15 01:30:52 DEBUG : pacer: Reducing sleep to 60.818595ms
2025/10/15 01:30:52 DEBUG : pacer: Reducing sleep to 45.613946ms
2025/10/15 01:30:52 INFO  : sub dir: Made directory with modification time 2011-12-30 12:59:59 +0000 UTC
2025/10/15 01:31:00 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/10/15 01:31:00 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2025/10/15 01:31:00 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2025/10/15 01:31:00 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
2025/10/15 01:31:06 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dir2/very/very/very/very/very/nested not empty`)
2025/10/15 01:31:06 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/10/15 01:31:06 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dir2/very/very/very/very/very/nested not empty`)
2025/10/15 01:31:06 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/10/15 01:31:06 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dir2/very/very/very/very/very/nested not empty`)
2025/10/15 01:31:06 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/10/15 01:31:06 DEBUG : pacer: low level retry 4/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dir2/very/very/very/very/very/nested not empty`)
2025/10/15 01:31:06 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2025/10/15 01:31:06 DEBUG : pacer: low level retry 5/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dir2/very/very/very/very/very/nested not empty`)
2025/10/15 01:31:06 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2025/10/15 01:31:06 DEBUG : pacer: low level retry 6/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dir2/very/very/very/very/very/nested not empty`)
2025/10/15 01:31:06 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2025/10/15 01:31:07 DEBUG : pacer: Reducing sleep to 480ms
2025/10/15 01:31:07 DEBUG : pacer: Reducing sleep to 360ms
2025/10/15 01:31:08 DEBUG : pacer: Reducing sleep to 270ms
2025/10/15 01:31:08 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dir2/very/very/very not empty`)
2025/10/15 01:31:08 DEBUG : pacer: Rate limited, increasing sleep to 540ms
2025/10/15 01:31:08 DEBUG : pacer: Reducing sleep to 405ms
2025/10/15 01:31:09 DEBUG : pacer: Reducing sleep to 303.75ms
2025/10/15 01:31:09 DEBUG : pacer: Reducing sleep to 227.8125ms
2025/10/15 01:31:10 DEBUG : pacer: Reducing sleep to 170.859375ms
2025/10/15 01:31:10 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dir2 not empty`)
2025/10/15 01:31:10 DEBUG : pacer: Rate limited, increasing sleep to 341.71875ms
2025/10/15 01:31:10 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-wexewob0suzu/sub dir2 not empty`)
2025/10/15 01:31:10 DEBUG : pacer: Rate limited, increasing sleep to 683.4375ms
2025/10/15 01:31:10 DEBUG : pacer: Reducing sleep to 512.578125ms
2025/10/15 01:31:11 DEBUG : pacer: Reducing sleep to 384.433593ms
2025/10/15 01:31:11 DEBUG : pacer: Reducing sleep to 288.325194ms
--- PASS: TestNothingToTransferWithoutEmptyDirs (19.68s)
FAIL
2025/10/15 01:31:11 DEBUG : files root 'rclone-test-wexewob0suzu': Purge remote
2025/10/15 01:31:12 DEBUG : pacer: Reducing sleep to 216.243895ms
"./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestMoveOverSelf|TestNothingToTransferWithEmptyDirs|TestNothingToTransferWithoutEmptyDirs|TestSyncWithTrackRenames)$'" - Finished ERROR in 48.73544394s (try 2/5): exit status 1: Failed [TestSyncWithTrackRenames]