"./vfs.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bSHA1HashS3: -verbose -size-limit 1024 -test.run '^(TestRWFileHandleMethodsWrite|TestRWFileHandleWriteAt|TestRWFileHandleWriteNoWrite|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleWriteAt)$'" - Starting (try 5/5)
=== RUN   TestRWFileHandleMethodsWrite
    run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3'", Local "Local file system at /tmp/rclone404921565", Modify Window "1ns"
2020/08/16 05:23:01 INFO  : Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3': poll-interval is not supported by this remote
2020/08/16 05:23:01 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bSHA1HashS3/rclone-test-zenomoj8ralenuh1qozubos3"
2020/08/16 05:23:01 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bSHA1HashS3/rclone-test-zenomoj8ralenuh1qozubos3"
2020/08/16 05:23:01 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/08/16 05:23:01 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2020/08/16 05:23:01 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/08/16 05:23:01 DEBUG : file1: newRWFileHandle: 
2020/08/16 05:23:01 DEBUG : file1(0xc0002b1e40): openPending: 
2020/08/16 05:23:01 DEBUG : file1: vfs cache: truncate to size=0
2020/08/16 05:23:01 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:23:01 DEBUG : file1(0xc0002b1e40): >openPending: err=<nil>
2020/08/16 05:23:01 DEBUG : file1: >newRWFileHandle: err=<nil>
2020/08/16 05:23:01 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:23:01 DEBUG : file1: >Open: fd=file1 (rw), err=<nil>
2020/08/16 05:23:01 DEBUG : file1: >OpenFile: fd=file1 (rw), err=<nil>
2020/08/16 05:23:01 DEBUG : file1(0xc0002b1e40): _writeAt: size=5, off=0
2020/08/16 05:23:01 DEBUG : file1(0xc0002b1e40): >_writeAt: n=5, err=<nil>
2020/08/16 05:23:01 DEBUG : file1(0xc0002b1e40): _writeAt: size=7, off=5
2020/08/16 05:23:01 DEBUG : file1(0xc0002b1e40): >_writeAt: n=7, err=<nil>
2020/08/16 05:23:01 DEBUG : file1: vfs cache: truncate to size=11
2020/08/16 05:23:01 DEBUG : file1(0xc0002b1e40): close: 
2020/08/16 05:23:01 DEBUG : file1: vfs cache: setting modification time to 2020-08-16 05:23:01.844300943 +0000 UTC m=+0.142438304
2020/08/16 05:23:01 INFO  : file1: vfs cache: queuing for upload in 100ms
2020/08/16 05:23:01 DEBUG : file1(0xc0002b1e40): >close: err=<nil>
2020/08/16 05:23:01 DEBUG : file1(0xc0002b1e40): close: 
2020/08/16 05:23:01 DEBUG : file1(0xc0002b1e40): >close: err=file already closed
2020/08/16 05:23:01 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:23:01 DEBUG : : Looking for writers
2020/08/16 05:23:01 DEBUG : file1: reading active writers
2020/08/16 05:23:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2020/08/16 05:23:01 DEBUG : : Looking for writers
2020/08/16 05:23:01 DEBUG : file1: reading active writers
2020/08/16 05:23:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2020/08/16 05:23:01 DEBUG : : Looking for writers
2020/08/16 05:23:01 DEBUG : file1: reading active writers
2020/08/16 05:23:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2020/08/16 05:23:01 DEBUG : : Looking for writers
2020/08/16 05:23:01 DEBUG : file1: reading active writers
2020/08/16 05:23:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2020/08/16 05:23:01 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23:01 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>B01D99F18090D225</RequestId><HostId>QHz+sJF6j9IXFBQpvtDCwY1OSOXSGXWHT4/bt7SPLYdLTn1z5nnXd0QMlStFgGoDWt4TtFNYZ4g=</HostId></Error>
2020/08/16 05:23:01 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>B01D99F18090D225</RequestId><HostId>QHz+sJF6j9IXFBQpvtDCwY1OSOXSGXWHT4/bt7SPLYdLTn1z5nnXd0QMlStFgGoDWt4TtFNYZ4g=</HostId></Error>
2020/08/16 05:23:01 DEBUG : : Looking for writers
2020/08/16 05:23:01 DEBUG : file1: reading active writers
2020/08/16 05:23:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2020/08/16 05:23:02 DEBUG : : Looking for writers
2020/08/16 05:23:02 DEBUG : file1: reading active writers
2020/08/16 05:23:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2020/08/16 05:23:02 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23:02 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>3A25D208DE28075E</RequestId><HostId>Rt9XReEnas8uYLARfN8trOFVRPY3sZ+jOqvBKLyJv2vF8icnNHGU5VF0bQu6pHjXCHtpd1AaZNk=</HostId></Error>
2020/08/16 05:23:02 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>3A25D208DE28075E</RequestId><HostId>Rt9XReEnas8uYLARfN8trOFVRPY3sZ+jOqvBKLyJv2vF8icnNHGU5VF0bQu6pHjXCHtpd1AaZNk=</HostId></Error>
2020/08/16 05:23:02 DEBUG : : Looking for writers
2020/08/16 05:23:02 DEBUG : file1: reading active writers
2020/08/16 05:23:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2020/08/16 05:23:02 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23:02 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>620589014135B12B</RequestId><HostId>r7spkSVL5+J3/8wsnF8SyaEXtfrelFCaorWoyaLG28/nqIGxPq3FaeowC5TMnb0r2gbgdvK/xO4=</HostId></Error>
2020/08/16 05:23:02 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>620589014135B12B</RequestId><HostId>r7spkSVL5+J3/8wsnF8SyaEXtfrelFCaorWoyaLG28/nqIGxPq3FaeowC5TMnb0r2gbgdvK/xO4=</HostId></Error>
2020/08/16 05:23:03 DEBUG : : Looking for writers
2020/08/16 05:23:03 DEBUG : file1: reading active writers
2020/08/16 05:23:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:03 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23:03 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>7S3N8M2W4W5K3N2P</RequestId><HostId>cUfWOSmV0DJGt7fqnk4YRAGJKZhra1Lg5Q4enxYi88s1hKJv4q7zsJ8IAbg1DVgRRsBnHFqjUX4=</HostId></Error>
2020/08/16 05:23:03 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>7S3N8M2W4W5K3N2P</RequestId><HostId>cUfWOSmV0DJGt7fqnk4YRAGJKZhra1Lg5Q4enxYi88s1hKJv4q7zsJ8IAbg1DVgRRsBnHFqjUX4=</HostId></Error>
2020/08/16 05:23:04 DEBUG : : Looking for writers
2020/08/16 05:23:04 DEBUG : file1: reading active writers
2020/08/16 05:23:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:05 DEBUG : : Looking for writers
2020/08/16 05:23:05 DEBUG : file1: reading active writers
2020/08/16 05:23:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:05 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23:05 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>779B39297E537934</RequestId><HostId>TTjEqxMBTM09HxfyDHvWrMSKuMoRFElYPoqaedzqr/zWdPFoidfImc+ArEkh/xkAfj7V8o+P47Q=</HostId></Error>
2020/08/16 05:23:05 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>779B39297E537934</RequestId><HostId>TTjEqxMBTM09HxfyDHvWrMSKuMoRFElYPoqaedzqr/zWdPFoidfImc+ArEkh/xkAfj7V8o+P47Q=</HostId></Error>
2020/08/16 05:23:06 DEBUG : : Looking for writers
2020/08/16 05:23:06 DEBUG : file1: reading active writers
2020/08/16 05:23:06 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:07 DEBUG : : Looking for writers
2020/08/16 05:23:07 DEBUG : file1: reading active writers
2020/08/16 05:23:07 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:08 DEBUG : : Looking for writers
2020/08/16 05:23:08 DEBUG : file1: reading active writers
2020/08/16 05:23:08 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:08 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23: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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>4A7F1C859E5565FB</RequestId><HostId>Y0Lv8zLPd6dq7dGsjLMwbumT+hlfCPPDoU/sS0ZelWlDKo9dI/UK+RRjdsoTDg2+aoF1ZO1DH/s=</HostId></Error>
2020/08/16 05:23:08 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>4A7F1C859E5565FB</RequestId><HostId>Y0Lv8zLPd6dq7dGsjLMwbumT+hlfCPPDoU/sS0ZelWlDKo9dI/UK+RRjdsoTDg2+aoF1ZO1DH/s=</HostId></Error>
2020/08/16 05:23:09 DEBUG : : Looking for writers
2020/08/16 05:23:09 DEBUG : file1: reading active writers
2020/08/16 05:23:09 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:10 DEBUG : : Looking for writers
2020/08/16 05:23:10 DEBUG : file1: reading active writers
2020/08/16 05:23:10 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:11 DEBUG : : Looking for writers
2020/08/16 05:23:11 DEBUG : file1: reading active writers
2020/08/16 05:23:11 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:11 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s
Cache{
	"file1": &{c:0xc0005dc630 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13818818876048343695 ext:142438304 loc:0x25a1860} ATime:{wall:13818818876048356877 ext:142451459 loc:0x25a1860} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1},
}
2020/08/16 05:23:11 DEBUG : >WaitForWriters: 
    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
