"./vfs.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bMD5HashS3: -verbose -size-limit 1024 -test.run '^(TestRWFileHandleMethodsWrite|TestRWFileHandleWriteAt|TestRWFileHandleWriteNoWrite|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleWriteAt)$'" - Starting (try 2/5)
=== RUN   TestRWFileHandleMethodsWrite
    run.go:176: Remote "Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4'", Local "Local file system at /tmp/rclone998968602", Modify Window "1ns"
2020/08/16 05:02:28 INFO  : Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4': poll-interval is not supported by this remote
2020/08/16 05:02:28 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bMD5HashS3/rclone-test-vimehes1berexen5kokicis4"
2020/08/16 05:02:28 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bMD5HashS3/rclone-test-vimehes1berexen5kokicis4"
2020/08/16 05:02:28 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/08/16 05:02: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:02:28 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/08/16 05:02:28 DEBUG : file1: newRWFileHandle: 
2020/08/16 05:02:28 DEBUG : file1(0xc0001ed540): openPending: 
2020/08/16 05:02:28 DEBUG : file1: vfs cache: truncate to size=0
2020/08/16 05:02:28 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:02:28 DEBUG : file1(0xc0001ed540): >openPending: err=<nil>
2020/08/16 05:02:28 DEBUG : file1: >newRWFileHandle: err=<nil>
2020/08/16 05:02:28 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:02:28 DEBUG : file1: >Open: fd=file1 (rw), err=<nil>
2020/08/16 05:02:28 DEBUG : file1: >OpenFile: fd=file1 (rw), err=<nil>
2020/08/16 05:02:28 DEBUG : file1(0xc0001ed540): _writeAt: size=5, off=0
2020/08/16 05:02:28 DEBUG : file1(0xc0001ed540): >_writeAt: n=5, err=<nil>
2020/08/16 05:02:28 DEBUG : file1(0xc0001ed540): _writeAt: size=7, off=5
2020/08/16 05:02:28 DEBUG : file1(0xc0001ed540): >_writeAt: n=7, err=<nil>
2020/08/16 05:02:28 DEBUG : file1: vfs cache: truncate to size=11
2020/08/16 05:02:28 DEBUG : file1(0xc0001ed540): close: 
2020/08/16 05:02:28 DEBUG : file1: vfs cache: setting modification time to 2020-08-16 05:02:28.718913126 +0000 UTC m=+0.193203696
2020/08/16 05:02:28 INFO  : file1: vfs cache: queuing for upload in 100ms
2020/08/16 05:02:28 DEBUG : file1(0xc0001ed540): >close: err=<nil>
2020/08/16 05:02:28 DEBUG : file1(0xc0001ed540): close: 
2020/08/16 05:02:28 DEBUG : file1(0xc0001ed540): >close: err=file already closed
2020/08/16 05:02:28 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:02:28 DEBUG : : Looking for writers
2020/08/16 05:02:28 DEBUG : file1: reading active writers
2020/08/16 05:02:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2020/08/16 05:02:28 DEBUG : : Looking for writers
2020/08/16 05:02:28 DEBUG : file1: reading active writers
2020/08/16 05:02:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2020/08/16 05:02:28 DEBUG : : Looking for writers
2020/08/16 05:02:28 DEBUG : file1: reading active writers
2020/08/16 05:02:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2020/08/16 05:02:28 DEBUG : : Looking for writers
2020/08/16 05:02:28 DEBUG : file1: reading active writers
2020/08/16 05:02:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2020/08/16 05:02:28 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:02:28 DEBUG : : Looking for writers
2020/08/16 05:02:28 DEBUG : file1: reading active writers
2020/08/16 05:02:28 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2020/08/16 05:02:28 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-vimehes1berexen5kokicis4</BucketName><RequestId>E0098E106A3E8D19</RequestId><HostId>4Z0no3iMbLJW0YeQO/L0KYjUagBc1q0T6E5bXyYoESYRaW8KUs2RUIH2KQ1Lhegb/nits5e5Xjk=</HostId></Error>
2020/08/16 05:02:28 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-vimehes1berexen5kokicis4</BucketName><RequestId>E0098E106A3E8D19</RequestId><HostId>4Z0no3iMbLJW0YeQO/L0KYjUagBc1q0T6E5bXyYoESYRaW8KUs2RUIH2KQ1Lhegb/nits5e5Xjk=</HostId></Error>
2020/08/16 05:02:29 DEBUG : : Looking for writers
2020/08/16 05:02:29 DEBUG : file1: reading active writers
2020/08/16 05:02:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2020/08/16 05:02:29 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>859357DDD0956C55</RequestId><HostId>mfaCU6rXnCOoXlJx/BRPM7WboZFsLStCNCzR9ukvhIw8TQEfCwVJf1rnyE6kW5pSwBOgbcAPUno=</HostId></Error>
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>859357DDD0956C55</RequestId><HostId>mfaCU6rXnCOoXlJx/BRPM7WboZFsLStCNCzR9ukvhIw8TQEfCwVJf1rnyE6kW5pSwBOgbcAPUno=</HostId></Error>
2020/08/16 05:02:29 DEBUG : : Looking for writers
2020/08/16 05:02:29 DEBUG : file1: reading active writers
2020/08/16 05:02:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2020/08/16 05:02:29 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>0AFE9CCB8E568F37</RequestId><HostId>8JB4ms9eg9Fza4H9ftB9SCyL7km6cPSZe++CIMu3WlP3EPAVivksHJ9Znu0R2YSSG3xXk0aLieo=</HostId></Error>
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>0AFE9CCB8E568F37</RequestId><HostId>8JB4ms9eg9Fza4H9ftB9SCyL7km6cPSZe++CIMu3WlP3EPAVivksHJ9Znu0R2YSSG3xXk0aLieo=</HostId></Error>
2020/08/16 05:02:29 DEBUG : : Looking for writers
2020/08/16 05:02:29 DEBUG : file1: reading active writers
2020/08/16 05:02:29 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:30 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>9F1208B2CD647483</RequestId><HostId>6CvCI05pDv+mlcxGtoc2esVcrAyF/hj8iyTA737Whr5HjIo/YM6hI4ZVHyRsz6yl95Lqu2hMWqg=</HostId></Error>
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>9F1208B2CD647483</RequestId><HostId>6CvCI05pDv+mlcxGtoc2esVcrAyF/hj8iyTA737Whr5HjIo/YM6hI4ZVHyRsz6yl95Lqu2hMWqg=</HostId></Error>
2020/08/16 05:02:30 DEBUG : : Looking for writers
2020/08/16 05:02:30 DEBUG : file1: reading active writers
2020/08/16 05:02:30 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:31 DEBUG : : Looking for writers
2020/08/16 05:02:31 DEBUG : file1: reading active writers
2020/08/16 05:02:31 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:32 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>BFFF8A1E97EEB695</RequestId><HostId>HnT1GNu3/oG1UEeWFucN+FwsRzm++sPGhFwVJFuJJ+z+LxoWU/gqf8hdtxt/o7tPxyHqTbE+68Y=</HostId></Error>
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>BFFF8A1E97EEB695</RequestId><HostId>HnT1GNu3/oG1UEeWFucN+FwsRzm++sPGhFwVJFuJJ+z+LxoWU/gqf8hdtxt/o7tPxyHqTbE+68Y=</HostId></Error>
2020/08/16 05:02:32 DEBUG : : Looking for writers
2020/08/16 05:02:32 DEBUG : file1: reading active writers
2020/08/16 05:02:32 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:33 DEBUG : : Looking for writers
2020/08/16 05:02:33 DEBUG : file1: reading active writers
2020/08/16 05:02:33 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:34 DEBUG : : Looking for writers
2020/08/16 05:02:34 DEBUG : file1: reading active writers
2020/08/16 05:02:34 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:35 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>AR2N1KDR4Z7VFP5R</RequestId><HostId>68bRTtLI2Lm3czQ9GfEXxT+e4RVwwdglXXhx8MgAVJpzKIt/PVbVXe4TDVl6EmIMC3Je4f7z/eU=</HostId></Error>
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>AR2N1KDR4Z7VFP5R</RequestId><HostId>68bRTtLI2Lm3czQ9GfEXxT+e4RVwwdglXXhx8MgAVJpzKIt/PVbVXe4TDVl6EmIMC3Je4f7z/eU=</HostId></Error>
2020/08/16 05:02:35 DEBUG : : Looking for writers
2020/08/16 05:02:35 DEBUG : file1: reading active writers
2020/08/16 05:02:35 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:36 DEBUG : : Looking for writers
2020/08/16 05:02:36 DEBUG : file1: reading active writers
2020/08/16 05:02:36 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:37 DEBUG : : Looking for writers
2020/08/16 05:02:37 DEBUG : file1: reading active writers
2020/08/16 05:02:37 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:38 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s
Cache{
	"file1": &{c:0xc0000266c0 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13818817551999286886 ext:193203696 loc:0x25a1860} ATime:{wall:13818817551999304172 ext:193220948 loc:0x25a1860} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1},
}
2020/08/16 05:02: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:02:41 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>BECD2D44CD189824</RequestId><HostId>wY3zyqX9+P2aa2NmxgNPBPejDPg972Somhsoe6pw1u9ikRhaaMFCr/ROXC0TOSCJO0Cn955vLkc=</HostId></Error>
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>BECD2D44CD189824</RequestId><HostId>wY3zyqX9+P2aa2NmxgNPBPejDPg972Somhsoe6pw1u9ikRhaaMFCr/ROXC0TOSCJO0Cn955vLkc=</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: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:02:45 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:02:45 DEBUG : : Looking for writers
2020/08/16 05:02:45 DEBUG : file1: reading active writers
2020/08/16 05:02:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2020/08/16 05:02:45 DEBUG : : Looking for writers
2020/08/16 05:02:45 DEBUG : file1: reading active writers
2020/08/16 05:02:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2020/08/16 05:02:45 DEBUG : : Looking for writers
2020/08/16 05:02:45 DEBUG : file1: reading active writers
2020/08/16 05:02:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2020/08/16 05:02:45 DEBUG : : Looking for writers
2020/08/16 05:02:45 DEBUG : file1: reading active writers
2020/08/16 05:02:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2020/08/16 05:02:45 DEBUG : : Looking for writers
2020/08/16 05:02:45 DEBUG : file1: reading active writers
2020/08/16 05:02:45 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2020/08/16 05:02:46 DEBUG : : Looking for writers
2020/08/16 05:02:46 DEBUG : file1: reading active writers
2020/08/16 05:02:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2020/08/16 05:02:46 DEBUG : : Looking for writers
2020/08/16 05:02:46 DEBUG : file1: reading active writers
2020/08/16 05:02:46 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2020/08/16 05:02:47 DEBUG : : Looking for writers
2020/08/16 05:02:47 DEBUG : file1: reading active writers
2020/08/16 05:02:47 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:48 DEBUG : : Looking for writers
2020/08/16 05:02:48 DEBUG : file1: reading active writers
2020/08/16 05:02:48 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:49 DEBUG : : Looking for writers
2020/08/16 05:02:49 DEBUG : file1: reading active writers
2020/08/16 05:02:49 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:50 DEBUG : : Looking for writers
2020/08/16 05:02:50 DEBUG : file1: reading active writers
2020/08/16 05:02:50 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:51 DEBUG : : Looking for writers
2020/08/16 05:02:51 DEBUG : file1: reading active writers
2020/08/16 05:02:51 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:52 DEBUG : : Looking for writers
2020/08/16 05:02:52 DEBUG : file1: reading active writers
2020/08/16 05:02:52 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:53 DEBUG : : Looking for writers
2020/08/16 05:02:53 DEBUG : file1: reading active writers
2020/08/16 05:02:53 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:54 DEBUG : : Looking for writers
2020/08/16 05:02:54 DEBUG : file1: reading active writers
2020/08/16 05:02:54 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:54 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>439A7AF8047C97B7</RequestId><HostId>XELWLfutfcQCY7I/XU2erhGHmp6ZeECZVkOFCZTBVgHM6wHgH0dgowqUMXao0zsh4w79eZWPp5Y=</HostId></Error>
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>439A7AF8047C97B7</RequestId><HostId>XELWLfutfcQCY7I/XU2erhGHmp6ZeECZVkOFCZTBVgHM6wHgH0dgowqUMXao0zsh4w79eZWPp5Y=</HostId></Error>
2020/08/16 05:02:55 DEBUG : : Looking for writers
2020/08/16 05:02:55 DEBUG : file1: reading active writers
2020/08/16 05:02:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:55 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s
Cache{
	"file1": &{c:0xc0000266c0 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13818817551999286886 ext:193203696 loc:0x25a1860} ATime:{wall:13818817551999304172 ext:193220948 loc:0x25a1860} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1},
}
2020/08/16 05:02:55 DEBUG : >WaitForWriters: 
2020/08/16 05:02:55 DEBUG : vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleMethodsWrite (27.27s)
=== RUN   TestRWFileHandleWriteAt
    run.go:176: Remote "Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4'", Local "Local file system at /tmp/rclone998968602", Modify Window "1ns"
