"./vfs.test -test.v -test.timeout 1h0m0s -remote TestPikPak: -verbose -test.run '^(TestDirEntryModTimeInvalidation|TestFileReadAtNonZeroLength)$'" - Starting (try 3/5) 2025/04/30 18:40:53 DEBUG : Creating backend with remote "TestPikPak:rclone-test-gucamoj0noba" 2025/04/30 18:40:53 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/30 18:40:54 DEBUG : Creating backend with remote "/tmp/rclone3156987062" === RUN TestDirEntryModTimeInvalidation run.go:180: Remote "PikPak root 'rclone-test-gucamoj0noba'", Local "Local file system at /tmp/rclone3156987062", Modify Window "876000h0m0s" 2025/04/30 18:40:54 INFO : PikPak root 'rclone-test-gucamoj0noba': poll-interval is not supported by this remote 2025/04/30 18:40:54 NOTICE: PikPak root 'rclone-test-gucamoj0noba': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/04/30 18:40:56 DEBUG : dir/file1: calculating gcid: failed to unwrap object from src: dir/file1 2025/04/30 18:40:56 DEBUG : dir/file1: gcid = 3823e2b83a3ba8d1137efc1fe13e3a2e7cfb8d82 2025/04/30 18:40:57 DEBUG : dir: forgetting directory cache 2025/04/30 18:40:57 DEBUG : : forgetting directory cache 2025/04/30 18:40:57 DEBUG : dir: forgetting directory cache 2025/04/30 18:40:58 DEBUG : dir/file2: calculating gcid: failed to unwrap object from src: dir/file2 2025/04/30 18:40:58 DEBUG : dir/file2: gcid = 8f6e1023f7530ee92b8667061641e57f5c481570 dir_test.go:687: ModTime not invalidated 2025/04/30 18:40:59 DEBUG : WaitForWriters: timeout=30s 2025/04/30 18:40:59 DEBUG : dir: Looking for writers 2025/04/30 18:40:59 DEBUG : : Looking for writers 2025/04/30 18:40:59 DEBUG : dir: reading active writers 2025/04/30 18:40:59 DEBUG : >WaitForWriters: 2025/04/30 18:40:59 DEBUG : dir: forgetting directory cache 2025/04/30 18:40:59 DEBUG : : forgetting directory cache 2025/04/30 18:40:59 DEBUG : dir: forgetting directory cache 2025/04/30 18:41:02 DEBUG : dir: Rmdir: contains trashed file: "file2" 2025/04/30 18:41:02 DEBUG : dir: Rmdir: contains trashed file: "file1" 2025/04/30 18:41:04 DEBUG : Saving config "captcha_token" in section "TestPikPak" of the config file --- FAIL: TestDirEntryModTimeInvalidation (10.15s) === RUN TestFileReadAtNonZeroLength run.go:180: Remote "PikPak root 'rclone-test-gucamoj0noba'", Local "Local file system at /tmp/rclone3156987062", Modify Window "876000h0m0s" 2025/04/30 18:41:04 INFO : PikPak root 'rclone-test-gucamoj0noba': poll-interval is not supported by this remote 2025/04/30 18:41:04 NOTICE: PikPak root 'rclone-test-gucamoj0noba': --vfs-cache-mode writes or full is recommended for this remote as it can't stream 2025/04/30 18:41:04 DEBUG : file1: OpenFile: flags=O_WRONLY|O_CREATE, perm=-rwxrwxrwx 2025/04/30 18:41:05 DEBUG : file1: Open: flags=O_WRONLY|O_CREATE 2025/04/30 18:41:05 DEBUG : : Added virtual directory entry vAddFile: "file1" 2025/04/30 18:41:05 DEBUG : file1: >Open: fd=file1 (w), err= 2025/04/30 18:41:05 DEBUG : file1: >OpenFile: fd=file1 (w), err= 2025/04/30 18:41:05 DEBUG : : Added virtual directory entry vAddFile: "file1" 2025/04/30 18:41:05 DEBUG : PikPak root 'rclone-test-gucamoj0noba': File to upload is small (100 bytes), uploading instead of streaming 2025/04/30 18:41:05 DEBUG : file1: calculating gcid: failed to unwrap object from src: file1 2025/04/30 18:41:05 DEBUG : file1: gcid = db398280325099f7c2bcc2ceea7c919f5fc52a02 2025/04/30 18:41:07 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/04/30 18:41:07 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2025/04/30 18:41:08 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/04/30 18:41:08 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2025/04/30 18:41:08 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/04/30 18:41:08 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2025/04/30 18:41:08 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/04/30 18:41:08 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2025/04/30 18:41:09 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/04/30 18:41:09 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/04/30 18:41:11 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/04/30 18:41:13 DEBUG : pacer: Reducing sleep to 1.5s 2025/04/30 18:41:13 DEBUG : file1: Dst hash empty - aborting Src hash check 2025/04/30 18:41:13 DEBUG : file1: Size of src and dst objects identical 2025/04/30 18:41:13 DEBUG : : Added virtual directory entry vAddFile: "file1" 2025/04/30 18:41:13 DEBUG : file1: OpenFile: flags=O_RDONLY, perm=---------- 2025/04/30 18:41:13 DEBUG : file1: Open: flags=O_RDONLY 2025/04/30 18:41:13 DEBUG : file1: >Open: fd=file1 (r), err= 2025/04/30 18:41:13 DEBUG : file1: >OpenFile: fd=file1 (r), err= 2025/04/30 18:41:13 DEBUG : file1: ChunkedReader.openRange at 0 length 134217728 2025/04/30 18:41:15 DEBUG : pacer: low level retry 1/10 (error no link) 2025/04/30 18:41:15 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/04/30 18:41:16 DEBUG : pacer: low level retry 2/10 (error no link) 2025/04/30 18:41:18 DEBUG : pacer: low level retry 3/10 (error no link) 2025/04/30 18:41:20 DEBUG : pacer: low level retry 4/10 (error no link) 2025/04/30 18:41:22 DEBUG : pacer: low level retry 5/10 (error no link) 2025/04/30 18:41:24 DEBUG : pacer: low level retry 6/10 (error no link) 2025/04/30 18:41:26 DEBUG : pacer: low level retry 7/10 (error no link) 2025/04/30 18:41:28 DEBUG : pacer: low level retry 8/10 (error no link) 2025/04/30 18:41:30 DEBUG : pacer: low level retry 9/10 (error no link) 2025/04/30 18:41:32 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{0x68, 0x61, 0x71, 0x65, 0x77, 0x6f, 0x63, 0x31, 0x77, 0x75, 0x6c, 0x75, 0x76, 0x6f, 0x71, 0x30, 0x77, 0x65, 0x68, 0x75, 0x78, 0x61, 0x6b, 0x30, 0x73, 0x75, 0x66, 0x61, 0x70, 0x75, 0x78, 0x31, 0x77, 0x65, 0x6c, 0x75, 0x70, 0x75, 0x6d, 0x39, 0x79, 0x61, 0x79, 0x6f, 0x63, 0x75, 0x76, 0x37, 0x63, 0x65, 0x68, 0x61, 0x7a, 0x69, 0x64, 0x31, 0x73, 0x61, 0x70, 0x75, 0x79, 0x69, 0x6d, 0x38, 0x7a, 0x75, 0x74, 0x6f, 0x6c, 0x61, 0x64, 0x32, 0x64, 0x6f, 0x74, 0x69, 0x6e, 0x6f, 0x77, 0x35, 0x67, 0x75, 0x66, 0x65, 0x67, 0x65, 0x64, 0x39, 0x71, 0x75, 0x67, 0x61, 0x72, 0x69, 0x72, 0x39, 0x6e, 0x69, 0x72, 0x6f} actual : []byte{} Diff: --- Expected +++ Actual @@ -1,9 +1,2 @@ -([]uint8) (len=100) { - 00000000 68 61 71 65 77 6f 63 31 77 75 6c 75 76 6f 71 30 |haqewoc1wuluvoq0| - 00000010 77 65 68 75 78 61 6b 30 73 75 66 61 70 75 78 31 |wehuxak0sufapux1| - 00000020 77 65 6c 75 70 75 6d 39 79 61 79 6f 63 75 76 37 |welupum9yayocuv7| - 00000030 63 65 68 61 7a 69 64 31 73 61 70 75 79 69 6d 38 |cehazid1sapuyim8| - 00000040 7a 75 74 6f 6c 61 64 32 64 6f 74 69 6e 6f 77 35 |zutolad2dotinow5| - 00000050 67 75 66 65 67 65 64 39 71 75 67 61 72 69 72 39 |gufeged9qugarir9| - 00000060 6e 69 72 6f |niro| +([]uint8) { } Test: TestFileReadAtNonZeroLength 2025/04/30 18:41:32 DEBUG : WaitForWriters: timeout=30s 2025/04/30 18:41:32 DEBUG : : Looking for writers 2025/04/30 18:41:32 DEBUG : file1: reading active writers 2025/04/30 18:41:32 DEBUG : >WaitForWriters: 2025/04/30 18:41:34 DEBUG : pacer: Reducing sleep to 1.5s 2025/04/30 18:41:36 DEBUG : pacer: Reducing sleep to 1.125s 2025/04/30 18:41:38 DEBUG : pacer: Reducing sleep to 843.75ms 2025/04/30 18:41:39 DEBUG : pacer: Reducing sleep to 632.8125ms --- FAIL: TestFileReadAtNonZeroLength (34.46s) FAIL 2025/04/30 18:41:39 DEBUG : PikPak root 'rclone-test-gucamoj0noba': Purge remote 2025/04/30 18:41:40 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/04/30 18:41:40 DEBUG : pacer: Reducing sleep to 355.957031ms "./vfs.test -test.v -test.timeout 1h0m0s -remote TestPikPak: -verbose -test.run '^(TestDirEntryModTimeInvalidation|TestFileReadAtNonZeroLength)$'" - Finished ERROR in 47.693610043s (try 3/5): exit status 1: Failed [TestDirEntryModTimeInvalidation TestFileReadAtNonZeroLength]