2020/08/16 05:23:14 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23: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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>2FD13C7A35B6D24D</RequestId><HostId>AN4Veb54EZb6uu+xe/InNbu1mdDPTJ1z5QUqNW1ZAJQoZ1W1/xl9NHmDEY3BI4ix8/pxxO2+fOk=</HostId></Error>
2020/08/16 05:23:14 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>2FD13C7A35B6D24D</RequestId><HostId>AN4Veb54EZb6uu+xe/InNbu1mdDPTJ1z5QUqNW1ZAJQoZ1W1/xl9NHmDEY3BI4ix8/pxxO2+fOk=</HostId></Error>
    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
2020/08/16 05:23:18 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:23:18 DEBUG : : Looking for writers
2020/08/16 05:23:18 DEBUG : file1: reading active writers
2020/08/16 05:23:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2020/08/16 05:23:18 DEBUG : : Looking for writers
2020/08/16 05:23:18 DEBUG : file1: reading active writers
2020/08/16 05:23:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2020/08/16 05:23:18 DEBUG : : Looking for writers
2020/08/16 05:23:18 DEBUG : file1: reading active writers
2020/08/16 05:23:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2020/08/16 05:23:18 DEBUG : : Looking for writers
2020/08/16 05:23:18 DEBUG : file1: reading active writers
2020/08/16 05:23:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2020/08/16 05:23:19 DEBUG : : Looking for writers
2020/08/16 05:23:19 DEBUG : file1: reading active writers
2020/08/16 05:23:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2020/08/16 05:23:19 DEBUG : : Looking for writers
2020/08/16 05:23:19 DEBUG : file1: reading active writers
2020/08/16 05:23:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2020/08/16 05:23:19 DEBUG : : Looking for writers
2020/08/16 05:23:19 DEBUG : file1: reading active writers
2020/08/16 05:23:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2020/08/16 05:23:20 DEBUG : : Looking for writers
2020/08/16 05:23:20 DEBUG : file1: reading active writers
2020/08/16 05:23:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:21 DEBUG : : Looking for writers
2020/08/16 05:23:21 DEBUG : file1: reading active writers
2020/08/16 05:23:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:22 DEBUG : : Looking for writers
2020/08/16 05:23:22 DEBUG : file1: reading active writers
2020/08/16 05:23:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:23 DEBUG : : Looking for writers
2020/08/16 05:23:23 DEBUG : file1: reading active writers
2020/08/16 05:23:23 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:24 DEBUG : : Looking for writers
2020/08/16 05:23:24 DEBUG : file1: reading active writers
2020/08/16 05:23:24 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:25 DEBUG : : Looking for writers
2020/08/16 05:23:25 DEBUG : file1: reading active writers
2020/08/16 05:23:25 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:26 DEBUG : : Looking for writers
2020/08/16 05:23:26 DEBUG : file1: reading active writers
2020/08/16 05:23:26 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:27 DEBUG : : Looking for writers
2020/08/16 05:23:27 DEBUG : file1: reading active writers
2020/08/16 05:23:27 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:27 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23: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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>21AE601E161AC5C8</RequestId><HostId>tmMpUXeqlRW5VkbbTMzUttWCWT9rkVmhWH8jQe++clnBwhSdElTyFwejRvj4MHPOlRnQq5enP7o=</HostId></Error>
2020/08/16 05:23:27 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>21AE601E161AC5C8</RequestId><HostId>tmMpUXeqlRW5VkbbTMzUttWCWT9rkVmhWH8jQe++clnBwhSdElTyFwejRvj4MHPOlRnQq5enP7o=</HostId></Error>
2020/08/16 05:23:28 DEBUG : : Looking for writers
2020/08/16 05:23:28 DEBUG : file1: reading active writers
2020/08/16 05:23:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:28 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s
Cache{
	"file1": &{c:0xc0005dc630 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13818818876048343695 ext:142438304 loc:0x25a1860} ATime:{wall:13818818876048356877 ext:142451459 loc:0x25a1860} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1},
}
2020/08/16 05:23:28 DEBUG : >WaitForWriters: 
2020/08/16 05:23:28 DEBUG : vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleMethodsWrite (27.20s)
=== RUN   TestRWFileHandleWriteAt
    run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3'", Local "Local file system at /tmp/rclone404921565", Modify Window "1ns"
