"./vfs.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bSHA1QuickS3: -verbose -size-limit 1024 -test.run '^(TestRWFileHandleMethodsWrite|TestRWFileHandleWriteAt|TestRWFileHandleWriteNoWrite|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleWriteAt)$'" - Starting (try 3/5)
=== RUN   TestRWFileHandleMethodsWrite
2020/07/24 10:37:46 INFO  : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1': poll-interval is not supported by this remote
2020/07/24 10:37:46 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bSHA1QuickS3/rclone-test-nuzoyen3bohiqub9bamejav1"
2020/07/24 10:37:46 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bSHA1QuickS3/rclone-test-nuzoyen3bohiqub9bamejav1"
2020/07/24 10:37:46 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/07/24 10:37:46 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2020/07/24 10:37:47 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/07/24 10:37:47 DEBUG : file1: newRWFileHandle: 
2020/07/24 10:37:47 DEBUG : file1(0xc000748700): openPending: 
2020/07/24 10:37:47 DEBUG : file1: vfs cache: truncate to size=0
2020/07/24 10:37:47 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/07/24 10:37:47 DEBUG : file1(0xc000748700): >openPending: err=<nil>
2020/07/24 10:37:47 DEBUG : file1: >newRWFileHandle: err=<nil>
2020/07/24 10:37:47 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/07/24 10:37:47 DEBUG : file1: >Open: fd=file1 (rw), err=<nil>
2020/07/24 10:37:47 DEBUG : file1: >OpenFile: fd=file1 (rw), err=<nil>
2020/07/24 10:37:47 DEBUG : file1(0xc000748700): _writeAt: size=5, off=0
2020/07/24 10:37:47 DEBUG : file1(0xc000748700): >_writeAt: n=5, err=<nil>
2020/07/24 10:37:47 DEBUG : file1(0xc000748700): _writeAt: size=7, off=5
2020/07/24 10:37:47 DEBUG : file1(0xc000748700): >_writeAt: n=7, err=<nil>
2020/07/24 10:37:47 DEBUG : file1: vfs cache: truncate to size=11
2020/07/24 10:37:47 DEBUG : file1(0xc000748700): close: 
2020/07/24 10:37:47 DEBUG : file1: vfs cache: setting modification time to 2020-07-24 10:37:47.077834567 +0000 UTC m=+0.125510580
2020/07/24 10:37:47 INFO  : file1: vfs cache: queuing for upload in 100ms
2020/07/24 10:37:47 DEBUG : file1(0xc000748700): >close: err=<nil>
2020/07/24 10:37:47 DEBUG : file1(0xc000748700): close: 
2020/07/24 10:37:47 DEBUG : file1(0xc000748700): >close: err=file already closed
2020/07/24 10:37:47 DEBUG : WaitForWriters: timeout=10s
2020/07/24 10:37:47 DEBUG : : Looking for writers
2020/07/24 10:37:47 DEBUG : file1: reading active writers
2020/07/24 10:37:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2020/07/24 10:37:47 DEBUG : : Looking for writers
2020/07/24 10:37:47 DEBUG : file1: reading active writers
2020/07/24 10:37:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2020/07/24 10:37:47 DEBUG : : Looking for writers
2020/07/24 10:37:47 DEBUG : file1: reading active writers
2020/07/24 10:37:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2020/07/24 10:37:47 DEBUG : : Looking for writers
2020/07/24 10:37:47 DEBUG : file1: reading active writers
2020/07/24 10:37:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2020/07/24 10:37:47 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:37:47 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>D333BF6CAE871FA1</RequestId><HostId>W8otA+3qjtCqXnr/68TDYr7u5YjqZvfzChqvSmV8SYZQ1PlQqpAh3zz7mqnt2Zbp0OmDVeg5ZuE=</HostId></Error>
2020/07/24 10:37:47 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>D333BF6CAE871FA1</RequestId><HostId>W8otA+3qjtCqXnr/68TDYr7u5YjqZvfzChqvSmV8SYZQ1PlQqpAh3zz7mqnt2Zbp0OmDVeg5ZuE=</HostId></Error>
2020/07/24 10:37:47 DEBUG : : Looking for writers
2020/07/24 10:37:47 DEBUG : file1: reading active writers
2020/07/24 10:37:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2020/07/24 10:37:47 DEBUG : : Looking for writers
2020/07/24 10:37:47 DEBUG : file1: reading active writers
2020/07/24 10:37:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2020/07/24 10:37:47 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:37:47 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>B5C1789954F87A76</RequestId><HostId>zgsSq1PrOqXONjd487GJ8X7MVr0vIqnHociowWtGIMXJtmbhaoZGJfQkaP8Wa1pZS0m+4aW6rGQ=</HostId></Error>
2020/07/24 10:37:47 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>B5C1789954F87A76</RequestId><HostId>zgsSq1PrOqXONjd487GJ8X7MVr0vIqnHociowWtGIMXJtmbhaoZGJfQkaP8Wa1pZS0m+4aW6rGQ=</HostId></Error>
2020/07/24 10:37:47 DEBUG : : Looking for writers
2020/07/24 10:37:47 DEBUG : file1: reading active writers
2020/07/24 10:37:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2020/07/24 10:37:47 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:37:47 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>EF989DC7661554F7</RequestId><HostId>8fIRZ3mSxYcz3ZILZLX246JEMZAhN7YSF19M9ttTC0prW0s7VgiO1mt/amRZUQ+L0wT0rhJ9kK4=</HostId></Error>
2020/07/24 10:37:47 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>EF989DC7661554F7</RequestId><HostId>8fIRZ3mSxYcz3ZILZLX246JEMZAhN7YSF19M9ttTC0prW0s7VgiO1mt/amRZUQ+L0wT0rhJ9kK4=</HostId></Error>
2020/07/24 10:37:48 DEBUG : : Looking for writers
2020/07/24 10:37:48 DEBUG : file1: reading active writers
2020/07/24 10:37:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:37:48 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:37:48 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>8F0A26B4015D4D74</RequestId><HostId>F4cUcO2HsmgL5Lj6BHV8cPC0jZudOFKda3J82H11joWUXACI6LyociN8UaCiNpk8uNJDYtQeM44=</HostId></Error>
2020/07/24 10:37:48 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>8F0A26B4015D4D74</RequestId><HostId>F4cUcO2HsmgL5Lj6BHV8cPC0jZudOFKda3J82H11joWUXACI6LyociN8UaCiNpk8uNJDYtQeM44=</HostId></Error>
2020/07/24 10:37:49 DEBUG : : Looking for writers
2020/07/24 10:37:49 DEBUG : file1: reading active writers
2020/07/24 10:37:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:37:50 DEBUG : : Looking for writers
2020/07/24 10:37:50 DEBUG : file1: reading active writers
2020/07/24 10:37:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:37:50 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:37:50 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>A8F219480A16A64A</RequestId><HostId>/5k8Wpx+pJ6kyU2B07VRX/83q5S0ecqIyLt7P2xtS+a/I/fHNFBGzFV5f4FrmpGaMoYSHry+Jj8=</HostId></Error>
2020/07/24 10:37:50 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>A8F219480A16A64A</RequestId><HostId>/5k8Wpx+pJ6kyU2B07VRX/83q5S0ecqIyLt7P2xtS+a/I/fHNFBGzFV5f4FrmpGaMoYSHry+Jj8=</HostId></Error>
2020/07/24 10:37:51 DEBUG : : Looking for writers
2020/07/24 10:37:51 DEBUG : file1: reading active writers
2020/07/24 10:37:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:37:52 DEBUG : : Looking for writers
2020/07/24 10:37:52 DEBUG : file1: reading active writers
2020/07/24 10:37:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:37:53 DEBUG : : Looking for writers
2020/07/24 10:37:53 DEBUG : file1: reading active writers
2020/07/24 10:37:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:37:53 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:37:53 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>C680DCE848CF47D5</RequestId><HostId>ts6PZDOHgJ3huP45pl5IuLtQfwESWqVYRsrK+iyIfVN1ovn0ZeSZfDc3XNEdcD4NIVJZ1WAhJkI=</HostId></Error>
2020/07/24 10:37:53 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>C680DCE848CF47D5</RequestId><HostId>ts6PZDOHgJ3huP45pl5IuLtQfwESWqVYRsrK+iyIfVN1ovn0ZeSZfDc3XNEdcD4NIVJZ1WAhJkI=</HostId></Error>
2020/07/24 10:37:54 DEBUG : : Looking for writers
2020/07/24 10:37:54 DEBUG : file1: reading active writers
2020/07/24 10:37:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:37:55 DEBUG : : Looking for writers
2020/07/24 10:37:55 DEBUG : file1: reading active writers
2020/07/24 10:37:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:37:56 DEBUG : : Looking for writers
2020/07/24 10:37:56 DEBUG : file1: reading active writers
2020/07/24 10:37:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:37:57 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s
Cache{
	"file1": &{c:0xc0001053b0 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13816705414217312583 ext:125510580 loc:0x28e63c0} ATime:{wall:13816705414217325099 ext:125523054 loc:0x28e63c0} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1},
}
2020/07/24 10:37:57 DEBUG : >WaitForWriters: 
2020/07/24 10:38:00 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:00 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>E4D4248F01D4863A</RequestId><HostId>b22+pJ2y4OS4hOjusc1jEdAb29FTJX2SXXG0hzuSKedoX1FfXsmsJZEMrcJnJs/umtCR2eFtshg=</HostId></Error>
2020/07/24 10:38:00 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>E4D4248F01D4863A</RequestId><HostId>b22+pJ2y4OS4hOjusc1jEdAb29FTJX2SXXG0hzuSKedoX1FfXsmsJZEMrcJnJs/umtCR2eFtshg=</HostId></Error>
2020/07/24 10:38:04 DEBUG : WaitForWriters: timeout=10s
2020/07/24 10:38:04 DEBUG : : Looking for writers
2020/07/24 10:38:04 DEBUG : file1: reading active writers
2020/07/24 10:38:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2020/07/24 10:38:04 DEBUG : : Looking for writers
2020/07/24 10:38:04 DEBUG : file1: reading active writers
2020/07/24 10:38:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2020/07/24 10:38:04 DEBUG : : Looking for writers
2020/07/24 10:38:04 DEBUG : file1: reading active writers
2020/07/24 10:38:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2020/07/24 10:38:04 DEBUG : : Looking for writers
2020/07/24 10:38:04 DEBUG : file1: reading active writers
2020/07/24 10:38:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2020/07/24 10:38:04 DEBUG : : Looking for writers
2020/07/24 10:38:04 DEBUG : file1: reading active writers
2020/07/24 10:38:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2020/07/24 10:38:04 DEBUG : : Looking for writers
2020/07/24 10:38:04 DEBUG : file1: reading active writers
2020/07/24 10:38:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2020/07/24 10:38:04 DEBUG : : Looking for writers
2020/07/24 10:38:04 DEBUG : file1: reading active writers
2020/07/24 10:38:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2020/07/24 10:38:05 DEBUG : : Looking for writers
2020/07/24 10:38:05 DEBUG : file1: reading active writers
2020/07/24 10:38:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:06 DEBUG : : Looking for writers
2020/07/24 10:38:06 DEBUG : file1: reading active writers
2020/07/24 10:38:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:07 DEBUG : : Looking for writers
2020/07/24 10:38:07 DEBUG : file1: reading active writers
2020/07/24 10:38:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:08 DEBUG : : Looking for writers
2020/07/24 10:38:08 DEBUG : file1: reading active writers
2020/07/24 10:38:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:09 DEBUG : : Looking for writers
2020/07/24 10:38:09 DEBUG : file1: reading active writers
2020/07/24 10:38:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:10 DEBUG : : Looking for writers
2020/07/24 10:38:10 DEBUG : file1: reading active writers
2020/07/24 10:38:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:11 DEBUG : : Looking for writers
2020/07/24 10:38:11 DEBUG : file1: reading active writers
2020/07/24 10:38:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:12 DEBUG : : Looking for writers
2020/07/24 10:38:12 DEBUG : file1: reading active writers
2020/07/24 10:38:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:13 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:13 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>ED700AE80D608C05</RequestId><HostId>3//RUp6xcev/Fi42DzUULZMbUOkM121C0sPy+5ZWkt93MYUXmN0bB4bxBGwR2IM/GUqEXyzXEAc=</HostId></Error>
2020/07/24 10:38:13 ERROR : file1: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>ED700AE80D608C05</RequestId><HostId>3//RUp6xcev/Fi42DzUULZMbUOkM121C0sPy+5ZWkt93MYUXmN0bB4bxBGwR2IM/GUqEXyzXEAc=</HostId></Error>
2020/07/24 10:38:13 DEBUG : : Looking for writers
2020/07/24 10:38:13 DEBUG : file1: reading active writers
2020/07/24 10:38:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:14 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s
Cache{
	"file1": &{c:0xc0001053b0 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13816705414217312583 ext:125510580 loc:0x28e63c0} ATime:{wall:13816705414217325099 ext:125523054 loc:0x28e63c0} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1},
}
2020/07/24 10:38:14 DEBUG : >WaitForWriters: 
2020/07/24 10:38:14 DEBUG : vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleMethodsWrite (27.19s)
    run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1'", Local "Local file system at /tmp/rclone582682359", Modify Window "1ns"
    fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3
    fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3
    fstest.go:302: 
        	Error Trace:	fstest.go:302
        	            				fstest.go:335
        	            				read_write_test.go:344
        	Error:      	Should be true
        	Test:       	TestRWFileHandleMethodsWrite
        	Messages:   	listing wrong, want
        	            	  file1 (11) got
        	            	  
    fstest.go:200: Not found "file1"
    fstest.go:203: 
        	Error Trace:	fstest.go:203
        	            				fstest.go:307
        	            				fstest.go:335
        	            				read_write_test.go:344
        	Error:      	Not equal: 
        	            	expected: 0
        	            	actual  : 1
        	Test:       	TestRWFileHandleMethodsWrite
        	Messages:   	1 objects not found