2020/08/16 05:02:55 INFO  : Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4': poll-interval is not supported by this remote
2020/08/16 05:02:55 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bMD5HashS3/rclone-test-vimehes1berexen5kokicis4"
2020/08/16 05:02:55 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bMD5HashS3/rclone-test-vimehes1berexen5kokicis4"
2020/08/16 05:02:55 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/08/16 05:02:55 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:02:55 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/08/16 05:02:55 DEBUG : file1: newRWFileHandle: 
2020/08/16 05:02:55 DEBUG : file1(0xc0003c8800): openPending: 
2020/08/16 05:02:55 DEBUG : file1: vfs cache: truncate to size=0
2020/08/16 05:02:55 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:02:55 DEBUG : file1(0xc0003c8800): >openPending: err=<nil>
2020/08/16 05:02:55 DEBUG : file1: >newRWFileHandle: err=<nil>
2020/08/16 05:02:55 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:02:55 DEBUG : file1: >Open: fd=file1 (rw), err=<nil>
2020/08/16 05:02:55 DEBUG : file1: >OpenFile: fd=file1 (rw), err=<nil>
2020/08/16 05:02:55 DEBUG : file1(0xc0003c8800): _writeAt: size=7, off=0
2020/08/16 05:02:55 DEBUG : file1(0xc0003c8800): >_writeAt: n=7, err=<nil>
2020/08/16 05:02:55 DEBUG : file1(0xc0003c8800): _writeAt: size=6, off=5
2020/08/16 05:02:55 DEBUG : file1(0xc0003c8800): >_writeAt: n=6, err=<nil>
2020/08/16 05:02:55 DEBUG : file1(0xc0003c8800): close: 
2020/08/16 05:02:55 DEBUG : file1: vfs cache: setting modification time to 2020-08-16 05:02:55.83467642 +0000 UTC m=+27.308966942
2020/08/16 05:02:55 INFO  : file1: vfs cache: queuing for upload in 100ms
2020/08/16 05:02:55 DEBUG : file1(0xc0003c8800): >close: err=<nil>
2020/08/16 05:02:55 DEBUG : file1(0xc0003c8800): _writeAt: size=5, off=0
2020/08/16 05:02:55 DEBUG : file1(0xc0003c8800): >_writeAt: n=0, err=file already closed
2020/08/16 05:02:55 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:02:55 DEBUG : : Looking for writers
2020/08/16 05:02:55 DEBUG : file1: reading active writers
2020/08/16 05:02:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2020/08/16 05:02:55 DEBUG : : Looking for writers
2020/08/16 05:02:55 DEBUG : file1: reading active writers
2020/08/16 05:02:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2020/08/16 05:02:55 DEBUG : : Looking for writers
2020/08/16 05:02:55 DEBUG : file1: reading active writers
2020/08/16 05:02:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2020/08/16 05:02:55 DEBUG : : Looking for writers
2020/08/16 05:02:55 DEBUG : file1: reading active writers
2020/08/16 05:02:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2020/08/16 05:02:55 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:02:55 DEBUG : : Looking for writers
2020/08/16 05:02:55 DEBUG : file1: reading active writers
2020/08/16 05:02:55 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2020/08/16 05:02:55 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-vimehes1berexen5kokicis4</BucketName><RequestId>B25DF36AF9B71E14</RequestId><HostId>nJB3CUA962o4U+CisYzRIbpuZuD0lFWYvwB+UZV7ezUh3Ue3BNiOTiut/cXrJfwVsD/glXTfVQo=</HostId></Error>
2020/08/16 05:02:55 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-vimehes1berexen5kokicis4</BucketName><RequestId>B25DF36AF9B71E14</RequestId><HostId>nJB3CUA962o4U+CisYzRIbpuZuD0lFWYvwB+UZV7ezUh3Ue3BNiOTiut/cXrJfwVsD/glXTfVQo=</HostId></Error>
2020/08/16 05:02:56 DEBUG : : Looking for writers
2020/08/16 05:02:56 DEBUG : file1: reading active writers
2020/08/16 05:02:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2020/08/16 05:02:56 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>A06404913755B764</RequestId><HostId>pemjXGHWYGSUgPLzAdxImth+kTC0TwM/4tvpbZFuZUxVnBIr0iRkbggjCupREpgF9seHYVliO7o=</HostId></Error>
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>A06404913755B764</RequestId><HostId>pemjXGHWYGSUgPLzAdxImth+kTC0TwM/4tvpbZFuZUxVnBIr0iRkbggjCupREpgF9seHYVliO7o=</HostId></Error>
2020/08/16 05:02:56 DEBUG : : Looking for writers
2020/08/16 05:02:56 DEBUG : file1: reading active writers
2020/08/16 05:02:56 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2020/08/16 05:02:56 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>D7728E62C575AC1F</RequestId><HostId>PLPXH3zchcZWS/jq4BfGYsDF4/cGyANYraAv1+R1jjlNtJohlScgUdjVoEH1cAYSAG/kikxIgPI=</HostId></Error>
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>D7728E62C575AC1F</RequestId><HostId>PLPXH3zchcZWS/jq4BfGYsDF4/cGyANYraAv1+R1jjlNtJohlScgUdjVoEH1cAYSAG/kikxIgPI=</HostId></Error>
2020/08/16 05:02:57 DEBUG : : Looking for writers
2020/08/16 05:02:57 DEBUG : file1: reading active writers
2020/08/16 05:02:57 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:57 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>D0697B9127481976</RequestId><HostId>jHfZXeDRxskBevX+V/91cOPETwkTgue2ptao1HnqHWVYJpMVrpddvXgrRa1BUBW6pLzE/r6VMS8=</HostId></Error>
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>D0697B9127481976</RequestId><HostId>jHfZXeDRxskBevX+V/91cOPETwkTgue2ptao1HnqHWVYJpMVrpddvXgrRa1BUBW6pLzE/r6VMS8=</HostId></Error>
2020/08/16 05:02:58 DEBUG : : Looking for writers
2020/08/16 05:02:58 DEBUG : file1: reading active writers
2020/08/16 05:02:58 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:59 DEBUG : : Looking for writers
2020/08/16 05:02:59 DEBUG : file1: reading active writers
2020/08/16 05:02:59 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:02:59 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>98170473CA067079</RequestId><HostId>YTQvQbwC50LhnEQOq4cS17x8iWfVFSZHniPVxONjo0FkeGIfAJGwg9tkgN6zfd4hOCVn31ck3+M=</HostId></Error>
2020/08/16 05:02: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-vimehes1berexen5kokicis4</BucketName><RequestId>98170473CA067079</RequestId><HostId>YTQvQbwC50LhnEQOq4cS17x8iWfVFSZHniPVxONjo0FkeGIfAJGwg9tkgN6zfd4hOCVn31ck3+M=</HostId></Error>
2020/08/16 05:03:00 DEBUG : : Looking for writers
2020/08/16 05:03:00 DEBUG : file1: reading active writers
2020/08/16 05:03:00 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:03:01 DEBUG : : Looking for writers
2020/08/16 05:03:01 DEBUG : file1: reading active writers
2020/08/16 05:03:01 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:03:02 DEBUG : : Looking for writers
2020/08/16 05:03:02 DEBUG : file1: reading active writers
2020/08/16 05:03:02 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:03:02 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:03: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-vimehes1berexen5kokicis4</BucketName><RequestId>9C309C8E97A9098B</RequestId><HostId>axvTbAl0H/jPpeGALeFwx3kG0jzpSH5a+VkkXVEaFBp1rF6AC7WPHVWAspnMSouz0jt3x1t7PZA=</HostId></Error>
2020/08/16 05:03: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-vimehes1berexen5kokicis4</BucketName><RequestId>9C309C8E97A9098B</RequestId><HostId>axvTbAl0H/jPpeGALeFwx3kG0jzpSH5a+VkkXVEaFBp1rF6AC7WPHVWAspnMSouz0jt3x1t7PZA=</HostId></Error>
2020/08/16 05:03:03 DEBUG : : Looking for writers
2020/08/16 05:03:03 DEBUG : file1: reading active writers
2020/08/16 05:03:03 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:03:04 DEBUG : : Looking for writers
2020/08/16 05:03:04 DEBUG : file1: reading active writers
2020/08/16 05:03:04 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:03:05 DEBUG : : Looking for writers
2020/08/16 05:03:05 DEBUG : file1: reading active writers
2020/08/16 05:03:05 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:03:05 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s
Cache{
	"file1": &{c:0xc00075a2d0 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13818817581106079428 ext:27308966942 loc:0x25a1860} ATime:{wall:13818817581106096091 ext:27308983619 loc:0x25a1860} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1},
}
2020/08/16 05:03:05 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:03:08 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:03: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-vimehes1berexen5kokicis4</BucketName><RequestId>5179E56623F88378</RequestId><HostId>CAGcd8O7IXqS7JRNFx0/gHehDvL1+4HXq5ku4TL3cTP59Pc25WWTk4Boodg2tOBOq5bhOMCIVZw=</HostId></Error>
2020/08/16 05:03: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-vimehes1berexen5kokicis4</BucketName><RequestId>5179E56623F88378</RequestId><HostId>CAGcd8O7IXqS7JRNFx0/gHehDvL1+4HXq5ku4TL3cTP59Pc25WWTk4Boodg2tOBOq5bhOMCIVZw=</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:03:12 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:03:12 DEBUG : : Looking for writers
2020/08/16 05:03:12 DEBUG : file1: reading active writers
2020/08/16 05:03:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 10ms
2020/08/16 05:03:12 DEBUG : : Looking for writers
2020/08/16 05:03:12 DEBUG : file1: reading active writers
2020/08/16 05:03:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 20ms
2020/08/16 05:03:12 DEBUG : : Looking for writers
2020/08/16 05:03:12 DEBUG : file1: reading active writers
2020/08/16 05:03:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 40ms
2020/08/16 05:03:12 DEBUG : : Looking for writers
2020/08/16 05:03:12 DEBUG : file1: reading active writers
2020/08/16 05:03:12 DEBUG : Still 0 writers active and 1 cache items in use, waiting 80ms
2020/08/16 05:03:13 DEBUG : : Looking for writers
2020/08/16 05:03:13 DEBUG : file1: reading active writers
2020/08/16 05:03:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 160ms
2020/08/16 05:03:13 DEBUG : : Looking for writers
2020/08/16 05:03:13 DEBUG : file1: reading active writers
2020/08/16 05:03:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 320ms
2020/08/16 05:03:13 DEBUG : : Looking for writers
2020/08/16 05:03:13 DEBUG : file1: reading active writers
2020/08/16 05:03:13 DEBUG : Still 0 writers active and 1 cache items in use, waiting 640ms
2020/08/16 05:03:14 DEBUG : : Looking for writers
2020/08/16 05:03:14 DEBUG : file1: reading active writers
2020/08/16 05:03:14 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:03:15 DEBUG : : Looking for writers
2020/08/16 05:03:15 DEBUG : file1: reading active writers
2020/08/16 05:03:15 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:03:16 DEBUG : : Looking for writers
2020/08/16 05:03:16 DEBUG : file1: reading active writers
2020/08/16 05:03:16 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:03:17 DEBUG : : Looking for writers
2020/08/16 05:03:17 DEBUG : file1: reading active writers
2020/08/16 05:03:17 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:03:18 DEBUG : : Looking for writers
2020/08/16 05:03:18 DEBUG : file1: reading active writers
2020/08/16 05:03:18 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:03:19 DEBUG : : Looking for writers
2020/08/16 05:03:19 DEBUG : file1: reading active writers
2020/08/16 05:03:19 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:03:20 DEBUG : : Looking for writers
2020/08/16 05:03:20 DEBUG : file1: reading active writers
2020/08/16 05:03:20 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:03:21 DEBUG : : Looking for writers
2020/08/16 05:03:21 DEBUG : file1: reading active writers
2020/08/16 05:03:21 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:03:21 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:03: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-vimehes1berexen5kokicis4</BucketName><RequestId>6A1E58588024E649</RequestId><HostId>mAGq2PhUthIRK3ljH87BJyRb3VtQiFQtW8rsZKKbRNUONGtcrPAmka62otamhcCzcQWlUjKa+/o=</HostId></Error>
2020/08/16 05:03: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-vimehes1berexen5kokicis4</BucketName><RequestId>6A1E58588024E649</RequestId><HostId>mAGq2PhUthIRK3ljH87BJyRb3VtQiFQtW8rsZKKbRNUONGtcrPAmka62otamhcCzcQWlUjKa+/o=</HostId></Error>
2020/08/16 05:03:22 DEBUG : : Looking for writers
2020/08/16 05:03:22 DEBUG : file1: reading active writers
2020/08/16 05:03:22 DEBUG : Still 0 writers active and 1 cache items in use, waiting 1s
2020/08/16 05:03:22 ERROR : Exiting even though 0 writers active and 1 cache items in use after 10s
Cache{
	"file1": &{c:0xc00075a2d0 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13818817581106079428 ext:27308966942 loc:0x25a1860} ATime:{wall:13818817581106096091 ext:27308983619 loc:0x25a1860} Size:11 Rs:[{Pos:0 Size:11}] Fingerprint: Dirty:true} writeBackID:1},
}
2020/08/16 05:03:22 DEBUG : >WaitForWriters: 
2020/08/16 05:03:22 DEBUG : vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleWriteAt (27.14s)
=== RUN   TestRWFileHandleWriteNoWrite
    run.go:176: Remote "Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4'", Local "Local file system at /tmp/rclone998968602", Modify Window "1ns"