2020/08/16 05:23:28 INFO  : Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3': poll-interval is not supported by this remote
2020/08/16 05:23:28 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bSHA1HashS3/rclone-test-zenomoj8ralenuh1qozubos3"
2020/08/16 05:23:28 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bSHA1HashS3/rclone-test-zenomoj8ralenuh1qozubos3"
2020/08/16 05:23:28 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/08/16 05:23:28 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2020/08/16 05:23:28 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/08/16 05:23:28 DEBUG : file1: newRWFileHandle: 
2020/08/16 05:23:28 DEBUG : file1(0xc0008b47c0): openPending: 
2020/08/16 05:23:28 DEBUG : file1: vfs cache: truncate to size=0
2020/08/16 05:23:28 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:23:28 DEBUG : file1(0xc0008b47c0): >openPending: err=<nil>
2020/08/16 05:23:28 DEBUG : file1: >newRWFileHandle: err=<nil>
2020/08/16 05:23:28 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:23:28 DEBUG : file1: >Open: fd=file1 (rw), err=<nil>
2020/08/16 05:23:28 DEBUG : file1: >OpenFile: fd=file1 (rw), err=<nil>
2020/08/16 05:23:28 DEBUG : file1(0xc0008b47c0): _writeAt: size=7, off=0
2020/08/16 05:23:28 DEBUG : file1(0xc0008b47c0): >_writeAt: n=7, err=<nil>
2020/08/16 05:23:28 DEBUG : file1(0xc0008b47c0): _writeAt: size=6, off=5
2020/08/16 05:23:28 DEBUG : file1(0xc0008b47c0): >_writeAt: n=6, err=<nil>
2020/08/16 05:23:28 DEBUG : file1(0xc0008b47c0): close: 
2020/08/16 05:23:28 DEBUG : file1: vfs cache: setting modification time to 2020-08-16 05:23:28.937205384 +0000 UTC m=+27.235342699
2020/08/16 05:23:28 INFO  : file1: vfs cache: queuing for upload in 100ms
2020/08/16 05:23:28 DEBUG : file1(0xc0008b47c0): >close: err=<nil>
2020/08/16 05:23:28 DEBUG : file1(0xc0008b47c0): _writeAt: size=5, off=0
2020/08/16 05:23:28 DEBUG : file1(0xc0008b47c0): >_writeAt: n=0, err=file already closed
2020/08/16 05:23:28 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:23:28 DEBUG : : Looking for writers
2020/08/16 05:23:28 DEBUG : file1: reading active writers
2020/08/16 05:23:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2020/08/16 05:23:28 DEBUG : : Looking for writers
2020/08/16 05:23:28 DEBUG : file1: reading active writers
2020/08/16 05:23:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2020/08/16 05:23:28 DEBUG : : Looking for writers
2020/08/16 05:23:28 DEBUG : file1: reading active writers
2020/08/16 05:23:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2020/08/16 05:23:29 DEBUG : : Looking for writers
2020/08/16 05:23:29 DEBUG : file1: reading active writers
2020/08/16 05:23:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2020/08/16 05:23:29 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23:29 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>8A1BE8612900FB95</RequestId><HostId>XOTgRdfULICxbze24BJW/f9quKwaYnQFHYQ18bXK/1VnrDASwRnLMUS3uVD6RFR1PmEH/yc6G8o=</HostId></Error>
2020/08/16 05:23:29 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>8A1BE8612900FB95</RequestId><HostId>XOTgRdfULICxbze24BJW/f9quKwaYnQFHYQ18bXK/1VnrDASwRnLMUS3uVD6RFR1PmEH/yc6G8o=</HostId></Error>
2020/08/16 05:23:29 DEBUG : : Looking for writers
2020/08/16 05:23:29 DEBUG : file1: reading active writers
2020/08/16 05:23:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2020/08/16 05:23:29 DEBUG : : Looking for writers
2020/08/16 05:23:29 DEBUG : file1: reading active writers
2020/08/16 05:23:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2020/08/16 05:23:29 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23:29 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>0P6M1T0R2Q7VCSCG</RequestId><HostId>9pF0Kuo1HlfW0Xl9GbceavtTOHW/20WGEA66LpfasnZ8Ot4tRMWIkMm8MMtzC7tNEO94tkFKSrU=</HostId></Error>
2020/08/16 05:23:29 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>0P6M1T0R2Q7VCSCG</RequestId><HostId>9pF0Kuo1HlfW0Xl9GbceavtTOHW/20WGEA66LpfasnZ8Ot4tRMWIkMm8MMtzC7tNEO94tkFKSrU=</HostId></Error>
2020/08/16 05:23:29 DEBUG : : Looking for writers
2020/08/16 05:23:29 DEBUG : file1: reading active writers
2020/08/16 05:23:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2020/08/16 05:23:29 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23:29 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>B825D8F9623518C3</RequestId><HostId>rAEUZrVCD6fvXBpf20dJplGUp3rmqNufbmf87y9axzNogqZNz1YuG8yYiEoaDEXdUJuvE9jC6Nc=</HostId></Error>
2020/08/16 05:23:29 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>B825D8F9623518C3</RequestId><HostId>rAEUZrVCD6fvXBpf20dJplGUp3rmqNufbmf87y9axzNogqZNz1YuG8yYiEoaDEXdUJuvE9jC6Nc=</HostId></Error>
2020/08/16 05:23:30 DEBUG : : Looking for writers
2020/08/16 05:23:30 DEBUG : file1: reading active writers
2020/08/16 05:23:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:30 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23:30 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>D7847F2831855D29</RequestId><HostId>xoIREVAkwzHNnlVYyClWuL0I78oC6m9Vzo77pZ5fTnKLtYyV7wAAG2shTjr2SAOKP5A8g+O0Roo=</HostId></Error>
2020/08/16 05:23:30 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>D7847F2831855D29</RequestId><HostId>xoIREVAkwzHNnlVYyClWuL0I78oC6m9Vzo77pZ5fTnKLtYyV7wAAG2shTjr2SAOKP5A8g+O0Roo=</HostId></Error>
2020/08/16 05:23:31 DEBUG : : Looking for writers
2020/08/16 05:23:31 DEBUG : file1: reading active writers
2020/08/16 05:23:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:32 DEBUG : : Looking for writers
2020/08/16 05:23:32 DEBUG : file1: reading active writers
2020/08/16 05:23:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:32 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23:32 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>7B6D0AE8DB41AC6F</RequestId><HostId>tSh2b57eQmFbgCjwcwXJ33fZ6wFLAXyxUnELTeaveiWxtqf3duQVVGvrUHG5PheogSJvvhkMTCA=</HostId></Error>
2020/08/16 05:23:32 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>7B6D0AE8DB41AC6F</RequestId><HostId>tSh2b57eQmFbgCjwcwXJ33fZ6wFLAXyxUnELTeaveiWxtqf3duQVVGvrUHG5PheogSJvvhkMTCA=</HostId></Error>
2020/08/16 05:23:33 DEBUG : : Looking for writers
2020/08/16 05:23:33 DEBUG : file1: reading active writers
2020/08/16 05:23:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:34 DEBUG : : Looking for writers
2020/08/16 05:23:34 DEBUG : file1: reading active writers
2020/08/16 05:23:34 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:35 DEBUG : : Looking for writers
2020/08/16 05:23:35 DEBUG : file1: reading active writers
2020/08/16 05:23:35 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:35 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23:35 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>AC49C13D983F3361</RequestId><HostId>4RmoGmyz9ekfKf2fMVNmtxS7YGEpnRif8JnNW/hz3ohER3dN45RrSu+zkiSyql9KY3JHhsHn8UU=</HostId></Error>
2020/08/16 05:23:35 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>AC49C13D983F3361</RequestId><HostId>4RmoGmyz9ekfKf2fMVNmtxS7YGEpnRif8JnNW/hz3ohER3dN45RrSu+zkiSyql9KY3JHhsHn8UU=</HostId></Error>
2020/08/16 05:23:36 DEBUG : : Looking for writers
2020/08/16 05:23:36 DEBUG : file1: reading active writers
2020/08/16 05:23:36 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:37 DEBUG : : Looking for writers
2020/08/16 05:23:37 DEBUG : file1: reading active writers
2020/08/16 05:23:37 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:38 DEBUG : : Looking for writers
2020/08/16 05:23:38 DEBUG : file1: reading active writers
2020/08/16 05:23:38 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:38 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s
Cache{
	"file1": &{c:0xc00078e990 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13818818905132277384 ext:27235342699 loc:0x25a1860} ATime:{wall:13818818905132308653 ext:27235373981 loc:0x25a1860} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1},
}
2020/08/16 05:23:38 DEBUG : >WaitForWriters: 
    fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3
2020/08/16 05:23:41 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23: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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>FX9WDX7KFP3NFR0Y</RequestId><HostId>1ktpwBPlr74msJzEuRqUUFnlI7opEbTYnOmnE/8HFEo7q5sFwB0t3uBiriitEvoIH8sKHKeuA+o=</HostId></Error>
2020/08/16 05:23:41 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>FX9WDX7KFP3NFR0Y</RequestId><HostId>1ktpwBPlr74msJzEuRqUUFnlI7opEbTYnOmnE/8HFEo7q5sFwB0t3uBiriitEvoIH8sKHKeuA+o=</HostId></Error>
    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
