"./bisync.test -test.v -test.timeout 1h0m0s -remote TestGoFile: -verbose" - Starting (try 4/5)
2025/09/09 05:58:18 DEBUG : Creating backend with remote "TestGoFile:rclone-test-roqicim3xugu"
2025/09/09 05:58:18 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/09/09 05:58:18 DEBUG : Creating backend with remote "/tmp/rclone2266537108"
=== RUN   TestBisyncRemoteLocal
2025/09/09 05:58:18 DEBUG : Creating backend with remote "TestGoFile:rclone-test-numerem3fipe"
2025/09/09 05:58:18 NOTICE: remote: TestGoFile:rclone-test-numerem3fipe
=== RUN   TestBisyncRemoteLocal/all_changed
2025/09/09 05:58:18 DEBUG : Creating backend with remote "TestGoFile:rclone-test-numerem3fipe/055818no"
2025/09/09 05:58:19 INFO  : path1: Making directory
2025/09/09 05:58:19 DEBUG : Creating backend with remote "TestGoFile:rclone-test-numerem3fipe/055818no/all_changed/path1"
2025/09/09 05:58:20 DEBUG : Creating backend with remote "/tmp/055818no"
2025/09/09 05:58:20 DEBUG : Creating backend with remote "/tmp/055818no/all_changed/path2"
2025/09/09 05:58:20 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_all_changed/initial"
2025/09/09 05:58:20 DEBUG : Creating backend with remote "/tmp/055818no/initdir/test_all_changed-sodetev9"
2025/09/09 05:58:20 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/09/09 05:58:20 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination
2025/09/09 05:58:20 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination
2025/09/09 05:58:20 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination
2025/09/09 05:58:20 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination
2025/09/09 05:58:20 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination
2025/09/09 05:58:20 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/09/09 05:58:20 DEBUG : subdir: Making directory with metadata
2025/09/09 05:58:20 INFO  : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/09/09 05:58:20 DEBUG : Added delayed dir = "subdir", newDst=subdir
2025/09/09 05:58:20 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/09/09 05:58:20 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 05:58:20 DEBUG : file1.copy2.txt.455881d5.partial: renamed to: file1.copy2.txt
2025/09/09 05:58:20 INFO  : file1.copy2.txt: Copied (new)
2025/09/09 05:58:20 DEBUG : Local file system at /tmp/055818no/initdir/test_all_changed-sodetev9: Waiting for checks to finish
2025/09/09 05:58:20 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 05:58:20 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 05:58:20 DEBUG : file1.copy1.txt.21b8fa2b.partial: renamed to: file1.copy1.txt
2025/09/09 05:58:20 INFO  : file1.copy1.txt: Copied (new)
2025/09/09 05:58:20 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 05:58:20 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 05:58:20 DEBUG : file1.copy3.txt.d0285540.partial: renamed to: file1.copy3.txt
2025/09/09 05:58:20 INFO  : file1.copy3.txt: Copied (new)
2025/09/09 05:58:20 DEBUG : file1.copy5.txt.19e8a2bc.partial: renamed to: file1.copy5.txt
2025/09/09 05:58:20 INFO  : file1.copy5.txt: Copied (new)
2025/09/09 05:58:20 DEBUG : Local file system at /tmp/055818no/initdir/test_all_changed-sodetev9: Waiting for transfers to finish
2025/09/09 05:58:20 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/09/09 05:58:20 DEBUG : file1.copy4.txt.8c987629.partial: renamed to: file1.copy4.txt
2025/09/09 05:58:20 INFO  : file1.copy4.txt: Copied (new)
2025/09/09 05:58:20 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 05:58:20 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 05:58:20 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST
2025/09/09 05:58:20 INFO  : RCLONE_TEST: Copied (new)
2025/09/09 05:58:20 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt
2025/09/09 05:58:20 INFO  : subdir/file20.txt: Copied (new)
2025/09/09 05:58:20 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt
2025/09/09 05:58:20 INFO  : file1.txt: Copied (new)
2025/09/09 05:58:20 INFO  : subdir: Set directory modification time (using SetModTime)
2025/09/09 05:58:20 DEBUG : Waiting for deletions to finish
2025/09/09 05:58:20 ERROR : error listing: directory not found
2025/09/09 05:58:20 ERROR : Local file system at /tmp/055818no/all_changed/path2: Failed to list "": directory not found
2025/09/09 05:58:20 DEBUG : removing 1 level 0 directories
2025/09/09 05:58:20 INFO  : Local file system at /tmp/055818no/all_changed/path2: Removing directory
2025/09/09 05:58:20 ERROR : Failed to rmdir: stat /tmp/055818no/all_changed/path2: no such file or directory
2025/09/09 05:58:20 ERROR : error listing: directory not found
2025/09/09 05:58:20 NOTICE: checking initFs Local file system at /tmp/055818no/initdir/test_all_changed-sodetev9
2025/09/09 05:58:20 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/09/09 05:58:20 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination
2025/09/09 05:58:20 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination
2025/09/09 05:58:20 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination
2025/09/09 05:58:20 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination
2025/09/09 05:58:20 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination
2025/09/09 05:58:20 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/09/09 05:58:20 INFO  : subdir: Making directory
2025/09/09 05:58:20 INFO  : subdir: Made directory with modification time 2021-11-02 05:00:07 +0000 UTC
2025/09/09 05:58:20 DEBUG : Added delayed dir = "subdir", newDst=<nil>
2025/09/09 05:58:20 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/09/09 05:58:20 DEBUG : gofile root 'rclone-test-numerem3fipe/055818no/all_changed/path1': Waiting for checks to finish
2025/09/09 05:58:20 DEBUG : gofile root 'rclone-test-numerem3fipe/055818no/all_changed/path1': Waiting for transfers to finish
2025/09/09 05:58:21 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 05:58:21 INFO  : file1.copy3.txt: Copied (new)
2025/09/09 05:58:21 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/09/09 05:58:21 INFO  : RCLONE_TEST: Copied (new)
2025/09/09 05:58:21 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 05:58:21 INFO  : file1.copy5.txt: Copied (new)
2025/09/09 06:00:31 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:00:31 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:00:31 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:00:31 DEBUG : file1.copy1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 0/10
2025/09/09 06:00:32 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:00:32 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:00:32 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:00:32 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:00:32 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:00:32 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:00:32 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/09/09 06:00:32 DEBUG : file1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 0/10
2025/09/09 06:00:32 DEBUG : file1.copy2.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 0/10
2025/09/09 06:00:32 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:00:32 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:00:32 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/09/09 06:00:32 DEBUG : file1.copy4.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 0/10
2025/09/09 06:00:32 DEBUG : pacer: Reducing sleep to 40ms
2025/09/09 06:00:32 DEBUG : pacer: Reducing sleep to 20ms
2025/09/09 06:00:32 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:00:32 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:00:32 INFO  : file1.txt: Copied (new)
2025/09/09 06:00:32 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:00:32 INFO  : file1.copy2.txt: Copied (new)
2025/09/09 06:00:32 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:00:32 INFO  : file1.copy4.txt: Copied (new)
2025/09/09 06:00:32 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:00:32 INFO  : subdir/file20.txt: Copied (new)
2025/09/09 06:02:43 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:02:43 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:02:43 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:02:43 DEBUG : file1.copy1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 1/10
2025/09/09 06:02:43 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:04:54 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:04:54 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:04:54 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:04:54 DEBUG : file1.copy1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 2/10
2025/09/09 06:04:54 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:07:05 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:07:05 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:07:05 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:07:05 DEBUG : file1.copy1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 3/10
2025/09/09 06:07:05 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:09:16 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:09:16 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:09:16 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:09:16 DEBUG : file1.copy1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 4/10
2025/09/09 06:09:16 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:11:27 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:11:27 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:11:27 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:11:27 DEBUG : file1.copy1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 5/10
2025/09/09 06:11:27 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:13:38 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:13:38 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:13:38 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:13:38 DEBUG : file1.copy1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 6/10
2025/09/09 06:13:38 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:15:49 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:15:49 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:15:49 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:15:49 DEBUG : file1.copy1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 7/10
2025/09/09 06:15:49 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:18:00 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:18:00 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:18:00 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:18:00 DEBUG : file1.copy1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 8/10
2025/09/09 06:18:00 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:20:11 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:20:11 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:20:11 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:20:11 DEBUG : file1.copy1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 9/10
2025/09/09 06:20:11 ERROR : file1.copy1.txt: Failed to copy: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n"
2025/09/09 06:20:11 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:20:11 INFO  : subdir: Set directory modification time (using DirSetModTime)
    bisync_test.go:2013: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:2013
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:506
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:405
        	Error:      	Received unexpected error:
        	            	failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n"
        	Test:       	TestBisyncRemoteLocal/all_changed
        	Messages:   	setting up path1
2025/09/09 06:20:11 NOTICE: checking Path1 gofile root 'rclone-test-numerem3fipe/055818no/all_changed/path1'
    fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:298: Flushing the directory cache
    fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3
    fstest.go:298: Flushing the directory cache
    fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3
    fstest.go:298: Flushing the directory cache
    fstest.go:302: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:508
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:405
        	Error:      	Should be true
        	Test:       	TestBisyncRemoteLocal/all_changed
        	Messages:   	listing wrong, want
        	            	  RCLONE_TEST (109), file1.copy1.txt (0), file1.copy2.txt (0), file1.copy3.txt (0), file1.copy4.txt (0), file1.copy5.txt (0), file1.txt (0), subdir/file20.txt (0) got
        	            	  RCLONE_TEST (109)
    fstest.go:200: Not found "file1.copy3.txt"
    fstest.go:200: Not found "file1.copy4.txt"
    fstest.go:200: Not found "file1.copy5.txt"
    fstest.go:200: Not found "file1.txt"
    fstest.go:200: Not found "subdir/file20.txt"
    fstest.go:200: Not found "file1.copy1.txt"
    fstest.go:200: Not found "file1.copy2.txt"
    fstest.go:203: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:203
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:307
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:508
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:405
        	Error:      	Not equal: 
        	            	expected: 0
        	            	actual  : 7
        	Test:       	TestBisyncRemoteLocal/all_changed
        	Messages:   	7 objects not found