2020/08/16 05:03:22 INFO  : Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4': poll-interval is not supported by this remote
2020/08/16 05:03:22 DEBUG : vfs cache: root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bMD5HashS3/rclone-test-vimehes1berexen5kokicis4"
2020/08/16 05:03:22 DEBUG : vfs cache: metadata root is "/home/rclone/.cache/rclone/vfs/TestChunkerChunk50bMD5HashS3/rclone-test-vimehes1berexen5kokicis4"
2020/08/16 05:03:22 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/08/16 05:03:22 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:03:22 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/08/16 05:03:22 DEBUG : file1: newRWFileHandle: 
2020/08/16 05:03:22 DEBUG : file1(0xc0005a4f40): openPending: 
2020/08/16 05:03:22 DEBUG : file1: vfs cache: truncate to size=0
2020/08/16 05:03:22 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:03:22 DEBUG : file1(0xc0005a4f40): >openPending: err=<nil>
2020/08/16 05:03:22 DEBUG : file1: >newRWFileHandle: err=<nil>
2020/08/16 05:03:22 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:03:22 DEBUG : file1: >Open: fd=file1 (rw), err=<nil>
2020/08/16 05:03:22 DEBUG : file1: >OpenFile: fd=file1 (rw), err=<nil>
2020/08/16 05:03:22 DEBUG : file1(0xc0005a4f40): close: 
2020/08/16 05:03:22 DEBUG : file1: vfs cache: setting modification time to 2020-08-16 05:03:22.976028718 +0000 UTC m=+54.450319261
2020/08/16 05:03:22 INFO  : file1: vfs cache: queuing for upload in 100ms
2020/08/16 05:03:22 DEBUG : file1(0xc0005a4f40): >close: err=<nil>
2020/08/16 05:03:22 DEBUG : file2: OpenFile: flags=O_WRONLY|O_CREATE|O_TRUNC, perm=-rwxrwxrwx
2020/08/16 05:03:22 DEBUG : file2: Open: flags=O_WRONLY|O_CREATE|O_TRUNC
2020/08/16 05:03:22 DEBUG : file2: newRWFileHandle: 
2020/08/16 05:03:22 DEBUG : file2(0xc0005a5080): openPending: 
2020/08/16 05:03:22 DEBUG : file2: vfs cache: truncate to size=0
2020/08/16 05:03:22 DEBUG : : Added virtual directory entry vAdd: "file2"
2020/08/16 05:03:22 DEBUG : file2(0xc0005a5080): >openPending: err=<nil>
2020/08/16 05:03:22 DEBUG : file2: >newRWFileHandle: err=<nil>
2020/08/16 05:03:22 DEBUG : : Added virtual directory entry vAdd: "file2"
2020/08/16 05:03:22 DEBUG : file2: >Open: fd=file2 (rw), err=<nil>
2020/08/16 05:03:22 DEBUG : file2: >OpenFile: fd=file2 (rw), err=<nil>
2020/08/16 05:03:22 DEBUG : file2(0xc0005a5080): RWFileHandle.Flush
2020/08/16 05:03:22 DEBUG : file2(0xc0005a5080): RWFileHandle.Release
2020/08/16 05:03:22 DEBUG : file2(0xc0005a5080): close: 
2020/08/16 05:03:22 DEBUG : file2: vfs cache: setting modification time to 2020-08-16 05:03:22.977181416 +0000 UTC m=+54.451471952
2020/08/16 05:03:22 INFO  : file2: vfs cache: queuing for upload in 100ms
2020/08/16 05:03:22 DEBUG : file2(0xc0005a5080): >close: err=<nil>
2020/08/16 05:03:22 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:03:22 DEBUG : : Looking for writers
2020/08/16 05:03:22 DEBUG : file1: reading active writers
2020/08/16 05:03:22 DEBUG : file2: reading active writers
2020/08/16 05:03:22 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms
2020/08/16 05:03:22 DEBUG : : Looking for writers
2020/08/16 05:03:22 DEBUG : file1: reading active writers
2020/08/16 05:03:22 DEBUG : file2: reading active writers
2020/08/16 05:03:22 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms
2020/08/16 05:03:23 DEBUG : : Looking for writers
2020/08/16 05:03:23 DEBUG : file1: reading active writers
2020/08/16 05:03:23 DEBUG : file2: reading active writers
2020/08/16 05:03:23 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms
2020/08/16 05:03:23 DEBUG : : Looking for writers
2020/08/16 05:03:23 DEBUG : file1: reading active writers
2020/08/16 05:03:23 DEBUG : file2: reading active writers
2020/08/16 05:03:23 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms
2020/08/16 05:03:23 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:03:23 DEBUG : file2: vfs cache: starting upload
2020/08/16 05:03: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-vimehes1berexen5kokicis4</BucketName><RequestId>24B040B458160D15</RequestId><HostId>LHm1WmxtaOiKJK2RplSp/p6HwxQZWfXyhf0aXzBh7lpzfB56bCdyJ6Eshvr1P1sc8zYqcXh6LWk=</HostId></Error>
2020/08/16 05:03:23 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-vimehes1berexen5kokicis4</BucketName><RequestId>24B040B458160D15</RequestId><HostId>LHm1WmxtaOiKJK2RplSp/p6HwxQZWfXyhf0aXzBh7lpzfB56bCdyJ6Eshvr1P1sc8zYqcXh6LWk=</HostId></Error>
2020/08/16 05:03:23 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-vimehes1berexen5kokicis4</BucketName><RequestId>99C0B2D79FAE8D03</RequestId><HostId>iMWPDgY8408eo7iYVLPjIJ2w3CO5aL41WQH3y0zXYPI20DCsFs9UPIRwTdRvQY83TlR5Q4X1A04=</HostId></Error>
2020/08/16 05:03:23 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-vimehes1berexen5kokicis4</BucketName><RequestId>99C0B2D79FAE8D03</RequestId><HostId>iMWPDgY8408eo7iYVLPjIJ2w3CO5aL41WQH3y0zXYPI20DCsFs9UPIRwTdRvQY83TlR5Q4X1A04=</HostId></Error>
2020/08/16 05:03:23 DEBUG : : Looking for writers
2020/08/16 05:03:23 DEBUG : file2: reading active writers
2020/08/16 05:03:23 DEBUG : file1: reading active writers
2020/08/16 05:03:23 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms
2020/08/16 05:03:23 DEBUG : : Looking for writers
2020/08/16 05:03:23 DEBUG : file1: reading active writers
2020/08/16 05:03:23 DEBUG : file2: reading active writers
2020/08/16 05:03:23 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms
2020/08/16 05:03:23 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:03:23 DEBUG : file2: vfs cache: starting upload
2020/08/16 05:03: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-vimehes1berexen5kokicis4</BucketName><RequestId>B2C8C06125249953</RequestId><HostId>hPRF8T6MsIf5o/xxE38OKuaremO4ARZx8B82+A4bLVdtZETW5HOHaYpZGUDcBixlMKyuzvZqjfw=</HostId></Error>
2020/08/16 05:03:23 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-vimehes1berexen5kokicis4</BucketName><RequestId>B2C8C06125249953</RequestId><HostId>hPRF8T6MsIf5o/xxE38OKuaremO4ARZx8B82+A4bLVdtZETW5HOHaYpZGUDcBixlMKyuzvZqjfw=</HostId></Error>
2020/08/16 05:03:23 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-vimehes1berexen5kokicis4</BucketName><RequestId>4720FB40F0131F1A</RequestId><HostId>n4dHrnynffUUf2NsHdou3g6MbgC3lcOK2aVbP/jNO52in3eeWQeCovy83S/SqKUZrqBVXkFdBIE=</HostId></Error>
2020/08/16 05:03:23 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-vimehes1berexen5kokicis4</BucketName><RequestId>4720FB40F0131F1A</RequestId><HostId>n4dHrnynffUUf2NsHdou3g6MbgC3lcOK2aVbP/jNO52in3eeWQeCovy83S/SqKUZrqBVXkFdBIE=</HostId></Error>
2020/08/16 05:03:23 DEBUG : : Looking for writers
2020/08/16 05:03:23 DEBUG : file2: reading active writers
2020/08/16 05:03:23 DEBUG : file1: reading active writers
2020/08/16 05:03:23 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms
2020/08/16 05:03:23 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:03:23 DEBUG : file2: vfs cache: starting upload
2020/08/16 05:03: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-vimehes1berexen5kokicis4</BucketName><RequestId>9842D32BDE21D02C</RequestId><HostId>ZXjzvizhjGigi8MxsRPvSVm7uB2WvWzJeK3ibLlFfAuEZ8De88tHKh0nkZVlD3xVEztT/azRMKU=</HostId></Error>
2020/08/16 05:03:23 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-vimehes1berexen5kokicis4</BucketName><RequestId>9842D32BDE21D02C</RequestId><HostId>ZXjzvizhjGigi8MxsRPvSVm7uB2WvWzJeK3ibLlFfAuEZ8De88tHKh0nkZVlD3xVEztT/azRMKU=</HostId></Error>
2020/08/16 05:03:23 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-vimehes1berexen5kokicis4</BucketName><RequestId>6DD88D36BE5C94FB</RequestId><HostId>bGYe2vj7Vm1VYuPbNkN5n6rvN5QKNOqlVshFzvO0WBk4kBOBdP9u9fJGsgzU5GTKwXAQYdj44S0=</HostId></Error>
2020/08/16 05:03:23 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-vimehes1berexen5kokicis4</BucketName><RequestId>6DD88D36BE5C94FB</RequestId><HostId>bGYe2vj7Vm1VYuPbNkN5n6rvN5QKNOqlVshFzvO0WBk4kBOBdP9u9fJGsgzU5GTKwXAQYdj44S0=</HostId></Error>
2020/08/16 05:03:24 DEBUG : : Looking for writers
2020/08/16 05:03:24 DEBUG : file1: reading active writers
2020/08/16 05:03:24 DEBUG : file2: reading active writers
2020/08/16 05:03:24 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:24 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:03:24 DEBUG : file2: vfs cache: starting upload
2020/08/16 05:03:24 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-vimehes1berexen5kokicis4</BucketName><RequestId>F21D349EFCE59D49</RequestId><HostId>avfX3Ed/qwFtmMBq1IFvhw7BFumFlyrZL9/+dX4kWZyfV1xt7MtfOiax1i/JaZV1zShXyPfbvmA=</HostId></Error>
2020/08/16 05:03:24 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-vimehes1berexen5kokicis4</BucketName><RequestId>F21D349EFCE59D49</RequestId><HostId>avfX3Ed/qwFtmMBq1IFvhw7BFumFlyrZL9/+dX4kWZyfV1xt7MtfOiax1i/JaZV1zShXyPfbvmA=</HostId></Error>
2020/08/16 05:03:24 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-vimehes1berexen5kokicis4</BucketName><RequestId>C7BC2E43C011CC5D</RequestId><HostId>Dm8M4oUW8AjHhzk5YGXKyhkg7wwl2i+KoUs6oMiKyx1JVsgZEjqVUQoR+DcmFEzHXC624j5ZGkE=</HostId></Error>
2020/08/16 05:03:24 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-vimehes1berexen5kokicis4</BucketName><RequestId>C7BC2E43C011CC5D</RequestId><HostId>Dm8M4oUW8AjHhzk5YGXKyhkg7wwl2i+KoUs6oMiKyx1JVsgZEjqVUQoR+DcmFEzHXC624j5ZGkE=</HostId></Error>
2020/08/16 05:03:25 DEBUG : : Looking for writers
2020/08/16 05:03:25 DEBUG : file1: reading active writers
2020/08/16 05:03:25 DEBUG : file2: reading active writers
2020/08/16 05:03:25 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:26 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:03:26 DEBUG : file2: vfs cache: starting upload
2020/08/16 05:03: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-vimehes1berexen5kokicis4</BucketName><RequestId>5404414C5A52DAE0</RequestId><HostId>3dmE7vrh7atEKLi/LiAJcYDrqIuU4YPhu5wDwclYXxUdAGKs72LBNfosJuBXxqQIb5I9QqT5O7c=</HostId></Error>
2020/08/16 05:03:26 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-vimehes1berexen5kokicis4</BucketName><RequestId>5404414C5A52DAE0</RequestId><HostId>3dmE7vrh7atEKLi/LiAJcYDrqIuU4YPhu5wDwclYXxUdAGKs72LBNfosJuBXxqQIb5I9QqT5O7c=</HostId></Error>
2020/08/16 05:03:26 DEBUG : : Looking for writers
2020/08/16 05:03:26 DEBUG : file1: reading active writers
2020/08/16 05:03:26 DEBUG : file2: reading active writers
2020/08/16 05:03:26 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:26 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-vimehes1berexen5kokicis4</BucketName><RequestId>6EEF3A66754E0066</RequestId><HostId>0xi14cF0htaGwQBf439DDbYsJTCWTpxzNPBRRHDTVW1Tko8XTgB3kstGJkrJcX1Jk6W3THC8ebo=</HostId></Error>
2020/08/16 05:03:26 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-vimehes1berexen5kokicis4</BucketName><RequestId>6EEF3A66754E0066</RequestId><HostId>0xi14cF0htaGwQBf439DDbYsJTCWTpxzNPBRRHDTVW1Tko8XTgB3kstGJkrJcX1Jk6W3THC8ebo=</HostId></Error>
2020/08/16 05:03:27 DEBUG : : Looking for writers
2020/08/16 05:03:27 DEBUG : file1: reading active writers
2020/08/16 05:03:27 DEBUG : file2: reading active writers
2020/08/16 05:03:27 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:28 DEBUG : : Looking for writers
2020/08/16 05:03:28 DEBUG : file1: reading active writers
2020/08/16 05:03:28 DEBUG : file2: reading active writers
2020/08/16 05:03:28 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:29 DEBUG : : Looking for writers
2020/08/16 05:03:29 DEBUG : file1: reading active writers
2020/08/16 05:03:29 DEBUG : file2: reading active writers
2020/08/16 05:03:29 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:29 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:03:29 DEBUG : file2: vfs cache: starting upload
2020/08/16 05:03: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-vimehes1berexen5kokicis4</BucketName><RequestId>36E00B983B9A7854</RequestId><HostId>NnYUMy6bBiSeRraJA7mOfgtAA5/hAfVJVxNwjqjxOyRlKgR2PJtsa/JQQn19fUQSwXTrrweZ4Vs=</HostId></Error>
2020/08/16 05:03:29 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-vimehes1berexen5kokicis4</BucketName><RequestId>36E00B983B9A7854</RequestId><HostId>NnYUMy6bBiSeRraJA7mOfgtAA5/hAfVJVxNwjqjxOyRlKgR2PJtsa/JQQn19fUQSwXTrrweZ4Vs=</HostId></Error>
2020/08/16 05:03:29 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-vimehes1berexen5kokicis4</BucketName><RequestId>407C1819883302A5</RequestId><HostId>eX+sJT+JAaDnc7EHzzomCsz+mgF2on3o2wU3TlbWM0wnnSBS5KAavObDK+H2sqtDNXDbAKuEoCw=</HostId></Error>
2020/08/16 05:03:29 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-vimehes1berexen5kokicis4</BucketName><RequestId>407C1819883302A5</RequestId><HostId>eX+sJT+JAaDnc7EHzzomCsz+mgF2on3o2wU3TlbWM0wnnSBS5KAavObDK+H2sqtDNXDbAKuEoCw=</HostId></Error>
2020/08/16 05:03:30 DEBUG : : Looking for writers
2020/08/16 05:03:30 DEBUG : file1: reading active writers
2020/08/16 05:03:30 DEBUG : file2: reading active writers
2020/08/16 05:03:30 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:31 DEBUG : : Looking for writers
2020/08/16 05:03:31 DEBUG : file1: reading active writers
2020/08/16 05:03:31 DEBUG : file2: reading active writers
2020/08/16 05:03:31 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:32 DEBUG : : Looking for writers
2020/08/16 05:03:32 DEBUG : file1: reading active writers
2020/08/16 05:03:32 DEBUG : file2: reading active writers
2020/08/16 05:03:32 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:32 ERROR : Exiting even though 0 writers active and 2 cache items in use after 10s
Cache{
	"file1": &{c:0xc0006f8240 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13818817610238460974 ext:54450319261 loc:0x25a1860} ATime:{wall:13818817610238617593 ext:54450475878 loc:0x25a1860} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1},
	"file2": &{c:0xc0006f8240 mu:{state:0 sema:0} name:file2 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13818817610239613672 ext:54451471952 loc:0x25a1860} ATime:{wall:13818817610239727033 ext:54451585313 loc:0x25a1860} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2},
}
2020/08/16 05:03:32 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:03:35 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:03: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-vimehes1berexen5kokicis4</BucketName><RequestId>7B03D6CFF3A13153</RequestId><HostId>aWgrQ/nly4g59CNgbfg+FqPqIk9Ez1Xcz4U/wI0rWRecLExcfYT4de/vK+SkUt5qNrW/yGCsom4=</HostId></Error>
2020/08/16 05:03:35 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-vimehes1berexen5kokicis4</BucketName><RequestId>7B03D6CFF3A13153</RequestId><HostId>aWgrQ/nly4g59CNgbfg+FqPqIk9Ez1Xcz4U/wI0rWRecLExcfYT4de/vK+SkUt5qNrW/yGCsom4=</HostId></Error>
2020/08/16 05:03:35 DEBUG : file2: vfs cache: starting upload
2020/08/16 05:03:35 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-vimehes1berexen5kokicis4</BucketName><RequestId>B6D4B11348D5F8B4</RequestId><HostId>F/FD7walOJ4zjXpZuRRc8h33cB1XotoMeFeaExtT+sUfRtD4LhTNGdMSanysTYOD1LCxsgk9QBM=</HostId></Error>
2020/08/16 05:03:35 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-vimehes1berexen5kokicis4</BucketName><RequestId>B6D4B11348D5F8B4</RequestId><HostId>F/FD7walOJ4zjXpZuRRc8h33cB1XotoMeFeaExtT+sUfRtD4LhTNGdMSanysTYOD1LCxsgk9QBM=</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:03:39 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:03:39 DEBUG : : Looking for writers
2020/08/16 05:03:39 DEBUG : file1: reading active writers
2020/08/16 05:03:39 DEBUG : file2: reading active writers
2020/08/16 05:03:39 DEBUG : Still 0 writers active and 2 cache items in use, waiting 10ms
2020/08/16 05:03:40 DEBUG : : Looking for writers
2020/08/16 05:03:40 DEBUG : file1: reading active writers
2020/08/16 05:03:40 DEBUG : file2: reading active writers
2020/08/16 05:03:40 DEBUG : Still 0 writers active and 2 cache items in use, waiting 20ms
2020/08/16 05:03:40 DEBUG : : Looking for writers
2020/08/16 05:03:40 DEBUG : file1: reading active writers
2020/08/16 05:03:40 DEBUG : file2: reading active writers
2020/08/16 05:03:40 DEBUG : Still 0 writers active and 2 cache items in use, waiting 40ms
2020/08/16 05:03:40 DEBUG : : Looking for writers
2020/08/16 05:03:40 DEBUG : file2: reading active writers
2020/08/16 05:03:40 DEBUG : file1: reading active writers
2020/08/16 05:03:40 DEBUG : Still 0 writers active and 2 cache items in use, waiting 80ms
2020/08/16 05:03:40 DEBUG : : Looking for writers
2020/08/16 05:03:40 DEBUG : file2: reading active writers
2020/08/16 05:03:40 DEBUG : file1: reading active writers
2020/08/16 05:03:40 DEBUG : Still 0 writers active and 2 cache items in use, waiting 160ms
2020/08/16 05:03:40 DEBUG : : Looking for writers
2020/08/16 05:03:40 DEBUG : file1: reading active writers
2020/08/16 05:03:40 DEBUG : file2: reading active writers
2020/08/16 05:03:40 DEBUG : Still 0 writers active and 2 cache items in use, waiting 320ms
2020/08/16 05:03:40 DEBUG : : Looking for writers
2020/08/16 05:03:40 DEBUG : file1: reading active writers
2020/08/16 05:03:40 DEBUG : file2: reading active writers
2020/08/16 05:03:40 DEBUG : Still 0 writers active and 2 cache items in use, waiting 640ms
2020/08/16 05:03:41 DEBUG : : Looking for writers
2020/08/16 05:03:41 DEBUG : file1: reading active writers
2020/08/16 05:03:41 DEBUG : file2: reading active writers
2020/08/16 05:03:41 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:42 DEBUG : : Looking for writers
2020/08/16 05:03:42 DEBUG : file1: reading active writers
2020/08/16 05:03:42 DEBUG : file2: reading active writers
2020/08/16 05:03:42 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:43 DEBUG : : Looking for writers
2020/08/16 05:03:43 DEBUG : file1: reading active writers
2020/08/16 05:03:43 DEBUG : file2: reading active writers
2020/08/16 05:03:43 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:44 DEBUG : : Looking for writers
2020/08/16 05:03:44 DEBUG : file1: reading active writers
2020/08/16 05:03:44 DEBUG : file2: reading active writers
2020/08/16 05:03:44 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:45 DEBUG : : Looking for writers
2020/08/16 05:03:45 DEBUG : file1: reading active writers
2020/08/16 05:03:45 DEBUG : file2: reading active writers
2020/08/16 05:03:45 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:46 DEBUG : : Looking for writers
2020/08/16 05:03:46 DEBUG : file1: reading active writers
2020/08/16 05:03:46 DEBUG : file2: reading active writers
2020/08/16 05:03:46 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:47 DEBUG : : Looking for writers
2020/08/16 05:03:47 DEBUG : file1: reading active writers
2020/08/16 05:03:47 DEBUG : file2: reading active writers
2020/08/16 05:03:47 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:48 DEBUG : : Looking for writers
2020/08/16 05:03:48 DEBUG : file1: reading active writers
2020/08/16 05:03:48 DEBUG : file2: reading active writers
2020/08/16 05:03:48 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:48 DEBUG : file1: vfs cache: starting upload
2020/08/16 05:03: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-vimehes1berexen5kokicis4</BucketName><RequestId>BBF8A6EA90CF8860</RequestId><HostId>Sch6+8jJre9lIFdlFjWJcYFWiXQwURIizOf3RLtJAQCb61M8+XhD7ASG7t6lmKfDwsWvX1ej9fw=</HostId></Error>
2020/08/16 05:03:48 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-vimehes1berexen5kokicis4</BucketName><RequestId>BBF8A6EA90CF8860</RequestId><HostId>Sch6+8jJre9lIFdlFjWJcYFWiXQwURIizOf3RLtJAQCb61M8+XhD7ASG7t6lmKfDwsWvX1ej9fw=</HostId></Error>
2020/08/16 05:03:48 DEBUG : file2: vfs cache: starting upload
2020/08/16 05:03:48 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-vimehes1berexen5kokicis4</BucketName><RequestId>EAC39A47A79E5AC9</RequestId><HostId>fRcq8NnJZKvlGKYm62hf0p2kNQXLh+6z2mB1+iTMdodfyHeE0QdKBnn/4UFTkJdD5n4rvP5Jjx8=</HostId></Error>
2020/08/16 05:03:48 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-vimehes1berexen5kokicis4</BucketName><RequestId>EAC39A47A79E5AC9</RequestId><HostId>fRcq8NnJZKvlGKYm62hf0p2kNQXLh+6z2mB1+iTMdodfyHeE0QdKBnn/4UFTkJdD5n4rvP5Jjx8=</HostId></Error>
2020/08/16 05:03:49 DEBUG : : Looking for writers
2020/08/16 05:03:49 DEBUG : file2: reading active writers
2020/08/16 05:03:49 DEBUG : file1: reading active writers
2020/08/16 05:03:49 DEBUG : Still 0 writers active and 2 cache items in use, waiting 1s
2020/08/16 05:03:49 ERROR : Exiting even though 0 writers active and 2 cache items in use after 10s
Cache{
	"file1": &{c:0xc0006f8240 mu:{state:0 sema:0} name:file1 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13818817610238460974 ext:54450319261 loc:0x25a1860} ATime:{wall:13818817610238617593 ext:54450475878 loc:0x25a1860} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:1},
	"file2": &{c:0xc0006f8240 mu:{state:0 sema:0} name:file2 opens:0 downloaders:<nil> o:<nil> fd:<nil> metaDirty:false modified:false info:{ModTime:{wall:13818817610239613672 ext:54451471952 loc:0x25a1860} ATime:{wall:13818817610239727033 ext:54451585313 loc:0x25a1860} Size:0 Rs:[] Fingerprint: Dirty:true} writeBackID:2},
}
2020/08/16 05:03:49 DEBUG : >WaitForWriters: 
2020/08/16 05:03:49 DEBUG : vfs cache: cleaner exiting
--- FAIL: TestRWFileHandleWriteNoWrite (27.04s)
=== RUN   TestWriteFileHandleMethods
    run.go:176: Remote "Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4'", Local "Local file system at /tmp/rclone998968602", Modify Window "1ns"