2020/08/16 05:23:46 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:23:46 DEBUG : : Looking for writers
2020/08/16 05:23:46 DEBUG : file1: reading active writers
2020/08/16 05:23:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2020/08/16 05:23:46 DEBUG : : Looking for writers
2020/08/16 05:23:46 DEBUG : file1: reading active writers
2020/08/16 05:23:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2020/08/16 05:23:46 DEBUG : : Looking for writers
2020/08/16 05:23:46 DEBUG : file1: reading active writers
2020/08/16 05:23:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2020/08/16 05:23:46 DEBUG : : Looking for writers
2020/08/16 05:23:46 DEBUG : file1: reading active writers
2020/08/16 05:23:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2020/08/16 05:23:46 DEBUG : : Looking for writers
2020/08/16 05:23:46 DEBUG : file1: reading active writers
2020/08/16 05:23:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2020/08/16 05:23:46 DEBUG : : Looking for writers
2020/08/16 05:23:46 DEBUG : file1: reading active writers
2020/08/16 05:23:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2020/08/16 05:23:46 DEBUG : : Looking for writers
2020/08/16 05:23:46 DEBUG : file1: reading active writers
2020/08/16 05:23:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2020/08/16 05:23:47 DEBUG : : Looking for writers
2020/08/16 05:23:47 DEBUG : file1: reading active writers
2020/08/16 05:23:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:48 DEBUG : : Looking for writers
2020/08/16 05:23:48 DEBUG : file1: reading active writers
2020/08/16 05:23:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:49 DEBUG : : Looking for writers
2020/08/16 05:23:49 DEBUG : file1: reading active writers
2020/08/16 05:23:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:50 DEBUG : : Looking for writers
2020/08/16 05:23:50 DEBUG : file1: reading active writers
2020/08/16 05:23:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:51 DEBUG : : Looking for writers
2020/08/16 05:23:51 DEBUG : file1: reading active writers
2020/08/16 05:23:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:52 DEBUG : : Looking for writers
2020/08/16 05:23:52 DEBUG : file1: reading active writers
2020/08/16 05:23:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:53 DEBUG : : Looking for writers
2020/08/16 05:23:53 DEBUG : file1: reading active writers
2020/08/16 05:23:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:54 DEBUG : : Looking for writers
2020/08/16 05:23:54 DEBUG : file1: reading active writers
2020/08/16 05:23:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:54 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23: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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>DED304BE6903A926</RequestId><HostId>kIifGRb/iEJWbAXmq4ANFl4ZlsYpmv41sQ3c0DCtr1MSE4PpMYh06BUFs9f+qV6m64Rn30QLwMY=</HostId></Error>
2020/08/16 05:23:54 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>DED304BE6903A926</RequestId><HostId>kIifGRb/iEJWbAXmq4ANFl4ZlsYpmv41sQ3c0DCtr1MSE4PpMYh06BUFs9f+qV6m64Rn30QLwMY=</HostId></Error>
2020/08/16 05:23:55 DEBUG : : Looking for writers
2020/08/16 05:23:55 DEBUG : file1: reading active writers
2020/08/16 05:23:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:23:56 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s
Cache{
	"file1": &{c:0xc00078e990 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13818818905132277384 ext:27235342699 loc:0x25a1860} ATime:{wall:13818818905132308653 ext:27235373981 loc:0x25a1860} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1},
}
2020/08/16 05:23:56 DEBUG : >WaitForWriters: 
2020/08/16 05:23:56 DEBUG : vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleWriteAt (27.17s)
=== RUN   TestRWFileHandleWriteNoWrite
    run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3'", Local "Local file system at /tmp/rclone404921565", Modify Window "1ns"
