"./sync.test -test.v -test.timeout 1h0m0s -remote TestGoFile: -verbose -test.run '^(TestCopyWithDryRun|TestServerSideCopy|TestSyncNoEmptyDirectories|TestSyncNoUpdateDirModtime|TestSyncSetDelayedModTimes)$'" - Starting (try 2/5)
2026/05/22 03:25:08 DEBUG : Creating backend with remote "TestGoFile:rclone-test-badukec4piza"
2026/05/22 03:25:08 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/05/22 03:25:08 DEBUG : Creating backend with remote "/tmp/rclone3261519041"
=== RUN   TestCopyWithDryRun
    run.go:198: Remote "gofile root 'rclone-test-badukec4piza'", Local "Local file system at /tmp/rclone3261519041", Modify Window "1s"
2026/05/22 03:25:08 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2026/05/22 03:25:08 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/05/22 03:25:08 DEBUG : gofile root 'rclone-test-badukec4piza': Waiting for checks to finish
2026/05/22 03:25:08 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11)
2026/05/22 03:25:08 DEBUG : gofile root 'rclone-test-badukec4piza': Waiting for transfers to finish
2026/05/22 03:25:08 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set
--- PASS: TestCopyWithDryRun (0.48s)
=== RUN   TestSyncNoUpdateDirModtime
    run.go:198: Remote "gofile root 'rclone-test-badukec4piza'", Local "Local file system at /tmp/rclone3261519041", Modify Window "1s"
2026/05/22 03:25:09 DEBUG : sub dir no update dir modtime: Making directory with metadata
2026/05/22 03:25:09 INFO  : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z)
2026/05/22 03:25:09 DEBUG : gofile root 'rclone-test-badukec4piza': Waiting for checks to finish
2026/05/22 03:25:09 DEBUG : gofile root 'rclone-test-badukec4piza': Waiting for transfers to finish
2026/05/22 03:25:09 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncNoUpdateDirModtime (0.78s)
=== RUN   TestSyncSetDelayedModTimes
    run.go:198: Remote "gofile root 'rclone-test-badukec4piza'", Local "Local file system at /tmp/rclone3261519041", Modify Window "1s"