=== RUN   TestRWFileHandleWriteAt
2020/07/24 10:38:14 INFO  : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1': poll-interval is not supported by this remote
2020/07/24 10:38:14 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bSHA1QuickS3/rclone-test-nuzoyen3bohiqub9bamejav1"
2020/07/24 10:38:14 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bSHA1QuickS3/rclone-test-nuzoyen3bohiqub9bamejav1"
2020/07/24 10:38:14 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/07/24 10:38:14 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2020/07/24 10:38:14 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/07/24 10:38:14 DEBUG : file1: newRWFileHandle: 
2020/07/24 10:38:14 DEBUG : file1(0xc00070a700): openPending: 
2020/07/24 10:38:14 DEBUG : file1: vfs cache: truncate to size=0
2020/07/24 10:38:14 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/07/24 10:38:14 DEBUG : file1(0xc00070a700): >openPending: err=<nil>
2020/07/24 10:38:14 DEBUG : file1: >newRWFileHandle: err=<nil>
2020/07/24 10:38:14 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/07/24 10:38:14 DEBUG : file1: >Open: fd=file1 (rw), err=<nil>
2020/07/24 10:38:14 DEBUG : file1: >OpenFile: fd=file1 (rw), err=<nil>
2020/07/24 10:38:14 DEBUG : file1(0xc00070a700): _writeAt: size=7, off=0
2020/07/24 10:38:14 DEBUG : file1(0xc00070a700): >_writeAt: n=7, err=<nil>
2020/07/24 10:38:14 DEBUG : file1(0xc00070a700): _writeAt: size=6, off=5
2020/07/24 10:38:14 DEBUG : file1(0xc00070a700): >_writeAt: n=6, err=<nil>
2020/07/24 10:38:14 DEBUG : file1(0xc00070a700): close: 
2020/07/24 10:38:14 DEBUG : file1: vfs cache: setting modification time to 2020-07-24 10:38:14.169585613 +0000 UTC m=+27.217261585
2020/07/24 10:38:14 INFO  : file1: vfs cache: queuing for upload in 100ms
2020/07/24 10:38:14 DEBUG : file1(0xc00070a700): >close: err=<nil>
2020/07/24 10:38:14 DEBUG : file1(0xc00070a700): _writeAt: size=5, off=0
2020/07/24 10:38:14 DEBUG : file1(0xc00070a700): >_writeAt: n=0, err=file already closed
2020/07/24 10:38:14 DEBUG : WaitForWriters: timeout=10s
2020/07/24 10:38:14 DEBUG : : Looking for writers
2020/07/24 10:38:14 DEBUG : file1: reading active writers
2020/07/24 10:38:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2020/07/24 10:38:14 DEBUG : : Looking for writers
2020/07/24 10:38:14 DEBUG : file1: reading active writers
2020/07/24 10:38:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2020/07/24 10:38:14 DEBUG : : Looking for writers
2020/07/24 10:38:14 DEBUG : file1: reading active writers
2020/07/24 10:38:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2020/07/24 10:38:14 DEBUG : : Looking for writers
2020/07/24 10:38:14 DEBUG : file1: reading active writers
2020/07/24 10:38:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2020/07/24 10:38:14 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:14 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>E58F795F68BE5B4B</RequestId><HostId>hXUtrCuO1j3V+NbeJzdoR2NvloyeLMfi7//SwWpFeHslblD0Ks+c2dQp/nibQWdsiuNYNMKpfCo=</HostId></Error>
2020/07/24 10:38:14 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>E58F795F68BE5B4B</RequestId><HostId>hXUtrCuO1j3V+NbeJzdoR2NvloyeLMfi7//SwWpFeHslblD0Ks+c2dQp/nibQWdsiuNYNMKpfCo=</HostId></Error>
2020/07/24 10:38:14 DEBUG : : Looking for writers
2020/07/24 10:38:14 DEBUG : file1: reading active writers
2020/07/24 10:38:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2020/07/24 10:38:14 DEBUG : : Looking for writers
2020/07/24 10:38:14 DEBUG : file1: reading active writers
2020/07/24 10:38:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2020/07/24 10:38:14 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:14 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>58664C3872E5B7D2</RequestId><HostId>Ka4Ow7FXXe4NWwNJJV+H0u4iZMzZgUfTz2SwvOm558Y7Z9jTyNmc3lPseJfgcvh8nIpVd0EMSeg=</HostId></Error>
2020/07/24 10:38:14 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>58664C3872E5B7D2</RequestId><HostId>Ka4Ow7FXXe4NWwNJJV+H0u4iZMzZgUfTz2SwvOm558Y7Z9jTyNmc3lPseJfgcvh8nIpVd0EMSeg=</HostId></Error>
2020/07/24 10:38:14 DEBUG : : Looking for writers
2020/07/24 10:38:14 DEBUG : file1: reading active writers
2020/07/24 10:38:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2020/07/24 10:38:14 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:15 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>566CFDB368A8CD86</RequestId><HostId>dILLwrbWI8PlPg3UQ6OTf+LUCVAJspT2TpOpb3v5ee4/beBjCl3RvuG0W/RT9PXIYOymFjuPbBM=</HostId></Error>
2020/07/24 10:38:15 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>566CFDB368A8CD86</RequestId><HostId>dILLwrbWI8PlPg3UQ6OTf+LUCVAJspT2TpOpb3v5ee4/beBjCl3RvuG0W/RT9PXIYOymFjuPbBM=</HostId></Error>
2020/07/24 10:38:15 DEBUG : : Looking for writers
2020/07/24 10:38:15 DEBUG : file1: reading active writers
2020/07/24 10:38:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:15 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:15 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>2EE7C36F0D146E32</RequestId><HostId>cIIi89BofAPuCRuMNq3CgxLXsmgSijld2kfMQQGAVhJ6W7Yr3PCsOp7XF1GGSeC5H3GIlGo2/eg=</HostId></Error>
2020/07/24 10:38:15 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>2EE7C36F0D146E32</RequestId><HostId>cIIi89BofAPuCRuMNq3CgxLXsmgSijld2kfMQQGAVhJ6W7Yr3PCsOp7XF1GGSeC5H3GIlGo2/eg=</HostId></Error>
2020/07/24 10:38:16 DEBUG : : Looking for writers
2020/07/24 10:38:16 DEBUG : file1: reading active writers
2020/07/24 10:38:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:17 DEBUG : : Looking for writers
2020/07/24 10:38:17 DEBUG : file1: reading active writers
2020/07/24 10:38:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:17 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:17 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>A2403EEEBB59BA1A</RequestId><HostId>cUUfWn6hRYKpo+/AQbrKHc2+9oNgUfUhGcZ+ocRO42X+s4NI+Oh4ZImalcmot+0iHnedfZPmt9I=</HostId></Error>
2020/07/24 10:38:17 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>A2403EEEBB59BA1A</RequestId><HostId>cUUfWn6hRYKpo+/AQbrKHc2+9oNgUfUhGcZ+ocRO42X+s4NI+Oh4ZImalcmot+0iHnedfZPmt9I=</HostId></Error>
2020/07/24 10:38:18 DEBUG : : Looking for writers
2020/07/24 10:38:18 DEBUG : file1: reading active writers
2020/07/24 10:38:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:19 DEBUG : : Looking for writers
2020/07/24 10:38:19 DEBUG : file1: reading active writers
2020/07/24 10:38:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:20 DEBUG : : Looking for writers
2020/07/24 10:38:20 DEBUG : file1: reading active writers
2020/07/24 10:38:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:20 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:20 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>B02F13784F58A8B3</RequestId><HostId>bbaEQIk1VzsWIi+CnR/OCVgLQ15zTRBk30jgPShdzu7d0n8byvmd+jOxKIYaMJYRRnaHV5dEfOY=</HostId></Error>
2020/07/24 10:38:20 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>B02F13784F58A8B3</RequestId><HostId>bbaEQIk1VzsWIi+CnR/OCVgLQ15zTRBk30jgPShdzu7d0n8byvmd+jOxKIYaMJYRRnaHV5dEfOY=</HostId></Error>
2020/07/24 10:38:21 DEBUG : : Looking for writers
2020/07/24 10:38:21 DEBUG : file1: reading active writers
2020/07/24 10:38:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:22 DEBUG : : Looking for writers
2020/07/24 10:38:22 DEBUG : file1: reading active writers
2020/07/24 10:38:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:23 DEBUG : : Looking for writers
2020/07/24 10:38:23 DEBUG : file1: reading active writers
2020/07/24 10:38:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:24 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s
Cache{
	"file1": &{c:0xc000788750 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13816705443300092877 ext:27217261585 loc:0x28e63c0} ATime:{wall:13816705443300142277 ext:27217310981 loc:0x28e63c0} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1},
}
2020/07/24 10:38:24 DEBUG : >WaitForWriters: 
2020/07/24 10:38:27 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:27 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>8157336E7FB99EDC</RequestId><HostId>cDzbCr8DVLCMytDd5p6lb0BcIFEr3e39pB7b0mhEeF/6EaJXvWQ+mmHZ7hCV7u3xwKkTfcOT+gU=</HostId></Error>
2020/07/24 10:38:27 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>8157336E7FB99EDC</RequestId><HostId>cDzbCr8DVLCMytDd5p6lb0BcIFEr3e39pB7b0mhEeF/6EaJXvWQ+mmHZ7hCV7u3xwKkTfcOT+gU=</HostId></Error>
2020/07/24 10:38:31 DEBUG : WaitForWriters: timeout=10s
2020/07/24 10:38:31 DEBUG : : Looking for writers
2020/07/24 10:38:31 DEBUG : file1: reading active writers
2020/07/24 10:38:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2020/07/24 10:38:31 DEBUG : : Looking for writers
2020/07/24 10:38:31 DEBUG : file1: reading active writers
2020/07/24 10:38:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2020/07/24 10:38:31 DEBUG : : Looking for writers
2020/07/24 10:38:31 DEBUG : file1: reading active writers
2020/07/24 10:38:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2020/07/24 10:38:31 DEBUG : : Looking for writers
2020/07/24 10:38:31 DEBUG : file1: reading active writers
2020/07/24 10:38:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2020/07/24 10:38:31 DEBUG : : Looking for writers
2020/07/24 10:38:31 DEBUG : file1: reading active writers
2020/07/24 10:38:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2020/07/24 10:38:31 DEBUG : : Looking for writers
2020/07/24 10:38:31 DEBUG : file1: reading active writers
2020/07/24 10:38:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2020/07/24 10:38:31 DEBUG : : Looking for writers
2020/07/24 10:38:31 DEBUG : file1: reading active writers
2020/07/24 10:38:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2020/07/24 10:38:32 DEBUG : : Looking for writers
2020/07/24 10:38:32 DEBUG : file1: reading active writers
2020/07/24 10:38:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:33 DEBUG : : Looking for writers
2020/07/24 10:38:33 DEBUG : file1: reading active writers
2020/07/24 10:38:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:34 DEBUG : : Looking for writers
2020/07/24 10:38:34 DEBUG : file1: reading active writers
2020/07/24 10:38:34 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:35 DEBUG : : Looking for writers
2020/07/24 10:38:35 DEBUG : file1: reading active writers
2020/07/24 10:38:35 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:36 DEBUG : : Looking for writers
2020/07/24 10:38:36 DEBUG : file1: reading active writers
2020/07/24 10:38:36 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:37 DEBUG : : Looking for writers
2020/07/24 10:38:37 DEBUG : file1: reading active writers
2020/07/24 10:38:37 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:38 DEBUG : : Looking for writers
2020/07/24 10:38:38 DEBUG : file1: reading active writers
2020/07/24 10:38:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:39 DEBUG : : Looking for writers
2020/07/24 10:38:39 DEBUG : file1: reading active writers
2020/07/24 10:38:39 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:40 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:40 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>9CF095A1D3DC002A</RequestId><HostId>gb2WKRG23vnxoUskgZRviS0goLw3rLD1luXkj73gFZXXPACvCmkrPlnu//aFHgSFAebKSrQOT8o=</HostId></Error>
2020/07/24 10:38:40 ERROR : file1: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>9CF095A1D3DC002A</RequestId><HostId>gb2WKRG23vnxoUskgZRviS0goLw3rLD1luXkj73gFZXXPACvCmkrPlnu//aFHgSFAebKSrQOT8o=</HostId></Error>
2020/07/24 10:38:40 DEBUG : : Looking for writers
2020/07/24 10:38:40 DEBUG : file1: reading active writers
2020/07/24 10:38:40 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/07/24 10:38:41 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s
Cache{
	"file1": &{c:0xc000788750 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13816705443300092877 ext:27217261585 loc:0x28e63c0} ATime:{wall:13816705443300142277 ext:27217310981 loc:0x28e63c0} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1},
}
2020/07/24 10:38:41 DEBUG : >WaitForWriters: 
2020/07/24 10:38:41 DEBUG : vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleWriteAt (27.06s)
    run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1'", Local "Local file system at /tmp/rclone582682359", Modify Window "1ns"
    fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3
    fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3
    fstest.go:302: 
        	Error Trace:	fstest.go:302
        	            				fstest.go:335
        	            				read_write_test.go:392
        	Error:      	Should be true
        	Test:       	TestRWFileHandleWriteAt
        	Messages:   	listing wrong, want
        	            	  file1 (11) got
        	            	  
    fstest.go:200: Not found "file1"
    fstest.go:203: 
        	Error Trace:	fstest.go:203
        	            				fstest.go:307
        	            				fstest.go:335
        	            				read_write_test.go:392
        	Error:      	Not equal: 
        	            	expected: 0
        	            	actual  : 1
        	Test:       	TestRWFileHandleWriteAt
        	Messages:   	1 objects not found