2020/08/16 05:23:56 INFO  : Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3': poll-interval is not supported by this remote
2020/08/16 05:23:56 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bSHA1HashS3/rclone-test-zenomoj8ralenuh1qozubos3"
2020/08/16 05:23:56 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bSHA1HashS3/rclone-test-zenomoj8ralenuh1qozubos3"
2020/08/16 05:23:56 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/08/16 05:23:56 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2020/08/16 05:23:56 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/08/16 05:23:56 DEBUG : file1: newRWFileHandle: 
2020/08/16 05:23:56 DEBUG : file1(0xc000a8b6c0): openPending: 
2020/08/16 05:23:56 DEBUG : file1: vfs cache: truncate to size=0
2020/08/16 05:23:56 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:23:56 DEBUG : file1(0xc000a8b6c0): >openPending: err=<nil>
2020/08/16 05:23:56 DEBUG : file1: >newRWFileHandle: err=<nil>
2020/08/16 05:23:56 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:23:56 DEBUG : file1: >Open: fd=file1 (rw), err=<nil>
2020/08/16 05:23:56 DEBUG : file1: >OpenFile: fd=file1 (rw), err=<nil>
2020/08/16 05:23:56 DEBUG : file1(0xc000a8b6c0): close: 
2020/08/16 05:23:56 DEBUG : file1: vfs cache: setting modification time to 2020-08-16 05:23:56.103876339 +0000 UTC m=+54.402013666
2020/08/16 05:23:56 INFO  : file1: vfs cache: queuing for upload in 100ms
2020/08/16 05:23:56 DEBUG : file1(0xc000a8b6c0): >close: err=<nil>
2020/08/16 05:23:56 DEBUG : file2: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx
2020/08/16 05:23:56 DEBUG : file2: Open: flags=O_WRONLY|O_CREATE|O_TRUNC
2020/08/16 05:23:56 DEBUG : file2: newRWFileHandle: 
2020/08/16 05:23:56 DEBUG : file2(0xc000a8b7c0): openPending: 
2020/08/16 05:23:56 DEBUG : file2: vfs cache: truncate to size=0
2020/08/16 05:23:56 DEBUG : : Added virtual directory entry vAdd: "file2"
2020/08/16 05:23:56 DEBUG : file2(0xc000a8b7c0): >openPending: err=<nil>
2020/08/16 05:23:56 DEBUG : file2: >newRWFileHandle: err=<nil>
2020/08/16 05:23:56 DEBUG : : Added virtual directory entry vAdd: "file2"
2020/08/16 05:23:56 DEBUG : file2: >Open: fd=file2 (rw), err=<nil>
2020/08/16 05:23:56 DEBUG : file2: >OpenFile: fd=file2 (rw), err=<nil>
2020/08/16 05:23:56 DEBUG : file2(0xc000a8b7c0): RWFileHandle.Flush
2020/08/16 05:23:56 DEBUG : file2(0xc000a8b7c0): RWFileHandle.Release
2020/08/16 05:23:56 DEBUG : file2(0xc000a8b7c0): close: 
2020/08/16 05:23:56 DEBUG : file2: vfs cache: setting modification time to 2020-08-16 05:23:56.104728643 +0000 UTC m=+54.402865977
2020/08/16 05:23:56 INFO  : file2: vfs cache: queuing for upload in 100ms
2020/08/16 05:23:56 DEBUG : file2(0xc000a8b7c0): >close: err=<nil>
2020/08/16 05:23:56 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:23:56 DEBUG : : Looking for writers
2020/08/16 05:23:56 DEBUG : file1: reading active writers
2020/08/16 05:23:56 DEBUG : file2: reading active writers
2020/08/16 05:23:56 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms
2020/08/16 05:23:56 DEBUG : : Looking for writers
2020/08/16 05:23:56 DEBUG : file2: reading active writers
2020/08/16 05:23:56 DEBUG : file1: reading active writers
2020/08/16 05:23:56 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms
2020/08/16 05:23:56 DEBUG : : Looking for writers
2020/08/16 05:23:56 DEBUG : file2: reading active writers
2020/08/16 05:23:56 DEBUG : file1: reading active writers
2020/08/16 05:23:56 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms
2020/08/16 05:23:56 DEBUG : : Looking for writers
2020/08/16 05:23:56 DEBUG : file1: reading active writers
2020/08/16 05:23:56 DEBUG : file2: reading active writers
2020/08/16 05:23:56 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms
2020/08/16 05:23:56 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23:56 DEBUG : file2: vfs cache: starting upload
2020/08/16 05:23:56 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>95C7E48E9E2BD18B</RequestId><HostId>wn0d8UtwcBXeOr2FxmC+gRleTAtpHiR7VpKLgzAeEDQPg5CVlFdRT660M50EALtKeoJXyENjmKU=</HostId></Error>
2020/08/16 05:23:56 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>95C7E48E9E2BD18B</RequestId><HostId>wn0d8UtwcBXeOr2FxmC+gRleTAtpHiR7VpKLgzAeEDQPg5CVlFdRT660M50EALtKeoJXyENjmKU=</HostId></Error>
2020/08/16 05:23:56 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>8B4FD586BDDE182C</RequestId><HostId>+Y7bPDJH+qeDIomtXYGft4QMRfSxr+twzjQcStYAlRUDZohWnp8Mp6OSju/vm3bh+RNUiFipyGQ=</HostId></Error>
2020/08/16 05:23:56 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>8B4FD586BDDE182C</RequestId><HostId>+Y7bPDJH+qeDIomtXYGft4QMRfSxr+twzjQcStYAlRUDZohWnp8Mp6OSju/vm3bh+RNUiFipyGQ=</HostId></Error>
2020/08/16 05:23:56 DEBUG : : Looking for writers
2020/08/16 05:23:56 DEBUG : file1: reading active writers
2020/08/16 05:23:56 DEBUG : file2: reading active writers
2020/08/16 05:23:56 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms
2020/08/16 05:23:56 DEBUG : : Looking for writers
2020/08/16 05:23:56 DEBUG : file1: reading active writers
2020/08/16 05:23:56 DEBUG : file2: reading active writers
2020/08/16 05:23:56 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms
2020/08/16 05:23:56 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23:56 DEBUG : file2: vfs cache: starting upload
2020/08/16 05:23:56 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>D2BE6304F4D32DDF</RequestId><HostId>lgW+S/lM+qRYWdx81x/NcOL616oWDNzNBZOPffg5hWHGqWbbsY1Gv2bUvFviV7tBwC9YQIBux8I=</HostId></Error>
2020/08/16 05:23:56 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>D2BE6304F4D32DDF</RequestId><HostId>lgW+S/lM+qRYWdx81x/NcOL616oWDNzNBZOPffg5hWHGqWbbsY1Gv2bUvFviV7tBwC9YQIBux8I=</HostId></Error>
2020/08/16 05:23:56 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>83C847D6A617D983</RequestId><HostId>Fu51VmXp2C6CGH5rom/seB39qs+UnpWA2YurqJ1gQDKZ00ObxO+NDKp3jvbOZldJ/XXT4b01y7I=</HostId></Error>
2020/08/16 05:23:56 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>83C847D6A617D983</RequestId><HostId>Fu51VmXp2C6CGH5rom/seB39qs+UnpWA2YurqJ1gQDKZ00ObxO+NDKp3jvbOZldJ/XXT4b01y7I=</HostId></Error>
2020/08/16 05:23:56 DEBUG : : Looking for writers
2020/08/16 05:23:56 DEBUG : file2: reading active writers
2020/08/16 05:23:56 DEBUG : file1: reading active writers
2020/08/16 05:23:56 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms
2020/08/16 05:23:56 DEBUG : file2: vfs cache: starting upload
2020/08/16 05:23:56 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23:56 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>C48F8392BB71CFF7</RequestId><HostId>z4gqUCrUItT5B+kUmS9Y+bnGSEC9cgPmLoCxRv5p9Futdtfvg5gAMsp79cW3XDJQCqHQelvmmZs=</HostId></Error>
2020/08/16 05:23:56 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>C48F8392BB71CFF7</RequestId><HostId>z4gqUCrUItT5B+kUmS9Y+bnGSEC9cgPmLoCxRv5p9Futdtfvg5gAMsp79cW3XDJQCqHQelvmmZs=</HostId></Error>
2020/08/16 05:23:56 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>93AAEDC8EFAD7D4C</RequestId><HostId>A9hdSBLnTXAhyQhF/nZY2dz2jUJBJon9mPhiUd7X1KcNFH9+Z0NQwfZ4EnRBU/X5oY4zPMdJsZU=</HostId></Error>
2020/08/16 05:23:56 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>93AAEDC8EFAD7D4C</RequestId><HostId>A9hdSBLnTXAhyQhF/nZY2dz2jUJBJon9mPhiUd7X1KcNFH9+Z0NQwfZ4EnRBU/X5oY4zPMdJsZU=</HostId></Error>
2020/08/16 05:23:57 DEBUG : : Looking for writers
2020/08/16 05:23:57 DEBUG : file1: reading active writers
2020/08/16 05:23:57 DEBUG : file2: reading active writers
2020/08/16 05:23:57 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:23:57 DEBUG : file2: vfs cache: starting upload
2020/08/16 05:23:57 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23:57 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>5862EC57DAB3BE8F</RequestId><HostId>dx2xbwDsrp7dXPYc61C74l3pHMu8AWXNi5hr4PPQXh/P0iKBYbVw47nzqxp9iMFJuyUIwQdV3iQ=</HostId></Error>
2020/08/16 05:23:57 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>5862EC57DAB3BE8F</RequestId><HostId>dx2xbwDsrp7dXPYc61C74l3pHMu8AWXNi5hr4PPQXh/P0iKBYbVw47nzqxp9iMFJuyUIwQdV3iQ=</HostId></Error>
2020/08/16 05:23:57 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>F70666773A709D6F</RequestId><HostId>tbxFz9VN18Cad6WSIOzomAzWhDdcrIyo2R6Os47CJX64GKQOxZe83G/w9ApCxuLAwShQ7BBDPn0=</HostId></Error>
2020/08/16 05:23:57 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>F70666773A709D6F</RequestId><HostId>tbxFz9VN18Cad6WSIOzomAzWhDdcrIyo2R6Os47CJX64GKQOxZe83G/w9ApCxuLAwShQ7BBDPn0=</HostId></Error>
2020/08/16 05:23:58 DEBUG : : Looking for writers
2020/08/16 05:23:58 DEBUG : file1: reading active writers
2020/08/16 05:23:58 DEBUG : file2: reading active writers
2020/08/16 05:23:58 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:23:59 DEBUG : file2: vfs cache: starting upload
2020/08/16 05:23:59 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:23:59 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>1E80CD33E4CF9470</RequestId><HostId>rgRVwA4/95IMwMjOZYXHFlyq1sGAWqftxc5k2vNCPdh5IzrcdqeGwHdCoZU/p6wtU5vzjb9PAGw=</HostId></Error>
2020/08/16 05:23:59 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>1E80CD33E4CF9470</RequestId><HostId>rgRVwA4/95IMwMjOZYXHFlyq1sGAWqftxc5k2vNCPdh5IzrcdqeGwHdCoZU/p6wtU5vzjb9PAGw=</HostId></Error>
2020/08/16 05:23:59 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>19167EAB4E4F6C64</RequestId><HostId>QUXi17VECMhACa1pd2pRZLx6hCTwWHOHae5+sLkNw6nFTuEIY+GbwPzFY5vLsgyb+dvLD6e3cm0=</HostId></Error>
2020/08/16 05:23:59 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>19167EAB4E4F6C64</RequestId><HostId>QUXi17VECMhACa1pd2pRZLx6hCTwWHOHae5+sLkNw6nFTuEIY+GbwPzFY5vLsgyb+dvLD6e3cm0=</HostId></Error>
2020/08/16 05:23:59 DEBUG : : Looking for writers
2020/08/16 05:23:59 DEBUG : file1: reading active writers
2020/08/16 05:23:59 DEBUG : file2: reading active writers
2020/08/16 05:23:59 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:24:00 DEBUG : : Looking for writers
2020/08/16 05:24:00 DEBUG : file1: reading active writers
2020/08/16 05:24:00 DEBUG : file2: reading active writers
2020/08/16 05:24:00 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:24:01 DEBUG : : Looking for writers
2020/08/16 05:24:01 DEBUG : file1: reading active writers
2020/08/16 05:24:01 DEBUG : file2: reading active writers
2020/08/16 05:24:01 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:24:02 DEBUG : : Looking for writers
2020/08/16 05:24:02 DEBUG : file1: reading active writers
2020/08/16 05:24:02 DEBUG : file2: reading active writers
2020/08/16 05:24:02 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:24:02 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:24:02 DEBUG : file2: vfs cache: starting upload
2020/08/16 05:24:02 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>FW3G2P6S6KCK1N8T</RequestId><HostId>FPZBY6Z6SRX3bBH/UqDTcduSYZ3eb0HZWuaEEN42ZMWrUCIzDslC7wJL4Qygfr8ee8nLpMw95K0=</HostId></Error>
2020/08/16 05:24:02 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>FW3G2P6S6KCK1N8T</RequestId><HostId>FPZBY6Z6SRX3bBH/UqDTcduSYZ3eb0HZWuaEEN42ZMWrUCIzDslC7wJL4Qygfr8ee8nLpMw95K0=</HostId></Error>
2020/08/16 05:24:02 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>D7474F14364B9074</RequestId><HostId>RWeXWj1jG2mVSRdFjpn4QpVLcfny6IC7iUqQHC+E4ZaouBiR7VlUI0nukPQPy5zzStKxSZieunw=</HostId></Error>
2020/08/16 05:24:02 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>D7474F14364B9074</RequestId><HostId>RWeXWj1jG2mVSRdFjpn4QpVLcfny6IC7iUqQHC+E4ZaouBiR7VlUI0nukPQPy5zzStKxSZieunw=</HostId></Error>
2020/08/16 05:24:03 DEBUG : : Looking for writers
2020/08/16 05:24:03 DEBUG : file1: reading active writers
2020/08/16 05:24:03 DEBUG : file2: reading active writers
2020/08/16 05:24:03 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:24:04 DEBUG : : Looking for writers
2020/08/16 05:24:04 DEBUG : file1: reading active writers
2020/08/16 05:24:04 DEBUG : file2: reading active writers
2020/08/16 05:24:04 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:24:05 DEBUG : : Looking for writers
2020/08/16 05:24:05 DEBUG : file1: reading active writers
2020/08/16 05:24:05 DEBUG : file2: reading active writers
2020/08/16 05:24:05 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:24:06 ERROR : Exiting even though 0 writers active and 2 cache items in use after 10s
Cache{
	"file2": &{c:0xc00078e510 mu:{state:0 sema:0} name:file2 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13818818934364571715 ext:54402865977 loc:0x25a1860} ATime:{wall:13818818934364733536 ext:54403027792 loc:0x25a1860} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2},
	"file1": &{c:0xc00078e510 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13818818934363719411 ext:54402013666 loc:0x25a1860} ATime:{wall:13818818934363855680 ext:54402149942 loc:0x25a1860} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1},
}
2020/08/16 05:24:06 DEBUG : >WaitForWriters: 
    fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3
    fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3
