"./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestCopyNoEmptyDirectories|TestNothingToTransferWithoutEmptyDirs|TestSyncBackupDirSuffixOnly|TestSyncEmptyDirectories|TestSyncNoEmptyDirectories|TestSyncNoUpdateDirModtime|TestSyncSetDelayedModTimes)$'" - Starting (try 2/5) 2026/08/10 01:42:40 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-topinal0pawo" 2026/08/10 01:42:40 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2026/08/10 01:42:41 DEBUG : Creating backend with remote "/tmp/rclone2709816778" === RUN TestCopyNoEmptyDirectories run.go:198: Remote "files root 'rclone-test-topinal0pawo'", Local "Local file system at /tmp/rclone2709816778", Modify Window "1s" 2026/08/10 01:42:41 INFO : sub dir2: Making directory 2026/08/10 01:42:41 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2026/08/10 01:42:41 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2026/08/10 01:42:42 DEBUG : Added delayed dir = "sub dir2", newDst= 2026/08/10 01:42:42 DEBUG : Added delayed dir = "sub dir", newDst= 2026/08/10 01:42:42 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2026/08/10 01:42:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2026/08/10 01:42:42 DEBUG : files root 'rclone-test-topinal0pawo': Waiting for checks to finish 2026/08/10 01:42:42 DEBUG : files root 'rclone-test-topinal0pawo': Waiting for transfers to finish 2026/08/10 01:42:43 DEBUG : sub dir/hello world: size = 11 OK 2026/08/10 01:42:43 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2026/08/10 01:42:43 INFO : sub dir/hello world: Copied (new) 2026/08/10 01:42:43 INFO : sub dir: Set directory modification time (using DirSetModTime) --- PASS: TestCopyNoEmptyDirectories (3.35s) === RUN TestSyncNoUpdateDirModtime run.go:198: Remote "files root 'rclone-test-topinal0pawo'", Local "Local file system at /tmp/rclone2709816778", Modify Window "1s" 2026/08/10 01:42:44 DEBUG : sub dir no update dir modtime: Making directory with metadata 2026/08/10 01:42:44 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2026/08/10 01:42:45 DEBUG : files root 'rclone-test-topinal0pawo': Waiting for checks to finish 2026/08/10 01:42:45 DEBUG : files root 'rclone-test-topinal0pawo': Waiting for transfers to finish 2026/08/10 01:42:45 DEBUG : Waiting for deletions to finish --- PASS: TestSyncNoUpdateDirModtime (1.55s) === RUN TestSyncEmptyDirectories run.go:198: Remote "files root 'rclone-test-topinal0pawo'", Local "Local file system at /tmp/rclone2709816778", Modify Window "1s" 2026/08/10 01:42:46 DEBUG : sub dir2: Making directory with metadata 2026/08/10 01:42:46 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2026/08/10 01:42:46 INFO : sub dir: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:46 INFO : sub dir2: Making directory 2026/08/10 01:42:46 INFO : sub dir2: Made directory with modification time 2011-12-25 12:59:59.123456789 +0000 UTC 2026/08/10 01:42:46 DEBUG : Added delayed dir = "sub dir2", newDst= 2026/08/10 01:42:46 INFO : sub dir: Making directory 2026/08/10 01:42:47 INFO : sub dir: Made directory with modification time 2001-02-03 04:05:06.499999999 +0000 UTC 2026/08/10 01:42:47 DEBUG : Added delayed dir = "sub dir", newDst= 2026/08/10 01:42:47 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2026/08/10 01:42:47 DEBUG : files root 'rclone-test-topinal0pawo': Waiting for checks to finish 2026/08/10 01:42:47 DEBUG : files root 'rclone-test-topinal0pawo': Waiting for transfers to finish 2026/08/10 01:42:48 DEBUG : sub dir/hello world: size = 11 OK 2026/08/10 01:42:48 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2026/08/10 01:42:48 INFO : sub dir/hello world: Copied (new) 2026/08/10 01:42:48 DEBUG : Waiting for deletions to finish 2026/08/10 01:42:48 INFO : sub dir: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:48 INFO : sub dir2: Set directory modification time (using DirSetModTime) --- PASS: TestSyncEmptyDirectories (3.66s) === RUN TestSyncSetDelayedModTimes run.go:198: Remote "files root 'rclone-test-topinal0pawo'", Local "Local file system at /tmp/rclone2709816778", Modify Window "1s" 2026/08/10 01:42:50 INFO : a1/b2/c1/d1/e1/f1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:50 INFO : a1/b2/c1/d1/e1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:50 INFO : a1/b2/c1/d1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:50 INFO : a1/b2/c1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:50 INFO : a1/b2: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:50 INFO : a1/b1/c1/d2/e1/f2: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:50 INFO : a1/b1/c1/d2/e1/f1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:50 INFO : a1/b1/c1/d2/e1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:50 INFO : a1/b1/c1/d2: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:50 INFO : a1/b1/c1/d1/e1/f1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:50 INFO : a1/b1/c1/d1/e1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:50 INFO : a1/b1/c1/d1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:50 INFO : a1/b1/c1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:50 INFO : a1/b1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:50 INFO : a1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:50 INFO : a1: Making directory 2026/08/10 01:42:50 INFO : a1: Made directory with modification time 2001-02-03 04:19:06.499999999 +0000 UTC 2026/08/10 01:42:50 DEBUG : Added delayed dir = "a1", newDst= 2026/08/10 01:42:50 INFO : a1/b1: Making directory 2026/08/10 01:42:50 INFO : a1/b1: Made directory with modification time 2001-02-03 04:18:06.499999999 +0000 UTC 2026/08/10 01:42:50 DEBUG : Added delayed dir = "a1/b1", newDst= 2026/08/10 01:42:50 INFO : a1/b2: Making directory 2026/08/10 01:42:51 INFO : a1/b2: Made directory with modification time 2001-02-03 04:09:06.499999999 +0000 UTC 2026/08/10 01:42:51 DEBUG : Added delayed dir = "a1/b2", newDst= 2026/08/10 01:42:51 INFO : a1/b2/c1: Making directory 2026/08/10 01:42:51 INFO : a1/b1/c1: Making directory 2026/08/10 01:42:51 INFO : a1/b2/c1: Made directory with modification time 2001-02-03 04:08:06.499999999 +0000 UTC 2026/08/10 01:42:51 DEBUG : Added delayed dir = "a1/b2/c1", newDst= 2026/08/10 01:42:51 INFO : a1/b2/c1/d1: Making directory 2026/08/10 01:42:51 INFO : a1/b1/c1: Made directory with modification time 2001-02-03 04:17:06.499999999 +0000 UTC 2026/08/10 01:42:51 DEBUG : Added delayed dir = "a1/b1/c1", newDst= 2026/08/10 01:42:51 INFO : a1/b1/c1/d1: Making directory 2026/08/10 01:42:52 INFO : a1/b2/c1/d1: Made directory with modification time 2001-02-03 04:07:06.499999999 +0000 UTC 2026/08/10 01:42:52 DEBUG : Added delayed dir = "a1/b2/c1/d1", newDst= 2026/08/10 01:42:52 INFO : a1/b2/c1/d1/e1: Making directory 2026/08/10 01:42:52 INFO : a1/b1/c1/d1: Made directory with modification time 2001-02-03 04:16:06.499999999 +0000 UTC 2026/08/10 01:42:52 DEBUG : Added delayed dir = "a1/b1/c1/d1", newDst= 2026/08/10 01:42:52 INFO : a1/b1/c1/d2: Making directory 2026/08/10 01:42:52 INFO : a1/b2/c1/d1/e1: Made directory with modification time 2001-02-03 04:06:06.499999999 +0000 UTC 2026/08/10 01:42:52 DEBUG : Added delayed dir = "a1/b2/c1/d1/e1", newDst= 2026/08/10 01:42:52 INFO : a1/b2/c1/d1/e1/f1: Making directory 2026/08/10 01:42:52 INFO : a1/b1/c1/d2: Made directory with modification time 2001-02-03 04:13:06.499999999 +0000 UTC 2026/08/10 01:42:52 DEBUG : Added delayed dir = "a1/b1/c1/d2", newDst= 2026/08/10 01:42:52 INFO : a1/b1/c1/d1/e1: Making directory 2026/08/10 01:42:52 INFO : a1/b1/c1/d2/e1: Making directory 2026/08/10 01:42:52 INFO : a1/b2/c1/d1/e1/f1: Made directory with modification time 2001-02-03 04:05:06.499999999 +0000 UTC 2026/08/10 01:42:52 DEBUG : Added delayed dir = "a1/b2/c1/d1/e1/f1", newDst= 2026/08/10 01:42:52 INFO : a1/b1/c1/d2/e1: Made directory with modification time 2001-02-03 04:12:06.499999999 +0000 UTC 2026/08/10 01:42:52 DEBUG : Added delayed dir = "a1/b1/c1/d2/e1", newDst= 2026/08/10 01:42:52 INFO : a1/b1/c1/d2/e1/f1: Making directory 2026/08/10 01:42:53 INFO : a1/b1/c1/d1/e1: Made directory with modification time 2001-02-03 04:15:06.499999999 +0000 UTC 2026/08/10 01:42:53 DEBUG : Added delayed dir = "a1/b1/c1/d1/e1", newDst= 2026/08/10 01:42:53 INFO : a1/b1/c1/d1/e1/f1: Making directory 2026/08/10 01:42:53 INFO : a1/b1/c1/d2/e1/f1: Made directory with modification time 2001-02-03 04:11:06.499999999 +0000 UTC 2026/08/10 01:42:53 DEBUG : Added delayed dir = "a1/b1/c1/d2/e1/f1", newDst= 2026/08/10 01:42:53 INFO : a1/b1/c1/d2/e1/f2: Making directory 2026/08/10 01:42:53 INFO : a1/b1/c1/d1/e1/f1: Made directory with modification time 2001-02-03 04:14:06.499999999 +0000 UTC 2026/08/10 01:42:53 DEBUG : Added delayed dir = "a1/b1/c1/d1/e1/f1", newDst= 2026/08/10 01:42:53 INFO : a1/b1/c1/d2/e1/f2: Made directory with modification time 2001-02-03 04:10:06.499999999 +0000 UTC 2026/08/10 01:42:53 DEBUG : Added delayed dir = "a1/b1/c1/d2/e1/f2", newDst= 2026/08/10 01:42:53 DEBUG : files root 'rclone-test-topinal0pawo': Waiting for checks to finish 2026/08/10 01:42:53 DEBUG : files root 'rclone-test-topinal0pawo': Waiting for transfers to finish 2026/08/10 01:42:53 DEBUG : Waiting for deletions to finish 2026/08/10 01:42:53 INFO : a1/b1/c1/d2/e1/f2: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:53 INFO : a1/b2/c1/d1/e1/f1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:53 INFO : a1/b1/c1/d1/e1/f1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:53 INFO : a1/b1/c1/d2/e1/f1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:54 INFO : a1/b1/c1/d1/e1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:54 INFO : a1/b1/c1/d2/e1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:54 INFO : a1/b2/c1/d1/e1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:54 INFO : a1/b1/c1/d2: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:54 INFO : a1/b2/c1/d1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:54 INFO : a1/b1/c1/d1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:54 INFO : a1/b1/c1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:54 INFO : a1/b2/c1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:54 INFO : a1/b1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:54 INFO : a1/b2: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:54 INFO : a1: Set directory modification time (using DirSetModTime) 2026/08/10 01:42:59 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/a1/b2/c1/d1/e1 not empty`) 2026/08/10 01:42:59 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/10 01:42:59 DEBUG : pacer: Reducing sleep to 15ms 2026/08/10 01:42:59 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/a1/b2/c1/d1 not empty`) 2026/08/10 01:42:59 DEBUG : pacer: Rate limited, increasing sleep to 30ms 2026/08/10 01:42:59 DEBUG : pacer: Reducing sleep to 22.5ms 2026/08/10 01:43:00 DEBUG : pacer: Reducing sleep to 16.875ms 2026/08/10 01:43:00 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/a1/b2 not empty`) 2026/08/10 01:43:00 DEBUG : pacer: Rate limited, increasing sleep to 33.75ms 2026/08/10 01:43:00 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/a1/b2 not empty`) 2026/08/10 01:43:00 DEBUG : pacer: Rate limited, increasing sleep to 67.5ms 2026/08/10 01:43:00 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/a1/b2 not empty`) 2026/08/10 01:43:00 DEBUG : pacer: Rate limited, increasing sleep to 135ms 2026/08/10 01:43:00 DEBUG : pacer: Reducing sleep to 101.25ms 2026/08/10 01:43:00 DEBUG : pacer: Reducing sleep to 75.9375ms 2026/08/10 01:43:01 DEBUG : pacer: Reducing sleep to 56.953125ms 2026/08/10 01:43:01 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/a1/b1/c1/d2/e1 not empty`) 2026/08/10 01:43:01 DEBUG : pacer: Rate limited, increasing sleep to 113.90625ms 2026/08/10 01:43:01 DEBUG : pacer: Reducing sleep to 85.429687ms 2026/08/10 01:43:01 DEBUG : pacer: Reducing sleep to 64.072265ms 2026/08/10 01:43:01 DEBUG : pacer: Reducing sleep to 48.054198ms 2026/08/10 01:43:01 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/a1/b1/c1/d1/e1 not empty`) 2026/08/10 01:43:01 DEBUG : pacer: Rate limited, increasing sleep to 96.108396ms 2026/08/10 01:43:01 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/a1/b1/c1/d1/e1 not empty`) 2026/08/10 01:43:01 DEBUG : pacer: Rate limited, increasing sleep to 192.216792ms 2026/08/10 01:43:02 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/a1/b1/c1/d1/e1 not empty`) 2026/08/10 01:43:02 DEBUG : pacer: Rate limited, increasing sleep to 384.433584ms 2026/08/10 01:43:02 DEBUG : pacer: Reducing sleep to 288.325188ms 2026/08/10 01:43:02 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/a1/b1/c1/d1 not empty`) 2026/08/10 01:43:02 DEBUG : pacer: Rate limited, increasing sleep to 576.650376ms 2026/08/10 01:43:02 DEBUG : pacer: Reducing sleep to 432.487782ms 2026/08/10 01:43:03 DEBUG : pacer: Reducing sleep to 324.365836ms 2026/08/10 01:43:03 DEBUG : pacer: Reducing sleep to 243.274377ms 2026/08/10 01:43:04 DEBUG : pacer: Reducing sleep to 182.455782ms 2026/08/10 01:43:04 DEBUG : pacer: Reducing sleep to 136.841836ms --- PASS: TestSyncSetDelayedModTimes (14.43s) === RUN TestSyncNoEmptyDirectories run.go:198: Remote "files root 'rclone-test-topinal0pawo'", Local "Local file system at /tmp/rclone2709816778", Modify Window "1s" 2026/08/10 01:43:04 INFO : sub dir2: Making directory 2026/08/10 01:43:04 DEBUG : pacer: Reducing sleep to 102.631377ms 2026/08/10 01:43:04 DEBUG : Added delayed dir = "sub dir2", newDst= 2026/08/10 01:43:04 DEBUG : Added delayed dir = "sub dir", newDst= 2026/08/10 01:43:04 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2026/08/10 01:43:04 DEBUG : files root 'rclone-test-topinal0pawo': Waiting for checks to finish 2026/08/10 01:43:04 DEBUG : files root 'rclone-test-topinal0pawo': Waiting for transfers to finish 2026/08/10 01:43:05 DEBUG : pacer: Reducing sleep to 76.973532ms 2026/08/10 01:43:05 DEBUG : pacer: Reducing sleep to 57.730149ms 2026/08/10 01:43:06 DEBUG : pacer: Reducing sleep to 43.297611ms 2026/08/10 01:43:06 DEBUG : sub dir/hello world: size = 11 OK 2026/08/10 01:43:06 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK 2026/08/10 01:43:06 INFO : sub dir/hello world: Copied (new) 2026/08/10 01:43:06 DEBUG : Waiting for deletions to finish 2026/08/10 01:43:06 DEBUG : pacer: Reducing sleep to 32.473208ms 2026/08/10 01:43:06 INFO : sub dir: Set directory modification time (using DirSetModTime) 2026/08/10 01:43:06 DEBUG : pacer: Reducing sleep to 24.354906ms 2026/08/10 01:43:06 DEBUG : pacer: Reducing sleep to 18.266179ms 2026/08/10 01:43:06 DEBUG : pacer: Reducing sleep to 13.699634ms 2026/08/10 01:43:06 DEBUG : pacer: Reducing sleep to 10.274725ms 2026/08/10 01:43:06 DEBUG : pacer: Reducing sleep to 10ms --- PASS: TestSyncNoEmptyDirectories (2.72s) === RUN TestSyncBackupDirSuffixOnly run.go:198: Remote "files root 'rclone-test-topinal0pawo'", Local "Local file system at /tmp/rclone2709816778", Modify Window "1s" 2026/08/10 01:43:10 DEBUG : Creating backend with remote "TestFilesCom:rclone-test-topinal0pawo/dst" 2026/08/10 01:43:11 DEBUG : one: size = 4 (Local file system at /tmp/rclone2709816778) 2026/08/10 01:43:11 DEBUG : one: size = 3 (files root 'rclone-test-topinal0pawo/dst') 2026/08/10 01:43:11 DEBUG : one: Sizes differ 2026/08/10 01:43:11 DEBUG : two: size = 3 OK 2026/08/10 01:43:11 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2026/08/10 01:43:11 DEBUG : two: Unchanged skipping 2026/08/10 01:43:11 DEBUG : files root 'rclone-test-topinal0pawo/dst': Waiting for checks to finish 2026/08/10 01:43:12 INFO : one: Moved (server-side) to: one.bak 2026/08/10 01:43:12 DEBUG : files root 'rclone-test-topinal0pawo/dst': Waiting for transfers to finish 2026/08/10 01:43:14 DEBUG : one: size = 4 OK 2026/08/10 01:43:14 DEBUG : one: md5 = c7957179c41f69d44f217a108c7915d8 OK 2026/08/10 01:43:14 INFO : one: Copied (new) 2026/08/10 01:43:14 DEBUG : Waiting for deletions to finish 2026/08/10 01:43:14 INFO : three.txt: Moved (server-side) to: three.txt.bak 2026/08/10 01:43:14 INFO : three.txt: Moved into backup dir 2026/08/10 01:43:15 DEBUG : pacer: low level retry 1/10 (error Put "https://s3.amazonaws.com/objects.brickftp.com/metadata/126732/90e059d4-8917-4b76-b778-c3d637db424c?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=AKIAU5E2BGFBKFOVPYNZ%2F20260810%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20260810T014315Z&X-Amz-Expires=900&X-Amz-SignedHeaders=host&partNumber=1&response-content-type=application%2Foctet-stream&uploadId=p0wrOkG5Yqidj5QUD_z5q4_7HrwbMYq2xTjXQAq.CJfukIqw6TMAjvlTl8uxSj9Ye8gTU1UTZJZqXw9joewpZa_O9rFhQcO6qPW5aymsI4DShr_K5SMZPs.4qZU7lJAc&X-Amz-Signature=f84bb3d0308fae18938c6de018190af32f3f40dc36e8a6606556a5ea3f3d910c": EOF) 2026/08/10 01:43:15 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/10 01:43:17 DEBUG : pacer: Reducing sleep to 15ms 2026/08/10 01:43:17 DEBUG : pacer: Reducing sleep to 11.25ms 2026/08/10 01:43:17 DEBUG : pacer: Reducing sleep to 10ms fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:298: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:305: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:358 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2435 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2470 /usr/local/go/src/runtime/asm_amd64.s:1771 Error: Should be true Test: TestSyncBackupDirSuffixOnly Messages: listing wrong, want dst/one (4), dst/one.bak (3), dst/three.txt (6), dst/three.txt.bak (5), dst/two (3) got dst/one (4), dst/one.bak (3), dst/three.txt (0), dst/three.txt.bak (5), dst/two (3) fstest.go:143: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:143 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:149 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:195 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:358 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2435 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2470 Error: Should be true Test: TestSyncBackupDirSuffixOnly Messages: files root 'rclone-test-topinal0pawo'/dst/three.txt: md5 hash incorrect - expecting "91341eed84691a83caea73aa785736d5" got "d41d8cd98f00b204e9800998ecf8427e" fstest.go:143: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:143 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:149 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:195 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:358 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2435 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2470 Error: Should be true Test: TestSyncBackupDirSuffixOnly Messages: files root 'rclone-test-topinal0pawo'/dst/three.txt: crc32 hash incorrect - expecting "1e485dc0" got "00000000" fstest.go:150: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:150 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:195 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:358 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2435 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2470 Error: Not equal: expected: 6 actual : 0 Test: TestSyncBackupDirSuffixOnly Messages: dst/three.txt: size incorrect file=6 vs obj=0 2026/08/10 01:43:26 DEBUG : one.bak: Excluded (Path Filter) 2026/08/10 01:43:26 DEBUG : one.bak: Excluded 2026/08/10 01:43:26 DEBUG : three.txt.bak: Excluded (Path Filter) 2026/08/10 01:43:26 DEBUG : three.txt.bak: Excluded 2026/08/10 01:43:26 DEBUG : one: size = 5 (Local file system at /tmp/rclone2709816778) 2026/08/10 01:43:26 DEBUG : two: size = 3 OK 2026/08/10 01:43:26 DEBUG : one: size = 4 (files root 'rclone-test-topinal0pawo/dst') 2026/08/10 01:43:26 DEBUG : one: Sizes differ 2026/08/10 01:43:26 DEBUG : two: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2026/08/10 01:43:26 DEBUG : two: Unchanged skipping 2026/08/10 01:43:26 DEBUG : files root 'rclone-test-topinal0pawo/dst': Waiting for checks to finish 2026/08/10 01:43:26 INFO : one.bak: Deleted 2026/08/10 01:43:27 INFO : one: Moved (server-side) to: one.bak 2026/08/10 01:43:27 DEBUG : files root 'rclone-test-topinal0pawo/dst': Waiting for transfers to finish 2026/08/10 01:43:28 DEBUG : one: size = 5 OK 2026/08/10 01:43:28 DEBUG : one: md5 = 0f93e81041f0cab37c37a05ae998b219 OK 2026/08/10 01:43:28 INFO : one: Copied (new) 2026/08/10 01:43:28 DEBUG : Waiting for deletions to finish 2026/08/10 01:43:29 INFO : three.txt.bak: Deleted 2026/08/10 01:43:29 INFO : three.txt: Moved (server-side) to: three.txt.bak 2026/08/10 01:43:29 INFO : three.txt: Moved into backup dir fstest.go:298: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:298: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:298: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:305: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:305 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:358 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2454 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2470 /usr/local/go/src/runtime/asm_amd64.s:1771 Error: Should be true Test: TestSyncBackupDirSuffixOnly Messages: listing wrong, want dst/one (5), dst/one.bak (4), dst/three.txt.bak (6), dst/two (3) got dst/one (5), dst/one.bak (4), dst/three.txt.bak (0), dst/two (3) fstest.go:143: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:143 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:149 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:195 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:358 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2454 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2470 Error: Should be true Test: TestSyncBackupDirSuffixOnly Messages: files root 'rclone-test-topinal0pawo'/dst/three.txt.bak: md5 hash incorrect - expecting "91341eed84691a83caea73aa785736d5" got "d41d8cd98f00b204e9800998ecf8427e" fstest.go:143: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:143 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:149 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:195 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:358 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2454 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2470 Error: Should be true Test: TestSyncBackupDirSuffixOnly Messages: files root 'rclone-test-topinal0pawo'/dst/three.txt.bak: crc32 hash incorrect - expecting "1e485dc0" got "00000000" fstest.go:150: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:150 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:195 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:308 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:338 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:350 /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:358 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2454 /home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2470 Error: Not equal: expected: 6 actual : 0 Test: TestSyncBackupDirSuffixOnly Messages: dst/three.txt.bak: size incorrect file=6 vs obj=0 --- FAIL: TestSyncBackupDirSuffixOnly (33.56s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:198: Remote "files root 'rclone-test-topinal0pawo'", Local "Local file system at /tmp/rclone2709816778", Modify Window "1s" 2026/08/10 01:43:40 INFO : sub dir: Set directory modification time (using DirSetModTime) 2026/08/10 01:43:40 INFO : sub dir: Making directory 2026/08/10 01:43:41 INFO : sub dir: Made directory with modification time 2011-12-30 12:59:59 +0000 UTC 2026/08/10 01:43:49 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2026/08/10 01:43:49 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2026/08/10 01:43:49 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2026/08/10 01:43:49 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) 2026/08/10 01:43:55 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/sub dir2/very/very/very/very/very/nested not empty`) 2026/08/10 01:43:55 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2026/08/10 01:43:55 DEBUG : pacer: Reducing sleep to 15ms 2026/08/10 01:43:55 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/sub dir2/very/very/very/very/very not empty`) 2026/08/10 01:43:55 DEBUG : pacer: Rate limited, increasing sleep to 30ms 2026/08/10 01:43:55 DEBUG : pacer: Reducing sleep to 22.5ms 2026/08/10 01:43:55 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/sub dir2/very/very/very/very not empty`) 2026/08/10 01:43:55 DEBUG : pacer: Rate limited, increasing sleep to 45ms 2026/08/10 01:43:55 DEBUG : pacer: Reducing sleep to 33.75ms 2026/08/10 01:43:56 DEBUG : pacer: Reducing sleep to 25.3125ms 2026/08/10 01:43:56 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/sub dir2/very/very not empty`) 2026/08/10 01:43:56 DEBUG : pacer: Rate limited, increasing sleep to 50.625ms 2026/08/10 01:43:56 DEBUG : pacer: Reducing sleep to 37.96875ms 2026/08/10 01:43:56 DEBUG : pacer: Reducing sleep to 28.476562ms 2026/08/10 01:43:56 DEBUG : pacer: Reducing sleep to 21.357421ms 2026/08/10 01:43:57 DEBUG : pacer: low level retry 1/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/sub dir2 not empty`) 2026/08/10 01:43:57 DEBUG : pacer: Rate limited, increasing sleep to 42.714842ms 2026/08/10 01:43:57 DEBUG : pacer: low level retry 2/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/sub dir2 not empty`) 2026/08/10 01:43:57 DEBUG : pacer: Rate limited, increasing sleep to 85.429684ms 2026/08/10 01:43:57 DEBUG : pacer: low level retry 3/10 (error Folder Not Empty - `Folder rclone-test-topinal0pawo/sub dir2 not empty`) 2026/08/10 01:43:57 DEBUG : pacer: Rate limited, increasing sleep to 170.859368ms 2026/08/10 01:43:57 DEBUG : pacer: Reducing sleep to 128.144526ms 2026/08/10 01:43:57 DEBUG : pacer: Reducing sleep to 96.108394ms 2026/08/10 01:43:57 DEBUG : pacer: Reducing sleep to 72.081295ms --- PASS: TestNothingToTransferWithoutEmptyDirs (16.93s) FAIL 2026/08/10 01:43:57 DEBUG : files root 'rclone-test-topinal0pawo': Purge remote 2026/08/10 01:43:57 DEBUG : pacer: Reducing sleep to 54.060971ms "./sync.test -test.v -test.timeout 1h0m0s -remote TestFilesCom: -verbose -test.run '^(TestCopyNoEmptyDirectories|TestNothingToTransferWithoutEmptyDirs|TestSyncBackupDirSuffixOnly|TestSyncEmptyDirectories|TestSyncNoEmptyDirectories|TestSyncNoUpdateDirModtime|TestSyncSetDelayedModTimes)$'" - Finished ERROR in 1m17.295801884s (try 2/5): exit status 1: Failed [TestSyncBackupDirSuffixOnly]