2026/05/22 03:25:09 INFO  : a1/b2/c1/d1/e1/f1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:09 INFO  : a1/b2/c1/d1/e1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:09 INFO  : a1/b2/c1/d1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:09 INFO  : a1/b2/c1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:09 INFO  : a1/b2: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:09 INFO  : a1/b1/c1/d2/e1/f2: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:09 INFO  : a1/b1/c1/d2/e1/f1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:09 INFO  : a1/b1/c1/d2/e1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:09 INFO  : a1/b1/c1/d2: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:09 INFO  : a1/b1/c1/d1/e1/f1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:09 INFO  : a1/b1/c1/d1/e1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:09 INFO  : a1/b1/c1/d1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:09 INFO  : a1/b1/c1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:09 INFO  : a1/b1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:09 INFO  : a1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:09 INFO  : a1: Making directory
2026/05/22 03:25:10 INFO  : a1: Made directory with modification time 2001-02-03 04:19:06.499999999 +0000 UTC
2026/05/22 03:25:10 DEBUG : Added delayed dir = "a1", newDst=<nil>
2026/05/22 03:25:10 INFO  : a1/b1: Making directory
2026/05/22 03:25:10 INFO  : a1/b1: Made directory with modification time 2001-02-03 04:18:06.499999999 +0000 UTC
2026/05/22 03:25:10 DEBUG : Added delayed dir = "a1/b1", newDst=<nil>
2026/05/22 03:25:10 INFO  : a1/b2: Making directory
2026/05/22 03:25:10 INFO  : a1/b2: Made directory with modification time 2001-02-03 04:09:06.499999999 +0000 UTC
2026/05/22 03:25:10 DEBUG : Added delayed dir = "a1/b2", newDst=<nil>
2026/05/22 03:25:10 INFO  : a1/b2/c1: Making directory
2026/05/22 03:25:10 INFO  : a1/b1/c1: Making directory
2026/05/22 03:25:10 INFO  : a1/b2/c1: Made directory with modification time 2001-02-03 04:08:06.499999999 +0000 UTC
2026/05/22 03:25:10 DEBUG : Added delayed dir = "a1/b2/c1", newDst=<nil>
2026/05/22 03:25:10 INFO  : a1/b2/c1/d1: Making directory
2026/05/22 03:25:11 INFO  : a1/b1/c1: Made directory with modification time 2001-02-03 04:17:06.499999999 +0000 UTC
2026/05/22 03:25:11 DEBUG : Added delayed dir = "a1/b1/c1", newDst=<nil>
2026/05/22 03:25:11 INFO  : a1/b1/c1/d1: Making directory
2026/05/22 03:25:11 INFO  : a1/b2/c1/d1: Made directory with modification time 2001-02-03 04:07:06.499999999 +0000 UTC
2026/05/22 03:25:11 DEBUG : Added delayed dir = "a1/b2/c1/d1", newDst=<nil>
2026/05/22 03:25:11 INFO  : a1/b2/c1/d1/e1: Making directory
2026/05/22 03:25:11 INFO  : a1/b2/c1/d1/e1: Made directory with modification time 2001-02-03 04:06:06.499999999 +0000 UTC
2026/05/22 03:25:11 DEBUG : Added delayed dir = "a1/b2/c1/d1/e1", newDst=<nil>
2026/05/22 03:25:11 INFO  : a1/b2/c1/d1/e1/f1: Making directory
2026/05/22 03:25:11 INFO  : a1/b1/c1/d1: Made directory with modification time 2001-02-03 04:16:06.499999999 +0000 UTC
2026/05/22 03:25:11 DEBUG : Added delayed dir = "a1/b1/c1/d1", newDst=<nil>
2026/05/22 03:25:11 INFO  : a1/b1/c1/d2: Making directory
2026/05/22 03:25:11 INFO  : a1/b2/c1/d1/e1/f1: Made directory with modification time 2001-02-03 04:05:06.499999999 +0000 UTC
2026/05/22 03:25:11 DEBUG : Added delayed dir = "a1/b2/c1/d1/e1/f1", newDst=<nil>
2026/05/22 03:25:11 INFO  : a1/b1/c1/d2: Made directory with modification time 2001-02-03 04:13:06.499999999 +0000 UTC
2026/05/22 03:25:11 DEBUG : Added delayed dir = "a1/b1/c1/d2", newDst=<nil>
2026/05/22 03:25:11 INFO  : a1/b1/c1/d2/e1: Making directory
2026/05/22 03:25:11 INFO  : a1/b1/c1/d1/e1: Making directory
2026/05/22 03:25:12 INFO  : a1/b1/c1/d2/e1: Made directory with modification time 2001-02-03 04:12:06.499999999 +0000 UTC
2026/05/22 03:25:12 DEBUG : Added delayed dir = "a1/b1/c1/d2/e1", newDst=<nil>
2026/05/22 03:25:12 INFO  : a1/b1/c1/d2/e1/f1: Making directory
2026/05/22 03:25:12 INFO  : a1/b1/c1/d1/e1: Made directory with modification time 2001-02-03 04:15:06.499999999 +0000 UTC
2026/05/22 03:25:12 DEBUG : Added delayed dir = "a1/b1/c1/d1/e1", newDst=<nil>
2026/05/22 03:25:12 INFO  : a1/b1/c1/d1/e1/f1: Making directory
2026/05/22 03:25:12 INFO  : a1/b1/c1/d1/e1/f1: Made directory with modification time 2001-02-03 04:14:06.499999999 +0000 UTC
2026/05/22 03:25:12 DEBUG : Added delayed dir = "a1/b1/c1/d1/e1/f1", newDst=<nil>
2026/05/22 03:25:12 INFO  : a1/b1/c1/d2/e1/f1: Made directory with modification time 2001-02-03 04:11:06.499999999 +0000 UTC
2026/05/22 03:25:12 DEBUG : Added delayed dir = "a1/b1/c1/d2/e1/f1", newDst=<nil>
2026/05/22 03:25:12 INFO  : a1/b1/c1/d2/e1/f2: Making directory
2026/05/22 03:25:13 INFO  : a1/b1/c1/d2/e1/f2: Made directory with modification time 2001-02-03 04:10:06.499999999 +0000 UTC
2026/05/22 03:25:13 DEBUG : Added delayed dir = "a1/b1/c1/d2/e1/f2", newDst=<nil>
2026/05/22 03:25:13 DEBUG : gofile root 'rclone-test-badukec4piza': Waiting for checks to finish
2026/05/22 03:25:13 DEBUG : gofile root 'rclone-test-badukec4piza': Waiting for transfers to finish
2026/05/22 03:25:13 DEBUG : Waiting for deletions to finish
2026/05/22 03:25:13 INFO  : a1/b1/c1/d2/e1/f2: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:13 INFO  : a1/b1/c1/d1/e1/f1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:13 INFO  : a1/b1/c1/d2/e1/f1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:13 INFO  : a1/b2/c1/d1/e1/f1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:13 INFO  : a1/b1/c1/d1/e1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:13 INFO  : a1/b2/c1/d1/e1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:13 INFO  : a1/b1/c1/d2/e1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:13 INFO  : a1/b1/c1/d2: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:13 INFO  : a1/b2/c1/d1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:13 INFO  : a1/b1/c1/d1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:13 INFO  : a1/b1/c1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:14 INFO  : a1/b2/c1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:14 INFO  : a1/b2: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:14 INFO  : a1/b1: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:14 INFO  : a1: Set directory modification time (using DirSetModTime)
--- PASS: TestSyncSetDelayedModTimes (11.47s)
=== RUN   TestSyncNoEmptyDirectories
    run.go:198: Remote "gofile root 'rclone-test-badukec4piza'", Local "Local file system at /tmp/rclone3261519041", Modify Window "1s"
