"./vfs.test -test.v -test.timeout 1h0m0s -remote TestPikPak: -verbose -test.run '^(TestDirEntryModTimeInvalidation|TestFileReadAtNonZeroLength|TestReadFileHandleSeek)$'" - Starting (try 2/5) 2025/04/30 18:40:09 DEBUG : Creating backend with remote "TestPikPak:rclone-test-wuxikab3luqa" 2025/04/30 18:40:09 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/30 18:40:10 DEBUG : Creating backend with remote "/tmp/rclone2069406095" === RUN TestDirEntryModTimeInvalidation run.go:180: Remote "PikPak root 'rclone-test-wuxikab3luqa'", Local "Local file system at /tmp/rclone2069406095", Modify Window "876000h0m0s" 2025/04/30 18:40:10 INFO : PikPak root 'rclone-test-wuxikab3luqa': poll-interval is not supported by this remote 2025/04/30 18:40:10 NOTICE: PikPak root 'rclone-test-wuxikab3luqa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/04/30 18:40:11 DEBUG : dir/file1: calculating gcid: failed to unwrap object from src: dir/file1 2025/04/30 18:40:11 DEBUG : dir/file1: gcid = 3823e2b83a3ba8d1137efc1fe13e3a2e7cfb8d82 2025/04/30 18:40:12 DEBUG : dir: forgetting directory cache 2025/04/30 18:40:12 DEBUG : : forgetting directory cache 2025/04/30 18:40:12 DEBUG : dir: forgetting directory cache 2025/04/30 18:40:12 DEBUG : dir/file2: calculating gcid: failed to unwrap object from src: dir/file2 2025/04/30 18:40:12 DEBUG : dir/file2: gcid = 8f6e1023f7530ee92b8667061641e57f5c481570 dir_test.go:687: ModTime not invalidated 2025/04/30 18:40:13 DEBUG : WaitForWriters: timeout=30s 2025/04/30 18:40:13 DEBUG : dir: Looking for writers 2025/04/30 18:40:13 DEBUG : : Looking for writers 2025/04/30 18:40:13 DEBUG : dir: reading active writers 2025/04/30 18:40:13 DEBUG : >WaitForWriters: 2025/04/30 18:40:13 DEBUG : dir: forgetting directory cache 2025/04/30 18:40:13 DEBUG : : forgetting directory cache 2025/04/30 18:40:13 DEBUG : dir: forgetting directory cache 2025/04/30 18:40:16 DEBUG : dir: Rmdir: contains trashed file: "file2" 2025/04/30 18:40:16 DEBUG : dir: Rmdir: contains trashed file: "file1" --- FAIL: TestDirEntryModTimeInvalidation (7.02s) === RUN TestReadFileHandleSeek run.go:180: Remote "PikPak root 'rclone-test-wuxikab3luqa'", Local "Local file system at /tmp/rclone2069406095", Modify Window "876000h0m0s" 2025/04/30 18:40:17 INFO : PikPak root 'rclone-test-wuxikab3luqa': poll-interval is not supported by this remote 2025/04/30 18:40:17 NOTICE: PikPak root 'rclone-test-wuxikab3luqa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/04/30 18:40:17 DEBUG : dir/file1: calculating gcid: failed to unwrap object from src: dir/file1 2025/04/30 18:40:17 DEBUG : dir/file1: gcid = 75291f3a188a427f873fb88fbc37ce5ce150d01c 2025/04/30 18:40:19 DEBUG : dir/file1: OpenFile: flags=O_RDONLY, perm=-rwxrwxrwx 2025/04/30 18:40:19 DEBUG : dir/file1: Open: flags=O_RDONLY 2025/04/30 18:40:19 DEBUG : dir/file1: >Open: fd=dir/file1 (r), err= 2025/04/30 18:40:19 DEBUG : dir/file1: >OpenFile: fd=dir/file1 (r), err= 2025/04/30 18:40:19 DEBUG : dir/file1: ChunkedReader.openRange at 0 length 134217728 2025/04/30 18:40:21 DEBUG : pacer: low level retry 1/10 (error no link) 2025/04/30 18:40:21 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2025/04/30 18:40:21 DEBUG : pacer: Reducing sleep to 150ms 2025/04/30 18:40:23 DEBUG : pacer: Reducing sleep to 112.5ms 2025/04/30 18:40:23 DEBUG : dir/file1: ChunkedReader.Read at 0 length 1 chunkOffset 0 chunkSize 134217728 2025/04/30 18:40:23 DEBUG : dir/file1: waiting for in-sequence read to 5 for 20ms 2025/04/30 18:40:23 DEBUG : dir/file1: aborting in-sequence read wait, off=5 2025/04/30 18:40:23 DEBUG : dir/file1: failed to wait for in-sequence read to 5 2025/04/30 18:40:23 DEBUG : dir/file1: ReadFileHandle.seek from 1 to 5 (fs.RangeSeeker) 2025/04/30 18:40:23 DEBUG : dir/file1: ChunkedReader.RangeSeek from 1 to 5 length -1 2025/04/30 18:40:23 DEBUG : dir/file1: ChunkedReader.Read at -1 length 1 chunkOffset 5 chunkSize 134217728 2025/04/30 18:40:23 DEBUG : dir/file1: ChunkedReader.openRange at 5 length 134217728 2025/04/30 18:40:24 DEBUG : pacer: Reducing sleep to 100ms 2025/04/30 18:40:24 DEBUG : dir/file1: ReadFileHandle.seek from 6 to 3 (fs.RangeSeeker) 2025/04/30 18:40:24 DEBUG : dir/file1: ChunkedReader.RangeSeek from 6 to 3 length -1 2025/04/30 18:40:24 DEBUG : dir/file1: ChunkedReader.Read at -1 length 1 chunkOffset 3 chunkSize 134217728 2025/04/30 18:40:24 DEBUG : dir/file1: ChunkedReader.openRange at 3 length 134217728 2025/04/30 18:40:25 DEBUG : dir/file1: ReadFileHandle.seek from 4 to 13 (fs.RangeSeeker) 2025/04/30 18:40:25 DEBUG : dir/file1: ChunkedReader.RangeSeek from 4 to 13 length -1 2025/04/30 18:40:25 DEBUG : dir/file1: ChunkedReader.Read at -1 length 1 chunkOffset 13 chunkSize 134217728 2025/04/30 18:40:25 DEBUG : dir/file1: ChunkedReader.openRange at 13 length 134217728 2025/04/30 18:40:26 DEBUG : WaitForWriters: timeout=30s 2025/04/30 18:40:26 DEBUG : dir: Looking for writers 2025/04/30 18:40:26 DEBUG : file1: reading active writers 2025/04/30 18:40:26 DEBUG : : Looking for writers 2025/04/30 18:40:26 DEBUG : dir: reading active writers 2025/04/30 18:40:26 DEBUG : >WaitForWriters: 2025/04/30 18:40:28 DEBUG : dir: Rmdir: contains trashed file: "file1" --- PASS: TestReadFileHandleSeek (12.96s) === RUN TestFileReadAtNonZeroLength run.go:180: Remote "PikPak root 'rclone-test-wuxikab3luqa'", Local "Local file system at /tmp/rclone2069406095", Modify Window "876000h0m0s" 2025/04/30 18:40:30 INFO : PikPak root 'rclone-test-wuxikab3luqa': poll-interval is not supported by this remote 2025/04/30 18:40:30 NOTICE: PikPak root 'rclone-test-wuxikab3luqa': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/04/30 18:40:30 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/04/30 18:40:30 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/04/30 18:40:30 DEBUG : : Added virtual directory entry vAddFile: "file1" 2025/04/30 18:40:30 DEBUG : file1: >Open: fd=file1 (w), err= 2025/04/30 18:40:30 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/04/30 18:40:30 DEBUG : : Added virtual directory entry vAddFile: "file1" 2025/04/30 18:40:30 DEBUG : PikPak root 'rclone-test-wuxikab3luqa': File to upload is small (100 bytes), uploading instead of streaming 2025/04/30 18:40:30 DEBUG : file1: calculating gcid: failed to unwrap object from src: file1 2025/04/30 18:40:30 DEBUG : file1: gcid = d35b1c13e1a9a01c2206a62d466ef3d733e75425 2025/04/30 18:40:33 DEBUG : file1: Dst hash empty - aborting Src hash check 2025/04/30 18:40:33 DEBUG : file1: Size of src and dst objects identical 2025/04/30 18:40:33 DEBUG : : Added virtual directory entry vAddFile: "file1" 2025/04/30 18:40:33 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2025/04/30 18:40:33 DEBUG : file1: Open: flags=O_RDONLY 2025/04/30 18:40:33 DEBUG : file1: >Open: fd=file1 (r), err= 2025/04/30 18:40:33 DEBUG : file1: >OpenFile: fd=file1 (r), err= 2025/04/30 18:40:33 DEBUG : file1: ChunkedReader.openRange at 0 length 134217728 2025/04/30 18:40:33 DEBUG : pacer: low level retry 1/10 (error no link) 2025/04/30 18:40:33 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2025/04/30 18:40:33 DEBUG : pacer: low level retry 2/10 (error no link) 2025/04/30 18:40:33 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2025/04/30 18:40:34 DEBUG : pacer: low level retry 3/10 (error no link) 2025/04/30 18:40:34 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2025/04/30 18:40:34 DEBUG : pacer: low level retry 4/10 (error no link) 2025/04/30 18:40:34 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2025/04/30 18:40:35 DEBUG : pacer: low level retry 5/10 (error no link) 2025/04/30 18:40:35 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/04/30 18:40:36 DEBUG : pacer: low level retry 6/10 (error no link) 2025/04/30 18:40:38 DEBUG : pacer: low level retry 7/10 (error no link) 2025/04/30 18:40:40 DEBUG : pacer: low level retry 8/10 (error no link) 2025/04/30 18:40:42 DEBUG : pacer: low level retry 9/10 (error no link) 2025/04/30 18:40:44 DEBUG : pacer: low level retry 10/10 (error no link) write_test.go:370: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:370 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:384 Error: Received unexpected error: can't download: no link Test: TestFileReadAtNonZeroLength write_test.go:372: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:372 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:384 Error: Not equal: expected: 0 actual : 100 Test: TestFileReadAtNonZeroLength write_test.go:373: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:373 /home/rclone/go/src/github.com/rclone/rclone/vfs/write_test.go:384 Error: Not equal: expected: []byte{0x6e, 0x61, 0x7a, 0x75, 0x68, 0x6f, 0x67, 0x36, 0x67, 0x61, 0x78, 0x6f, 0x74, 0x65, 0x67, 0x36, 0x71, 0x61, 0x7a, 0x75, 0x6d, 0x65, 0x76, 0x39, 0x63, 0x75, 0x68, 0x61, 0x71, 0x6f, 0x6a, 0x33, 0x6d, 0x69, 0x63, 0x65, 0x64, 0x61, 0x6e, 0x31, 0x62, 0x65, 0x77, 0x65, 0x72, 0x65, 0x6c, 0x35, 0x63, 0x69, 0x77, 0x69, 0x77, 0x65, 0x6e, 0x34, 0x70, 0x75, 0x6e, 0x69, 0x70, 0x6f, 0x68, 0x36, 0x68, 0x75, 0x62, 0x6f, 0x68, 0x65, 0x6b, 0x38, 0x70, 0x65, 0x76, 0x69, 0x72, 0x75, 0x66, 0x34, 0x63, 0x75, 0x70, 0x69, 0x73, 0x6f, 0x76, 0x32, 0x63, 0x65, 0x77, 0x69, 0x6d, 0x61, 0x7a, 0x34, 0x62, 0x69, 0x67, 0x61} actual : []byte{} Diff: --- Expected +++ Actual @@ -1,9 +1,2 @@ -([]uint8) (len=100) { - 00000000 6e 61 7a 75 68 6f 67 36 67 61 78 6f 74 65 67 36 |nazuhog6gaxoteg6| - 00000010 71 61 7a 75 6d 65 76 39 63 75 68 61 71 6f 6a 33 |qazumev9cuhaqoj3| - 00000020 6d 69 63 65 64 61 6e 31 62 65 77 65 72 65 6c 35 |micedan1bewerel5| - 00000030 63 69 77 69 77 65 6e 34 70 75 6e 69 70 6f 68 36 |ciwiwen4punipoh6| - 00000040 68 75 62 6f 68 65 6b 38 70 65 76 69 72 75 66 34 |hubohek8peviruf4| - 00000050 63 75 70 69 73 6f 76 32 63 65 77 69 6d 61 7a 34 |cupisov2cewimaz4| - 00000060 62 69 67 61 |biga| +([]uint8) { } Test: TestFileReadAtNonZeroLength 2025/04/30 18:40:44 DEBUG : WaitForWriters: timeout=30s 2025/04/30 18:40:44 DEBUG : : Looking for writers 2025/04/30 18:40:44 DEBUG : file1: reading active writers 2025/04/30 18:40:44 DEBUG : >WaitForWriters: 2025/04/30 18:40:46 DEBUG : pacer: Reducing sleep to 1.5s 2025/04/30 18:40:48 DEBUG : pacer: Reducing sleep to 1.125s 2025/04/30 18:40:50 DEBUG : pacer: Reducing sleep to 843.75ms 2025/04/30 18:40:51 DEBUG : pacer: Reducing sleep to 632.8125ms --- FAIL: TestFileReadAtNonZeroLength (21.39s) FAIL 2025/04/30 18:40:51 DEBUG : PikPak root 'rclone-test-wuxikab3luqa': Purge remote 2025/04/30 18:40:52 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/04/30 18:40:53 DEBUG : pacer: Reducing sleep to 355.957031ms "./vfs.test -test.v -test.timeout 1h0m0s -remote TestPikPak: -verbose -test.run '^(TestDirEntryModTimeInvalidation|TestFileReadAtNonZeroLength|TestReadFileHandleSeek)$'" - Finished ERROR in 43.692231224s (try 2/5): exit status 1: Failed [TestDirEntryModTimeInvalidation TestFileReadAtNonZeroLength]