2025/09/09 06:20:19 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/09/09 06:20:19 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination
2025/09/09 06:20:19 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination
2025/09/09 06:20:19 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination
2025/09/09 06:20:19 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination
2025/09/09 06:20:19 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:20:19 DEBUG : file1.copy2.txt.455881d5.partial: renamed to: file1.copy2.txt
2025/09/09 06:20:19 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:20:19 INFO  : file1.copy2.txt: Copied (new)
2025/09/09 06:20:19 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination
2025/09/09 06:20:19 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/09/09 06:20:19 DEBUG : subdir: Making directory with metadata
2025/09/09 06:20:19 DEBUG : file1.copy1.txt.21b8fa2b.partial: renamed to: file1.copy1.txt
2025/09/09 06:20:19 INFO  : file1.copy1.txt: Copied (new)
2025/09/09 06:20:19 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:20:19 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:20:19 DEBUG : file1.copy4.txt.8c987629.partial: renamed to: file1.copy4.txt
2025/09/09 06:20:19 INFO  : file1.copy4.txt: Copied (new)
2025/09/09 06:20:19 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:20:19 DEBUG : file1.copy3.txt.d0285540.partial: renamed to: file1.copy3.txt
2025/09/09 06:20:19 INFO  : file1.copy3.txt: Copied (new)
2025/09/09 06:20:19 INFO  : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/09/09 06:20:19 DEBUG : Added delayed dir = "subdir", newDst=subdir
2025/09/09 06:20:19 DEBUG : file1.copy5.txt.19e8a2bc.partial: renamed to: file1.copy5.txt
2025/09/09 06:20:19 INFO  : file1.copy5.txt: Copied (new)
2025/09/09 06:20:19 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/09/09 06:20:19 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:20:19 DEBUG : Local file system at /tmp/055818no/all_changed/path2: Waiting for checks to finish
2025/09/09 06:20:19 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt
2025/09/09 06:20:19 INFO  : file1.txt: Copied (new)
2025/09/09 06:20:19 DEBUG : Local file system at /tmp/055818no/all_changed/path2: Waiting for transfers to finish
2025/09/09 06:20:19 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:20:19 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt
2025/09/09 06:20:19 INFO  : subdir/file20.txt: Copied (new)
2025/09/09 06:20:19 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/09/09 06:20:19 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST
2025/09/09 06:20:19 INFO  : RCLONE_TEST: Copied (new)
2025/09/09 06:20:19 INFO  : subdir: Set directory modification time (using SetModTime)
2025/09/09 06:20:19 NOTICE: checking path2 Local file system at /tmp/055818no/all_changed/path2
2025/09/09 06:20:19 NOTICE: (01)  : test all-changed
2025/09/09 06:20:19 NOTICE: (02)  : test initial bisync
2025/09/09 06:20:19 NOTICE: (03)  : bisync resync
2025/09/09 06:22:30 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:22:30 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:22:30 DEBUG : pacer: Rate limited, increasing sleep to 20ms
    bisync_test.go:1025: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:1025
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:1045
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:1111
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:788
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:542
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:405
        	Error:      	Received unexpected error:
        	            	failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n"
        	Test:       	TestBisyncRemoteLocal/all_changed
=== RUN   TestBisyncRemoteLocal/backupdir
2025/09/09 06:22:30 DEBUG : Creating backend with remote "TestGoFile:rclone-test-numerem3fipe/055818no"
2025/09/09 06:22:30 DEBUG : Config file has changed externally - reloading
2025/09/09 06:22:31 INFO  : path1: Making directory
2025/09/09 06:22:31 DEBUG : Creating backend with remote "TestGoFile:rclone-test-numerem3fipe/055818no/backupdir/path1"
2025/09/09 06:22:31 DEBUG : Creating backend with remote "/tmp/055818no"
2025/09/09 06:22:31 DEBUG : Creating backend with remote "/tmp/055818no/backupdir/path2"
2025/09/09 06:22:31 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_backupdir/initial"
2025/09/09 06:22:31 DEBUG : Creating backend with remote "/tmp/055818no/initdir/test_backupdir-suqunaw0"
2025/09/09 06:22:31 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file5.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file8.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:22:31 DEBUG : Local file system at /tmp/055818no/initdir/test_backupdir-suqunaw0: Waiting for checks to finish
2025/09/09 06:22:31 DEBUG : Local file system at /tmp/055818no/initdir/test_backupdir-suqunaw0: Waiting for transfers to finish
2025/09/09 06:22:31 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:22:31 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt
2025/09/09 06:22:31 INFO  : file3.txt: Copied (new)
2025/09/09 06:22:31 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt
2025/09/09 06:22:31 INFO  : file2.txt: Copied (new)
2025/09/09 06:22:31 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:22:31 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt
2025/09/09 06:22:31 INFO  : file1.txt: Copied (new)
2025/09/09 06:22:31 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:22:31 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/09/09 06:22:31 DEBUG : file5.txt.6e808e0e.partial: renamed to: file5.txt
2025/09/09 06:22:31 INFO  : file5.txt: Copied (new)
2025/09/09 06:22:31 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:22:31 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST
2025/09/09 06:22:31 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt
2025/09/09 06:22:31 INFO  : file4.txt: Copied (new)
2025/09/09 06:22:31 INFO  : RCLONE_TEST: Copied (new)
2025/09/09 06:22:31 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:22:31 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:22:31 DEBUG : file6.txt.0a60f5f0.partial: renamed to: file6.txt
2025/09/09 06:22:31 INFO  : file6.txt: Copied (new)
2025/09/09 06:22:31 DEBUG : file8.txt.b300b322.partial: renamed to: file8.txt
2025/09/09 06:22:31 INFO  : file8.txt: Copied (new)
2025/09/09 06:22:31 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:22:31 DEBUG : file7.txt.9f102165.partial: renamed to: file7.txt
2025/09/09 06:22:31 INFO  : file7.txt: Copied (new)
2025/09/09 06:22:31 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_backupdir/modfiles"
2025/09/09 06:22:31 DEBUG : Creating backend with remote "/tmp/055818no/datadir/test_backupdir-yewuvof3"
2025/09/09 06:22:31 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file10.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file11.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file5L.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file5R.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : Local file system at /tmp/055818no/datadir/test_backupdir-yewuvof3: Waiting for checks to finish
2025/09/09 06:22:31 DEBUG : Local file system at /tmp/055818no/datadir/test_backupdir-yewuvof3: Waiting for transfers to finish
2025/09/09 06:22:31 DEBUG : file10.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK
2025/09/09 06:22:31 DEBUG : file10.txt.c02780cb.partial: renamed to: file10.txt
2025/09/09 06:22:31 INFO  : file10.txt: Copied (new)
2025/09/09 06:22:31 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK
2025/09/09 06:22:31 DEBUG : file11.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK
2025/09/09 06:22:31 DEBUG : file1.txt.75b77f44.partial: renamed to: file1.txt
2025/09/09 06:22:31 INFO  : file1.txt: Copied (new)
2025/09/09 06:22:31 DEBUG : file11.txt.40d797d4.partial: renamed to: file11.txt
2025/09/09 06:22:31 INFO  : file11.txt: Copied (new)
2025/09/09 06:22:31 DEBUG : file5L.txt: md5 = 0860a03592626642f8fd6c8bfb447d2a OK
2025/09/09 06:22:31 DEBUG : file5L.txt.8dd6541a.partial: renamed to: file5L.txt
2025/09/09 06:22:31 INFO  : file5L.txt: Copied (new)
2025/09/09 06:22:31 DEBUG : file2.txt: md5 = fb3ecfb2800400fb01b0bfd39903e9fb OK
2025/09/09 06:22:31 DEBUG : file2.txt.4526d70e.partial: renamed to: file2.txt
2025/09/09 06:22:31 INFO  : file2.txt: Copied (new)
2025/09/09 06:22:31 DEBUG : file5R.txt: md5 = 979a803b15d27df0c31ad7d29006d10b OK
2025/09/09 06:22:31 DEBUG : file7.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK
2025/09/09 06:22:31 DEBUG : file5R.txt.ee3b9525.partial: renamed to: file5R.txt
2025/09/09 06:22:31 DEBUG : file6.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK
2025/09/09 06:22:31 INFO  : file5R.txt: Copied (new)
2025/09/09 06:22:31 DEBUG : file7.txt.c1750184.partial: renamed to: file7.txt
2025/09/09 06:22:31 INFO  : file7.txt: Copied (new)
2025/09/09 06:22:31 DEBUG : file6.txt.4185169b.partial: renamed to: file6.txt
2025/09/09 06:22:31 INFO  : file6.txt: Copied (new)
2025/09/09 06:22:31 DEBUG : Waiting for deletions to finish
2025/09/09 06:22:31 ERROR : error listing: directory not found
2025/09/09 06:22:31 ERROR : Local file system at /tmp/055818no/backupdir/path2: Failed to list "": directory not found
2025/09/09 06:22:31 DEBUG : removing 1 level 0 directories
2025/09/09 06:22:31 INFO  : Local file system at /tmp/055818no/backupdir/path2: Removing directory
2025/09/09 06:22:31 ERROR : Failed to rmdir: stat /tmp/055818no/backupdir/path2: no such file or directory
2025/09/09 06:22:31 ERROR : error listing: directory not found
2025/09/09 06:22:31 NOTICE: checking initFs Local file system at /tmp/055818no/initdir/test_backupdir-suqunaw0
2025/09/09 06:22:31 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file5.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : file8.txt: Need to transfer - File not found at Destination
2025/09/09 06:22:31 DEBUG : gofile root 'rclone-test-numerem3fipe/055818no/backupdir/path1': Waiting for checks to finish
2025/09/09 06:22:31 DEBUG : gofile root 'rclone-test-numerem3fipe/055818no/backupdir/path1': Waiting for transfers to finish
2025/09/09 06:22:32 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:22:32 INFO  : file2.txt: Copied (new)
2025/09/09 06:22:32 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/09/09 06:22:32 INFO  : RCLONE_TEST: Copied (new)
2025/09/09 06:22:32 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:22:32 INFO  : file4.txt: Copied (new)
2025/09/09 06:22:32 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:22:32 INFO  : file5.txt: Copied (new)
2025/09/09 06:22:32 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:22:32 INFO  : file6.txt: Copied (new)
2025/09/09 06:22:32 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:22:32 INFO  : file7.txt: Copied (new)
2025/09/09 06:22:32 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:22:32 INFO  : file8.txt: Copied (new)
2025/09/09 06:24:41 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:24:41 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:24:41 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:24:41 DEBUG : file1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 0/10
2025/09/09 06:24:42 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:24:42 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:24:42 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:24:42 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:24:42 DEBUG : file3.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 0/10
2025/09/09 06:24:42 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:26:52 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:26:52 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:26:52 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:26:52 DEBUG : file1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 1/10
2025/09/09 06:26:53 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:26:53 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:26:53 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:26:53 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:26:53 DEBUG : file3.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 1/10
2025/09/09 06:26:53 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:29:04 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:29:04 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:29:04 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:29:04 DEBUG : file1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 2/10
2025/09/09 06:29:04 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:29:04 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:29:04 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:29:04 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:29:04 DEBUG : file3.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 2/10
2025/09/09 06:29:04 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:31:15 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:31:15 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:31:15 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:31:15 DEBUG : file1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 3/10
2025/09/09 06:31:15 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:31:15 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:31:15 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:31:15 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:31:15 DEBUG : file3.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 3/10
2025/09/09 06:31:15 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:33:26 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:33:26 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:33:26 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:33:26 DEBUG : file1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 4/10
2025/09/09 06:33:26 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:33:26 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:33:26 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:33:26 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:33:26 DEBUG : file3.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 4/10
2025/09/09 06:33:26 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:35:37 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:35:37 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:35:37 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:35:37 DEBUG : file1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 5/10
2025/09/09 06:35:37 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:35:37 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:35:37 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:35:37 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:35:37 DEBUG : file3.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 5/10
2025/09/09 06:35:37 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:37:48 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:37:48 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:37:48 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:37:48 DEBUG : file1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 6/10
2025/09/09 06:37:48 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:37:48 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:37:48 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:37:48 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:37:48 DEBUG : file3.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 6/10
2025/09/09 06:37:48 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:39:59 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:39:59 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:39:59 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:39:59 DEBUG : file1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 7/10
2025/09/09 06:39:59 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:39:59 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:39:59 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:39:59 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:39:59 DEBUG : file3.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 7/10
2025/09/09 06:39:59 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:42:10 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:42:10 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:42:10 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:42:10 DEBUG : file1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 8/10
2025/09/09 06:42:10 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:42:10 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:42:10 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:42:10 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:42:10 DEBUG : file3.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 8/10
2025/09/09 06:42:10 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:44:21 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:44:21 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:44:21 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:44:21 DEBUG : file1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 9/10
2025/09/09 06:44:21 ERROR : file1.txt: Failed to copy: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n"
2025/09/09 06:44:21 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:44:21 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:44:21 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/09/09 06:44:21 DEBUG : file3.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 9/10
2025/09/09 06:44:21 ERROR : file3.txt: Failed to copy: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n"
    bisync_test.go:2013: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:2013
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:506
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:405
        	Error:      	Received unexpected error:
        	            	failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n"
        	Test:       	TestBisyncRemoteLocal/backupdir
        	Messages:   	setting up path1