2020/08/16 05:03:50 INFO  : Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4': poll-interval is not supported by this remote
2020/08/16 05:03:50 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/08/16 05:03:50 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/08/16 05:03:50 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:03:50 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2020/08/16 05:03:50 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2020/08/16 05:03:50 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:03:50 ERROR : file1: WriteFileHandle: Read: Can't read and write to file without --vfs-cache-mode >= minimal
2020/08/16 05:03:50 ERROR : file1: WriteFileHandle: ReadAt: Can't read and write to file without --vfs-cache-mode >= minimal
2020/08/16 05:03:50 ERROR : file1: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes
2020/08/16 05:03:50 DEBUG : Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4': File to upload is small (5 bytes), uploading instead of streaming
2020/08/16 05:03: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-vimehes1berexen5kokicis4</BucketName><RequestId>BD651E787DB858A5</RequestId><HostId>3hOCvXmQgQWiyAfX3dONOgcBrxuZSRV8HkJa2d2zzIYzMhMOuKyDOsl17EyWn2q0sbT7uQntvRs=</HostId></Error>
2020/08/16 05:03:50 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-vimehes1berexen5kokicis4</BucketName><RequestId>BD651E787DB858A5</RequestId><HostId>3hOCvXmQgQWiyAfX3dONOgcBrxuZSRV8HkJa2d2zzIYzMhMOuKyDOsl17EyWn2q0sbT7uQntvRs=</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-vimehes1berexen5kokicis4</BucketName><RequestId>BD651E787DB858A5</RequestId><HostId>3hOCvXmQgQWiyAfX3dONOgcBrxuZSRV8HkJa2d2zzIYzMhMOuKyDOsl17EyWn2q0sbT7uQntvRs=</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:03:57 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/08/16 05:03:57 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/08/16 05:03:57 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:03:57 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2020/08/16 05:03:57 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2020/08/16 05:03:57 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:03:57 DEBUG : Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4': File to upload is small (0 bytes), uploading instead of streaming
2020/08/16 05:03: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-vimehes1berexen5kokicis4</BucketName><RequestId>0B90E557D672046C</RequestId><HostId>7XsbM+c3glFFvnyN17xhzpY6j3c1STAXOE90iVGZP3WLcFdFA6i7bJPpgvRQJtXDPjcaJQlGOlc=</HostId></Error>
2020/08/16 05:03:57 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-vimehes1berexen5kokicis4</BucketName><RequestId>0B90E557D672046C</RequestId><HostId>7XsbM+c3glFFvnyN17xhzpY6j3c1STAXOE90iVGZP3WLcFdFA6i7bJPpgvRQJtXDPjcaJQlGOlc=</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-vimehes1berexen5kokicis4</BucketName><RequestId>0B90E557D672046C</RequestId><HostId>7XsbM+c3glFFvnyN17xhzpY6j3c1STAXOE90iVGZP3WLcFdFA6i7bJPpgvRQJtXDPjcaJQlGOlc=</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:03:57 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/08/16 05:03:57 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/08/16 05:03:57 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:03:57 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2020/08/16 05:03:57 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2020/08/16 05:03:57 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:03:57 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:03:57 DEBUG : : Looking for writers
2020/08/16 05:03:57 DEBUG : file1: reading active writers
2020/08/16 05:03:57 DEBUG : file1: active writers 1
2020/08/16 05:03:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 10ms
2020/08/16 05:03:57 DEBUG : : Looking for writers
2020/08/16 05:03:57 DEBUG : file1: reading active writers
2020/08/16 05:03:57 DEBUG : file1: active writers 1
2020/08/16 05:03:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 20ms
2020/08/16 05:03:57 DEBUG : : Looking for writers
2020/08/16 05:03:57 DEBUG : file1: reading active writers
2020/08/16 05:03:57 DEBUG : file1: active writers 1
2020/08/16 05:03:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 40ms
2020/08/16 05:03:57 DEBUG : : Looking for writers
2020/08/16 05:03:57 DEBUG : file1: reading active writers
2020/08/16 05:03:57 DEBUG : file1: active writers 1
2020/08/16 05:03:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 80ms
2020/08/16 05:03:57 DEBUG : : Looking for writers
2020/08/16 05:03:57 DEBUG : file1: reading active writers
2020/08/16 05:03:57 DEBUG : file1: active writers 1
2020/08/16 05:03:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 160ms
2020/08/16 05:03:57 DEBUG : : Looking for writers
2020/08/16 05:03:57 DEBUG : file1: reading active writers
2020/08/16 05:03:57 DEBUG : file1: active writers 1
2020/08/16 05:03:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 320ms
2020/08/16 05:03:57 DEBUG : : Looking for writers
2020/08/16 05:03:57 DEBUG : file1: reading active writers
2020/08/16 05:03:57 DEBUG : file1: active writers 1
2020/08/16 05:03:57 DEBUG : Still 1 writers active and 0 cache items in use, waiting 640ms
2020/08/16 05:03:58 DEBUG : : Looking for writers
2020/08/16 05:03:58 DEBUG : file1: reading active writers
2020/08/16 05:03:58 DEBUG : file1: active writers 1
2020/08/16 05:03:58 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:03:59 DEBUG : : Looking for writers
2020/08/16 05:03:59 DEBUG : file1: reading active writers
2020/08/16 05:03:59 DEBUG : file1: active writers 1
2020/08/16 05:03:59 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:04:00 DEBUG : : Looking for writers
2020/08/16 05:04:00 DEBUG : file1: reading active writers
2020/08/16 05:04:00 DEBUG : file1: active writers 1
2020/08/16 05:04:00 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:04:01 DEBUG : : Looking for writers
2020/08/16 05:04:01 DEBUG : file1: reading active writers
2020/08/16 05:04:01 DEBUG : file1: active writers 1
2020/08/16 05:04:01 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:04:02 DEBUG : : Looking for writers
2020/08/16 05:04:02 DEBUG : file1: reading active writers
2020/08/16 05:04:02 DEBUG : file1: active writers 1
2020/08/16 05:04:02 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:04:03 DEBUG : : Looking for writers
2020/08/16 05:04:03 DEBUG : file1: reading active writers
2020/08/16 05:04:03 DEBUG : file1: active writers 1
2020/08/16 05:04:03 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:04:04 DEBUG : : Looking for writers
2020/08/16 05:04:04 DEBUG : file1: reading active writers
2020/08/16 05:04:04 DEBUG : file1: active writers 1
2020/08/16 05:04:04 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:04:05 DEBUG : : Looking for writers
2020/08/16 05:04:05 DEBUG : file1: reading active writers
2020/08/16 05:04:05 DEBUG : file1: active writers 1
2020/08/16 05:04:05 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:04:06 DEBUG : : Looking for writers
2020/08/16 05:04:06 DEBUG : file1: reading active writers
2020/08/16 05:04:06 DEBUG : file1: active writers 1
2020/08/16 05:04:06 DEBUG : Still 1 writers active and 0 cache items in use, waiting 1s
2020/08/16 05:04:07 ERROR : Exiting even though 1 writers active and 0 cache items in use after 10s
Cache: <nil>
2020/08/16 05:04:07 DEBUG : >WaitForWriters: 
--- FAIL: TestWriteFileHandleMethods (17.14s)
=== RUN   TestWriteFileHandleWriteAt
    run.go:176: Remote "Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4'", Local "Local file system at /tmp/rclone998968602", Modify Window "1ns"