=== RUN   TestRWFileHandleWriteNoWrite
2020/07/24 10:38:41 INFO  : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1': poll-interval is not supported by this remote
2020/07/24 10:38:41 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bSHA1QuickS3/rclone-test-nuzoyen3bohiqub9bamejav1"
2020/07/24 10:38:41 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bSHA1QuickS3/rclone-test-nuzoyen3bohiqub9bamejav1"
2020/07/24 10:38:41 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/07/24 10:38:41 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2020/07/24 10:38:41 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/07/24 10:38:41 DEBUG : file1: newRWFileHandle: 
2020/07/24 10:38:41 DEBUG : file1(0xc0006e0400): openPending: 
2020/07/24 10:38:41 DEBUG : file1: vfs cache: truncate to size=0
2020/07/24 10:38:41 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/07/24 10:38:41 DEBUG : file1(0xc0006e0400): >openPending: err=<nil>
2020/07/24 10:38:41 DEBUG : file1: >newRWFileHandle: err=<nil>
2020/07/24 10:38:41 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/07/24 10:38:41 DEBUG : file1: >Open: fd=file1 (rw), err=<nil>
2020/07/24 10:38:41 DEBUG : file1: >OpenFile: fd=file1 (rw), err=<nil>
2020/07/24 10:38:41 DEBUG : file1(0xc0006e0400): close: 
2020/07/24 10:38:41 DEBUG : file1: vfs cache: setting modification time to 2020-07-24 10:38:41.226401901 +0000 UTC m=+54.274077877
2020/07/24 10:38:41 INFO  : file1: vfs cache: queuing for upload in 100ms
2020/07/24 10:38:41 DEBUG : file1(0xc0006e0400): >close: err=<nil>
2020/07/24 10:38:41 DEBUG : file2: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx
2020/07/24 10:38:41 DEBUG : file2: Open: flags=O_WRONLY|O_CREATE|O_TRUNC
2020/07/24 10:38:41 DEBUG : file2: newRWFileHandle: 
2020/07/24 10:38:41 DEBUG : file2(0xc0006e0780): openPending: 
2020/07/24 10:38:41 DEBUG : file2: vfs cache: truncate to size=0
2020/07/24 10:38:41 DEBUG : : Added virtual directory entry vAdd: "file2"
2020/07/24 10:38:41 DEBUG : file2(0xc0006e0780): >openPending: err=<nil>
2020/07/24 10:38:41 DEBUG : file2: >newRWFileHandle: err=<nil>
2020/07/24 10:38:41 DEBUG : : Added virtual directory entry vAdd: "file2"
2020/07/24 10:38:41 DEBUG : file2: >Open: fd=file2 (rw), err=<nil>
2020/07/24 10:38:41 DEBUG : file2: >OpenFile: fd=file2 (rw), err=<nil>
2020/07/24 10:38:41 DEBUG : file2(0xc0006e0780): RWFileHandle.Flush
2020/07/24 10:38:41 DEBUG : file2(0xc0006e0780): RWFileHandle.Release
2020/07/24 10:38:41 DEBUG : file2(0xc0006e0780): close: 
2020/07/24 10:38:41 DEBUG : file2: vfs cache: setting modification time to 2020-07-24 10:38:41.227045923 +0000 UTC m=+54.274721891
2020/07/24 10:38:41 INFO  : file2: vfs cache: queuing for upload in 100ms
2020/07/24 10:38:41 DEBUG : file2(0xc0006e0780): >close: err=<nil>
2020/07/24 10:38:41 DEBUG : WaitForWriters: timeout=10s
2020/07/24 10:38:41 DEBUG : : Looking for writers
2020/07/24 10:38:41 DEBUG : file1: reading active writers
2020/07/24 10:38:41 DEBUG : file2: reading active writers
2020/07/24 10:38:41 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms
2020/07/24 10:38:41 DEBUG : : Looking for writers
2020/07/24 10:38:41 DEBUG : file1: reading active writers
2020/07/24 10:38:41 DEBUG : file2: reading active writers
2020/07/24 10:38:41 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms
2020/07/24 10:38:41 DEBUG : : Looking for writers
2020/07/24 10:38:41 DEBUG : file1: reading active writers
2020/07/24 10:38:41 DEBUG : file2: reading active writers
2020/07/24 10:38:41 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms
2020/07/24 10:38:41 DEBUG : : Looking for writers
2020/07/24 10:38:41 DEBUG : file2: reading active writers
2020/07/24 10:38:41 DEBUG : file1: reading active writers
2020/07/24 10:38:41 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms
2020/07/24 10:38:41 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:41 DEBUG : file2: vfs cache: starting upload
2020/07/24 10:38:41 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>D78598061B94E99B</RequestId><HostId>JGpGleeuwYPNRY4m11xeecOC72T8K4i8gcuitdzmwk0orISwBRTQesQTVPcXd8Si52hilrZb+/0=</HostId></Error>
2020/07/24 10:38:41 ERROR : file1: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>D78598061B94E99B</RequestId><HostId>JGpGleeuwYPNRY4m11xeecOC72T8K4i8gcuitdzmwk0orISwBRTQesQTVPcXd8Si52hilrZb+/0=</HostId></Error>
2020/07/24 10:38:41 DEBUG : : Looking for writers
2020/07/24 10:38:41 DEBUG : file1: reading active writers
2020/07/24 10:38:41 DEBUG : file2: reading active writers
2020/07/24 10:38:41 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms
2020/07/24 10:38:41 ERROR : file2: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>8915995138D2D060</RequestId><HostId>LN4PWpy9rzt7Osyod6sqnGsx7xevpHjFh0GC6oxwceB45UbD5RLFXSw1iV2vYEz8xPmLA0WwpFY=</HostId></Error>
2020/07/24 10:38:41 ERROR : file2: vfs cache: failed to upload try #1, will retry in 200ms: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>8915995138D2D060</RequestId><HostId>LN4PWpy9rzt7Osyod6sqnGsx7xevpHjFh0GC6oxwceB45UbD5RLFXSw1iV2vYEz8xPmLA0WwpFY=</HostId></Error>
2020/07/24 10:38:41 DEBUG : : Looking for writers
2020/07/24 10:38:41 DEBUG : file1: reading active writers
2020/07/24 10:38:41 DEBUG : file2: reading active writers
2020/07/24 10:38:41 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms
2020/07/24 10:38:41 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:41 DEBUG : file2: vfs cache: starting upload
2020/07/24 10:38:41 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>AA8AB2702FF74E50</RequestId><HostId>lLDhsB+u6GfC1pgVxFssiRr/i1OptfHOgUuilGcSDncGoIvkKCSQatJTWhyr2dTfSYl3Y6ZRRC0=</HostId></Error>
2020/07/24 10:38:41 ERROR : file1: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>AA8AB2702FF74E50</RequestId><HostId>lLDhsB+u6GfC1pgVxFssiRr/i1OptfHOgUuilGcSDncGoIvkKCSQatJTWhyr2dTfSYl3Y6ZRRC0=</HostId></Error>
2020/07/24 10:38:41 ERROR : file2: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>7Z0R1WDG4J8TDQ1Y</RequestId><HostId>8BxAbgbABQFQGQxX+XfoBtTH+j+oMjrWM7zM5M36JrnnNRT26OD7h2cMTBKpFIBe2Y0E3JFf4nw=</HostId></Error>
2020/07/24 10:38:41 ERROR : file2: vfs cache: failed to upload try #2, will retry in 400ms: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>7Z0R1WDG4J8TDQ1Y</RequestId><HostId>8BxAbgbABQFQGQxX+XfoBtTH+j+oMjrWM7zM5M36JrnnNRT26OD7h2cMTBKpFIBe2Y0E3JFf4nw=</HostId></Error>
2020/07/24 10:38:41 DEBUG : : Looking for writers
2020/07/24 10:38:41 DEBUG : file1: reading active writers
2020/07/24 10:38:41 DEBUG : file2: reading active writers
2020/07/24 10:38:41 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms
2020/07/24 10:38:41 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:42 DEBUG : file2: vfs cache: starting upload
2020/07/24 10:38:42 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>907199F030BB4953</RequestId><HostId>haGI6yTaYJzLlE+cN9suQncQ9o+kL2IrL43JXQU7dI+UTlFV1/cfpbypritoFRyMll2wtvGeUbY=</HostId></Error>
2020/07/24 10:38:42 ERROR : file1: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>907199F030BB4953</RequestId><HostId>haGI6yTaYJzLlE+cN9suQncQ9o+kL2IrL43JXQU7dI+UTlFV1/cfpbypritoFRyMll2wtvGeUbY=</HostId></Error>
2020/07/24 10:38:42 ERROR : file2: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>FD9AFA0D7C237A74</RequestId><HostId>3VxGur0g4vDkcghCVQX4t9U4LHHVzGqCmw+Fsy7wHSvh4Nu99Dvx/2FN7hTgH1nCPMZNRIuAoSE=</HostId></Error>
2020/07/24 10:38:42 ERROR : file2: vfs cache: failed to upload try #3, will retry in 800ms: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>FD9AFA0D7C237A74</RequestId><HostId>3VxGur0g4vDkcghCVQX4t9U4LHHVzGqCmw+Fsy7wHSvh4Nu99Dvx/2FN7hTgH1nCPMZNRIuAoSE=</HostId></Error>
2020/07/24 10:38:42 DEBUG : : Looking for writers
2020/07/24 10:38:42 DEBUG : file2: reading active writers
2020/07/24 10:38:42 DEBUG : file1: reading active writers
2020/07/24 10:38:42 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:38:42 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:42 DEBUG : file2: vfs cache: starting upload
2020/07/24 10:38:42 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>F48090AF8C28C3CC</RequestId><HostId>thrz4dgns7rEwvQ47YeLCxkF2HKT5g9gmnSHm0e8LnMhGzTDcsYzKyF1ITzR0XF8CD9Q/7akUik=</HostId></Error>
2020/07/24 10:38:42 ERROR : file1: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>F48090AF8C28C3CC</RequestId><HostId>thrz4dgns7rEwvQ47YeLCxkF2HKT5g9gmnSHm0e8LnMhGzTDcsYzKyF1ITzR0XF8CD9Q/7akUik=</HostId></Error>
2020/07/24 10:38:42 ERROR : file2: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>13CE5079BD4D09C8</RequestId><HostId>ObI37OjU/hA21yLIZwsIx6n80IJB4kdQn7ecCOTruephfEhWXQ/eaUHvRtTmbzb92seB4UtJojs=</HostId></Error>
2020/07/24 10:38:42 ERROR : file2: vfs cache: failed to upload try #4, will retry in 1.6s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>13CE5079BD4D09C8</RequestId><HostId>ObI37OjU/hA21yLIZwsIx6n80IJB4kdQn7ecCOTruephfEhWXQ/eaUHvRtTmbzb92seB4UtJojs=</HostId></Error>
2020/07/24 10:38:43 DEBUG : : Looking for writers
2020/07/24 10:38:43 DEBUG : file1: reading active writers
2020/07/24 10:38:43 DEBUG : file2: reading active writers
2020/07/24 10:38:43 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:38:44 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:44 DEBUG : : Looking for writers
2020/07/24 10:38:44 DEBUG : file1: reading active writers
2020/07/24 10:38:44 DEBUG : file2: reading active writers
2020/07/24 10:38:44 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:38:44 DEBUG : file2: vfs cache: starting upload
2020/07/24 10:38:44 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>51A5EB785F227629</RequestId><HostId>AUUdXpD3fU0vgwrOMg3QUawui8BMGdisZgEK8gCzaE4tOzuADDgNQqvd9FOdxSs0ujqofEyatqY=</HostId></Error>
2020/07/24 10:38:44 ERROR : file1: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>51A5EB785F227629</RequestId><HostId>AUUdXpD3fU0vgwrOMg3QUawui8BMGdisZgEK8gCzaE4tOzuADDgNQqvd9FOdxSs0ujqofEyatqY=</HostId></Error>
2020/07/24 10:38:44 ERROR : file2: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>9F006E0835029A90</RequestId><HostId>1mFrA9Qcg7ZRZrle/mlyql+9hBMMBHOJ2FwN8PvgZVdU5S6d7APsOWsORwVgFFiNj6NNK1WZAHg=</HostId></Error>
2020/07/24 10:38:44 ERROR : file2: vfs cache: failed to upload try #5, will retry in 3.2s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>9F006E0835029A90</RequestId><HostId>1mFrA9Qcg7ZRZrle/mlyql+9hBMMBHOJ2FwN8PvgZVdU5S6d7APsOWsORwVgFFiNj6NNK1WZAHg=</HostId></Error>
2020/07/24 10:38:45 DEBUG : : Looking for writers
2020/07/24 10:38:45 DEBUG : file1: reading active writers
2020/07/24 10:38:45 DEBUG : file2: reading active writers
2020/07/24 10:38:45 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:38:46 DEBUG : : Looking for writers
2020/07/24 10:38:46 DEBUG : file1: reading active writers
2020/07/24 10:38:46 DEBUG : file2: reading active writers
2020/07/24 10:38:46 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:38:47 DEBUG : : Looking for writers
2020/07/24 10:38:47 DEBUG : file1: reading active writers
2020/07/24 10:38:47 DEBUG : file2: reading active writers
2020/07/24 10:38:47 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:38:47 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:47 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>9F616B4847769FBD</RequestId><HostId>zTQTezTKhtklZf9uzEC5v+U1ATe4y2BuakgBcttmXzIZwmCZpjvUuiq/bNkti7OmxhkEvvX/dos=</HostId></Error>
2020/07/24 10:38:47 ERROR : file1: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>9F616B4847769FBD</RequestId><HostId>zTQTezTKhtklZf9uzEC5v+U1ATe4y2BuakgBcttmXzIZwmCZpjvUuiq/bNkti7OmxhkEvvX/dos=</HostId></Error>
2020/07/24 10:38:47 DEBUG : file2: vfs cache: starting upload
2020/07/24 10:38:47 ERROR : file2: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>5E3664795135EA89</RequestId><HostId>s37sDBCpGzjDNmAApc+Nuj1gcn+sQgvTVomjhj8axNhEFEPOLkMjPtdL2hBytj/joPLD6H/rQ8o=</HostId></Error>
2020/07/24 10:38:47 ERROR : file2: vfs cache: failed to upload try #6, will retry in 6.4s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>5E3664795135EA89</RequestId><HostId>s37sDBCpGzjDNmAApc+Nuj1gcn+sQgvTVomjhj8axNhEFEPOLkMjPtdL2hBytj/joPLD6H/rQ8o=</HostId></Error>
2020/07/24 10:38:48 DEBUG : : Looking for writers
2020/07/24 10:38:48 DEBUG : file1: reading active writers
2020/07/24 10:38:48 DEBUG : file2: reading active writers
2020/07/24 10:38:48 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:38:49 DEBUG : : Looking for writers
2020/07/24 10:38:49 DEBUG : file1: reading active writers
2020/07/24 10:38:49 DEBUG : file2: reading active writers
2020/07/24 10:38:49 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:38:50 DEBUG : : Looking for writers
2020/07/24 10:38:50 DEBUG : file1: reading active writers
2020/07/24 10:38:50 DEBUG : file2: reading active writers
2020/07/24 10:38:50 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:38:51 ERROR : Exiting even though 0 writers active and 2 cache items in use after 10s
Cache{
	"file2": &{c:0xc00035ec60 mu:{state:0 sema:0} name:file2 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13816705472348582435 ext:54274721891 loc:0x28e63c0} ATime:{wall:13816705472348681196 ext:54274820653 loc:0x28e63c0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2},
	"file1": &{c:0xc00035ec60 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13816705472347938413 ext:54274077877 loc:0x28e63c0} ATime:{wall:13816705472348086393 ext:54274225854 loc:0x28e63c0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1},
}
2020/07/24 10:38:51 DEBUG : >WaitForWriters: 
2020/07/24 10:38:54 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:38:54 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>12B06223B2180FC3</RequestId><HostId>Nb/Y38Sq0hDZjimcy9x8wWROAtvV7DKd7VDAkHGE4Dmd0I1cLzR7U0t8RTtQIlWs5cwVNPPg4rk=</HostId></Error>
2020/07/24 10:38:54 ERROR : file1: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>12B06223B2180FC3</RequestId><HostId>Nb/Y38Sq0hDZjimcy9x8wWROAtvV7DKd7VDAkHGE4Dmd0I1cLzR7U0t8RTtQIlWs5cwVNPPg4rk=</HostId></Error>
2020/07/24 10:38:54 DEBUG : file2: vfs cache: starting upload
2020/07/24 10:38:54 ERROR : file2: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>DG2WCSAW9G2HEH9T</RequestId><HostId>H2veIrkAtTJFOzDos9LLaZSblQyJ5IYXz2kHhRuPi+2tFZsLZOshp3rxMyDsYe6/u6ToxqLlb/c=</HostId></Error>
2020/07/24 10:38:54 ERROR : file2: vfs cache: failed to upload try #7, will retry in 12.8s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>DG2WCSAW9G2HEH9T</RequestId><HostId>H2veIrkAtTJFOzDos9LLaZSblQyJ5IYXz2kHhRuPi+2tFZsLZOshp3rxMyDsYe6/u6ToxqLlb/c=</HostId></Error>
2020/07/24 10:38:58 DEBUG : WaitForWriters: timeout=10s
2020/07/24 10:38:58 DEBUG : : Looking for writers
2020/07/24 10:38:58 DEBUG : file1: reading active writers
2020/07/24 10:38:58 DEBUG : file2: reading active writers
2020/07/24 10:38:58 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms
2020/07/24 10:38:58 DEBUG : : Looking for writers
2020/07/24 10:38:58 DEBUG : file1: reading active writers
2020/07/24 10:38:58 DEBUG : file2: reading active writers
2020/07/24 10:38:58 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms
2020/07/24 10:38:58 DEBUG : : Looking for writers
2020/07/24 10:38:58 DEBUG : file1: reading active writers
2020/07/24 10:38:58 DEBUG : file2: reading active writers
2020/07/24 10:38:58 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms
2020/07/24 10:38:58 DEBUG : : Looking for writers
2020/07/24 10:38:58 DEBUG : file1: reading active writers
2020/07/24 10:38:58 DEBUG : file2: reading active writers
2020/07/24 10:38:58 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms
2020/07/24 10:38:58 DEBUG : : Looking for writers
2020/07/24 10:38:58 DEBUG : file1: reading active writers
2020/07/24 10:38:58 DEBUG : file2: reading active writers
2020/07/24 10:38:58 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms
2020/07/24 10:38:58 DEBUG : : Looking for writers
2020/07/24 10:38:58 DEBUG : file1: reading active writers
2020/07/24 10:38:58 DEBUG : file2: reading active writers
2020/07/24 10:38:58 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms
2020/07/24 10:38:58 DEBUG : : Looking for writers
2020/07/24 10:38:58 DEBUG : file1: reading active writers
2020/07/24 10:38:58 DEBUG : file2: reading active writers
2020/07/24 10:38:58 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms
2020/07/24 10:38:59 DEBUG : : Looking for writers
2020/07/24 10:38:59 DEBUG : file1: reading active writers
2020/07/24 10:38:59 DEBUG : file2: reading active writers
2020/07/24 10:38:59 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:39:00 DEBUG : : Looking for writers
2020/07/24 10:39:00 DEBUG : file1: reading active writers
2020/07/24 10:39:00 DEBUG : file2: reading active writers
2020/07/24 10:39:00 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:39:01 DEBUG : : Looking for writers
2020/07/24 10:39:01 DEBUG : file1: reading active writers
2020/07/24 10:39:01 DEBUG : file2: reading active writers
2020/07/24 10:39:01 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:39:02 DEBUG : : Looking for writers
2020/07/24 10:39:02 DEBUG : file2: reading active writers
2020/07/24 10:39:02 DEBUG : file1: reading active writers
2020/07/24 10:39:02 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:39:03 DEBUG : : Looking for writers
2020/07/24 10:39:03 DEBUG : file2: reading active writers
2020/07/24 10:39:03 DEBUG : file1: reading active writers
2020/07/24 10:39:03 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:39:04 DEBUG : : Looking for writers
2020/07/24 10:39:04 DEBUG : file1: reading active writers
2020/07/24 10:39:04 DEBUG : file2: reading active writers
2020/07/24 10:39:04 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:39:05 DEBUG : : Looking for writers
2020/07/24 10:39:05 DEBUG : file1: reading active writers
2020/07/24 10:39:05 DEBUG : file2: reading active writers
2020/07/24 10:39:05 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:39:06 DEBUG : : Looking for writers
2020/07/24 10:39:06 DEBUG : file1: reading active writers
2020/07/24 10:39:06 DEBUG : file2: reading active writers
2020/07/24 10:39:06 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:39:06 DEBUG : file1: vfs cache: starting upload
2020/07/24 10:39:06 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>79EEE9B5E27D9D37</RequestId><HostId>nfCRy6qZ9fVmvXVf6MOWmijmq7iXlb9oywz2QUxTTGncGKpIbMFiZcR7lfsU+oVXJp5sBlfwDp0=</HostId></Error>
2020/07/24 10:39:06 ERROR : file1: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>79EEE9B5E27D9D37</RequestId><HostId>nfCRy6qZ9fVmvXVf6MOWmijmq7iXlb9oywz2QUxTTGncGKpIbMFiZcR7lfsU+oVXJp5sBlfwDp0=</HostId></Error>
2020/07/24 10:39:07 DEBUG : file2: vfs cache: starting upload
2020/07/24 10:39:07 ERROR : file2: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>B0F93A644529A368</RequestId><HostId>2M+593xtLbH/DJKC5RewXuMvIJ/HHW6h2yfQHzTGyW8GA+1WlMTcBP8x1k2JtX9JywqmuGYotqs=</HostId></Error>
2020/07/24 10:39:07 ERROR : file2: vfs cache: failed to upload try #8, will retry in 25.6s: vfs cache: failed to transfer file from cache to remote: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>B0F93A644529A368</RequestId><HostId>2M+593xtLbH/DJKC5RewXuMvIJ/HHW6h2yfQHzTGyW8GA+1WlMTcBP8x1k2JtX9JywqmuGYotqs=</HostId></Error>
2020/07/24 10:39:07 DEBUG : : Looking for writers
2020/07/24 10:39:07 DEBUG : file1: reading active writers
2020/07/24 10:39:07 DEBUG : file2: reading active writers
2020/07/24 10:39:07 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/07/24 10:39:08 ERROR : Exiting even though 0 writers active and 2 cache items in use after 10s
Cache{
	"file1": &{c:0xc00035ec60 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13816705472347938413 ext:54274077877 loc:0x28e63c0} ATime:{wall:13816705472348086393 ext:54274225854 loc:0x28e63c0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1},
	"file2": &{c:0xc00035ec60 mu:{state:0 sema:0} name:file2 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13816705472348582435 ext:54274721891 loc:0x28e63c0} ATime:{wall:13816705472348681196 ext:54274820653 loc:0x28e63c0} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2},
}
2020/07/24 10:39:08 DEBUG : >WaitForWriters: 
2020/07/24 10:39:08 DEBUG : vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleWriteNoWrite (27.04s)
    run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1'", Local "Local file system at /tmp/rclone582682359", Modify Window "1ns"
    fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3
    fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3
    fstest.go:302: 
        	Error Trace:	fstest.go:302
        	            				fstest.go:335
        	            				read_write_test.go:426
        	Error:      	Should be true
        	Test:       	TestRWFileHandleWriteNoWrite
        	Messages:   	listing wrong, want
        	            	  file1 (0), file2 (0) got
        	            	  
    fstest.go:200: Not found "file1"
    fstest.go:200: Not found "file2"
    fstest.go:203: 
        	Error Trace:	fstest.go:203
        	            				fstest.go:307
        	            				fstest.go:335
        	            				read_write_test.go:426
        	Error:      	Not equal: 
        	            	expected: 0
        	            	actual  : 2
        	Test:       	TestRWFileHandleWriteNoWrite
        	Messages:   	2 objects not found