2025/09/09 06:44:21 NOTICE: checking Path1 gofile root 'rclone-test-numerem3fipe/055818no/backupdir/path1'
2025/09/09 06:44:21 DEBUG : pacer: Reducing sleep to 20ms
    fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:298: Flushing the directory cache
2025/09/09 06:44:23 DEBUG : pacer: Reducing sleep to 10ms
    fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3
    fstest.go:298: Flushing the directory cache
    fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3
    fstest.go:298: Flushing the directory cache
    fstest.go:302: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:302
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:508
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:405
        	Error:      	Should be true
        	Test:       	TestBisyncRemoteLocal/backupdir
        	Messages:   	listing wrong, want
        	            	  RCLONE_TEST (109), file1.txt (0), file2.txt (0), file3.txt (0), file4.txt (0), file5.txt (0), file6.txt (0), file7.txt (0), file8.txt (0) got
        	            	  RCLONE_TEST (109)
    fstest.go:200: Not found "file6.txt"
    fstest.go:200: Not found "file1.txt"
    fstest.go:200: Not found "file2.txt"
    fstest.go:200: Not found "file4.txt"
    fstest.go:200: Not found "file5.txt"
    fstest.go:200: Not found "file7.txt"
    fstest.go:200: Not found "file8.txt"
    fstest.go:200: Not found "file3.txt"
    fstest.go:203: 
        	Error Trace:	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:203
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:307
        	            				/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:335
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:508
        	            				/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:405
        	Error:      	Not equal: 
        	            	expected: 0
        	            	actual  : 8
        	Test:       	TestBisyncRemoteLocal/backupdir
        	Messages:   	8 objects not found
2025/09/09 06:44:29 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/09/09 06:44:29 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:29 DEBUG : file2.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:29 DEBUG : file3.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:29 DEBUG : file4.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:29 DEBUG : file5.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:29 DEBUG : file6.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:29 DEBUG : file7.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:29 DEBUG : file8.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:29 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:44:29 DEBUG : Local file system at /tmp/055818no/backupdir/path2: Waiting for checks to finish
2025/09/09 06:44:29 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt
2025/09/09 06:44:29 INFO  : file1.txt: Copied (new)
2025/09/09 06:44:29 DEBUG : Local file system at /tmp/055818no/backupdir/path2: Waiting for transfers to finish
2025/09/09 06:44:29 DEBUG : file2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:44:29 DEBUG : file3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:44:29 DEBUG : file2.txt.3230ad67.partial: renamed to: file2.txt
2025/09/09 06:44:29 DEBUG : file3.txt.a74079f2.partial: renamed to: file3.txt
2025/09/09 06:44:29 INFO  : file2.txt: Copied (new)
2025/09/09 06:44:29 INFO  : file3.txt: Copied (new)
2025/09/09 06:44:29 DEBUG : file4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:44:29 DEBUG : file4.txt.fbf05a9b.partial: renamed to: file4.txt
2025/09/09 06:44:29 INFO  : file4.txt: Copied (new)
2025/09/09 06:44:29 DEBUG : file6.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:44:29 DEBUG : file5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:44:29 DEBUG : file6.txt.0a60f5f0.partial: renamed to: file6.txt
2025/09/09 06:44:29 INFO  : file6.txt: Copied (new)
2025/09/09 06:44:29 DEBUG : file5.txt.6e808e0e.partial: renamed to: file5.txt
2025/09/09 06:44:29 INFO  : file5.txt: Copied (new)
2025/09/09 06:44:29 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/09/09 06:44:29 DEBUG : file7.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:44:29 DEBUG : file7.txt.9f102165.partial: renamed to: file7.txt
2025/09/09 06:44:29 INFO  : file7.txt: Copied (new)
2025/09/09 06:44:29 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST
2025/09/09 06:44:29 INFO  : RCLONE_TEST: Copied (new)
2025/09/09 06:44:29 DEBUG : file8.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:44:29 DEBUG : file8.txt.b300b322.partial: renamed to: file8.txt
2025/09/09 06:44:29 INFO  : file8.txt: Copied (new)
2025/09/09 06:44:29 NOTICE: checking path2 Local file system at /tmp/055818no/backupdir/path2
2025/09/09 06:44:29 NOTICE: (01)  : test backupdir
2025/09/09 06:44:29 NOTICE: (02)  : test initial bisync
2025/09/09 06:44:29 NOTICE: (03)  : bisync resync backupdir1=/tmp/055818no/workdir/backupdirs/backupdir1 backupdir2=/tmp/055818no/workdir/backupdirs/backupdir2
    bisync_test.go:975: backupdir test currently only works on local (it uses the workdir)