2020/08/16 05:04:07 INFO  : Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4': poll-interval is not supported by this remote
2020/08/16 05:04:07 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/08/16 05:04:07 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/08/16 05:04:07 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:04:07 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2020/08/16 05:04:07 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2020/08/16 05:04:07 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:04:07 DEBUG : file1: waiting for in-sequence write to 100 for 1s
2020/08/16 05:04:08 DEBUG : file1: aborting in-sequence write wait, off=100
2020/08/16 05:04:08 DEBUG : file1: failed to wait for in-sequence write to 100
2020/08/16 05:04:08 ERROR : file1: WriteFileHandle.Write: can't seek in file without --vfs-cache-mode >= writes
2020/08/16 05:04:08 DEBUG : Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4': File to upload is small (11 bytes), uploading instead of streaming
2020/08/16 05:04: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-vimehes1berexen5kokicis4</BucketName><RequestId>00F492C033CDA583</RequestId><HostId>3HM5+VWaLDvDQYYGyvmIM5OjrGAbcobXKtwp5R3/gruRqn4Q1J1OX9llBNvj+D2r2kiJzQVn9Wo=</HostId></Error>
2020/08/16 05:04: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-vimehes1berexen5kokicis4</BucketName><RequestId>00F492C033CDA583</RequestId><HostId>3HM5+VWaLDvDQYYGyvmIM5OjrGAbcobXKtwp5R3/gruRqn4Q1J1OX9llBNvj+D2r2kiJzQVn9Wo=</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-vimehes1berexen5kokicis4</BucketName><RequestId>00F492C033CDA583</RequestId><HostId>3HM5+VWaLDvDQYYGyvmIM5OjrGAbcobXKtwp5R3/gruRqn4Q1J1OX9llBNvj+D2r2kiJzQVn9Wo=</HostId></Error>
        	Test:       	TestWriteFileHandleWriteAt