=== RUN   TestWriteFileHandleMethods
2020/07/24 10:39:08 INFO  : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1': poll-interval is not supported by this remote
2020/07/24 10:39:08 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/07/24 10:39:08 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/07/24 10:39:08 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/07/24 10:39:08 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2020/07/24 10:39:08 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2020/07/24 10:39:08 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/07/24 10:39:08 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal
2020/07/24 10:39:08 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal
2020/07/24 10:39:08 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes
2020/07/24 10:39:08 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1': File to upload is small (5 bytes), uploading instead of streaming
2020/07/24 10:39:08 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>A54B366363AC40FE</RequestId><HostId>XnGKkLO5UM9XzL7fjBkHfhuoAhFTtGdeRz7zRwrZkHEWyKy60OcLRxX5bIHwIvBz/R+zYMafe/Y=</HostId></Error>
2020/07/24 10:39:08 ERROR : file1: WriteFileHandle.New Rcat failed: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>A54B366363AC40FE</RequestId><HostId>XnGKkLO5UM9XzL7fjBkHfhuoAhFTtGdeRz7zRwrZkHEWyKy60OcLRxX5bIHwIvBz/R+zYMafe/Y=</HostId></Error>
2020/07/24 10:39:15 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/07/24 10:39:15 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/07/24 10:39:15 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/07/24 10:39:15 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2020/07/24 10:39:15 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2020/07/24 10:39:15 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/07/24 10:39:15 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1': File to upload is small (0 bytes), uploading instead of streaming
2020/07/24 10:39:15 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>794AA2F14BCE71CE</RequestId><HostId>8A2lO2ctBPQPCikSIcVR+7l4JFioFPawvvz+B9KZ3SWFR8POt1QygvDlc7KUxDyK55yh5fraN/0=</HostId></Error>
2020/07/24 10:39:15 ERROR : file1: WriteFileHandle.New Rcat failed: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>794AA2F14BCE71CE</RequestId><HostId>8A2lO2ctBPQPCikSIcVR+7l4JFioFPawvvz+B9KZ3SWFR8POt1QygvDlc7KUxDyK55yh5fraN/0=</HostId></Error>
2020/07/24 10:39:15 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/07/24 10:39:15 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/07/24 10:39:15 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/07/24 10:39:15 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2020/07/24 10:39:15 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2020/07/24 10:39:15 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/07/24 10:39:15 DEBUG : WaitForWriters: timeout=10s
2020/07/24 10:39:15 DEBUG : : Looking for writers
2020/07/24 10:39:15 DEBUG : file1: reading active writers
2020/07/24 10:39:15 DEBUG : file1: active writers 1
2020/07/24 10:39:15 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms
2020/07/24 10:39:15 DEBUG : : Looking for writers
2020/07/24 10:39:15 DEBUG : file1: reading active writers
2020/07/24 10:39:15 DEBUG : file1: active writers 1
2020/07/24 10:39:15 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms
2020/07/24 10:39:15 DEBUG : : Looking for writers
2020/07/24 10:39:15 DEBUG : file1: reading active writers
2020/07/24 10:39:15 DEBUG : file1: active writers 1
2020/07/24 10:39:15 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms
2020/07/24 10:39:15 DEBUG : : Looking for writers
2020/07/24 10:39:15 DEBUG : file1: reading active writers
2020/07/24 10:39:15 DEBUG : file1: active writers 1
2020/07/24 10:39:15 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms
2020/07/24 10:39:15 DEBUG : : Looking for writers
2020/07/24 10:39:15 DEBUG : file1: reading active writers
2020/07/24 10:39:15 DEBUG : file1: active writers 1
2020/07/24 10:39:15 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms
2020/07/24 10:39:15 DEBUG : : Looking for writers
2020/07/24 10:39:15 DEBUG : file1: reading active writers
2020/07/24 10:39:15 DEBUG : file1: active writers 1
2020/07/24 10:39:15 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms
2020/07/24 10:39:15 DEBUG : : Looking for writers
2020/07/24 10:39:15 DEBUG : file1: reading active writers
2020/07/24 10:39:15 DEBUG : file1: active writers 1
2020/07/24 10:39:15 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms
2020/07/24 10:39:16 DEBUG : : Looking for writers
2020/07/24 10:39:16 DEBUG : file1: reading active writers
2020/07/24 10:39:16 DEBUG : file1: active writers 1
2020/07/24 10:39:16 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/07/24 10:39:17 DEBUG : : Looking for writers
2020/07/24 10:39:17 DEBUG : file1: reading active writers
2020/07/24 10:39:17 DEBUG : file1: active writers 1
2020/07/24 10:39:17 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/07/24 10:39:18 DEBUG : : Looking for writers
2020/07/24 10:39:18 DEBUG : file1: reading active writers
2020/07/24 10:39:18 DEBUG : file1: active writers 1
2020/07/24 10:39:18 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/07/24 10:39:19 DEBUG : : Looking for writers
2020/07/24 10:39:19 DEBUG : file1: reading active writers
2020/07/24 10:39:19 DEBUG : file1: active writers 1
2020/07/24 10:39:19 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/07/24 10:39:20 DEBUG : : Looking for writers
2020/07/24 10:39:20 DEBUG : file1: reading active writers
2020/07/24 10:39:20 DEBUG : file1: active writers 1
2020/07/24 10:39:20 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/07/24 10:39:21 DEBUG : : Looking for writers
2020/07/24 10:39:21 DEBUG : file1: reading active writers
2020/07/24 10:39:21 DEBUG : file1: active writers 1
2020/07/24 10:39:21 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/07/24 10:39:22 DEBUG : : Looking for writers
2020/07/24 10:39:22 DEBUG : file1: reading active writers
2020/07/24 10:39:22 DEBUG : file1: active writers 1
2020/07/24 10:39:22 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/07/24 10:39:23 DEBUG : : Looking for writers
2020/07/24 10:39:23 DEBUG : file1: reading active writers
2020/07/24 10:39:23 DEBUG : file1: active writers 1
2020/07/24 10:39:23 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/07/24 10:39:24 DEBUG : : Looking for writers
2020/07/24 10:39:24 DEBUG : file1: reading active writers
2020/07/24 10:39:24 DEBUG : file1: active writers 1
2020/07/24 10:39:24 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/07/24 10:39:25 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s
Cache: <nil>
2020/07/24 10:39:25 DEBUG : >WaitForWriters: 
--- FAIL: TestWriteFileHandleMethods (17.14s)
    run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1'", Local "Local file system at /tmp/rclone582682359", Modify Window "1ns"
    write_test.go:84: 
        	Error Trace:	write_test.go:84
        	Error:      	Received unexpected error:
        	            	s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
        	            	<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>A54B366363AC40FE</RequestId><HostId>XnGKkLO5UM9XzL7fjBkHfhuoAhFTtGdeRz7zRwrZkHEWyKy60OcLRxX5bIHwIvBz/R+zYMafe/Y=</HostId></Error>
        	Test:       	TestWriteFileHandleMethods
    fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3
    fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3
    fstest.go:302: 
        	Error Trace:	fstest.go:302
        	            				fstest.go:335
        	            				write_test.go:97
        	Error:      	Should be true
        	Test:       	TestWriteFileHandleMethods
        	Messages:   	listing wrong, want
        	            	  file1 (5) got
        	            	  
    fstest.go:200: Not found "file1"
    fstest.go:203: 
        	Error Trace:	fstest.go:203
        	            				fstest.go:307
        	            				fstest.go:335
        	            				write_test.go:97
        	Error:      	Not equal: 
        	            	expected: 0
        	            	actual  : 1
        	Test:       	TestWriteFileHandleMethods
        	Messages:   	1 objects not found
    write_test.go:103: 
        	Error Trace:	write_test.go:103
        	Error:      	Received unexpected error:
        	            	s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
        	            	<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>794AA2F14BCE71CE</RequestId><HostId>8A2lO2ctBPQPCikSIcVR+7l4JFioFPawvvz+B9KZ3SWFR8POt1QygvDlc7KUxDyK55yh5fraN/0=</HostId></Error>
        	Test:       	TestWriteFileHandleMethods
    dir_test.go:252: 
        	Error Trace:	dir_test.go:252
        	            				write_test.go:104
        	Error:      	Not equal: 
        	            	expected: []string{"file1,5,false"}
        	            	actual  : []string{"file1,0,false"}
        	            	
        	            	Diff:
        	            	--- Expected
        	            	+++ Actual
        	            	@@ -1,3 +1,3 @@
        	            	 ([]string) (len=1) {
        	            	- (string) (len=13) "file1,5,false"
        	            	+ (string) (len=13) "file1,0,false"
        	            	 }
        	Test:       	TestWriteFileHandleMethods
    write_test.go:111: 
        	Error Trace:	write_test.go:111
        	Error:      	Not equal: 
        	            	expected: *errors.errorString(&errors.errorString{s:"permission denied"})
        	            	actual  : <nil>(<nil>)
        	Test:       	TestWriteFileHandleMethods