=== RUN   TestBisyncRemoteLocal/basic
2025/09/09 06:44:29 DEBUG : Creating backend with remote "TestGoFile:rclone-test-numerem3fipe/055818no"
2025/09/09 06:44:29 DEBUG : Config file has changed externally - reloading
2025/09/09 06:44:29 INFO  : path1: Making directory
2025/09/09 06:44:30 DEBUG : Creating backend with remote "TestGoFile:rclone-test-numerem3fipe/055818no/basic/path1"
2025/09/09 06:44:30 DEBUG : Creating backend with remote "/tmp/055818no"
2025/09/09 06:44:30 DEBUG : Creating backend with remote "/tmp/055818no/basic/path2"
2025/09/09 06:44:30 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_basic/initial"
2025/09/09 06:44:30 DEBUG : Creating backend with remote "/tmp/055818no/initdir/test_basic-hicoxuc8"
2025/09/09 06:44:30 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/09/09 06:44:30 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:30 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:30 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:30 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:30 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:30 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:30 DEBUG : subdir: Making directory with metadata
2025/09/09 06:44:30 INFO  : subdir: Made directory with metadata (mtime=2021-11-02T05:00:07Z)
2025/09/09 06:44:30 DEBUG : Added delayed dir = "subdir", newDst=subdir
2025/09/09 06:44:30 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:30 DEBUG : file1.copy1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:44:30 DEBUG : file1.copy1.txt.21b8fa2b.partial: renamed to: file1.copy1.txt
2025/09/09 06:44:30 INFO  : file1.copy1.txt: Copied (new)
2025/09/09 06:44:30 DEBUG : file1.copy2.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:44:30 DEBUG : Local file system at /tmp/055818no/initdir/test_basic-hicoxuc8: Waiting for checks to finish
2025/09/09 06:44:30 DEBUG : file1.copy2.txt.455881d5.partial: renamed to: file1.copy2.txt
2025/09/09 06:44:30 DEBUG : Local file system at /tmp/055818no/initdir/test_basic-hicoxuc8: Waiting for transfers to finish
2025/09/09 06:44:30 INFO  : file1.copy2.txt: Copied (new)
2025/09/09 06:44:30 DEBUG : file1.copy3.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:44:30 DEBUG : file1.copy3.txt.d0285540.partial: renamed to: file1.copy3.txt
2025/09/09 06:44:30 INFO  : file1.copy3.txt: Copied (new)
2025/09/09 06:44:30 DEBUG : file1.copy4.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:44:30 DEBUG : file1.copy5.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:44:30 DEBUG : file1.copy4.txt.8c987629.partial: renamed to: file1.copy4.txt
2025/09/09 06:44:30 DEBUG : file1.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:44:30 INFO  : file1.copy4.txt: Copied (new)
2025/09/09 06:44:30 DEBUG : file1.copy5.txt.19e8a2bc.partial: renamed to: file1.copy5.txt
2025/09/09 06:44:30 INFO  : file1.copy5.txt: Copied (new)
2025/09/09 06:44:30 DEBUG : file1.txt.56d0d699.partial: renamed to: file1.txt
2025/09/09 06:44:30 INFO  : file1.txt: Copied (new)
2025/09/09 06:44:30 DEBUG : subdir/file20.txt: md5 = d41d8cd98f00b204e9800998ecf8427e OK
2025/09/09 06:44:30 DEBUG : subdir/file20.txt.1ac3db2f.partial: renamed to: subdir/file20.txt
2025/09/09 06:44:30 INFO  : subdir/file20.txt: Copied (new)
2025/09/09 06:44:30 DEBUG : RCLONE_TEST: md5 = 294d25b294ff26a5243dba914ac3fbf7 OK
2025/09/09 06:44:30 DEBUG : RCLONE_TEST.abb09051.partial: renamed to: RCLONE_TEST
2025/09/09 06:44:30 INFO  : RCLONE_TEST: Copied (new)
2025/09/09 06:44:30 INFO  : subdir: Set directory modification time (using SetModTime)
2025/09/09 06:44:30 DEBUG : Creating backend with remote "/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/testdata/test_basic/modfiles"
2025/09/09 06:44:30 DEBUG : Creating backend with remote "/tmp/055818no/datadir/test_basic-zoloqoc9"
2025/09/09 06:44:30 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:30 DEBUG : Local file system at /tmp/055818no/datadir/test_basic-zoloqoc9: Waiting for checks to finish
2025/09/09 06:44:30 DEBUG : Local file system at /tmp/055818no/datadir/test_basic-zoloqoc9: Waiting for transfers to finish
2025/09/09 06:44:30 DEBUG : file1.txt: md5 = 7fe98ed88552b828777d8630900346b8 OK
2025/09/09 06:44:30 DEBUG : file1.txt.75b77f44.partial: renamed to: file1.txt
2025/09/09 06:44:30 INFO  : file1.txt: Copied (new)
2025/09/09 06:44:30 DEBUG : Waiting for deletions to finish
2025/09/09 06:44:30 ERROR : error listing: directory not found
2025/09/09 06:44:30 ERROR : Local file system at /tmp/055818no/basic/path2: Failed to list "": directory not found
2025/09/09 06:44:30 DEBUG : removing 1 level 0 directories
2025/09/09 06:44:30 INFO  : Local file system at /tmp/055818no/basic/path2: Removing directory
2025/09/09 06:44:30 ERROR : Failed to rmdir: stat /tmp/055818no/basic/path2: no such file or directory
2025/09/09 06:44:30 ERROR : error listing: directory not found
2025/09/09 06:44:30 NOTICE: checking initFs Local file system at /tmp/055818no/initdir/test_basic-hicoxuc8
2025/09/09 06:44:30 DEBUG : RCLONE_TEST: Need to transfer - File not found at Destination
2025/09/09 06:44:30 DEBUG : file1.copy1.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:30 DEBUG : file1.copy2.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:30 DEBUG : file1.copy3.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:30 DEBUG : file1.copy4.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:30 DEBUG : file1.copy5.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:30 DEBUG : file1.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:30 INFO  : subdir: Making directory
2025/09/09 06:44:31 INFO  : subdir: Made directory with modification time 2021-11-02 05:00:07 +0000 UTC
2025/09/09 06:44:31 DEBUG : Added delayed dir = "subdir", newDst=<nil>
2025/09/09 06:44:31 DEBUG : subdir/file20.txt: Need to transfer - File not found at Destination
2025/09/09 06:44:31 DEBUG : gofile root 'rclone-test-numerem3fipe/055818no/basic/path1': Waiting for checks to finish
2025/09/09 06:44:31 DEBUG : gofile root 'rclone-test-numerem3fipe/055818no/basic/path1': Waiting for transfers to finish
2025/09/09 06:46:40 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:46:40 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:46:40 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:46:40 DEBUG : RCLONE_TEST: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 0/10
2025/09/09 06:46:41 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:46:41 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:46:41 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/09/09 06:46:41 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:46:41 DEBUG : file1.copy1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 0/10
2025/09/09 06:46:41 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:46:41 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:46:41 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/09/09 06:46:41 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:46:41 DEBUG : pacer: Rate limited, increasing sleep to 160ms
2025/09/09 06:46:41 DEBUG : file1.copy2.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 0/10
2025/09/09 06:46:41 DEBUG : file1.copy3.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 0/10
2025/09/09 06:46:41 DEBUG : pacer: Reducing sleep to 80ms
2025/09/09 06:46:41 DEBUG : pacer: Reducing sleep to 40ms
2025/09/09 06:46:41 DEBUG : pacer: Reducing sleep to 20ms
2025/09/09 06:46:41 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:48:51 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:48:51 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:48:51 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:48:51 DEBUG : file1.copy3.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 1/10
2025/09/09 06:48:52 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:48:52 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:48:52 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:48:52 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:48:52 DEBUG : file1.copy2.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 1/10
2025/09/09 06:48:52 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:48:52 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:48:52 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/09/09 06:48:52 DEBUG : file1.copy1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 1/10
2025/09/09 06:48:52 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:48:52 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:48:52 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/09/09 06:48:52 DEBUG : RCLONE_TEST: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 1/10
2025/09/09 06:48:52 DEBUG : pacer: Reducing sleep to 40ms
2025/09/09 06:48:52 DEBUG : pacer: Reducing sleep to 20ms
2025/09/09 06:48:52 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:51:02 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:51:02 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:51:02 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:51:02 DEBUG : file1.copy3.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 2/10
2025/09/09 06:51:03 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:51:03 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:51:03 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:51:03 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:51:03 DEBUG : file1.copy2.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 2/10
2025/09/09 06:51:03 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:51:03 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:51:03 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/09/09 06:51:03 DEBUG : file1.copy1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 2/10
2025/09/09 06:51:03 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:51:03 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:51:03 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/09/09 06:51:03 DEBUG : RCLONE_TEST: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 2/10
2025/09/09 06:51:03 DEBUG : pacer: Reducing sleep to 40ms
2025/09/09 06:51:03 DEBUG : pacer: Reducing sleep to 20ms
2025/09/09 06:51:03 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:53:14 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:53:14 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:53:14 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:53:14 DEBUG : file1.copy3.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 3/10
2025/09/09 06:53:14 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:53:14 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:53:14 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:53:14 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:53:14 DEBUG : file1.copy1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 3/10
2025/09/09 06:53:14 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:53:14 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:53:14 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:53:14 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/09/09 06:53:14 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:53:14 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/09/09 06:53:14 DEBUG : file1.copy2.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 3/10
2025/09/09 06:53:14 DEBUG : RCLONE_TEST: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 3/10
2025/09/09 06:53:14 DEBUG : pacer: Reducing sleep to 40ms
2025/09/09 06:53:14 DEBUG : pacer: Reducing sleep to 20ms
2025/09/09 06:53:14 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:55:25 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:55:25 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:55:25 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:55:25 DEBUG : file1.copy3.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 4/10
2025/09/09 06:55:25 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:55:25 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:55:25 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:55:25 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:55:25 DEBUG : RCLONE_TEST: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 4/10
2025/09/09 06:55:25 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:55:25 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:55:25 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/09/09 06:55:25 DEBUG : file1.copy1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 4/10
2025/09/09 06:55:25 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:55:25 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:55:25 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/09/09 06:55:25 DEBUG : file1.copy2.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 4/10
2025/09/09 06:55:25 DEBUG : pacer: Reducing sleep to 40ms
2025/09/09 06:55:25 DEBUG : pacer: Reducing sleep to 20ms
2025/09/09 06:55:25 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:57:36 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:57:36 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:57:36 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:57:36 DEBUG : file1.copy3.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 5/10
2025/09/09 06:57:36 DEBUG : pacer: Reducing sleep to 10ms
2025/09/09 06:57:36 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:57:36 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:57:36 DEBUG : pacer: Rate limited, increasing sleep to 20ms
2025/09/09 06:57:36 DEBUG : file1.copy1.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 5/10
2025/09/09 06:57:36 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:57:36 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:57:36 DEBUG : pacer: Rate limited, increasing sleep to 40ms
2025/09/09 06:57:36 DEBUG : RCLONE_TEST: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 5/10
2025/09/09 06:57:36 DEBUG : Couldn't decode error response: invalid character 'E' looking for beginning of value
2025/09/09 06:57:36 DEBUG : pacer: low level retry 1/1 (error Error "502 Bad Gateway (502): Error forwarding request to upload server\n")
2025/09/09 06:57:36 DEBUG : pacer: Rate limited, increasing sleep to 80ms
2025/09/09 06:57:36 DEBUG : file1.copy2.txt: Received error: failed to upload file: Error "502 Bad Gateway (502): Error forwarding request to upload server\n" - low level retry 5/10
2025/09/09 06:57:36 DEBUG : pacer: Reducing sleep to 40ms
2025/09/09 06:57:36 DEBUG : pacer: Reducing sleep to 20ms
2025/09/09 06:57:36 DEBUG : pacer: Reducing sleep to 10ms
panic: test timed out after 1h0m0s
	running tests:
		TestBisyncRemoteLocal (1h0m0s)
		TestBisyncRemoteLocal/basic (13m49s)

goroutine 2525 [running]:
testing.(*M).startAlarm.func1()
	/usr/local/go/src/testing/testing.go:2484 +0x394
created by time.goFunc
	/usr/local/go/src/time/sleep.go:215 +0x2d

goroutine 1 [chan receive, 59 minutes]:
testing.(*T).Run(0xc0009d4000, {0x27e6fa5?, 0xc0007776e0?}, 0x2912a38)
	/usr/local/go/src/testing/testing.go:1859 +0x431
testing.runTests.func1(0xc0009d4000)
	/usr/local/go/src/testing/testing.go:2279 +0x37
testing.tRunner(0xc0009d4000, 0xc000777820)
	/usr/local/go/src/testing/testing.go:1792 +0xf4
testing.runTests(0xc0009896f8, {0x40757c0, 0x4, 0x4}, {0xee051b8fa?, 0x40b3a80?, 0x40b3a80?})
	/usr/local/go/src/testing/testing.go:2277 +0x4b4
testing.(*M).Run(0xc00051bc20)
	/usr/local/go/src/testing/testing.go:2142 +0x64a
github.com/rclone/rclone/fstest.TestMain(0xc00051bc20)
	/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:69 +0xa5
github.com/rclone/rclone/cmd/bisync_test.TestMain(0xc00051bc20)
	/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:243 +0xf2
main.main()
	_testmain.go:55 +0xa8

goroutine 1875 [sync.WaitGroup.Wait, 13 minutes]:
sync.runtime_SemacquireWaitGroup(0x0?)
	/usr/local/go/src/runtime/sema.go:110 +0x25
sync.(*WaitGroup).Wait(0xc00098ee07?)
	/usr/local/go/src/sync/waitgroup.go:118 +0x48
github.com/rclone/rclone/fs/sync.(*syncCopyMove).stopTransfers(0xc0002fef08)
	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:543 +0x6f
github.com/rclone/rclone/fs/sync.(*syncCopyMove).run(0xc0002fef08)
	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:978 +0x325