2020/08/16 05:04:08 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:04:15 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:04:15 DEBUG : : Looking for writers
2020/08/16 05:04:15 DEBUG : file1: reading active writers
2020/08/16 05:04:15 DEBUG : >WaitForWriters: 
--- FAIL: TestWriteFileHandleWriteAt (8.14s)
=== RUN   TestWriteFileHandleFlush
    run.go:176: Remote "Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4'", Local "Local file system at /tmp/rclone998968602", Modify Window "1ns"
2020/08/16 05:04:15 INFO  : Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4': poll-interval is not supported by this remote
2020/08/16 05:04:15 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx
2020/08/16 05:04:15 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE
2020/08/16 05:04:15 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:04:15 DEBUG : file1: >Open: fd=file1 (w), err=<nil>
2020/08/16 05:04:15 DEBUG : file1: >OpenFile: fd=file1 (w), err=<nil>
2020/08/16 05:04:15 DEBUG : file1: WriteFileHandle.Flush unwritten handle, writing 0 bytes to avoid race conditions
2020/08/16 05:04:15 DEBUG : : Added virtual directory entry vAdd: "file1"
2020/08/16 05:04:15 DEBUG : Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4': File to upload is small (5 bytes), uploading instead of streaming
2020/08/16 05:04: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-vimehes1berexen5kokicis4</BucketName><RequestId>EE20CD7B46A3DF78</RequestId><HostId>2CaeVfaWaCgPW/dpys5WgOP1MP1DgRhvZiaUzGXzhMTf4qL/+swIGa+6FnpOQ8+jbHXR0QIypZA=</HostId></Error>
2020/08/16 05:04: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-vimehes1berexen5kokicis4</BucketName><RequestId>EE20CD7B46A3DF78</RequestId><HostId>2CaeVfaWaCgPW/dpys5WgOP1MP1DgRhvZiaUzGXzhMTf4qL/+swIGa+6FnpOQ8+jbHXR0QIypZA=</HostId></Error>
2020/08/16 05:04:15 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-vimehes1berexen5kokicis4</BucketName><RequestId>EE20CD7B46A3DF78</RequestId><HostId>2CaeVfaWaCgPW/dpys5WgOP1MP1DgRhvZiaUzGXzhMTf4qL/+swIGa+6FnpOQ8+jbHXR0QIypZA=</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-vimehes1berexen5kokicis4</BucketName><RequestId>EE20CD7B46A3DF78</RequestId><HostId>2CaeVfaWaCgPW/dpys5WgOP1MP1DgRhvZiaUzGXzhMTf4qL/+swIGa+6FnpOQ8+jbHXR0QIypZA=</HostId></Error>
        	Test:       	TestWriteFileHandleFlush