=== RUN   TestWriteFileHandleWriteAt
2020/07/24 10:39:25 INFO  : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1': poll-interval is not supported by this remote
2020/07/24 10:39:25 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/07/24 10:39:25 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/07/24 10:39:25 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/07/24 10:39:25 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2020/07/24 10:39:25 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2020/07/24 10:39:25 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/07/24 10:39:25 DEBUG : file1: waiting for in-sequence write to 100 for 1s
2020/07/24 10:39:26 DEBUG : file1: aborting in-sequence write wait, off=100
2020/07/24 10:39:26 DEBUG : file1: failed to wait for in-sequence write to 100
2020/07/24 10:39:26 ERROR : file1: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes
2020/07/24 10:39:26 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1': File to upload is small (11 bytes), uploading instead of streaming
2020/07/24 10:39:26 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>7AAB637819213EED</RequestId><HostId>jxm8konulaB8MssllbXyJlYMZnmb66oNvRcwg0AHqx4CAcHo8mBSMI4PD15Tf3UHDy8wfOmpx/I=</HostId></Error>
2020/07/24 10:39:26 ERROR : file1: WriteFileHandle.New Rcat failed: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>7AAB637819213EED</RequestId><HostId>jxm8konulaB8MssllbXyJlYMZnmb66oNvRcwg0AHqx4CAcHo8mBSMI4PD15Tf3UHDy8wfOmpx/I=</HostId></Error>
2020/07/24 10:39:26 ERROR : file1: WriteFileHandle.Write: error: Bad file descriptor
2020/07/24 10:39:33 DEBUG : WaitForWriters: timeout=10s
2020/07/24 10:39:33 DEBUG : : Looking for writers
2020/07/24 10:39:33 DEBUG : file1: reading active writers
2020/07/24 10:39:33 DEBUG : >WaitForWriters: 
--- FAIL: TestWriteFileHandleWriteAt (8.08s)
    run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1'", Local "Local file system at /tmp/rclone582682359", Modify Window "1ns"
    write_test.go:162: 
        	Error Trace:	write_test.go:162
        	Error:      	Received unexpected error:
        	            	s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
        	            	<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>7AAB637819213EED</RequestId><HostId>jxm8konulaB8MssllbXyJlYMZnmb66oNvRcwg0AHqx4CAcHo8mBSMI4PD15Tf3UHDy8wfOmpx/I=</HostId></Error>
        	Test:       	TestWriteFileHandleWriteAt
    fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3
    fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3
    fstest.go:302: 
        	Error Trace:	fstest.go:302
        	            				fstest.go:335
        	            				write_test.go:176
        	Error:      	Should be true
        	Test:       	TestWriteFileHandleWriteAt
        	Messages:   	listing wrong, want
        	            	  file1 (11) got
        	            	  
    fstest.go:200: Not found "file1"
    fstest.go:203: 
        	Error Trace:	fstest.go:203
        	            				fstest.go:307
        	            				fstest.go:335
        	            				write_test.go:176
        	Error:      	Not equal: 
        	            	expected: 0
        	            	actual  : 1
        	Test:       	TestWriteFileHandleWriteAt
        	Messages:   	1 objects not found
