"./bisync.test -test.v -test.timeout 1h0m0s -remote TestGoFile: -verbose -test.run '^TestBisyncRemoteLocal$/^all_changed$'" - Starting (try 2/5)
2026/06/08 06:52:22 DEBUG : Creating backend with remote "TestGoFile:rclone-test-mecosek4qewa"
2026/06/08 06:52:22 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2026/06/08 06:52:23 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:52:23 DEBUG : pacer: low level retry 1/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:52:23 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/06/08 06:52:23 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:52:23 DEBUG : pacer: low level retry 2/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:52:23 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/06/08 06:52:24 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:52:24 DEBUG : pacer: low level retry 3/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:52:24 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2026/06/08 06:52:24 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:52:24 DEBUG : pacer: low level retry 4/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:52:24 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/06/08 06:52:24 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:52:24 DEBUG : pacer: low level retry 5/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:52:24 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2026/06/08 06:52:24 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:52:24 DEBUG : pacer: low level retry 6/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:52:24 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/06/08 06:52:25 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:52:25 DEBUG : pacer: low level retry 7/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:52:25 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2026/06/08 06:52:26 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:52:26 DEBUG : pacer: low level retry 8/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:52:26 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2026/06/08 06:52:27 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:52:27 DEBUG : pacer: low level retry 9/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:52:27 DEBUG : pacer: Rate limited, increasing sleep to 5.12s
2026/06/08 06:52:29 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:52:29 DEBUG : pacer: low level retry 10/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:52:29 DEBUG : pacer: Rate limited, increasing sleep to 10.24s
2026/06/08 06:52:35 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:52:35 DEBUG : pacer: low level retry 1/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:52:35 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/06/08 06:52:45 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:52:45 DEBUG : pacer: low level retry 2/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:05 DEBUG : pacer: Reducing sleep to 10s
2026/06/08 06:53:05 DEBUG : Creating backend with remote "/tmp/rclone1368920679"
=== RUN TestBisyncRemoteLocal
2026/06/08 06:53:05 DEBUG : Creating backend with remote "TestGoFile:rclone-test-fusekis0vilu"
2026/06/08 06:53:17 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:17 DEBUG : pacer: low level retry 1/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:17 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/06/08 06:53:18 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:18 DEBUG : pacer: low level retry 2/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:18 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/06/08 06:53:18 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:18 DEBUG : pacer: low level retry 3/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:18 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2026/06/08 06:53:18 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:18 DEBUG : pacer: low level retry 4/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:18 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/06/08 06:53:18 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:18 DEBUG : pacer: low level retry 5/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:18 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2026/06/08 06:53:19 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:19 DEBUG : pacer: low level retry 6/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:19 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/06/08 06:53:19 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:19 DEBUG : pacer: low level retry 7/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:19 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2026/06/08 06:53:20 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:20 DEBUG : pacer: low level retry 8/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:20 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2026/06/08 06:53:21 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:21 DEBUG : pacer: low level retry 9/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:21 DEBUG : pacer: Rate limited, increasing sleep to 5.12s
2026/06/08 06:53:24 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:24 DEBUG : pacer: low level retry 10/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:24 DEBUG : pacer: Rate limited, increasing sleep to 10.24s
2026/06/08 06:53:29 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:29 DEBUG : pacer: low level retry 1/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:29 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/06/08 06:53:39 DEBUG : pacer: Reducing sleep to 10s
2026/06/08 06:53:39 NOTICE: remote: TestGoFile:rclone-test-fusekis0vilu
=== RUN TestBisyncRemoteLocal/all_changed
2026/06/08 06:53:39 DEBUG : Creating backend with remote "TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0"
2026/06/08 06:53:41 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:41 DEBUG : pacer: low level retry 1/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:41 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/06/08 06:53:42 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:42 DEBUG : pacer: low level retry 2/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:42 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/06/08 06:53:42 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:42 DEBUG : pacer: low level retry 3/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:42 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2026/06/08 06:53:43 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:43 DEBUG : pacer: low level retry 4/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:43 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/06/08 06:53:43 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:43 DEBUG : pacer: low level retry 5/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:43 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2026/06/08 06:53:43 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:43 DEBUG : pacer: low level retry 6/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:43 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/06/08 06:53:43 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:43 DEBUG : pacer: low level retry 7/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:43 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2026/06/08 06:53:44 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:44 DEBUG : pacer: low level retry 8/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:44 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2026/06/08 06:53:45 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:45 DEBUG : pacer: low level retry 9/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:45 DEBUG : pacer: Rate limited, increasing sleep to 5.12s
2026/06/08 06:53:48 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:53:48 DEBUG : pacer: low level retry 10/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:53:48 DEBUG : pacer: Rate limited, increasing sleep to 10.24s
2026/06/08 06:53:53 DEBUG : pacer: Reducing sleep to 5.12s
2026/06/08 06:53:53 INFO : path1: Making directory
2026/06/08 06:54:03 DEBUG : pacer: Reducing sleep to 2.56s
2026/06/08 06:54:08 DEBUG : pacer: Reducing sleep to 1.28s
2026/06/08 06:54:11 DEBUG : pacer: Reducing sleep to 640ms
2026/06/08 06:54:12 DEBUG : pacer: Reducing sleep to 320ms
2026/06/08 06:54:13 DEBUG : pacer: Reducing sleep to 160ms
2026/06/08 06:54:13 DEBUG : pacer: Reducing sleep to 80ms
2026/06/08 06:54:13 DEBUG : Creating backend with remote "TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1"
2026/06/08 06:54:15 DEBUG : Creating backend with remote "/tmp/065339wiwebij0"
2026/06/08 06:54:15 DEBUG : Creating backend with remote "/tmp/065339wiwebij0/all_changed/path2"
2026/06/08 06:54:15 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_all_changed/initial"
2026/06/08 06:54:15 DEBUG : Creating backend with remote "/tmp/065339wiwebij0/initdir/test_all_changed-tevuhud4"
2026/06/08 06:54:15 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2026/06/08 06:54:15 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:15 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:15 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:15 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:15 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:15 DEBUG : file1.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:15 DEBUG : subdir: Making directory with metadata
2026/06/08 06:54:15 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2026/06/08 06:54:15 DEBUG : Added delayed dir = "subdir", newDst=subdir
2026/06/08 06:54:15 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK
2026/06/08 06:54:15 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:15 DEBUG : file1.copy1.txt.21b8fa2b.partial: size = 0 OK
2026/06/08 06:54:15 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2026/06/08 06:54:15 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:15 DEBUG : file1.copy2.txt.455881d5.partial: size = 0 OK
2026/06/08 06:54:15 DEBUG : file1.copy1.txt.21b8fa2b.partial: renamed to: file1.copy1.txt
2026/06/08 06:54:15 INFO : file1.copy1.txt: Copied (new)
2026/06/08 06:54:15 DEBUG : file1.copy4.txt.8c987629.partial: size = 0 OK
2026/06/08 06:54:15 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST
2026/06/08 06:54:15 INFO : RCLONE_TEST: Copied (new)
2026/06/08 06:54:15 DEBUG : file1.copy3.txt.d0285540.partial: size = 0 OK
2026/06/08 06:54:15 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:15 DEBUG : file1.copy5.txt.19e8a2bc.partial: size = 0 OK
2026/06/08 06:54:15 DEBUG : file1.copy2.txt.455881d5.partial: renamed to: file1.copy2.txt
2026/06/08 06:54:15 INFO : file1.copy2.txt: Copied (new)
2026/06/08 06:54:15 DEBUG : Local file system at /tmp/065339wiwebij0/initdir/test_all_changed-tevuhud4: Waiting for checks to finish
2026/06/08 06:54:15 DEBUG : Local file system at /tmp/065339wiwebij0/initdir/test_all_changed-tevuhud4: Waiting for transfers to finish
2026/06/08 06:54:15 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:15 DEBUG : file1.txt.56d0d699.partial: size = 0 OK
2026/06/08 06:54:15 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:15 DEBUG : file1.copy3.txt.d0285540.partial: renamed to: file1.copy3.txt
2026/06/08 06:54:15 INFO : file1.copy3.txt: Copied (new)
2026/06/08 06:54:15 DEBUG : file1.copy4.txt.8c987629.partial: renamed to: file1.copy4.txt
2026/06/08 06:54:15 INFO : file1.copy4.txt: Copied (new)
2026/06/08 06:54:15 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:15 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt
2026/06/08 06:54:15 INFO : file1.txt: Copied (new)
2026/06/08 06:54:15 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK
2026/06/08 06:54:15 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:15 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt
2026/06/08 06:54:15 INFO : subdir/file20.txt: Copied (new)
2026/06/08 06:54:15 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:15 DEBUG : file1.copy5.txt.19e8a2bc.partial: renamed to: file1.copy5.txt
2026/06/08 06:54:15 INFO : file1.copy5.txt: Copied (new)
2026/06/08 06:54:15 INFO : subdir: Set directory modification time (using SetModTime)
2026/06/08 06:54:15 DEBUG : Waiting for deletions to finish
2026/06/08 06:54:15 ERROR : error listing: directory not found
2026/06/08 06:54:15 ERROR : Local file system at /tmp/065339wiwebij0/all_changed/path2: Failed to list "": directory not found
2026/06/08 06:54:15 DEBUG : removing 1 level 0 directories
2026/06/08 06:54:15 INFO : Local file system at /tmp/065339wiwebij0/all_changed/path2: Removing directory
2026/06/08 06:54:15 ERROR : Failed to rmdir: stat /tmp/065339wiwebij0/all_changed/path2: no such file or directory
2026/06/08 06:54:15 ERROR : error listing: directory not found
2026/06/08 06:54:15 NOTICE: checking initFs Local file system at /tmp/065339wiwebij0/initdir/test_all_changed-tevuhud4
2026/06/08 06:54:15 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2026/06/08 06:54:15 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:15 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:15 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:15 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:15 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:15 DEBUG : file1.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:15 INFO : subdir: Making directory
2026/06/08 06:54:16 DEBUG : file1.copy1.txt: size = 0 OK
2026/06/08 06:54:16 DEBUG : file1.copy3.txt: size = 0 OK
2026/06/08 06:54:16 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:16 INFO : file1.copy1.txt: Copied (new)
2026/06/08 06:54:16 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:16 INFO : file1.copy3.txt: Copied (new)
2026/06/08 06:54:17 DEBUG : file1.copy2.txt: size = 0 OK
2026/06/08 06:54:17 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:17 INFO : file1.copy2.txt: Copied (new)
2026/06/08 06:54:17 DEBUG : file1.copy4.txt: size = 0 OK
2026/06/08 06:54:17 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:17 INFO : file1.copy4.txt: Copied (new)
2026/06/08 06:54:17 INFO : subdir: Made directory with modification time 2021-11-02 05:00:07 +0000 UTC
2026/06/08 06:54:17 DEBUG : Added delayed dir = "subdir", newDst=
2026/06/08 06:54:17 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:17 DEBUG : gofile root 'rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1': Waiting for checks to finish
2026/06/08 06:54:17 DEBUG : gofile root 'rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1': Waiting for transfers to finish
2026/06/08 06:54:17 DEBUG : RCLONE_TEST: size = 109 OK
2026/06/08 06:54:17 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2026/06/08 06:54:17 INFO : RCLONE_TEST: Copied (new)
2026/06/08 06:54:17 DEBUG : file1.copy5.txt: size = 0 OK
2026/06/08 06:54:17 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:17 INFO : file1.copy5.txt: Copied (new)
2026/06/08 06:54:17 DEBUG : subdir/file20.txt: size = 0 OK
2026/06/08 06:54:17 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:17 INFO : subdir/file20.txt: Copied (new)
2026/06/08 06:54:17 DEBUG : file1.txt: size = 0 OK
2026/06/08 06:54:17 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:17 INFO : file1.txt: Copied (new)
2026/06/08 06:54:17 INFO : subdir: Set directory modification time (using DirSetModTime)
2026/06/08 06:54:17 NOTICE: checking Path1 gofile root 'rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1'
2026/06/08 06:54:18 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2026/06/08 06:54:18 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:18 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:18 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:18 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:18 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:18 DEBUG : file1.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:18 DEBUG : subdir: Making directory with metadata
2026/06/08 06:54:18 INFO : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2026/06/08 06:54:18 DEBUG : Added delayed dir = "subdir", newDst=subdir
2026/06/08 06:54:18 DEBUG : RCLONE_TEST.abb09051.partial: size = 109 OK
2026/06/08 06:54:18 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2026/06/08 06:54:18 DEBUG : Local file system at /tmp/065339wiwebij0/all_changed/path2: Waiting for checks to finish
2026/06/08 06:54:18 DEBUG : file1.copy1.txt.21b8fa2b.partial: size = 0 OK
2026/06/08 06:54:18 DEBUG : Local file system at /tmp/065339wiwebij0/all_changed/path2: Waiting for transfers to finish
2026/06/08 06:54:18 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2026/06/08 06:54:18 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:18 DEBUG : file1.copy2.txt.455881d5.partial: size = 0 OK
2026/06/08 06:54:18 DEBUG : file1.copy1.txt.21b8fa2b.partial: renamed to: file1.copy1.txt
2026/06/08 06:54:18 INFO : file1.copy1.txt: Copied (new)
2026/06/08 06:54:18 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST
2026/06/08 06:54:18 INFO : RCLONE_TEST: Copied (new)
2026/06/08 06:54:18 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:18 DEBUG : file1.copy2.txt.455881d5.partial: renamed to: file1.copy2.txt
2026/06/08 06:54:18 INFO : file1.copy2.txt: Copied (new)
2026/06/08 06:54:18 DEBUG : file1.copy4.txt.8c987629.partial: size = 0 OK
2026/06/08 06:54:18 DEBUG : file1.copy3.txt.d0285540.partial: size = 0 OK
2026/06/08 06:54:18 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:18 DEBUG : file1.copy5.txt.19e8a2bc.partial: size = 0 OK
2026/06/08 06:54:18 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:18 DEBUG : file1.txt.56d0d699.partial: size = 0 OK
2026/06/08 06:54:18 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:18 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:18 DEBUG : file1.copy4.txt.8c987629.partial: renamed to: file1.copy4.txt
2026/06/08 06:54:18 INFO : file1.copy4.txt: Copied (new)
2026/06/08 06:54:18 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt
2026/06/08 06:54:18 DEBUG : file1.copy3.txt.d0285540.partial: renamed to: file1.copy3.txt
2026/06/08 06:54:18 DEBUG : file1.copy5.txt.19e8a2bc.partial: renamed to: file1.copy5.txt
2026/06/08 06:54:18 INFO : file1.copy3.txt: Copied (new)
2026/06/08 06:54:18 INFO : file1.copy5.txt: Copied (new)
2026/06/08 06:54:18 INFO : file1.txt: Copied (new)
2026/06/08 06:54:18 DEBUG : subdir/file20.txt.1ac3db2f.partial: size = 0 OK
2026/06/08 06:54:18 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2026/06/08 06:54:18 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt
2026/06/08 06:54:18 INFO : subdir/file20.txt: Copied (new)
2026/06/08 06:54:18 INFO : subdir: Set directory modification time (using SetModTime)
2026/06/08 06:54:18 NOTICE: checking path2 Local file system at /tmp/065339wiwebij0/all_changed/path2
2026/06/08 06:54:18 NOTICE: [36m(01) :[0m [34mtest all-changed[0m
2026/06/08 06:54:18 NOTICE: [36m(02) :[0m [34mtest initial bisync[0m
2026/06/08 06:54:18 NOTICE: [36m(03) :[0m [34mbisync resync[0m
2026/06/08 06:54:21 INFO : subdir: Set directory modification time (using SetModTime)
2026/06/08 06:54:21 INFO : subdir: Set directory modification time (using SetModTime)
2026/06/08 06:54:21 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m
2026/06/08 06:54:21 INFO : Bisyncing with Comparison Settings:
{
"Modtime": true,
"Size": true,
"Checksum": false,
"HashType1": 0,
"HashType2": 0,
"NoSlowHash": false,
"SlowHashSyncOnly": false,
"SlowHashDetected": true,
"DownloadHash": false
}
2026/06/08 06:54:21 INFO : Synching Path1 "TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1/" with Path2 "/tmp/065339wiwebij0/all_changed/path2/"
2026/06/08 06:54:21 INFO : Copying Path2 files to Path1
2026/06/08 06:54:21 INFO : - [34mPath2[0m [35mResync is copying files to[0m - [36mPath1[0m
2026/06/08 06:54:21 INFO : There was nothing to transfer
2026/06/08 06:54:21 INFO : - [36mPath1[0m [35mResync is copying files to[0m - [36mPath2[0m
2026/06/08 06:54:22 INFO : There was nothing to transfer
2026/06/08 06:54:22 INFO : Resync updating listings
2026/06/08 06:54:22 INFO : Validating listings for Path1 "TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1/" vs Path2 "/tmp/065339wiwebij0/all_changed/path2/"
2026/06/08 06:54:22 INFO : [32mBisync successful[0m
2026/06/08 06:54:22 NOTICE: [36m(04) :[0m [34mtest change timestamp on all files except RCLONE_TEST[0m
2026/06/08 06:54:22 NOTICE: [36m(05) :[0m [34mtouch-glob 2005-01-02 TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1/ file*[0m
2026/06/08 06:54:22 DEBUG : Creating backend with remote "TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1/"
2026/06/08 06:54:22 DEBUG : fs cache: renaming cache item "TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1/" to be canonical "TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1"
2026/06/08 06:54:23 DEBUG : file1.copy2.txt: Set modification time 2005-01-02
2026/06/08 06:54:23 DEBUG : file1.copy4.txt: Set modification time 2005-01-02
2026/06/08 06:54:23 DEBUG : file1.copy5.txt: Set modification time 2005-01-02
2026/06/08 06:54:23 DEBUG : file1.txt: Set modification time 2005-01-02
2026/06/08 06:54:23 DEBUG : file1.copy1.txt: Set modification time 2005-01-02
2026/06/08 06:54:23 DEBUG : file1.copy3.txt: Set modification time 2005-01-02
2026/06/08 06:54:23 NOTICE: [36m(06) :[0m [34mtouch-glob 2005-01-02 TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1/subdir file*[0m
2026/06/08 06:54:23 DEBUG : Creating backend with remote "TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1/subdir"
2026/06/08 06:54:25 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:54:25 DEBUG : pacer: low level retry 1/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:54:25 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2026/06/08 06:54:26 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:54:26 DEBUG : pacer: low level retry 2/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:54:26 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2026/06/08 06:54:27 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:54:27 DEBUG : pacer: low level retry 3/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:54:27 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2026/06/08 06:54:27 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:54:27 DEBUG : pacer: low level retry 4/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:54:27 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2026/06/08 06:54:27 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:54:27 DEBUG : pacer: low level retry 5/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:54:27 DEBUG : pacer: Rate limited, increasing sleep to 320ms
2026/06/08 06:54:28 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:54:28 DEBUG : pacer: low level retry 6/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:54:28 DEBUG : pacer: Rate limited, increasing sleep to 640ms
2026/06/08 06:54:28 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:54:28 DEBUG : pacer: low level retry 7/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:54:28 DEBUG : pacer: Rate limited, increasing sleep to 1.28s
2026/06/08 06:54:31 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:54:31 DEBUG : pacer: low level retry 8/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:54:31 DEBUG : pacer: Rate limited, increasing sleep to 2.56s
2026/06/08 06:54:31 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:54:31 DEBUG : pacer: low level retry 9/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:54:31 DEBUG : pacer: Rate limited, increasing sleep to 5.12s
2026/06/08 06:54:34 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:54:34 DEBUG : pacer: low level retry 10/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:54:34 DEBUG : pacer: Rate limited, increasing sleep to 10.24s
2026/06/08 06:54:40 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:54:40 DEBUG : pacer: low level retry 1/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:54:40 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/06/08 06:54:50 DEBUG : pacer: Reducing sleep to 10s
2026/06/08 06:55:10 DEBUG : pacer: Reducing sleep to 5s
2026/06/08 06:55:19 DEBUG : pacer: Reducing sleep to 2.5s
2026/06/08 06:55:25 DEBUG : pacer: Reducing sleep to 1.25s
2026/06/08 06:55:27 DEBUG : pacer: Reducing sleep to 625ms
2026/06/08 06:55:28 DEBUG : pacer: Reducing sleep to 312.5ms
2026/06/08 06:55:29 DEBUG : pacer: Reducing sleep to 156.25ms
2026/06/08 06:55:29 DEBUG : pacer: Reducing sleep to 78.125ms
2026/06/08 06:55:29 DEBUG : pacer: Reducing sleep to 39.0625ms
2026/06/08 06:55:29 DEBUG : pacer: Reducing sleep to 19.53125ms
2026/06/08 06:55:30 DEBUG : pacer: Reducing sleep to 10ms
2026/06/08 06:55:30 DEBUG : file20.txt: Set modification time 2005-01-02
2026/06/08 06:55:30 NOTICE: [36m(07) :[0m [34mtest sync should pass[0m
2026/06/08 06:55:30 NOTICE: [36m(08) :[0m [34mbisync[0m
2026/06/08 06:55:33 INFO : subdir: Set directory modification time (using SetModTime)
2026/06/08 06:55:33 INFO : subdir: Set directory modification time (using SetModTime)
2026/06/08 06:55:33 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m
2026/06/08 06:55:33 INFO : Bisyncing with Comparison Settings:
{
"Modtime": true,
"Size": true,
"Checksum": false,
"HashType1": 0,
"HashType2": 0,
"NoSlowHash": false,
"SlowHashSyncOnly": false,
"SlowHashDetected": true,
"DownloadHash": false
}
2026/06/08 06:55:33 INFO : Synching Path1 "TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1/" with Path2 "/tmp/065339wiwebij0/all_changed/path2/"
2026/06/08 06:55:33 INFO : Building Path1 and Path2 listings
2026/06/08 06:55:34 INFO : Path1 checking for diffs
2026/06/08 06:55:34 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (newer)[0m[0m[0m - [36mfile1.copy1.txt[0m
2026/06/08 06:55:34 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (newer)[0m[0m[0m - [36mfile1.copy2.txt[0m
2026/06/08 06:55:34 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (newer)[0m[0m[0m - [36mfile1.copy3.txt[0m
2026/06/08 06:55:34 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (newer)[0m[0m[0m - [36mfile1.copy4.txt[0m
2026/06/08 06:55:34 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (newer)[0m[0m[0m - [36mfile1.copy5.txt[0m
2026/06/08 06:55:34 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (newer)[0m[0m[0m - [36mfile1.txt[0m
2026/06/08 06:55:34 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (newer)[0m[0m[0m - [36msubdir/file20.txt[0m
2026/06/08 06:55:34 INFO : Path1: 7 changes: [32m 0 new[0m, [33m 7 modified[0m, [31m 0 deleted[0m
2026/06/08 06:55:34 INFO : ([33mModified[0m: [36m 7 newer[0m, [34m 0 older[0m)
2026/06/08 06:55:34 INFO : Path2 checking for diffs
2026/06/08 06:55:34 INFO : Applying changes
2026/06/08 06:55:34 INFO : - [36mPath1[0m [35m[32mQueue copy to[0m Path2[0m - [36m/tmp/065339wiwebij0/all_changed/path2/file1.copy1.txt[0m
2026/06/08 06:55:34 INFO : - [36mPath1[0m [35m[32mQueue copy to[0m Path2[0m - [36m/tmp/065339wiwebij0/all_changed/path2/file1.copy2.txt[0m
2026/06/08 06:55:34 INFO : - [36mPath1[0m [35m[32mQueue copy to[0m Path2[0m - [36m/tmp/065339wiwebij0/all_changed/path2/file1.copy3.txt[0m
2026/06/08 06:55:34 INFO : - [36mPath1[0m [35m[32mQueue copy to[0m Path2[0m - [36m/tmp/065339wiwebij0/all_changed/path2/file1.copy4.txt[0m
2026/06/08 06:55:34 INFO : - [36mPath1[0m [35m[32mQueue copy to[0m Path2[0m - [36m/tmp/065339wiwebij0/all_changed/path2/file1.copy5.txt[0m
2026/06/08 06:55:34 INFO : - [36mPath1[0m [35m[32mQueue copy to[0m Path2[0m - [36m/tmp/065339wiwebij0/all_changed/path2/file1.txt[0m
2026/06/08 06:55:34 INFO : - [36mPath1[0m [35m[32mQueue copy to[0m Path2[0m - [36m/tmp/065339wiwebij0/all_changed/path2/subdir/file20.txt[0m
2026/06/08 06:55:34 INFO : - [36mPath1[0m [35mDo queued copies to[0m - [36mPath2[0m
2026/06/08 06:55:34 INFO : file1.copy1.txt: Updated modification time in destination
2026/06/08 06:55:34 INFO : file1.copy2.txt: Updated modification time in destination
2026/06/08 06:55:34 INFO : file1.copy5.txt: Updated modification time in destination
2026/06/08 06:55:34 INFO : file1.copy4.txt: Updated modification time in destination
2026/06/08 06:55:34 INFO : file1.txt: Updated modification time in destination
2026/06/08 06:55:34 INFO : file1.copy3.txt: Updated modification time in destination
2026/06/08 06:55:34 INFO : subdir/file20.txt: Updated modification time in destination
2026/06/08 06:55:34 INFO : There was nothing to transfer
2026/06/08 06:55:34 INFO : Updating listings
2026/06/08 06:55:34 INFO : Validating listings for Path1 "TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1/" vs Path2 "/tmp/065339wiwebij0/all_changed/path2/"
2026/06/08 06:55:34 INFO : [32mBisync successful[0m
2026/06/08 06:55:34 NOTICE: [36m(09) :[0m [34mtest change timestamp on all files including RCLONE_TEST[0m
2026/06/08 06:55:34 NOTICE: [36m(10) :[0m [34mtouch-glob 2004-01-02 TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1/ *[0m
2026/06/08 06:55:34 DEBUG : fs cache: switching user supplied name "TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1/" for canonical name "TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1"
2026/06/08 06:55:34 DEBUG : file1.copy2.txt: Set modification time 2004-01-02
2026/06/08 06:55:34 DEBUG : file1.copy4.txt: Set modification time 2004-01-02
2026/06/08 06:55:34 DEBUG : file1.copy5.txt: Set modification time 2004-01-02
2026/06/08 06:55:34 DEBUG : file1.txt: Set modification time 2004-01-02
2026/06/08 06:55:34 DEBUG : file1.copy1.txt: Set modification time 2004-01-02
2026/06/08 06:55:34 DEBUG : file1.copy3.txt: Set modification time 2004-01-02
2026/06/08 06:55:34 DEBUG : RCLONE_TEST: Set modification time 2004-01-02
2026/06/08 06:55:34 NOTICE: [36m(11) :[0m [34mtouch-glob 2004-01-02 TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1/subdir *[0m
2026/06/08 06:55:35 DEBUG : file20.txt: Set modification time 2004-01-02
2026/06/08 06:55:35 NOTICE: [36m(12) :[0m [34mtest sync should fail[0m
2026/06/08 06:55:35 NOTICE: [36m(13) :[0m [34mbisync[0m
2026/06/08 06:55:38 INFO : subdir: Set directory modification time (using SetModTime)
2026/06/08 06:55:38 INFO : subdir: Set directory modification time (using SetModTime)
2026/06/08 06:55:38 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m
2026/06/08 06:55:38 INFO : Bisyncing with Comparison Settings:
{
"Modtime": true,
"Size": true,
"Checksum": false,
"HashType1": 0,
"HashType2": 0,
"NoSlowHash": false,
"SlowHashSyncOnly": false,
"SlowHashDetected": true,
"DownloadHash": false
}
2026/06/08 06:55:38 INFO : Synching Path1 "TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1/" with Path2 "/tmp/065339wiwebij0/all_changed/path2/"
2026/06/08 06:55:38 INFO : Building Path1 and Path2 listings
2026/06/08 06:55:38 INFO : Path1 checking for diffs
2026/06/08 06:55:38 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (newer)[0m[0m[0m - [36mRCLONE_TEST[0m
2026/06/08 06:55:38 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (older)[0m[0m[0m - [36mfile1.copy1.txt[0m
2026/06/08 06:55:38 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (older)[0m[0m[0m - [36mfile1.copy2.txt[0m
2026/06/08 06:55:38 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (older)[0m[0m[0m - [36mfile1.copy3.txt[0m
2026/06/08 06:55:38 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (older)[0m[0m[0m - [36mfile1.copy4.txt[0m
2026/06/08 06:55:38 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (older)[0m[0m[0m - [36mfile1.copy5.txt[0m
2026/06/08 06:55:38 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (older)[0m[0m[0m - [36mfile1.txt[0m
2026/06/08 06:55:38 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (older)[0m[0m[0m - [36msubdir/file20.txt[0m
2026/06/08 06:55:38 INFO : Path1: 8 changes: [32m 0 new[0m, [33m 8 modified[0m, [31m 0 deleted[0m
2026/06/08 06:55:38 INFO : ([33mModified[0m: [36m 1 newer[0m, [34m 7 older[0m)
2026/06/08 06:55:38 INFO : Path2 checking for diffs
2026/06/08 06:55:38 ERROR : Safety abort: all files were changed on Path1 "TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1/". Run with --force if desired.
2026/06/08 06:55:38 NOTICE: [31mBisync aborted. Please try again.[0m
2026/06/08 06:55:38 NOTICE: Bisync error: all files were changed
2026/06/08 06:55:38 NOTICE: [36m(14) :[0m [34mtest sync with force should pass[0m
2026/06/08 06:55:38 NOTICE: [36m(15) :[0m [34mbisync force[0m
2026/06/08 06:55:41 INFO : subdir: Set directory modification time (using SetModTime)
2026/06/08 06:55:41 INFO : subdir: Set directory modification time (using SetModTime)
2026/06/08 06:55:41 INFO : [2mSetting --ignore-listing-checksum as neither --checksum nor --compare checksum are set.[0m
2026/06/08 06:55:41 INFO : Bisyncing with Comparison Settings:
{
"Modtime": true,
"Size": true,
"Checksum": false,
"HashType1": 0,
"HashType2": 0,
"NoSlowHash": false,
"SlowHashSyncOnly": false,
"SlowHashDetected": true,
"DownloadHash": false
}
2026/06/08 06:55:41 INFO : Synching Path1 "TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1/" with Path2 "/tmp/065339wiwebij0/all_changed/path2/"
2026/06/08 06:55:41 INFO : Building Path1 and Path2 listings
2026/06/08 06:55:41 INFO : Path1 checking for diffs
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (newer)[0m[0m[0m - [36mRCLONE_TEST[0m
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (older)[0m[0m[0m - [36mfile1.copy1.txt[0m
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (older)[0m[0m[0m - [36mfile1.copy2.txt[0m
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (older)[0m[0m[0m - [36mfile1.copy3.txt[0m
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (older)[0m[0m[0m - [36mfile1.copy4.txt[0m
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (older)[0m[0m[0m - [36mfile1.copy5.txt[0m
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (older)[0m[0m[0m - [36mfile1.txt[0m
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35m[33mFile changed: [35mtime (older)[0m[0m[0m - [36msubdir/file20.txt[0m
2026/06/08 06:55:41 INFO : Path1: 8 changes: [32m 0 new[0m, [33m 8 modified[0m, [31m 0 deleted[0m
2026/06/08 06:55:41 INFO : ([33mModified[0m: [36m 1 newer[0m, [34m 7 older[0m)
2026/06/08 06:55:41 INFO : Path2 checking for diffs
2026/06/08 06:55:41 INFO : Applying changes
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35m[32mQueue copy to[0m Path2[0m - [36m/tmp/065339wiwebij0/all_changed/path2/RCLONE_TEST[0m
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35m[32mQueue copy to[0m Path2[0m - [36m/tmp/065339wiwebij0/all_changed/path2/file1.copy1.txt[0m
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35m[32mQueue copy to[0m Path2[0m - [36m/tmp/065339wiwebij0/all_changed/path2/file1.copy2.txt[0m
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35m[32mQueue copy to[0m Path2[0m - [36m/tmp/065339wiwebij0/all_changed/path2/file1.copy3.txt[0m
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35m[32mQueue copy to[0m Path2[0m - [36m/tmp/065339wiwebij0/all_changed/path2/file1.copy4.txt[0m
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35m[32mQueue copy to[0m Path2[0m - [36m/tmp/065339wiwebij0/all_changed/path2/file1.copy5.txt[0m
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35m[32mQueue copy to[0m Path2[0m - [36m/tmp/065339wiwebij0/all_changed/path2/file1.txt[0m
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35m[32mQueue copy to[0m Path2[0m - [36m/tmp/065339wiwebij0/all_changed/path2/subdir/file20.txt[0m
2026/06/08 06:55:41 INFO : - [36mPath1[0m [35mDo queued copies to[0m - [36mPath2[0m
2026/06/08 06:55:42 INFO : file1.copy3.txt: Updated modification time in destination
2026/06/08 06:55:42 INFO : RCLONE_TEST: Updated modification time in destination
2026/06/08 06:55:42 INFO : file1.copy1.txt: Updated modification time in destination
2026/06/08 06:55:42 INFO : file1.copy2.txt: Updated modification time in destination
2026/06/08 06:55:42 INFO : file1.copy4.txt: Updated modification time in destination
2026/06/08 06:55:42 INFO : file1.copy5.txt: Updated modification time in destination
2026/06/08 06:55:42 INFO : file1.txt: Updated modification time in destination
2026/06/08 06:55:42 INFO : subdir/file20.txt: Updated modification time in destination
2026/06/08 06:55:42 INFO : There was nothing to transfer
2026/06/08 06:55:42 INFO : Updating listings
2026/06/08 06:55:42 INFO : Validating listings for Path1 "TestGoFile:rclone-test-fusekis0vilu/065339wiwebij0/all_changed/path1/" vs Path2 "/tmp/065339wiwebij0/all_changed/path2/"
2026/06/08 06:55:42 INFO : [32mBisync successful[0m
2026/06/08 06:55:42 DEBUG : Waiting for deletions to finish
2026/06/08 06:55:42 INFO : file1.copy3.txt: Deleted
2026/06/08 06:55:42 INFO : file1.txt: Deleted
2026/06/08 06:55:42 INFO : file1.copy5.txt: Deleted
2026/06/08 06:55:42 INFO : subdir/file20.txt: Deleted
2026/06/08 06:55:42 INFO : file1.copy4.txt: Deleted
2026/06/08 06:55:42 INFO : file1.copy1.txt: Deleted
2026/06/08 06:55:42 INFO : RCLONE_TEST: Deleted
2026/06/08 06:55:42 INFO : file1.copy2.txt: Deleted
2026/06/08 06:55:42 DEBUG : removing 1 level 1 directories
2026/06/08 06:55:42 INFO : subdir: Removing directory
2026/06/08 06:55:42 DEBUG : removing 1 level 0 directories
2026/06/08 06:55:42 INFO : Local file system at /tmp/065339wiwebij0/all_changed/path2: Removing directory
bisync_test.go:610: [32mTEST all_changed PASSED[0m
2026/06/08 06:55:42 DEBUG : gofile root 'rclone-test-fusekis0vilu': Purge remote
2026/06/08 06:55:54 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:55:54 DEBUG : pacer: low level retry 1/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:55:54 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/06/08 06:55:55 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:55:55 DEBUG : pacer: low level retry 2/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:56:14 DEBUG : pacer: Reducing sleep to 10s
2026/06/08 06:56:35 DEBUG : pacer: Reducing sleep to 5s
--- PASS: TestBisyncRemoteLocal (209.37s)
--- PASS: TestBisyncRemoteLocal/all_changed (122.76s)
PASS
2026/06/08 06:56:35 DEBUG : gofile root 'rclone-test-mecosek4qewa': Purge remote
2026/06/08 06:56:38 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:56:38 DEBUG : pacer: low level retry 1/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:56:38 DEBUG : pacer: Rate limited, increasing sleep to 20s
2026/06/08 06:56:45 DEBUG : Couldn't decode error response: invalid character '<' looking for beginning of value
2026/06/08 06:56:45 DEBUG : pacer: low level retry 2/10 (error Error "502 Bad Gateway (502): \r\n502 Bad Gateway\r\n\r\n502 Bad Gateway
\r\n
nginx\r\n\r\n\r\n")
2026/06/08 06:57:24 DEBUG : pacer: Reducing sleep to 10s
2026/06/08 06:57:24 NOTICE: purge failed: directory not found
"./bisync.test -test.v -test.timeout 1h0m0s -remote TestGoFile: -verbose -test.run '^TestBisyncRemoteLocal$/^all_changed$'" - Finished OK in 5m1.727458245s (try 2/5)