2020/08/16 05:24:08 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:24:08 DEBUG : file2: vfs cache: starting upload
2020/08/16 05:24:08 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>C67DDB83EDC2DB05</RequestId><HostId>frPgwpHELkx3SLupG/AYiuDZoSFeSC8jxKF/c/a8NghbKiA1hkMJADbfPEH5U2stqf5ypgv3vr8=</HostId></Error>
2020/08/16 05:24:08 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>C67DDB83EDC2DB05</RequestId><HostId>frPgwpHELkx3SLupG/AYiuDZoSFeSC8jxKF/c/a8NghbKiA1hkMJADbfPEH5U2stqf5ypgv3vr8=</HostId></Error>
2020/08/16 05:24: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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>DCF258DE76744FED</RequestId><HostId>ihR/NBwyLj3Cd6B7OcGayCdT4tisHpZRUX1EgGaxb6LrfgTfJwxAyxXwstue1hEZ3BkCv48t/nI=</HostId></Error>
2020/08/16 05:24:08 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>DCF258DE76744FED</RequestId><HostId>ihR/NBwyLj3Cd6B7OcGayCdT4tisHpZRUX1EgGaxb6LrfgTfJwxAyxXwstue1hEZ3BkCv48t/nI=</HostId></Error>
    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
2020/08/16 05:24:13 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:24:13 DEBUG : : Looking for writers
2020/08/16 05:24:13 DEBUG : file1: reading active writers
2020/08/16 05:24:13 DEBUG : file2: reading active writers
2020/08/16 05:24:13 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms
2020/08/16 05:24:13 DEBUG : : Looking for writers
2020/08/16 05:24:13 DEBUG : file1: reading active writers
2020/08/16 05:24:13 DEBUG : file2: reading active writers
2020/08/16 05:24:13 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms
2020/08/16 05:24:13 DEBUG : : Looking for writers
2020/08/16 05:24:13 DEBUG : file1: reading active writers
2020/08/16 05:24:13 DEBUG : file2: reading active writers
2020/08/16 05:24:13 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms
2020/08/16 05:24:13 DEBUG : : Looking for writers
2020/08/16 05:24:13 DEBUG : file1: reading active writers
2020/08/16 05:24:13 DEBUG : file2: reading active writers
2020/08/16 05:24:13 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms
2020/08/16 05:24:13 DEBUG : : Looking for writers
2020/08/16 05:24:13 DEBUG : file2: reading active writers
2020/08/16 05:24:13 DEBUG : file1: reading active writers
2020/08/16 05:24:13 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms
2020/08/16 05:24:13 DEBUG : : Looking for writers
2020/08/16 05:24:13 DEBUG : file2: reading active writers
2020/08/16 05:24:13 DEBUG : file1: reading active writers
2020/08/16 05:24:13 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms
2020/08/16 05:24:13 DEBUG : : Looking for writers
2020/08/16 05:24:13 DEBUG : file1: reading active writers
2020/08/16 05:24:13 DEBUG : file2: reading active writers
2020/08/16 05:24:13 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms
2020/08/16 05:24:14 DEBUG : : Looking for writers
2020/08/16 05:24:14 DEBUG : file1: reading active writers
2020/08/16 05:24:14 DEBUG : file2: reading active writers
2020/08/16 05:24:14 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:24:15 DEBUG : : Looking for writers
2020/08/16 05:24:15 DEBUG : file1: reading active writers
2020/08/16 05:24:15 DEBUG : file2: reading active writers
2020/08/16 05:24:15 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:24:16 DEBUG : : Looking for writers
2020/08/16 05:24:16 DEBUG : file1: reading active writers
2020/08/16 05:24:16 DEBUG : file2: reading active writers
2020/08/16 05:24:16 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:24:17 DEBUG : : Looking for writers
2020/08/16 05:24:17 DEBUG : file1: reading active writers
2020/08/16 05:24:17 DEBUG : file2: reading active writers
2020/08/16 05:24:17 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:24:18 DEBUG : : Looking for writers
2020/08/16 05:24:18 DEBUG : file1: reading active writers
2020/08/16 05:24:18 DEBUG : file2: reading active writers
2020/08/16 05:24:18 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:24:19 DEBUG : : Looking for writers
2020/08/16 05:24:19 DEBUG : file1: reading active writers
2020/08/16 05:24:19 DEBUG : file2: reading active writers
2020/08/16 05:24:19 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:24:20 DEBUG : : Looking for writers
2020/08/16 05:24:20 DEBUG : file1: reading active writers
2020/08/16 05:24:20 DEBUG : file2: reading active writers
2020/08/16 05:24:20 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:24:21 DEBUG : : Looking for writers
2020/08/16 05:24:21 DEBUG : file1: reading active writers
2020/08/16 05:24:21 DEBUG : file2: reading active writers
2020/08/16 05:24:21 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:24:21 DEBUG : file2: vfs cache: starting upload
2020/08/16 05:24:21 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:24:21 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>1A15133247221A9B</RequestId><HostId>18Hzs+P3RxkG0IhoDamF7kMcI6/io+X9tLiI2NcSWkM/rFY12mEnHrInm12Nqc4R5S5v8bfTtYM=</HostId></Error>
2020/08/16 05:24:21 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>8A007CF40FC0DA24</RequestId><HostId>ewGJbNo/HmzY6OJqmzvYVgYCEY7cDOfH27/dph0jQ5lZk37pB1yQK4C6dCOydsJReQbsHpdX27w=</HostId></Error>
2020/08/16 05:24:21 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>1A15133247221A9B</RequestId><HostId>18Hzs+P3RxkG0IhoDamF7kMcI6/io+X9tLiI2NcSWkM/rFY12mEnHrInm12Nqc4R5S5v8bfTtYM=</HostId></Error>
2020/08/16 05:24:21 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>8A007CF40FC0DA24</RequestId><HostId>ewGJbNo/HmzY6OJqmzvYVgYCEY7cDOfH27/dph0jQ5lZk37pB1yQK4C6dCOydsJReQbsHpdX27w=</HostId></Error>
2020/08/16 05:24:22 DEBUG : : Looking for writers
2020/08/16 05:24:22 DEBUG : file1: reading active writers
2020/08/16 05:24:22 DEBUG : file2: reading active writers
2020/08/16 05:24:22 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:24:23 ERROR : Exiting even though 0 writers active and 2 cache items in use after 10s
Cache{
	"file1": &{c:0xc00078e510 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13818818934363719411 ext:54402013666 loc:0x25a1860} ATime:{wall:13818818934363855680 ext:54402149942 loc:0x25a1860} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1},
	"file2": &{c:0xc00078e510 mu:{state:0 sema:0} name:file2 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13818818934364571715 ext:54402865977 loc:0x25a1860} ATime:{wall:13818818934364733536 ext:54403027792 loc:0x25a1860} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2},
}
2020/08/16 05:24:23 DEBUG : >WaitForWriters: 
2020/08/16 05:24:23 DEBUG : vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleWriteNoWrite (27.04s)
=== RUN   TestWriteFileHandleMethods
    run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3'", Local "Local file system at /tmp/rclone404921565", Modify Window "1ns"
