"./sync.test -test.v -test.timeout 1h0m0s -remote TestPixeldrain: -verbose -test.run '^(TestNothingToTransferWithEmptyDirs|TestSyncBackupDirWithSuffixKeepExtension)$'" - Starting (try 3/5)
2026/07/11 04:03:18 DEBUG : Creating backend with remote "TestPixeldrain:rclone-test-fuvibut9leti"
2026/07/11 04:03:18 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/07/11 04:03:18 INFO  : pixeldrain root 'rclone-test-fuvibut9leti': Logged in as 'ncw', subscription 'Prepaid', storage limit -1
2026/07/11 04:03:18 DEBUG : Creating backend with remote "/tmp/rclone1660999301"
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
    run.go:198: Remote "pixeldrain root 'rclone-test-fuvibut9leti'", Local "Local file system at /tmp/rclone1660999301", Modify Window "1ms"
2026/07/11 04:03:18 DEBUG : Creating backend with remote "TestPixeldrain:rclone-test-fuvibut9leti/dst"
2026/07/11 04:03:18 INFO  : pixeldrain root 'rclone-test-fuvibut9leti/dst': Logged in as 'ncw', subscription 'Prepaid', storage limit -1
2026/07/11 04:03:18 DEBUG : Creating backend with remote "TestPixeldrain:rclone-test-fuvibut9leti/backup"
2026/07/11 04:03:18 INFO  : pixeldrain root 'rclone-test-fuvibut9leti/backup': Logged in as 'ncw', subscription 'Prepaid', storage limit -1
2026/07/11 04:03:18 DEBUG : one: size = 4 (Local file system at /tmp/rclone1660999301)
2026/07/11 04:03:18 DEBUG : one: size = 3 (pixeldrain root 'rclone-test-fuvibut9leti/dst')
2026/07/11 04:03:18 DEBUG : one: Sizes differ
2026/07/11 04:03:18 DEBUG : pixeldrain root 'rclone-test-fuvibut9leti/dst': Waiting for checks to finish
2026/07/11 04:03:18 DEBUG : two: size = 3 OK
2026/07/11 04:03:18 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2026/07/11 04:03:18 DEBUG : two: Unchanged skipping
2026/07/11 04:03:18 INFO  : one: Moved (server-side) to: one-2019-01-01
2026/07/11 04:03:18 DEBUG : pixeldrain root 'rclone-test-fuvibut9leti/dst': Waiting for transfers to finish
2026/07/11 04:03:18 DEBUG : one: size = 4 OK
2026/07/11 04:03:18 DEBUG : one: sha256 = adefbbf0dff80800a3eb8cd37fa8160a530c6ab1fed4f44001b69139c5177a93 OK
2026/07/11 04:03:18 INFO  : one: Copied (new)
2026/07/11 04:03:18 DEBUG : Waiting for deletions to finish
2026/07/11 04:03:19 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2026/07/11 04:03:19 INFO  : three.txt: Moved into backup dir
2026/07/11 04:03:19 DEBUG : one: size = 5 (Local file system at /tmp/rclone1660999301)
2026/07/11 04:03:19 DEBUG : one: size = 4 (pixeldrain root 'rclone-test-fuvibut9leti/dst')
2026/07/11 04:03:19 DEBUG : one: Sizes differ
2026/07/11 04:03:19 DEBUG : pixeldrain root 'rclone-test-fuvibut9leti/dst': Waiting for checks to finish
2026/07/11 04:03:19 DEBUG : two: size = 3 OK
2026/07/11 04:03:19 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2026/07/11 04:03:19 DEBUG : two: Unchanged skipping
2026/07/11 04:03:19 INFO  : one-2019-01-01: Deleted
2026/07/11 04:03:19 INFO  : one: Moved (server-side) to: one-2019-01-01
2026/07/11 04:03:19 DEBUG : pixeldrain root 'rclone-test-fuvibut9leti/dst': Waiting for transfers to finish
2026/07/11 04:03:19 DEBUG : one: size = 5 OK
2026/07/11 04:03:19 DEBUG : one: sha256 = 517b021836359b3420b6082b5b16f379079452b9e0ac97b88ae86c6c757ee7b8 OK
2026/07/11 04:03:19 INFO  : one: Copied (new)
2026/07/11 04:03:19 DEBUG : Waiting for deletions to finish
2026/07/11 04:03:19 INFO  : three-2019-01-01.txt: Deleted
2026/07/11 04:03:19 INFO  : three.txt: Moved (server-side) to: three-2019-01-01.txt
2026/07/11 04:03:19 INFO  : three.txt: Moved into backup dir
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (1.36s)
=== RUN   TestNothingToTransferWithEmptyDirs
    run.go:198: Remote "pixeldrain root 'rclone-test-fuvibut9leti'", Local "Local file system at /tmp/rclone1660999301", Modify Window "1ms"
