"./vfs.test -test.v -test.timeout 30m0s -remote TestMega: -verbose -test.run '^TestFileRename$/^(CacheModeFull|CacheModeOff)$'" - Starting (try 3/5)
=== RUN   TestFileRename
=== RUN   TestFileRename/CacheModeOff
2020/03/09 05:54:30 INFO  : mega root 'rclone-test-hanejiq2yifudus7fucireg2': poll-interval is not supported by this remote
2020/03/09 05:54:30 DEBUG : Adding path "vfs/forget" to remote control registry
2020/03/09 05:54:30 DEBUG : Adding path "vfs/refresh" to remote control registry
2020/03/09 05:54:30 DEBUG : Adding path "vfs/poll-interval" to remote control registry
2020/03/09 05:54:31 INFO  : dir/file1: Moved (server side)
2020/03/09 05:54:31 DEBUG : dir/file1: Updating file with newLeaf 0xc000320600
2020/03/09 05:55:35 INFO  : newLeaf: Moved (server side)
2020/03/09 05:55:35 DEBUG : newLeaf: Updating file with dir/file1 0xc000320600
2020/03/09 05:56:38 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC
2020/03/09 05:56:38 DEBUG : dir/file1: >Open: fd=dir/file1 (w), err=<nil>
2020/03/09 05:56:38 DEBUG : dir/file1: File is currently open, delaying rename 0xc000320600
2020/03/09 05:56:38 DEBUG : mega root 'rclone-test-hanejiq2yifudus7fucireg2': File to upload is small (25 bytes), uploading instead of streaming
2020/03/09 05:56:38 INFO  : dir/file1: Copied (new)
2020/03/09 05:56:38 DEBUG : dir/file1: Running delayed rename now
2020/03/09 05:56:38 INFO  : newLeaf: Deleted
2020/03/09 05:56:38 INFO  : dir/file1: Moved (server side)
2020/03/09 05:56:38 DEBUG : dir/file1: Updating file with newLeaf 0xc000320600
=== RUN   TestFileRename/CacheModeFull
2020/03/09 05:56:38 INFO  : mega root 'rclone-test-hanejiq2yifudus7fucireg2': poll-interval is not supported by this remote
2020/03/09 05:56:38 DEBUG : vfs cache root is "/home/rclone/.cache/rclone/vfs/TestMega/rclone-test-hanejiq2yifudus7fucireg2"
2020/03/09 05:56:38 DEBUG : Adding path "vfs/forget" to remote control registry
2020/03/09 05:56:38 DEBUG : Adding path "vfs/refresh" to remote control registry
2020/03/09 05:56:38 DEBUG : Adding path "vfs/poll-interval" to remote control registry
2020/03/09 05:56:41 DEBUG : dir/file1: Open: flags=O_RDONLY
2020/03/09 05:56:41 DEBUG : dir/file1: >Open: fd=dir/file1 (rw), err=<nil>
2020/03/09 05:56:41 DEBUG : dir/file1: Need to transfer - File not found at Destination
2020/03/09 05:56:42 INFO  : dir/file1: Copied (new)
2020/03/09 05:56:42 DEBUG : dir/file1(0xc0003f33c0): Opening cached copy with flags=O_RDONLY
2020/03/09 05:56:42 DEBUG : dir/file1(0xc0003f33c0): close: 
2020/03/09 05:56:42 DEBUG : dir/file1(0xc0003f33c0): >close: err=<nil>
2020/03/09 05:56:42 INFO  : dir/file1: Renamed in cache
2020/03/09 05:56:42 INFO  : dir/file1: Moved (server side)
2020/03/09 05:56:42 DEBUG : dir/file1: Updating file with newLeaf 0xc0006720c0
2020/03/09 05:56:42 INFO  : newLeaf: Renamed in cache
2020/03/09 05:56:42 INFO  : newLeaf: Moved (server side)
2020/03/09 05:56:42 DEBUG : newLeaf: Updating file with dir/file1 0xc0006720c0
2020/03/09 05:57:38 INFO  : Cleaned the cache: objects 3 (was 3), total size 14 (was 0)
2020/03/09 05:57:45 DEBUG : dir/file1: Open: flags=O_WRONLY|O_TRUNC
2020/03/09 05:57:45 DEBUG : dir/file1(0xc0006d42c0): Opening cached copy with flags=O_WRONLY|O_TRUNC
2020/03/09 05:57:45 DEBUG : dir/file1: >Open: fd=dir/file1 (rw), err=<nil>
2020/03/09 05:57:45 INFO  : dir/file1: Renamed in cache
2020/03/09 05:57:45 DEBUG : dir/file1: File is currently open, delaying rename 0xc0006720c0
2020/03/09 05:57:45 DEBUG : newLeaf(0xc0006d42c0): close: 
2020/03/09 05:57:45 DEBUG : newLeaf: Sizes differ (src 25 vs dst 14)
2020/03/09 05:57:45 INFO  : newLeaf: Copied (replaced existing)
2020/03/09 05:57:45 DEBUG : dir/file1: transferred to remote
2020/03/09 05:57:45 DEBUG : dir/file1: Running delayed rename now
2020/03/09 05:57:46 INFO  : dir/file1: Moved (server side)
2020/03/09 05:57:46 DEBUG : dir/file1: Updating file with newLeaf 0xc0006720c0
2020/03/09 05:57:46 DEBUG : newLeaf(0xc0006d42c0): >close: err=<nil>
2020/03/09 05:58:38 INFO  : Cleaned the cache: objects 3 (was 3), total size 25 (was 14)
2020/03/09 05:59:38 INFO  : Cleaned the cache: objects 3 (was 3), total size 25 (was 25)
--- FAIL: TestFileRename (321.55s)
    --- FAIL: TestFileRename/CacheModeOff (128.02s)
        run.go:176: Remote "mega root 'rclone-test-hanejiq2yifudus7fucireg2'", Local "Local file system at /tmp/rclone104680827", Modify Window "876000h0m0s"
        fstest.go:289: Sleeping for 1s for list eventual consistency: 1/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 2s for list eventual consistency: 2/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 4s for list eventual consistency: 3/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 8s for list eventual consistency: 4/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 16s for list eventual consistency: 5/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 32s for list eventual consistency: 6/6
        fstest.go:292: Flushing the directory cache
        fstest.go:296: 
            	Error Trace:	fstest.go:296
            	            				fstest.go:329
            	            				fstest.go:341
            	            				file_test.go:274
            	            				file_test.go:329
            	Error:      	Should be true
            	Test:       	TestFileRename/CacheModeOff
            	Messages:   	listing wrong, want
            	            	  newLeaf (14) got
            	            	  file1 (14), newLeaf (14)
        fstest.go:182: 
            	Error Trace:	fstest.go:182
            	            				fstest.go:299
            	            				fstest.go:329
            	            				fstest.go:341
            	            				file_test.go:274
            	            				file_test.go:329
            	Error:      	Should be true
            	Test:       	TestFileRename/CacheModeOff
            	Messages:   	Unexpected file "file1"
        fstest.go:289: Sleeping for 1s for list eventual consistency: 1/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 2s for list eventual consistency: 2/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 4s for list eventual consistency: 3/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 8s for list eventual consistency: 4/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 16s for list eventual consistency: 5/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 32s for list eventual consistency: 6/6
        fstest.go:292: Flushing the directory cache
        fstest.go:296: 
            	Error Trace:	fstest.go:296
            	            				fstest.go:329
            	            				fstest.go:341
            	            				file_test.go:290
            	            				file_test.go:329
            	Error:      	Should be true
            	Test:       	TestFileRename/CacheModeOff
            	Messages:   	listing wrong, want
            	            	  dir/file1 (14) got
            	            	  dir/file1 (14), dir/file1 (14), newLeaf (14)
        fstest.go:182: 
            	Error Trace:	fstest.go:182
            	            				fstest.go:299
            	            				fstest.go:329
            	            				fstest.go:341
            	            				file_test.go:290
            	            				file_test.go:329
            	Error:      	Should be true
            	Test:       	TestFileRename/CacheModeOff
            	Messages:   	Unexpected file "newLeaf"
        fstest.go:182: 
            	Error Trace:	fstest.go:182
            	            				fstest.go:299
            	            				fstest.go:329
            	            				fstest.go:341
            	            				file_test.go:290
            	            				file_test.go:329
            	Error:      	Should be true
            	Test:       	TestFileRename/CacheModeOff
            	Messages:   	Unexpected file "dir/file1"
    --- FAIL: TestFileRename/CacheModeFull (193.52s)
        run.go:176: Remote "mega root 'rclone-test-hanejiq2yifudus7fucireg2'", Local "Local file system at /tmp/rclone104680827", Modify Window "876000h0m0s"
        fstest.go:289: Sleeping for 1s for list eventual consistency: 1/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 2s for list eventual consistency: 2/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 4s for list eventual consistency: 3/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 8s for list eventual consistency: 4/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 16s for list eventual consistency: 5/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 32s for list eventual consistency: 6/6
        fstest.go:292: Flushing the directory cache
        fstest.go:296: 
            	Error Trace:	fstest.go:296
            	            				fstest.go:329
            	            				fstest.go:341
            	            				file_test.go:290
            	            				file_test.go:332
            	Error:      	Should be true
            	Test:       	TestFileRename/CacheModeFull
            	Messages:   	listing wrong, want
            	            	  dir/file1 (14) got
            	            	  dir/file1 (14), dir/file1 (14)
        fstest.go:182: 
            	Error Trace:	fstest.go:182
            	            				fstest.go:299
            	            				fstest.go:329
            	            				fstest.go:341
            	            				file_test.go:290
            	            				file_test.go:332
            	Error:      	Should be true
            	Test:       	TestFileRename/CacheModeFull
            	Messages:   	Unexpected file "dir/file1"
        fstest.go:289: Sleeping for 1s for list eventual consistency: 1/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 2s for list eventual consistency: 2/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 4s for list eventual consistency: 3/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 8s for list eventual consistency: 4/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 16s for list eventual consistency: 5/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 32s for list eventual consistency: 6/6
        fstest.go:292: Flushing the directory cache
        fstest.go:296: 
            	Error Trace:	fstest.go:296
            	            				fstest.go:329
            	            				file_test.go:324
            	            				file_test.go:332
            	Error:      	Should be true
            	Test:       	TestFileRename/CacheModeFull
            	Messages:   	listing wrong, want
            	            	  newLeaf (25) got
            	            	  newLeaf (25), newLeaf (25)
        fstest.go:182: 
            	Error Trace:	fstest.go:182
            	            				fstest.go:299
            	            				fstest.go:329
            	            				file_test.go:324
            	            				file_test.go:332
            	Error:      	Should be true
            	Test:       	TestFileRename/CacheModeFull
            	Messages:   	Unexpected file "newLeaf"
        fstest.go:289: Sleeping for 1s for list eventual consistency: 1/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 2s for list eventual consistency: 2/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 4s for list eventual consistency: 3/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 8s for list eventual consistency: 4/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 16s for list eventual consistency: 5/6
        fstest.go:292: Flushing the directory cache
        fstest.go:289: Sleeping for 32s for list eventual consistency: 6/6
        fstest.go:292: Flushing the directory cache
        fstest.go:296: 
            	Error Trace:	fstest.go:296
            	            				fstest.go:329
            	            				run.go:169
            	            				run.go:339
            	            				file_test.go:325
            	            				file_test.go:332
            	Error:      	Should be true
            	Test:       	TestFileRename/CacheModeFull
            	Messages:   	listing wrong, want
            	            	   got
            	            	  newLeaf (25)
        fstest.go:182: 
            	Error Trace:	fstest.go:182
            	            				fstest.go:299
            	            				fstest.go:329
            	            				run.go:169
            	            				run.go:339
            	            				file_test.go:325
            	            				file_test.go:332
            	Error:      	Should be true
            	Test:       	TestFileRename/CacheModeFull
            	Messages:   	Unexpected file "newLeaf"
FAIL
2020/03/09 05:59:52 DEBUG : mega root 'rclone-test-hanejiq2yifudus7fucireg2': Purge remote
"./vfs.test -test.v -test.timeout 30m0s -remote TestMega: -verbose -test.run '^TestFileRename$/^(CacheModeFull|CacheModeOff)$'" - Finished ERROR in 5m26.466278579s (try 3/5): exit status 1: Failed [TestFileRename/CacheModeOff TestFileRename/CacheModeFull]