2020/08/16 05:24:23 INFO  : Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3': poll-interval is not supported by this remote
2020/08/16 05:24:23 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/08/16 05:24:23 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/08/16 05:24:23 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:24:23 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2020/08/16 05:24:23 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2020/08/16 05:24:23 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:24:23 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal
2020/08/16 05:24:23 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal
2020/08/16 05:24:23 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes
2020/08/16 05:24:23 DEBUG : Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3': File to upload is small (5 bytes), uploading instead of streaming
2020/08/16 05:24:23 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>44C410E921DA6D91</RequestId><HostId>nELZKuGUwiWgnOVVPZw9YO+2eabkr9p+nkjtJg69TuMO07zcZHaVwNl6QinwWiabb5Xti9EFNeQ=</HostId></Error>
2020/08/16 05:24:23 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>44C410E921DA6D91</RequestId><HostId>nELZKuGUwiWgnOVVPZw9YO+2eabkr9p+nkjtJg69TuMO07zcZHaVwNl6QinwWiabb5Xti9EFNeQ=</HostId></Error>
    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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>44C410E921DA6D91</RequestId><HostId>nELZKuGUwiWgnOVVPZw9YO+2eabkr9p+nkjtJg69TuMO07zcZHaVwNl6QinwWiabb5Xti9EFNeQ=</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
2020/08/16 05:24:30 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/08/16 05:24:30 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/08/16 05:24:30 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:24:30 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2020/08/16 05:24:30 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2020/08/16 05:24:30 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:24:30 DEBUG : Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3': File to upload is small (0 bytes), uploading instead of streaming
2020/08/16 05:24:30 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>53E14728D677EDB7</RequestId><HostId>ZozIAp+dnh4VuSJZLTpwDOssjdC/N4BLKShtUxqdpRQ+EW3EZa+ZvOq4O3uapL/eWb2Fxg5+ofQ=</HostId></Error>
2020/08/16 05:24:30 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>53E14728D677EDB7</RequestId><HostId>ZozIAp+dnh4VuSJZLTpwDOssjdC/N4BLKShtUxqdpRQ+EW3EZa+ZvOq4O3uapL/eWb2Fxg5+ofQ=</HostId></Error>
    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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>53E14728D677EDB7</RequestId><HostId>ZozIAp+dnh4VuSJZLTpwDOssjdC/N4BLKShtUxqdpRQ+EW3EZa+ZvOq4O3uapL/eWb2Fxg5+ofQ=</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
2020/08/16 05:24:30 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/08/16 05:24:30 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/08/16 05:24:30 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:24:30 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2020/08/16 05:24:30 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2020/08/16 05:24:30 DEBUG : : Added virtual directory entry vAdd: "file1"
    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