2026/05/22 03:25:21 INFO  : sub dir2: Making directory
2026/05/22 03:25:21 DEBUG : Added delayed dir = "sub dir2", newDst=<nil>
2026/05/22 03:25:21 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2026/05/22 03:25:21 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/05/22 03:25:21 DEBUG : gofile root 'rclone-test-badukec4piza': Waiting for checks to finish
2026/05/22 03:25:21 DEBUG : gofile root 'rclone-test-badukec4piza': Waiting for transfers to finish
2026/05/22 03:25:22 DEBUG : sub dir/hello world: size = 11 OK
2026/05/22 03:25:22 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK
2026/05/22 03:25:22 INFO  : sub dir/hello world: Copied (new)
2026/05/22 03:25:22 DEBUG : Waiting for deletions to finish
2026/05/22 03:25:22 INFO  : sub dir: Set directory modification time (using DirSetModTime)
--- PASS: TestSyncNoEmptyDirectories (1.63s)
=== RUN   TestServerSideCopy
    run.go:198: Remote "gofile root 'rclone-test-badukec4piza'", Local "Local file system at /tmp/rclone3261519041", Modify Window "1s"
2026/05/22 03:25:24 DEBUG : Creating backend with remote "TestGoFile:rclone-test-nuzequm8yedo"
    sync_test.go:620: Server side copy (if possible) gofile root 'rclone-test-badukec4piza' -> gofile root 'rclone-test-nuzequm8yedo'
2026/05/22 03:25:24 DEBUG : Added delayed dir = "sub dir", newDst=<nil>
2026/05/22 03:25:24 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination
2026/05/22 03:25:24 DEBUG : gofile root 'rclone-test-nuzequm8yedo': Waiting for checks to finish
2026/05/22 03:25:24 DEBUG : gofile root 'rclone-test-nuzequm8yedo': Waiting for transfers to finish
2026/05/22 03:25:25 DEBUG : sub dir/hello world: size = 11 OK
2026/05/22 03:25:25 DEBUG : sub dir/hello world: md5 = 5eb63bbbe01eeed093cb22bb8f5acdc3 OK
2026/05/22 03:25:25 INFO  : sub dir/hello world: Copied (server-side copy)
2026/05/22 03:25:25 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2026/05/22 03:25:25 DEBUG : gofile root 'rclone-test-nuzequm8yedo': Purge remote
--- PASS: TestServerSideCopy (3.36s)
PASS
2026/05/22 03:25:26 DEBUG : gofile root 'rclone-test-badukec4piza': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestGoFile: -verbose -test.run '^(TestCopyWithDryRun|TestServerSideCopy|TestSyncNoEmptyDirectories|TestSyncNoUpdateDirModtime|TestSyncSetDelayedModTimes)$'" - Finished OK in 18.162416158s (try 2/5)