=== RUN   TestWriteFileHandleFlush
2020/07/24 10:39:33 INFO  : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1': poll-interval is not supported by this remote
2020/07/24 10:39:33 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/07/24 10:39:33 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/07/24 10:39:33 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/07/24 10:39:33 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2020/07/24 10:39:33 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2020/07/24 10:39:33 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions
2020/07/24 10:39:33 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/07/24 10:39:33 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1': File to upload is small (5 bytes), uploading instead of streaming
2020/07/24 10:39:33 ERROR : file1: Failed to copy: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>4A36FB2AB164D9D1</RequestId><HostId>OHAiuN4Dko6MGnOfpWLOH215I8ddSKdrxmVyX1d9fkqKxzgSYjNmuUxBApHcfqUOLp36hgMhLko=</HostId></Error>
2020/07/24 10:39:33 ERROR : file1: WriteFileHandle.New Rcat failed: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>4A36FB2AB164D9D1</RequestId><HostId>OHAiuN4Dko6MGnOfpWLOH215I8ddSKdrxmVyX1d9fkqKxzgSYjNmuUxBApHcfqUOLp36hgMhLko=</HostId></Error>
2020/07/24 10:39:33 ERROR : file1: WriteFileHandle.Flush error: s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>4A36FB2AB164D9D1</RequestId><HostId>OHAiuN4Dko6MGnOfpWLOH215I8ddSKdrxmVyX1d9fkqKxzgSYjNmuUxBApHcfqUOLp36hgMhLko=</HostId></Error>
2020/07/24 10:39:33 DEBUG : file1: WriteFileHandle.Flush nothing to do
2020/07/24 10:39:33 DEBUG : WaitForWriters: timeout=10s
2020/07/24 10:39:33 DEBUG : : Looking for writers
2020/07/24 10:39:33 DEBUG : file1: reading active writers
2020/07/24 10:39:33 DEBUG : >WaitForWriters: 
--- FAIL: TestWriteFileHandleFlush (0.07s)
    run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1'", Local "Local file system at /tmp/rclone582682359", Modify Window "1ns"
    write_test.go:198: 
        	Error Trace:	write_test.go:198
        	Error:      	Received unexpected error:
        	            	s3 upload: 404 Not Found: <?xml version="1.0" encoding="UTF-8"?>
        	            	<Error><Code>NoSuchBucket</Code><Message>The specified bucket does not exist</Message><BucketName>rclone-test-nuzoyen3bohiqub9bamejav1</BucketName><RequestId>4A36FB2AB164D9D1</RequestId><HostId>OHAiuN4Dko6MGnOfpWLOH215I8ddSKdrxmVyX1d9fkqKxzgSYjNmuUxBApHcfqUOLp36hgMhLko=</HostId></Error>
        	Test:       	TestWriteFileHandleFlush
FAIL
2020/07/24 10:39:33 DEBUG : Chunked 'TestChunkerChunk50bSHA1QuickS3:rclone-test-nuzoyen3bohiqub9bamejav1': Purge dir ""
2020/07/24 10:39:33 purge failed to rmdir "": NoSuchBucket: The specified bucket does not exist
	status code: 404, request id: 8E94B5EDB91424ED, host id: WkQ51AxC96eA5Z/9KHhKTDx/E2RuOAB5CK2vr6EOdzIhZQNKfqDeneTJtnau/i1Sh0rKShWEAb4=
2020/07/24 10:39:33 purge failed: directory not found
"./vfs.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bSHA1QuickS3: -verbose -size-limit 1024 -test.run '^(TestRWFileHandleMethodsWrite|TestRWFileHandleWriteAt|TestRWFileHandleWriteNoWrite|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleWriteAt)$'" - Finished ERROR in 1m46.623691512s (try 3/5): exit status 1: Failed [TestRWFileHandleMethodsWrite TestRWFileHandleWriteAt TestRWFileHandleWriteNoWrite TestWriteFileHandleMethods TestWriteFileHandleWriteAt TestWriteFileHandleFlush]