github.com/rclone/rclone/fs/sync.runSyncCopyMove({0x2c69b88, 0xc00051d200}, {0x2c804f0, 0xc000424100}, {0x2c81050, 0xc00055f080}, 0x0, 0x0, 0x0, 0x1, ...)
	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:1369 +0x225
github.com/rclone/rclone/fs/sync.CopyDir(...)
	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:1380
github.com/rclone/rclone/cmd/bisync_test.(*bisyncTest).runTestCase(0xc0008468c0, {0x2c69b88, 0xc00044fb90}, 0x66b?, {0xc0004b0285?, 0x560200?})
	/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:506 +0xeda
github.com/rclone/rclone/cmd/bisync_test.testBisync.func4(0xc000846700)
	/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:405 +0x234
testing.tRunner(0xc000846700, 0xc0005c2ba0)
	/usr/local/go/src/testing/testing.go:1792 +0xf4
created by testing.(*T).Run in goroutine 68
	/usr/local/go/src/testing/testing.go:1851 +0x413

goroutine 25 [syscall, 60 minutes]:
os/signal.signal_recv()
	/usr/local/go/src/runtime/sigqueue.go:152 +0x29
os/signal.loop()
	/usr/local/go/src/os/signal/signal_unix.go:23 +0x13
created by os/signal.Notify.func1.1 in goroutine 1
	/usr/local/go/src/os/signal/signal.go:152 +0x1f

goroutine 26 [chan receive, 60 minutes]:
github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler.func1()
	/home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:24 +0x27
created by github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler in goroutine 1
	/home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:21 +0xa7

goroutine 27 [chan receive, 60 minutes]:
github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler.func1()
	/home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:24 +0x27
created by github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler in goroutine 1
	/home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:21 +0xa7

goroutine 35 [chan receive, 59 minutes]:
github.com/rclone/rclone/lib/atexit.Register.func1.1()
	/home/rclone/go/src/github.com/rclone/rclone/lib/atexit/atexit.go:45 +0x29
created by github.com/rclone/rclone/lib/atexit.Register.func1 in goroutine 68
	/home/rclone/go/src/github.com/rclone/rclone/lib/atexit/atexit.go:44 +0x68

goroutine 68 [chan receive, 13 minutes]:
testing.(*T).Run(0xc0009d41c0, {0xc0004b0285?, 0x2c2f088?}, 0xc0005c2ba0)
	/usr/local/go/src/testing/testing.go:1859 +0x431
github.com/rclone/rclone/cmd/bisync_test.testBisync({0x2c69b88, 0xc0007544b0}, 0xc0009d41c0, {0xc0009c3500, 0x23}, {0x0, 0x0})
	/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:398 +0x94f
github.com/rclone/rclone/cmd/bisync_test.TestBisyncRemoteLocal(0xc0009d41c0)
	/home/rclone/go/src/github.com/rclone/rclone/cmd/bisync/bisync_test.go:256 +0x175
testing.tRunner(0xc0009d41c0, 0x2912a38)
	/usr/local/go/src/testing/testing.go:1792 +0xf4
created by testing.(*T).Run in goroutine 1
	/usr/local/go/src/testing/testing.go:1851 +0x413

goroutine 2478 [select]:
github.com/rclone/rclone/fs/accounting.(*Account).averageLoop(0xc00025f000)
	/home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting.go:221 +0xed
created by github.com/rclone/rclone/fs/accounting.newAccountSizeName in goroutine 2173
	/home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting.go:119 +0x436

goroutine 2258 [select]:
net/http.(*persistConn).writeLoop(0xc00070a7e0)
	/usr/local/go/src/net/http/transport.go:2590 +0xe7
created by net/http.(*Transport).dialConn in goroutine 2229
	/usr/local/go/src/net/http/transport.go:1945 +0x17a5

goroutine 2185 [chan receive, 13 minutes]:
github.com/rclone/rclone/fs/march.(*March).Run.func2()
	/home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:255 +0x3c
created by github.com/rclone/rclone/fs/march.(*March).Run in goroutine 1875
	/home/rclone/go/src/github.com/rclone/rclone/fs/march/march.go:253 +0x378

goroutine 2174 [select]:
net/http.(*persistConn).roundTrip(0xc00070a900, 0xc000758280)
	/usr/local/go/src/net/http/transport.go:2826 +0x785
net/http.(*Transport).roundTrip(0xc000517520, 0xc0009932c0)
	/usr/local/go/src/net/http/transport.go:696 +0xb9a
net/http.(*Transport).RoundTrip(...)
	/usr/local/go/src/net/http/roundtrip.go:30
github.com/rclone/rclone/fs/fshttp.(*Transport).RoundTrip(0xc00053eae0, 0xc0009932c0)
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:496 +0x345
net/http.send(0xc0009932c0, {0x2c423a0, 0xc00053eae0}, {0x6fe001?, 0x281f497?, 0x0?})
	/usr/local/go/src/net/http/client.go:259 +0x5e2
net/http.(*Client).send(0xc0003ffdd0, 0xc0009932c0, {0xb?, 0x1?, 0x0?})
	/usr/local/go/src/net/http/client.go:180 +0x91
net/http.(*Client).do(0xc0003ffdd0, 0xc0009932c0)
	/usr/local/go/src/net/http/client.go:728 +0x989
net/http.(*Client).Do(...)
	/usr/local/go/src/net/http/client.go:587