2020/08/16 05:24:30 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:24:30 DEBUG : : Looking for writers
2020/08/16 05:24:30 DEBUG : file1: reading active writers
2020/08/16 05:24:30 DEBUG : file1: active writers 1
2020/08/16 05:24:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms
2020/08/16 05:24:30 DEBUG : : Looking for writers
2020/08/16 05:24:30 DEBUG : file1: reading active writers
2020/08/16 05:24:30 DEBUG : file1: active writers 1
2020/08/16 05:24:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms
2020/08/16 05:24:30 DEBUG : : Looking for writers
2020/08/16 05:24:30 DEBUG : file1: reading active writers
2020/08/16 05:24:30 DEBUG : file1: active writers 1
2020/08/16 05:24:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms
2020/08/16 05:24:30 DEBUG : : Looking for writers
2020/08/16 05:24:30 DEBUG : file1: reading active writers
2020/08/16 05:24:30 DEBUG : file1: active writers 1
2020/08/16 05:24:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms
2020/08/16 05:24:30 DEBUG : : Looking for writers
2020/08/16 05:24:30 DEBUG : file1: reading active writers
2020/08/16 05:24:30 DEBUG : file1: active writers 1
2020/08/16 05:24:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms
2020/08/16 05:24:30 DEBUG : : Looking for writers
2020/08/16 05:24:30 DEBUG : file1: reading active writers
2020/08/16 05:24:30 DEBUG : file1: active writers 1
2020/08/16 05:24:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms
2020/08/16 05:24:30 DEBUG : : Looking for writers
2020/08/16 05:24:30 DEBUG : file1: reading active writers
2020/08/16 05:24:30 DEBUG : file1: active writers 1
2020/08/16 05:24:30 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms
2020/08/16 05:24:31 DEBUG : : Looking for writers
2020/08/16 05:24:31 DEBUG : file1: reading active writers
2020/08/16 05:24:31 DEBUG : file1: active writers 1
2020/08/16 05:24:31 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:24:32 DEBUG : : Looking for writers
2020/08/16 05:24:32 DEBUG : file1: reading active writers
2020/08/16 05:24:32 DEBUG : file1: active writers 1
2020/08/16 05:24:32 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:24:33 DEBUG : : Looking for writers
2020/08/16 05:24:33 DEBUG : file1: reading active writers
2020/08/16 05:24:33 DEBUG : file1: active writers 1
2020/08/16 05:24:33 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:24:34 DEBUG : : Looking for writers
2020/08/16 05:24:34 DEBUG : file1: reading active writers
2020/08/16 05:24:34 DEBUG : file1: active writers 1
2020/08/16 05:24:34 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:24:35 DEBUG : : Looking for writers
2020/08/16 05:24:35 DEBUG : file1: reading active writers
2020/08/16 05:24:35 DEBUG : file1: active writers 1
2020/08/16 05:24:35 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:24:36 DEBUG : : Looking for writers
2020/08/16 05:24:36 DEBUG : file1: reading active writers
2020/08/16 05:24:36 DEBUG : file1: active writers 1
2020/08/16 05:24:36 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:24:37 DEBUG : : Looking for writers
2020/08/16 05:24:37 DEBUG : file1: reading active writers
2020/08/16 05:24:37 DEBUG : file1: active writers 1
2020/08/16 05:24:37 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:24:38 DEBUG : : Looking for writers
2020/08/16 05:24:38 DEBUG : file1: reading active writers
2020/08/16 05:24:38 DEBUG : file1: active writers 1
2020/08/16 05:24:38 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:24:39 DEBUG : : Looking for writers
2020/08/16 05:24:39 DEBUG : file1: reading active writers
2020/08/16 05:24:39 DEBUG : file1: active writers 1
2020/08/16 05:24:39 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:24:40 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s
Cache: <nil>
2020/08/16 05:24:40 DEBUG : >WaitForWriters: 
--- FAIL: TestWriteFileHandleMethods (17.16s)
=== RUN   TestWriteFileHandleWriteAt
    run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3'", Local "Local file system at /tmp/rclone404921565", Modify Window "1ns"
2020/08/16 05:24:40 INFO  : Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3': poll-interval is not supported by this remote
2020/08/16 05:24:40 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/08/16 05:24:40 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/08/16 05:24:40 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:24:40 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2020/08/16 05:24:40 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2020/08/16 05:24:40 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:24:40 DEBUG : file1: waiting for in-sequence write to 100 for 1s
2020/08/16 05:24:41 DEBUG : file1: aborting in-sequence write wait, off=100
2020/08/16 05:24:41 DEBUG : file1: failed to wait for in-sequence write to 100
2020/08/16 05:24:41 ERROR : file1: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes
2020/08/16 05:24:41 DEBUG : Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3': File to upload is small (11 bytes), uploading instead of streaming
2020/08/16 05:24: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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>F924FD75DE27170A</RequestId><HostId>IzutgTBKx9YpTo3LkjP+UPRCyV0z5xIVVCmlBwZrDW4cFir/0OCIU/p6FOx6DN5MrcvsROXMgmU=</HostId></Error>
2020/08/16 05:24:41 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>F924FD75DE27170A</RequestId><HostId>IzutgTBKx9YpTo3LkjP+UPRCyV0z5xIVVCmlBwZrDW4cFir/0OCIU/p6FOx6DN5MrcvsROXMgmU=</HostId></Error>
    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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>F924FD75DE27170A</RequestId><HostId>IzutgTBKx9YpTo3LkjP+UPRCyV0z5xIVVCmlBwZrDW4cFir/0OCIU/p6FOx6DN5MrcvsROXMgmU=</HostId></Error>
        	Test:       	TestWriteFileHandleWriteAt
2020/08/16 05:24:41 ERROR : file1: WriteFileHandle.Write: error: Bad file descriptor
    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
2020/08/16 05:24:48 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:24:48 DEBUG : : Looking for writers
2020/08/16 05:24:48 DEBUG : file1: reading active writers
2020/08/16 05:24:48 DEBUG : >WaitForWriters: 
--- FAIL: TestWriteFileHandleWriteAt (8.08s)
=== RUN   TestWriteFileHandleFlush
    run.go:176: Remote "Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3'", Local "Local file system at /tmp/rclone404921565", Modify Window "1ns"
2020/08/16 05:24:48 INFO  : Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3': poll-interval is not supported by this remote
2020/08/16 05:24:48 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/08/16 05:24:48 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/08/16 05:24:48 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:24:48 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2020/08/16 05:24:48 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2020/08/16 05:24:48 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions
2020/08/16 05:24:48 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:24:48 DEBUG : Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3': File to upload is small (5 bytes), uploading instead of streaming
2020/08/16 05:24: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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>1CDA5CB09AF49120</RequestId><HostId>KKYQA4PV4XM138RC1wwiBtS8yFx7GfBfpMc+r8AgSL8AXhrYB6uOu+g8h4UWfZMf5dx6r09tdEs=</HostId></Error>
2020/08/16 05:24:48 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>1CDA5CB09AF49120</RequestId><HostId>KKYQA4PV4XM138RC1wwiBtS8yFx7GfBfpMc+r8AgSL8AXhrYB6uOu+g8h4UWfZMf5dx6r09tdEs=</HostId></Error>
2020/08/16 05:24:48 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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>1CDA5CB09AF49120</RequestId><HostId>KKYQA4PV4XM138RC1wwiBtS8yFx7GfBfpMc+r8AgSL8AXhrYB6uOu+g8h4UWfZMf5dx6r09tdEs=</HostId></Error>
    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-zenomoj8ralenuh1qozubos3</BucketName><RequestId>1CDA5CB09AF49120</RequestId><HostId>KKYQA4PV4XM138RC1wwiBtS8yFx7GfBfpMc+r8AgSL8AXhrYB6uOu+g8h4UWfZMf5dx6r09tdEs=</HostId></Error>
        	Test:       	TestWriteFileHandleFlush
2020/08/16 05:24:48 DEBUG : file1: WriteFileHandle.Flush nothing to do
2020/08/16 05:24:48 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:24:48 DEBUG : : Looking for writers
2020/08/16 05:24:48 DEBUG : file1: reading active writers
2020/08/16 05:24:48 DEBUG : >WaitForWriters: 
--- FAIL: TestWriteFileHandleFlush (0.06s)
FAIL
2020/08/16 05:24:48 DEBUG : Chunked 'TestChunkerChunk50bSHA1HashS3:rclone-test-zenomoj8ralenuh1qozubos3': Purge dir ""
2020/08/16 05:24:48 purge failed to rmdir "": NoSuchBucket: The specified bucket does not exist
	status code: 404, request id: 986EE3195F8E92B9, host id: N6h+dSFPqjLakMWdTS2IniGT5hXY3Ebm4s5DTV6KosGBONl1LROQAddnSDJvHnGhZ+tSBaQu92A=
2020/08/16 05:24:48 purge failed: directory not found
"./vfs.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bSHA1HashS3: -verbose -size-limit 1024 -test.run '^(TestRWFileHandleMethodsWrite|TestRWFileHandleWriteAt|TestRWFileHandleWriteNoWrite|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleWriteAt)$'" - Finished ERROR in 1m46.77148411s (try 5/5): exit status 1: Failed [TestRWFileHandleMethodsWrite TestRWFileHandleWriteAt TestRWFileHandleWriteNoWrite TestWriteFileHandleMethods TestWriteFileHandleWriteAt TestWriteFileHandleFlush]