2020/08/16 05:04:15 DEBUG : file1: WriteFileHandle.Flush nothing to do
2020/08/16 05:04:15 DEBUG : WaitForWriters: timeout=10s
2020/08/16 05:04:15 DEBUG : : Looking for writers
2020/08/16 05:04:15 DEBUG : file1: reading active writers
2020/08/16 05:04:15 DEBUG : >WaitForWriters: 
--- FAIL: TestWriteFileHandleFlush (0.07s)
FAIL
2020/08/16 05:04:15 DEBUG : Chunked 'TestChunkerChunk50bMD5HashS3:rclone-test-vimehes1berexen5kokicis4': Purge dir ""
2020/08/16 05:04:15 purge failed to rmdir "": NoSuchBucket: The specified bucket does not exist
	status code: 404, request id: 2D3FD23E993F126B, host id: nct4gQCm5AbNOMDaHMiCh7dTrwJjeddvoLQ5ce3jqpwf31pKXDrViuR26PKdPp6BTf05KkWR4AA=
2020/08/16 05:04:15 purge failed: directory not found
"./vfs.test -test.v -test.timeout 1h0m0s -remote TestChunkerChunk50bMD5HashS3: -verbose -size-limit 1024 -test.run '^(TestRWFileHandleMethodsWrite|TestRWFileHandleWriteAt|TestRWFileHandleWriteNoWrite|TestWriteFileHandleFlush|TestWriteFileHandleMethods|TestWriteFileHandleWriteAt)$'" - Finished ERROR in 1m46.860960262s (try 2/5): exit status 1: Failed [TestRWFileHandleMethodsWrite TestRWFileHandleWriteAt TestRWFileHandleWriteNoWrite TestWriteFileHandleMethods TestWriteFileHandleWriteAt TestWriteFileHandleFlush]