github.com/rclone/rclone/lib/rest.(*Client).Call(0xc000759590, {0x2c69bc0, 0xc00098eeb0}, 0xc00006d260)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:353 +0xd67
github.com/rclone/rclone/lib/rest.(*Client).callCodec(0xc000759590, {0x2c69bc0, 0xc00098eeb0}, 0xc0000be008?, {0x0?, 0x0?}, {0x23442c0, 0xc00013f080}, 0x413a11?, 0x29141e8, ...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:550 +0x3f2
github.com/rclone/rclone/lib/rest.(*Client).CallJSON(...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:493
github.com/rclone/rclone/backend/gofile.(*Object).Update.func2()
	/home/rclone/go/src/github.com/rclone/rclone/backend/gofile/gofile.go:1461 +0x88
github.com/rclone/rclone/fs.pacerInvoker(0x1, 0x1, 0xc000780f30?)
	/home/rclone/go/src/github.com/rclone/rclone/fs/pacer.go:86 +0x32
github.com/rclone/rclone/lib/pacer.(*Pacer).call(0xc00053eb40, 0xc000a32540, 0x1)
	/home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:199 +0x7c
github.com/rclone/rclone/lib/pacer.(*Pacer).CallNoRetry(...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:227
github.com/rclone/rclone/backend/gofile.(*Object).Update(0xc000788c60, {0x2c69bc0, 0xc00098eeb0}, {0x2c40f80, 0xc000538900}, {0x7062c80443a0, 0xc0006dd6e0}, {0xc0008321d0, 0x1, 0x1})
	/home/rclone/go/src/github.com/rclone/rclone/backend/gofile/gofile.go:1460 +0x628
github.com/rclone/rclone/backend/gofile.(*Fs).PutUnchecked(0xc000424100, {0x2c69bc0, 0xc00098eeb0}, {0x2c40f80, 0xc000538900}, {0x7062c80443a0, 0xc0006dd6e0}, {0xc0008321d0, 0x1, 0x1})
	/home/rclone/go/src/github.com/rclone/rclone/backend/gofile/gofile.go:790 +0x14c
github.com/rclone/rclone/backend/gofile.(*Fs).Put(0xc000424100, {0x2c69bc0, 0xc00098eeb0}, {0x2c40f80, 0xc000538900}, {0x7062c80443a0, 0xc0006dd6e0}, {0xc0008321d0, 0x1, 0x1})
	/home/rclone/go/src/github.com/rclone/rclone/backend/gofile/gofile.go:763 +0x12c
github.com/rclone/rclone/fs/operations.(*copy).updateOrPut(0xc0007881b0, {0x2c69bc0, 0xc00098eeb0}, {0x2c54808?, 0xc0008f6460?}, {0xc0008321d0, 0x1, 0x1})
	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:221 +0x225
github.com/rclone/rclone/fs/operations.(*copy).manualCopy(0xc0007881b0, {0x2c69bc0, 0xc00098eeb0})
	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:274 +0x6d8
github.com/rclone/rclone/fs/operations.(*copy).copy(0xc0007881b0, {0x2c69bc0, 0xc00098eeb0})
	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:314 +0x170
github.com/rclone/rclone/fs/operations.Copy({0x2c69bc0, 0xc00098eeb0}, {0x2c804f0, 0xc000424100}, {0x0, 0x0}, {0xc000780f30, 0xb}, {0x2c810c0, 0xc0006dd6e0})
	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:416 +0x4db
github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove(0xc0002fef08, {0x2c69bc0, 0xc00098eeb0}, 0xc00098ee10, {0x2c804f0, 0xc000424100}, 0x19, 0x0?)
	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:505 +0x1fe
created by github.com/rclone/rclone/fs/sync.(*syncCopyMove).startTransfers in goroutine 1875
	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:535 +0x7d

goroutine 2176 [select]:
net/http.(*persistConn).roundTrip(0xc00070a7e0, 0xc0006945f0)
	/usr/local/go/src/net/http/transport.go:2826 +0x785
net/http.(*Transport).roundTrip(0xc000517520, 0xc00044ac80)
	/usr/local/go/src/net/http/transport.go:696 +0xb9a
net/http.(*Transport).RoundTrip(...)
	/usr/local/go/src/net/http/roundtrip.go:30
github.com/rclone/rclone/fs/fshttp.(*Transport).RoundTrip(0xc00053eae0, 0xc00044ac80)
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:496 +0x345
net/http.send(0xc00044ac80, {0x2c423a0, 0xc00053eae0}, {0x6fe001?, 0x281f497?, 0x0?})
	/usr/local/go/src/net/http/client.go:259 +0x5e2
net/http.(*Client).send(0xc0003ffdd0, 0xc00044ac80, {0xb?, 0x1?, 0x0?})
	/usr/local/go/src/net/http/client.go:180 +0x91
net/http.(*Client).do(0xc0003ffdd0, 0xc00044ac80)
	/usr/local/go/src/net/http/client.go:728 +0x989
net/http.(*Client).Do(...)
	/usr/local/go/src/net/http/client.go:587
github.com/rclone/rclone/lib/rest.(*Client).Call(0xc000759590, {0x2c69bc0, 0xc00098eeb0}, 0xc000b25260)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:353 +0xd67
github.com/rclone/rclone/lib/rest.(*Client).callCodec(0xc000759590, {0x2c69bc0, 0xc00098eeb0}, 0x419691?, {0x0?, 0x0?}, {0x23442c0, 0xc0009b9440}, 0x41373d?, 0x29141e8, ...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:550 +0x3f2
github.com/rclone/rclone/lib/rest.(*Client).CallJSON(...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:493
github.com/rclone/rclone/backend/gofile.(*Object).Update.func2()
	/home/rclone/go/src/github.com/rclone/rclone/backend/gofile/gofile.go:1461 +0x88
github.com/rclone/rclone/fs.pacerInvoker(0x1, 0x1, 0xc000781150?)
	/home/rclone/go/src/github.com/rclone/rclone/fs/pacer.go:86 +0x32
github.com/rclone/rclone/lib/pacer.(*Pacer).call(0xc00053eb40, 0xc00079cf80, 0x1)
	/home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:199 +0x7c
github.com/rclone/rclone/lib/pacer.(*Pacer).CallNoRetry(...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:227
github.com/rclone/rclone/backend/gofile.(*Object).Update(0xc0007ec360, {0x2c69bc0, 0xc00098eeb0}, {0x2c40f80, 0xc000894200}, {0x7062c80443a0, 0xc0006ddce0}, {0xc00098c1d0, 0x1, 0x1})
	/home/rclone/go/src/github.com/rclone/rclone/backend/gofile/gofile.go:1460 +0x628
github.com/rclone/rclone/backend/gofile.(*Fs).PutUnchecked(0xc000424100, {0x2c69bc0, 0xc00098eeb0}, {0x2c40f80, 0xc000894200}, {0x7062c80443a0, 0xc0006ddce0}, {0xc00098c1d0, 0x1, 0x1})
	/home/rclone/go/src/github.com/rclone/rclone/backend/gofile/gofile.go:790 +0x14c
github.com/rclone/rclone/backend/gofile.(*Fs).Put(0xc000424100, {0x2c69bc0, 0xc00098eeb0}, {0x2c40f80, 0xc000894200}, {0x7062c80443a0, 0xc0006ddce0}, {0xc00098c1d0, 0x1, 0x1})
	/home/rclone/go/src/github.com/rclone/rclone/backend/gofile/gofile.go:763 +0x12c
github.com/rclone/rclone/fs/operations.(*copy).updateOrPut(0xc0001f8bd0, {0x2c69bc0, 0xc00098eeb0}, {0x2c54808?, 0xc00082f260?}, {0xc00098c1d0, 0x1, 0x1})
	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:221 +0x225
github.com/rclone/rclone/fs/operations.(*copy).manualCopy(0xc0001f8bd0, {0x2c69bc0, 0xc00098eeb0})
	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:274 +0x6d8
github.com/rclone/rclone/fs/operations.(*copy).copy(0xc0001f8bd0, {0x2c69bc0, 0xc00098eeb0})
	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:314 +0x170
github.com/rclone/rclone/fs/operations.Copy({0x2c69bc0, 0xc00098eeb0}, {0x2c804f0, 0xc000424100}, {0x0, 0x0}, {0xc000781150, 0xf}, {0x2c810c0, 0xc0006ddce0})
	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:416 +0x4db
github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove(0xc0002fef08, {0x2c69bc0, 0xc00098eeb0}, 0xc00098ee10, {0x2c804f0, 0xc000424100}, 0x4b, 0x0?)
	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:505 +0x1fe
created by github.com/rclone/rclone/fs/sync.(*syncCopyMove).startTransfers in goroutine 1875
	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:535 +0x7d

goroutine 2417 [select]:
github.com/rclone/rclone/fs/accounting.(*Account).averageLoop(0xc000943800)
	/home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting.go:221 +0xed
created by github.com/rclone/rclone/fs/accounting.newAccountSizeName in goroutine 2175
	/home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting.go:119 +0x436

goroutine 2219 [select]:
net/http.(*persistConn).writeLoop(0xc000629200)
	/usr/local/go/src/net/http/transport.go:2590 +0xe7
created by net/http.(*Transport).dialConn in goroutine 2242
	/usr/local/go/src/net/http/transport.go:1945 +0x17a5

goroutine 2173 [select]:
net/http.(*persistConn).roundTrip(0xc000629200, 0xc000758370)
	/usr/local/go/src/net/http/transport.go:2826 +0x785
net/http.(*Transport).roundTrip(0xc000517520, 0xc0009937c0)
	/usr/local/go/src/net/http/transport.go:696 +0xb9a
net/http.(*Transport).RoundTrip(...)
	/usr/local/go/src/net/http/roundtrip.go:30
github.com/rclone/rclone/fs/fshttp.(*Transport).RoundTrip(0xc00053eae0, 0xc0009937c0)
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:496 +0x345
net/http.send(0xc0009937c0, {0x2c423a0, 0xc00053eae0}, {0x6fe001?, 0x281f497?, 0x0?})
	/usr/local/go/src/net/http/client.go:259 +0x5e2
net/http.(*Client).send(0xc0003ffdd0, 0xc0009937c0, {0xb?, 0x1?, 0x0?})
	/usr/local/go/src/net/http/client.go:180 +0x91
net/http.(*Client).do(0xc0003ffdd0, 0xc0009937c0)
	/usr/local/go/src/net/http/client.go:728 +0x989
net/http.(*Client).Do(...)
	/usr/local/go/src/net/http/client.go:587
github.com/rclone/rclone/lib/rest.(*Client).Call(0xc000759590, {0x2c69bc0, 0xc00098eeb0}, 0xc000b19260)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:353 +0xd67
github.com/rclone/rclone/lib/rest.(*Client).callCodec(0xc000759590, {0x2c69bc0, 0xc00098eeb0}, 0x419691?, {0x0?, 0x0?}, {0x23442c0, 0xc00013f200}, 0x41373d?, 0x29141e8, ...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:550 +0x3f2
github.com/rclone/rclone/lib/rest.(*Client).CallJSON(...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:493
github.com/rclone/rclone/backend/gofile.(*Object).Update.func2()
	/home/rclone/go/src/github.com/rclone/rclone/backend/gofile/gofile.go:1461 +0x88
github.com/rclone/rclone/fs.pacerInvoker(0x1, 0x1, 0xc0007811b0?)
	/home/rclone/go/src/github.com/rclone/rclone/fs/pacer.go:86 +0x32
github.com/rclone/rclone/lib/pacer.(*Pacer).call(0xc00053eb40, 0xc000a32640, 0x1)
	/home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:199 +0x7c
github.com/rclone/rclone/lib/pacer.(*Pacer).CallNoRetry(...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:227
github.com/rclone/rclone/backend/gofile.(*Object).Update(0xc000788e10, {0x2c69bc0, 0xc00098eeb0}, {0x2c40f80, 0xc00025f000}, {0x7062c80443a0, 0xc0006ddd40}, {0xc00079a3c0, 0x1, 0x1})
	/home/rclone/go/src/github.com/rclone/rclone/backend/gofile/gofile.go:1460 +0x628
github.com/rclone/rclone/backend/gofile.(*Fs).PutUnchecked(0xc000424100, {0x2c69bc0, 0xc00098eeb0}, {0x2c40f80, 0xc00025f000}, {0x7062c80443a0, 0xc0006ddd40}, {0xc00079a3c0, 0x1, 0x1})
	/home/rclone/go/src/github.com/rclone/rclone/backend/gofile/gofile.go:790 +0x14c
github.com/rclone/rclone/backend/gofile.(*Fs).Put(0xc000424100, {0x2c69bc0, 0xc00098eeb0}, {0x2c40f80, 0xc00025f000}, {0x7062c80443a0, 0xc0006ddd40}, {0xc00079a3c0, 0x1, 0x1})
	/home/rclone/go/src/github.com/rclone/rclone/backend/gofile/gofile.go:763 +0x12c
github.com/rclone/rclone/fs/operations.(*copy).updateOrPut(0xc000788480, {0x2c69bc0, 0xc00098eeb0}, {0x2c54808?, 0xc000926d20?}, {0xc00079a3c0, 0x1, 0x1})
	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:221 +0x225
github.com/rclone/rclone/fs/operations.(*copy).manualCopy(0xc000788480, {0x2c69bc0, 0xc00098eeb0})
	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:274 +0x6d8
github.com/rclone/rclone/fs/operations.(*copy).copy(0xc000788480, {0x2c69bc0, 0xc00098eeb0})
	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:314 +0x170
github.com/rclone/rclone/fs/operations.Copy({0x2c69bc0, 0xc00098eeb0}, {0x2c804f0, 0xc000424100}, {0x0, 0x0}, {0xc0007811b0, 0xf}, {0x2c810c0, 0xc0006ddd40})
	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:416 +0x4db
github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove(0xc0002fef08, {0x2c69bc0, 0xc00098eeb0}, 0xc00098ee10, {0x2c804f0, 0xc000424100}, 0x0, 0xc0004c9f40?)
	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:505 +0x1fe
created by github.com/rclone/rclone/fs/sync.(*syncCopyMove).startTransfers in goroutine 1875
	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:535 +0x7d

goroutine 2274 [select]:
net/http.(*persistConn).writeLoop(0xc0006b4a20)
	/usr/local/go/src/net/http/transport.go:2590 +0xe7
created by net/http.(*Transport).dialConn in goroutine 2157
	/usr/local/go/src/net/http/transport.go:1945 +0x17a5

goroutine 2175 [select]:
net/http.(*persistConn).roundTrip(0xc0006b4a20, 0xc000708910)
	/usr/local/go/src/net/http/transport.go:2826 +0x785
net/http.(*Transport).roundTrip(0xc000517520, 0xc0003da640)
	/usr/local/go/src/net/http/transport.go:696 +0xb9a
net/http.(*Transport).RoundTrip(...)
	/usr/local/go/src/net/http/roundtrip.go:30
github.com/rclone/rclone/fs/fshttp.(*Transport).RoundTrip(0xc00053eae0, 0xc0003da640)
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/http.go:496 +0x345
net/http.send(0xc0003da640, {0x2c423a0, 0xc00053eae0}, {0x6fe001?, 0x281f497?, 0x0?})
	/usr/local/go/src/net/http/client.go:259 +0x5e2
net/http.(*Client).send(0xc0003ffdd0, 0xc0003da640, {0xb?, 0x1?, 0x0?})
	/usr/local/go/src/net/http/client.go:180 +0x91
net/http.(*Client).do(0xc0003ffdd0, 0xc0003da640)
	/usr/local/go/src/net/http/client.go:728 +0x989
net/http.(*Client).Do(...)
	/usr/local/go/src/net/http/client.go:587
github.com/rclone/rclone/lib/rest.(*Client).Call(0xc000759590, {0x2c69bc0, 0xc00098eeb0}, 0xc000b1d260)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:353 +0xd67
github.com/rclone/rclone/lib/rest.(*Client).callCodec(0xc000759590, {0x2c69bc0, 0xc00098eeb0}, 0xc0000be808?, {0x0?, 0x0?}, {0x23442c0, 0xc00013ec00}, 0x413a11?, 0x29141e8, ...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:550 +0x3f2
github.com/rclone/rclone/lib/rest.(*Client).CallJSON(...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/rest/rest.go:493
github.com/rclone/rclone/backend/gofile.(*Object).Update.func2()
	/home/rclone/go/src/github.com/rclone/rclone/backend/gofile/gofile.go:1461 +0x88
github.com/rclone/rclone/fs.pacerInvoker(0x1, 0x1, 0xc000780d00?)
	/home/rclone/go/src/github.com/rclone/rclone/fs/pacer.go:86 +0x32
github.com/rclone/rclone/lib/pacer.(*Pacer).call(0xc00053eb40, 0xc000a32400, 0x1)
	/home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:199 +0x7c
github.com/rclone/rclone/lib/pacer.(*Pacer).CallNoRetry(...)
	/home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:227
github.com/rclone/rclone/backend/gofile.(*Object).Update(0xc000788b40, {0x2c69bc0, 0xc00098eeb0}, {0x2c40f80, 0xc000943800}, {0x7062c80443a0, 0xc0006dd140}, {0xc000668350, 0x1, 0x1})
	/home/rclone/go/src/github.com/rclone/rclone/backend/gofile/gofile.go:1460 +0x628
github.com/rclone/rclone/backend/gofile.(*Fs).PutUnchecked(0xc000424100, {0x2c69bc0, 0xc00098eeb0}, {0x2c40f80, 0xc000943800}, {0x7062c80443a0, 0xc0006dd140}, {0xc000668350, 0x1, 0x1})
	/home/rclone/go/src/github.com/rclone/rclone/backend/gofile/gofile.go:790 +0x14c
github.com/rclone/rclone/backend/gofile.(*Fs).Put(0xc000424100, {0x2c69bc0, 0xc00098eeb0}, {0x2c40f80, 0xc000943800}, {0x7062c80443a0, 0xc0006dd140}, {0xc000668350, 0x1, 0x1})
	/home/rclone/go/src/github.com/rclone/rclone/backend/gofile/gofile.go:763 +0x12c
github.com/rclone/rclone/fs/operations.(*copy).updateOrPut(0xc0001f8900, {0x2c69bc0, 0xc00098eeb0}, {0x2c54808?, 0xc0001f7180?}, {0xc000668350, 0x1, 0x1})
	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:221 +0x225
github.com/rclone/rclone/fs/operations.(*copy).manualCopy(0xc0001f8900, {0x2c69bc0, 0xc00098eeb0})
	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:274 +0x6d8
github.com/rclone/rclone/fs/operations.(*copy).copy(0xc0001f8900, {0x2c69bc0, 0xc00098eeb0})
	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:314 +0x170
github.com/rclone/rclone/fs/operations.Copy({0x2c69bc0, 0xc00098eeb0}, {0x2c804f0, 0xc000424100}, {0x0, 0x0}, {0xc000780d00, 0xf}, {0x2c810c0, 0xc0006dd140})
	/home/rclone/go/src/github.com/rclone/rclone/fs/operations/copy.go:416 +0x4db
github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove(0xc0002fef08, {0x2c69bc0, 0xc00098eeb0}, 0xc00098ee10, {0x2c804f0, 0xc000424100}, 0x32, 0xc000a2cf40?)
	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:505 +0x1fe
created by github.com/rclone/rclone/fs/sync.(*syncCopyMove).startTransfers in goroutine 1875
	/home/rclone/go/src/github.com/rclone/rclone/fs/sync/sync.go:535 +0x7d

goroutine 2110 [select]:
github.com/rclone/rclone/fs/accounting.(*StatsInfo).averageLoop(0xc0006c4780, {0x2c69bc0, 0xc000708000})
	/home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:339 +0x145
created by github.com/rclone/rclone/fs/accounting.(*StatsInfo)._startAverageLoop in goroutine 2174
	/home/rclone/go/src/github.com/rclone/rclone/fs/accounting/stats.go:376 +0x11a

goroutine 2477 [chan receive]:
github.com/rclone/rclone/backend/local.(*fadvise).worker(0xc0009249c0)
	/home/rclone/go/src/github.com/rclone/rclone/backend/local/fadvise_unix.go:114 +0x3f
created by github.com/rclone/rclone/backend/local.newFadvise in goroutine 2173
	/home/rclone/go/src/github.com/rclone/rclone/backend/local/fadvise_unix.go:74 +0x11f

goroutine 2416 [chan receive]:
github.com/rclone/rclone/backend/local.(*fadvise).worker(0xc000a321c0)
	/home/rclone/go/src/github.com/rclone/rclone/backend/local/fadvise_unix.go:114 +0x3f
created by github.com/rclone/rclone/backend/local.newFadvise in goroutine 2175
	/home/rclone/go/src/github.com/rclone/rclone/backend/local/fadvise_unix.go:74 +0x11f

goroutine 2244 [IO wait]:
internal/poll.runtime_pollWait(0x7062c8025f48, 0x72)
	/usr/local/go/src/runtime/netpoll.go:351 +0x85
internal/poll.(*pollDesc).wait(0xc000424200?, 0xc000d80000?, 0x0)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc000424200, {0xc000d80000, 0xc00, 0xc00})
	/usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a
net.(*netFD).Read(0xc000424200, {0xc000d80000?, 0x2000?, 0x0?})
	/usr/local/go/src/net/fd_posix.go:55 +0x25
net.(*conn).Read(0xc0001c03f0, {0xc000d80000?, 0x0?, 0x5?})
	/usr/local/go/src/net/net.go:194 +0x45
github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc000a80258, {0xc000d80000?, 0x7062b9e6b858?, 0x706310ee2108?})
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29
crypto/tls.(*atLeastReader).Read(0xc000a80240, {0xc000d80000?, 0x14e?, 0xc0009d99c8?})
	/usr/local/go/src/crypto/tls/conn.go:809 +0x3b
bytes.(*Buffer).ReadFrom(0xc0000cd0b8, {0x2c43aa0, 0xc000a80240})
	/usr/local/go/src/bytes/buffer.go:211 +0x98
crypto/tls.(*Conn).readFromUntil(0xc0000cce08, {0x7062ba737b18, 0xc000a80258}, 0x4426d4?)
	/usr/local/go/src/crypto/tls/conn.go:831 +0xde
crypto/tls.(*Conn).readRecordOrCCS(0xc0000cce08, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:629 +0x3cf
crypto/tls.(*Conn).readRecord(...)
	/usr/local/go/src/crypto/tls/conn.go:591
crypto/tls.(*Conn).Read(0xc0000cce08, {0xc000d98000, 0x1000, 0xc000584b10?})
	/usr/local/go/src/crypto/tls/conn.go:1385 +0x145
net/http.(*persistConn).Read(0xc00070a900, {0xc000d98000?, 0x810625?, 0x2c40580?})
	/usr/local/go/src/net/http/transport.go:2122 +0x47
bufio.(*Reader).fill(0xc00099ef00)
	/usr/local/go/src/bufio/bufio.go:113 +0x103
bufio.(*Reader).Peek(0xc00099ef00, 0x1)
	/usr/local/go/src/bufio/bufio.go:152 +0x53
net/http.(*persistConn).readLoop(0xc00070a900)
	/usr/local/go/src/net/http/transport.go:2275 +0x172
created by net/http.(*Transport).dialConn in goroutine 2237
	/usr/local/go/src/net/http/transport.go:1944 +0x174f

goroutine 2488 [select]:
github.com/rclone/rclone/fs/accounting.(*Account).averageLoop(0xc000538900)
	/home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting.go:221 +0xed
created by github.com/rclone/rclone/fs/accounting.newAccountSizeName in goroutine 2174
	/home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting.go:119 +0x436

goroutine 2487 [chan receive]:
github.com/rclone/rclone/backend/local.(*fadvise).worker(0xc0005ac380)
	/home/rclone/go/src/github.com/rclone/rclone/backend/local/fadvise_unix.go:114 +0x3f
created by github.com/rclone/rclone/backend/local.newFadvise in goroutine 2174
	/home/rclone/go/src/github.com/rclone/rclone/backend/local/fadvise_unix.go:74 +0x11f

goroutine 2475 [IO wait]:
internal/poll.runtime_pollWait(0x7062c8026178, 0x72)
	/usr/local/go/src/runtime/netpoll.go:351 +0x85
internal/poll.(*pollDesc).wait(0xc000424300?, 0xc0006a2000?, 0x0)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc000424300, {0xc0006a2000, 0xc00, 0xc00})
	/usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a
net.(*netFD).Read(0xc000424300, {0xc0006a2000?, 0xbfb?, 0xc000898280?})
	/usr/local/go/src/net/fd_posix.go:55 +0x25
net.(*conn).Read(0xc00011a118, {0xc0006a2000?, 0xc0006a2000?, 0x5?})
	/usr/local/go/src/net/net.go:194 +0x45
github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc000988078, {0xc0006a2000?, 0x706310e86480?, 0x706310ee2f30?})
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29
crypto/tls.(*atLeastReader).Read(0xc00083e450, {0xc0006a2000?, 0xbfb?, 0xc000784008?})
	/usr/local/go/src/crypto/tls/conn.go:809 +0x3b
bytes.(*Buffer).ReadFrom(0xc00067cd38, {0x2c43aa0, 0xc00083e450})
	/usr/local/go/src/bytes/buffer.go:211 +0x98
crypto/tls.(*Conn).readFromUntil(0xc00067ca88, {0x7062ba737b18, 0xc000988078}, 0x4426d4?)
	/usr/local/go/src/crypto/tls/conn.go:831 +0xde
crypto/tls.(*Conn).readRecordOrCCS(0xc00067ca88, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:629 +0x3cf
crypto/tls.(*Conn).readRecord(...)
	/usr/local/go/src/crypto/tls/conn.go:591
crypto/tls.(*Conn).Read(0xc00067ca88, {0xc0002bb000, 0x1000, 0xc000185dc0?})
	/usr/local/go/src/crypto/tls/conn.go:1385 +0x145
bufio.(*Reader).Read(0xc0009a46c0, {0xc000926ba0, 0x9, 0x401f210?})
	/usr/local/go/src/bufio/bufio.go:245 +0x197
io.ReadAtLeast({0x2c40760, 0xc0009a46c0}, {0xc000926ba0, 0x9, 0x9}, 0x9)
	/usr/local/go/src/io/io.go:335 +0x91
io.ReadFull(...)
	/usr/local/go/src/io/io.go:354
net/http.http2readFrameHeader({0xc000926ba0, 0x9, 0x703d40?}, {0x2c40760?, 0xc0009a46c0?})
	/usr/local/go/src/net/http/h2_bundle.go:1805 +0x65
net/http.(*http2Framer).ReadFrame(0xc000926b60)
	/usr/local/go/src/net/http/h2_bundle.go:2072 +0x7d
net/http.(*http2clientConnReadLoop).run(0xc000823fa8)
	/usr/local/go/src/net/http/h2_bundle.go:9933 +0xda
net/http.(*http2ClientConn).readLoop(0xc000846380)
	/usr/local/go/src/net/http/h2_bundle.go:9812 +0x79
created by net/http.(*http2Transport).newClientConn in goroutine 2474
	/usr/local/go/src/net/http/h2_bundle.go:8334 +0xde5

goroutine 2447 [select]:
github.com/rclone/rclone/fs/accounting.(*Account).averageLoop(0xc000894200)
	/home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting.go:221 +0xed
created by github.com/rclone/rclone/fs/accounting.newAccountSizeName in goroutine 2176
	/home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting.go:119 +0x436

goroutine 2218 [IO wait]:
internal/poll.runtime_pollWait(0x7062c80266f0, 0x72)
	/usr/local/go/src/runtime/netpoll.go:351 +0x85
internal/poll.(*pollDesc).wait(0xc000796500?, 0xc0006a3800?, 0x0)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc000796500, {0xc0006a3800, 0xc00, 0xc00})
	/usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a
net.(*netFD).Read(0xc000796500, {0xc0006a3800?, 0x2000?, 0x0?})
	/usr/local/go/src/net/fd_posix.go:55 +0x25
net.(*conn).Read(0xc000798210, {0xc0006a3800?, 0x0?, 0x5?})
	/usr/local/go/src/net/net.go:194 +0x45
github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc000988d20, {0xc0006a3800?, 0x706310e86480?, 0x706310ee2f30?})
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29
crypto/tls.(*atLeastReader).Read(0xc00083e0f0, {0xc0006a3800?, 0x11c?, 0xc0003869c8?})
	/usr/local/go/src/crypto/tls/conn.go:809 +0x3b
bytes.(*Buffer).ReadFrom(0xc00051e9b8, {0x2c43aa0, 0xc00083e0f0})
	/usr/local/go/src/bytes/buffer.go:211 +0x98
crypto/tls.(*Conn).readFromUntil(0xc00051e708, {0x7062ba737b18, 0xc000988d20}, 0x4426d4?)
	/usr/local/go/src/crypto/tls/conn.go:831 +0xde
crypto/tls.(*Conn).readRecordOrCCS(0xc00051e708, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:629 +0x3cf
crypto/tls.(*Conn).readRecord(...)
	/usr/local/go/src/crypto/tls/conn.go:591
crypto/tls.(*Conn).Read(0xc00051e708, {0xc000613000, 0x1000, 0xc000584b10?})
	/usr/local/go/src/crypto/tls/conn.go:1385 +0x145
net/http.(*persistConn).Read(0xc000629200, {0xc000613000?, 0x810625?, 0x2c40580?})
	/usr/local/go/src/net/http/transport.go:2122 +0x47
bufio.(*Reader).fill(0xc0008d65a0)
	/usr/local/go/src/bufio/bufio.go:113 +0x103
bufio.(*Reader).Peek(0xc0008d65a0, 0x1)
	/usr/local/go/src/bufio/bufio.go:152 +0x53
net/http.(*persistConn).readLoop(0xc000629200)
	/usr/local/go/src/net/http/transport.go:2275 +0x172
created by net/http.(*Transport).dialConn in goroutine 2242
	/usr/local/go/src/net/http/transport.go:1944 +0x174f

goroutine 2161 [IO wait]:
internal/poll.runtime_pollWait(0x7062c8025e30, 0x72)
	/usr/local/go/src/runtime/netpoll.go:351 +0x85
internal/poll.(*pollDesc).wait(0xc00025d480?, 0xc000d00000?, 0x0)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc00025d480, {0xc000d00000, 0xc00, 0xc00})
	/usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a
net.(*netFD).Read(0xc00025d480, {0xc000d00000?, 0x2000?, 0x0?})
	/usr/local/go/src/net/fd_posix.go:55 +0x25
net.(*conn).Read(0xc00011a918, {0xc000d00000?, 0x0?, 0x5?})
	/usr/local/go/src/net/net.go:194 +0x45
github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc0009ec9f0, {0xc000d00000?, 0x7062b9dfe588?, 0x706310ee2a78?})
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29
crypto/tls.(*atLeastReader).Read(0xc0009883d8, {0xc000d00000?, 0x40d9b80?, 0xc000a109c8?})
	/usr/local/go/src/crypto/tls/conn.go:809 +0x3b
bytes.(*Buffer).ReadFrom(0xc00067db38, {0x2c43aa0, 0xc0009883d8})
	/usr/local/go/src/bytes/buffer.go:211 +0x98
crypto/tls.(*Conn).readFromUntil(0xc00067d888, {0x7062ba737b18, 0xc0009ec9f0}, 0x4426d4?)
	/usr/local/go/src/crypto/tls/conn.go:831 +0xde
crypto/tls.(*Conn).readRecordOrCCS(0xc00067d888, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:629 +0x3cf
crypto/tls.(*Conn).readRecord(...)
	/usr/local/go/src/crypto/tls/conn.go:591
crypto/tls.(*Conn).Read(0xc00067d888, {0xc00070f000, 0x1000, 0xc000584b10?})
	/usr/local/go/src/crypto/tls/conn.go:1385 +0x145
net/http.(*persistConn).Read(0xc0006b4a20, {0xc00070f000?, 0x810625?, 0x2c40580?})
	/usr/local/go/src/net/http/transport.go:2122 +0x47
bufio.(*Reader).fill(0xc0009a56e0)
	/usr/local/go/src/bufio/bufio.go:113 +0x103
bufio.(*Reader).Peek(0xc0009a56e0, 0x1)
	/usr/local/go/src/bufio/bufio.go:152 +0x53
net/http.(*persistConn).readLoop(0xc0006b4a20)
	/usr/local/go/src/net/http/transport.go:2275 +0x172
created by net/http.(*Transport).dialConn in goroutine 2157
	/usr/local/go/src/net/http/transport.go:1944 +0x174f

goroutine 2241 [IO wait]:
internal/poll.runtime_pollWait(0x7062c8026060, 0x72)
	/usr/local/go/src/runtime/netpoll.go:351 +0x85
internal/poll.(*pollDesc).wait(0xc00074c480?, 0xc0009a6c00?, 0x0)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc00074c480, {0xc0009a6c00, 0xc00, 0xc00})
	/usr/local/go/src/internal/poll/fd_unix.go:165 +0x27a
net.(*netFD).Read(0xc00074c480, {0xc0009a6c00?, 0x2000?, 0x0?})
	/usr/local/go/src/net/fd_posix.go:55 +0x25
net.(*conn).Read(0xc00011a910, {0xc0009a6c00?, 0x0?, 0x5?})
	/usr/local/go/src/net/net.go:194 +0x45
github.com/rclone/rclone/fs/fshttp.(*timeoutConn).Read(0xc0009ec9a8, {0xc0009a6c00?, 0x7062b9dfcd28?, 0x706310ee25c0?})
	/home/rclone/go/src/github.com/rclone/rclone/fs/fshttp/dialer.go:111 +0x29
crypto/tls.(*atLeastReader).Read(0xc0009ec090, {0xc0009a6c00?, 0x11?, 0xc0008fe9c8?})
	/usr/local/go/src/crypto/tls/conn.go:809 +0x3b
bytes.(*Buffer).ReadFrom(0xc00067d0b8, {0x2c43aa0, 0xc0009ec090})
	/usr/local/go/src/bytes/buffer.go:211 +0x98
crypto/tls.(*Conn).readFromUntil(0xc00067ce08, {0x7062ba737b18, 0xc0009ec9a8}, 0x4426d4?)
	/usr/local/go/src/crypto/tls/conn.go:831 +0xde
crypto/tls.(*Conn).readRecordOrCCS(0xc00067ce08, 0x0)
	/usr/local/go/src/crypto/tls/conn.go:629 +0x3cf
crypto/tls.(*Conn).readRecord(...)
	/usr/local/go/src/crypto/tls/conn.go:591
crypto/tls.(*Conn).Read(0xc00067ce08, {0xc000856000, 0x1000, 0xc000584b10?})
	/usr/local/go/src/crypto/tls/conn.go:1385 +0x145
net/http.(*persistConn).Read(0xc00070a7e0, {0xc000856000?, 0x810625?, 0x2c40580?})
	/usr/local/go/src/net/http/transport.go:2122 +0x47
bufio.(*Reader).fill(0xc000b14780)
	/usr/local/go/src/bufio/bufio.go:113 +0x103
bufio.(*Reader).Peek(0xc000b14780, 0x1)
	/usr/local/go/src/bufio/bufio.go:152 +0x53
net/http.(*persistConn).readLoop(0xc00070a7e0)
	/usr/local/go/src/net/http/transport.go:2275 +0x172
created by net/http.(*Transport).dialConn in goroutine 2229
	/usr/local/go/src/net/http/transport.go:1944 +0x174f

goroutine 2245 [select]:
net/http.(*persistConn).writeLoop(0xc00070a900)
	/usr/local/go/src/net/http/transport.go:2590 +0xe7
created by net/http.(*Transport).dialConn in goroutine 2237
	/usr/local/go/src/net/http/transport.go:1945 +0x17a5

goroutine 2446 [chan receive]:
github.com/rclone/rclone/backend/local.(*fadvise).worker(0xc00079cac0)
	/home/rclone/go/src/github.com/rclone/rclone/backend/local/fadvise_unix.go:114 +0x3f
created by github.com/rclone/rclone/backend/local.newFadvise in goroutine 2176
	/home/rclone/go/src/github.com/rclone/rclone/backend/local/fadvise_unix.go:74 +0x11f
"./bisync.test -test.v -test.timeout 1h0m0s -remote TestGoFile: -verbose" - Finished ERROR in 1h0m0.323398709s (try 4/5): exit status 2: Failed []