2026/07/11 04:03:19 INFO  : sub dir: Set directory modification time (using DirSetModTime)
2026/07/11 04:03:19 INFO  : sub dir: Making directory
2026/07/11 04:03:19 INFO  : sub dir: Made directory with modification time 2011-12-30 12:59:59 +0000 UTC
    fstest.go:127: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:127
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:639
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:391
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2906
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2977
        	Error:      	Should be true
        	Test:       	TestNothingToTransferWithEmptyDirs
        	Messages:   	sub dir2/very: Modification time difference too big |-167.029197ms| > 1ms (want 2026-07-11 04:03:19.796970803 +0000 UTC vs got 2026-07-11 04:03:19.964 +0000 UTC) (precision 1ms)
    fstest.go:127: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:127
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:639
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:391
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2906
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2977
        	Error:      	Should be true
        	Test:       	TestNothingToTransferWithEmptyDirs
        	Messages:   	sub dir2/very/very: Modification time difference too big |-227.029197ms| > 1ms (want 2026-07-11 04:03:19.796970803 +0000 UTC vs got 2026-07-11 04:03:20.024 +0000 UTC) (precision 1ms)
    fstest.go:127: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:127
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:639
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:391
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2906
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2977
        	Error:      	Should be true
        	Test:       	TestNothingToTransferWithEmptyDirs
        	Messages:   	sub dir2/very/very/very/very/very/nested/subdir: Modification time difference too big |-538.029196ms| > 1ms (want 2026-07-11 04:03:19.797970804 +0000 UTC vs got 2026-07-11 04:03:20.336 +0000 UTC) (precision 1ms)
    sync_test.go:2933: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2933
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2977
        	Error:      	Should be false
        	Test:       	TestNothingToTransferWithEmptyDirs
        	Messages:   	expected to find no "Set directory modification time" logs, but found one: 2026/07/11 04:03:20 INFO  : sub dir2/very: Set directory modification time (using DirSetModTime)
        	            	2026/07/11 04:03:21 INFO  : sub dir2/very/very: Set directory modification time (using DirSetModTime)
        	            	2026/07/11 04:03:21 INFO  : sub dir2/very/very/very: Set directory modification time (using DirSetModTime)
        	            	2026/07/11 04:03:21 INFO  : sub dir2/very/very/very/very: Set directory modification time (using DirSetModTime)
        	            	2026/07/11 04:03:21 INFO  : sub dir2/very/very/very/very/very: Set directory modification time (using DirSetModTime)
        	            	2026/07/11 04:03:21 INFO  : sub dir2/very/very/very/very/very/nested/subdir: Set directory modification time (using DirSetModTime)
        	            	2026/07/11 04:03:21 INFO  : There was nothing to transfer
    sync_test.go:2935: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2935
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2977
        	Error:      	Should be false
        	Test:       	TestNothingToTransferWithEmptyDirs
        	Messages:   	expected to find no "directory"-related logs, but found one: 2026/07/11 04:03:20 INFO  : sub dir2/very: Set directory modification time (using DirSetModTime)
        	            	2026/07/11 04:03:21 INFO  : sub dir2/very/very: Set directory modification time (using DirSetModTime)
        	            	2026/07/11 04:03:21 INFO  : sub dir2/very/very/very: Set directory modification time (using DirSetModTime)
        	            	2026/07/11 04:03:21 INFO  : sub dir2/very/very/very/very: Set directory modification time (using DirSetModTime)
        	            	2026/07/11 04:03:21 INFO  : sub dir2/very/very/very/very/very: Set directory modification time (using DirSetModTime)
        	            	2026/07/11 04:03:21 INFO  : sub dir2/very/very/very/very/very/nested/subdir: Set directory modification time (using DirSetModTime)
        	            	2026/07/11 04:03:21 INFO  : There was nothing to transfer
2026/07/11 04:03:21 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2026/07/11 04:03:21 INFO  : sub dir2: Set directory modification time (using DirSetModTime)
2026/07/11 04:03:21 INFO  : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z)
2026/07/11 04:03:21 INFO  : sub dirEmpty: Set directory modification time (using DirSetModTime)
    fstest.go:127: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:127
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:639
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:391
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2965
        	            				/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync_test.go:2977
        	Error:      	Should be true
        	Test:       	TestNothingToTransferWithEmptyDirs
        	Messages:   	sub dir2/sub dir3: Modification time difference too big |-134.026779ms| > 1ms (want 2026-07-11 04:03:21.732973221 +0000 UTC vs got 2026-07-11 04:03:21.867 +0000 UTC) (precision 1ms)
--- FAIL: TestNothingToTransferWithEmptyDirs (3.62s)
FAIL
2026/07/11 04:03:23 DEBUG : pixeldrain root 'rclone-test-fuvibut9leti': Purge remote
"./sync.test -test.v -test.timeout 1h0m0s -remote TestPixeldrain: -verbose -test.run '^(TestNothingToTransferWithEmptyDirs|TestSyncBackupDirWithSuffixKeepExtension)$'" - Finished ERROR in 5.181218958s (try 3/5): exit status 1: Failed [TestNothingToTransferWithEmptyDirs]