"./operations.test -test.v -test.timeout 1h0m0s -remote TestPikPak: -verbose -test.run '^(TestCat|TestCheckSumDownload|TestParseSumFile)$|^TestHashSums$/^Md5Download$'" - Starting (try 2/5) 2025/08/24 03:38:43 DEBUG : Creating backend with remote "TestPikPak:rclone-test-biwahip7seci" 2025/08/24 03:38:43 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/08/24 03:38:44 DEBUG : Creating backend with remote "/tmp/rclone4051350482" === RUN TestParseSumFile run.go:180: Remote "PikPak root 'rclone-test-biwahip7seci'", Local "Local file system at /tmp/rclone4051350482", Modify Window "876000h0m0s" 2025/08/24 03:38:45 DEBUG : test.sum: calculating gcid: failed to unwrap object from src: test.sum 2025/08/24 03:38:45 DEBUG : test.sum: gcid = 7a6c4fea12fa7bf66997c8b984733019679b2f9f 2025/08/24 03:38:53 DEBUG : pacer: low level retry 1/10 (error no link) 2025/08/24 03:38:53 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2025/08/24 03:38:59 DEBUG : pacer: low level retry 2/10 (error no link) 2025/08/24 03:38:59 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2025/08/24 03:39:06 DEBUG : pacer: low level retry 3/10 (error no link) 2025/08/24 03:39:06 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2025/08/24 03:39:12 DEBUG : pacer: low level retry 4/10 (error no link) 2025/08/24 03:39:12 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2025/08/24 03:39:18 DEBUG : pacer: low level retry 5/10 (error no link) 2025/08/24 03:39:18 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/08/24 03:39:24 DEBUG : pacer: low level retry 6/10 (error no link) 2025/08/24 03:39:31 DEBUG : pacer: low level retry 7/10 (error no link) 2025/08/24 03:39:31 DEBUG : pacer: Reducing sleep to 1.5s 2025/08/24 03:39:34 DEBUG : pacer: Reducing sleep to 1.125s 2025/08/24 03:39:34 NOTICE: test.sum: improperly formatted checksum line 4 2025/08/24 03:39:34 NOTICE: test.sum: improperly formatted checksum line 5 2025/08/24 03:39:34 NOTICE: test.sum: improperly formatted checksum line 6 2025/08/24 03:39:34 NOTICE: test.sum: 2 warning(s) suppressed... 2025/08/24 03:39:35 DEBUG : pacer: Reducing sleep to 843.75ms 2025/08/24 03:39:35 DEBUG : test.sum: calculating gcid: failed to unwrap object from src: test.sum 2025/08/24 03:39:35 DEBUG : test.sum: gcid = bc9d7ca23a449ced8d5f88b9712e89097981d783 2025/08/24 03:39:37 DEBUG : pacer: Reducing sleep to 632.8125ms 2025/08/24 03:39:37 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/08/24 03:39:38 DEBUG : pacer: Reducing sleep to 355.957031ms 2025/08/24 03:39:38 DEBUG : pacer: Reducing sleep to 266.967773ms 2025/08/24 03:39:39 DEBUG : pacer: Reducing sleep to 200.225829ms 2025/08/24 03:39:45 DEBUG : pacer: low level retry 1/10 (error no link) 2025/08/24 03:39:45 DEBUG : pacer: Rate limited, increasing sleep to 400.451658ms 2025/08/24 03:39:51 DEBUG : pacer: low level retry 2/10 (error no link) 2025/08/24 03:39:51 DEBUG : pacer: Rate limited, increasing sleep to 800.903316ms 2025/08/24 03:39:58 DEBUG : pacer: low level retry 3/10 (error no link) 2025/08/24 03:39:58 DEBUG : pacer: Rate limited, increasing sleep to 1.601806632s 2025/08/24 03:40:04 DEBUG : pacer: low level retry 4/10 (error no link) 2025/08/24 03:40:04 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/08/24 03:40:10 DEBUG : pacer: low level retry 5/10 (error no link) 2025/08/24 03:40:16 DEBUG : pacer: low level retry 6/10 (error no link) 2025/08/24 03:40:23 DEBUG : pacer: low level retry 7/10 (error no link) 2025/08/24 03:40:29 DEBUG : pacer: low level retry 8/10 (error no link) 2025/08/24 03:40:35 DEBUG : pacer: low level retry 9/10 (error no link) 2025/08/24 03:40:42 DEBUG : pacer: low level retry 10/10 (error no link) check_test.go:311: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:311 Error: Received unexpected error: can't download: no link Test: TestParseSumFile check_test.go:313: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:313 Error: Not equal: expected: 4 actual : 0 Test: TestParseSumFile check_test.go:316: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:316 Error: Not equal: expected: "1" actual : "" Diff: --- Expected +++ Actual @@ -1 +1 @@ -1 + Test: TestParseSumFile check_test.go:316: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:316 Error: Not equal: expected: "2" actual : "" Diff: --- Expected +++ Actual @@ -1 +1 @@ -2 + Test: TestParseSumFile check_test.go:316: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:316 Error: Not equal: expected: "3" actual : "" Diff: --- Expected +++ Actual @@ -1 +1 @@ -3 + Test: TestParseSumFile check_test.go:316: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:316 Error: Not equal: expected: "4" actual : "" Diff: --- Expected +++ Actual @@ -1 +1 @@ -4 + Test: TestParseSumFile 2025/08/24 03:40:42 DEBUG : pacer: Reducing sleep to 1.5s 2025/08/24 03:40:44 DEBUG : pacer: Reducing sleep to 1.125s 2025/08/24 03:40:45 DEBUG : pacer: Reducing sleep to 843.75ms 2025/08/24 03:40:47 DEBUG : pacer: Reducing sleep to 632.8125ms --- FAIL: TestParseSumFile (122.35s) === RUN TestCheckSumDownload run.go:180: Remote "PikPak root 'rclone-test-biwahip7seci'", Local "Local file system at /tmp/rclone4051350482", Modify Window "876000h0m0s" 2025/08/24 03:40:47 DEBUG : Creating backend with remote "TestPikPak:rclone-test-biwahip7seci/data" 2025/08/24 03:40:49 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/08/24 03:40:49 DEBUG : pacer: Reducing sleep to 355.957031ms 2025/08/24 03:40:50 DEBUG : pacer: Reducing sleep to 266.967773ms 2025/08/24 03:40:50 DEBUG : data/banana: calculating gcid: failed to unwrap object from src: data/banana 2025/08/24 03:40:50 DEBUG : data/banana: gcid = 5a20dd2421f633d21da85b8911f9f37677f212d5 2025/08/24 03:40:51 DEBUG : pacer: Reducing sleep to 200.225829ms 2025/08/24 03:40:52 DEBUG : pacer: Reducing sleep to 150.169371ms 2025/08/24 03:40:52 DEBUG : test.sum: calculating gcid: failed to unwrap object from src: test.sum 2025/08/24 03:40:52 DEBUG : test.sum: gcid = a5968cd7981dde739b5ed764a5ed354ef42c42b2 2025/08/24 03:40:53 DEBUG : pacer: Reducing sleep to 112.627028ms 2025/08/24 03:40:53 DEBUG : pacer: Reducing sleep to 100ms === RUN TestCheckSumDownload/subtest1 === NAME TestCheckSumDownload check_test.go:404: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:404 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Received unexpected error: failed to parse sum file: can't download: no link Test: TestCheckSumDownload Messages: unexpected error in run 1 check_test.go:413: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:413 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: "" does not contain "matching files" Test: TestCheckSumDownload Messages: missing matching files in run 1 check_test.go:415: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:415 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Not equal: expected: 1 actual : 0 Test: TestCheckSumDownload Messages: wrong number of checks in run 1 check_test.go:384: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:384 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:417 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Not equal: expected: []string{"", "= banana"} actual : []string{} Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=2) { - (string) "", - (string) (len=8) "= banana" +([]string) { } Test: TestCheckSumDownload Messages: wrong combined result in run 1 check_test.go:384: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:384 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:420 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Not equal: expected: []string{"", "banana"} actual : []string{} Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=2) { - (string) "", - (string) (len=6) "banana" +([]string) { } Test: TestCheckSumDownload Messages: wrong match result in run 1 2025/08/24 03:41:57 DEBUG : pacer: Reducing sleep to 1.5s 2025/08/24 03:41:57 DEBUG : data/potato: calculating gcid: failed to unwrap object from src: data/potato 2025/08/24 03:41:57 DEBUG : data/potato: gcid = 7a3c15f717358c93392def5ff0639db84c0d363b 2025/08/24 03:42:00 DEBUG : pacer: Reducing sleep to 1.125s 2025/08/24 03:42:00 DEBUG : pacer: Reducing sleep to 843.75ms 2025/08/24 03:42:00 DEBUG : test.sum: calculating gcid: failed to unwrap object from src: test.sum 2025/08/24 03:42:00 DEBUG : test.sum: gcid = a5968cd7981dde739b5ed764a5ed354ef42c42b2 2025/08/24 03:42:03 DEBUG : pacer: Reducing sleep to 632.8125ms 2025/08/24 03:42:03 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/08/24 03:42:04 DEBUG : pacer: Reducing sleep to 355.957031ms 2025/08/24 03:42:04 DEBUG : pacer: Reducing sleep to 266.967773ms 2025/08/24 03:42:04 DEBUG : pacer: Reducing sleep to 200.225829ms 2025/08/24 03:42:05 DEBUG : pacer: Reducing sleep to 150.169371ms === RUN TestCheckSumDownload/subtest2 === NAME TestCheckSumDownload check_test.go:409: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:409 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Not equal: expected: 1 actual : 0 Test: TestCheckSumDownload Messages: wrong error count in run 2 check_test.go:413: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:413 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: "" does not contain "matching files" Test: TestCheckSumDownload Messages: missing matching files in run 2 check_test.go:415: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:415 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Not equal: expected: 2 actual : 0 Test: TestCheckSumDownload Messages: wrong number of checks in run 2 check_test.go:384: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:384 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:417 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Not equal: expected: []string{"", "- potato", "= banana"} actual : []string{} Diff: --- Expected +++ Actual @@ -1,5 +1,2 @@ -([]string) (len=3) { - (string) "", - (string) (len=8) "- potato", - (string) (len=8) "= banana" +([]string) { } Test: TestCheckSumDownload Messages: wrong combined result in run 2 check_test.go:384: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:384 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:418 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Not equal: expected: []string{"", "potato"} actual : []string{} Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=2) { - (string) "", - (string) (len=6) "potato" +([]string) { } Test: TestCheckSumDownload Messages: wrong missingonsrc result in run 2 check_test.go:384: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:384 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:420 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Not equal: expected: []string{"", "banana"} actual : []string{} Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=2) { - (string) "", - (string) (len=6) "banana" +([]string) { } Test: TestCheckSumDownload Messages: wrong match result in run 2 2025/08/24 03:43:09 DEBUG : pacer: Reducing sleep to 1.5s 2025/08/24 03:43:09 DEBUG : test.sum: calculating gcid: failed to unwrap object from src: test.sum 2025/08/24 03:43:09 DEBUG : test.sum: gcid = f3a0ff69df1baee079fa197e53142fe40231e82b 2025/08/24 03:43:12 DEBUG : pacer: Reducing sleep to 1.125s 2025/08/24 03:43:13 DEBUG : pacer: Reducing sleep to 843.75ms 2025/08/24 03:43:14 DEBUG : pacer: Reducing sleep to 632.8125ms 2025/08/24 03:43:15 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/08/24 03:43:15 DEBUG : pacer: Reducing sleep to 355.957031ms 2025/08/24 03:43:16 DEBUG : pacer: Reducing sleep to 266.967773ms === RUN TestCheckSumDownload/subtest3 2025/08/24 03:45:07 DEBUG : pacer: Reducing sleep to 843.75ms 2025/08/24 03:45:07 DEBUG : test.sum: calculating gcid: failed to unwrap object from src: test.sum 2025/08/24 03:45:07 DEBUG : test.sum: gcid = 4432a75a15f9e866fc8b0361de0580e4ab920bea 2025/08/24 03:45:08 DEBUG : pacer: Reducing sleep to 632.8125ms 2025/08/24 03:45:09 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/08/24 03:45:09 DEBUG : pacer: Reducing sleep to 355.957031ms 2025/08/24 03:45:10 DEBUG : pacer: Reducing sleep to 266.967773ms 2025/08/24 03:45:10 DEBUG : pacer: Reducing sleep to 200.225829ms 2025/08/24 03:45:11 DEBUG : pacer: Reducing sleep to 150.169371ms === RUN TestCheckSumDownload/subtest4 === NAME TestCheckSumDownload check_test.go:407: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:407 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: An error is expected but got nil. Test: TestCheckSumDownload Messages: no expected error in run 4 check_test.go:384: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:384 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:417 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Not equal: expected: []string{"", "* banana", "= potato"} actual : []string{"", "! banana", "= potato"} Diff: --- Expected +++ Actual @@ -2,3 +2,3 @@ (string) "", - (string) (len=8) "* banana", + (string) (len=8) "! banana", (string) (len=8) "= potato" Test: TestCheckSumDownload Messages: wrong combined result in run 4 check_test.go:384: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:384 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:421 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Not equal: expected: []string{"", "banana"} actual : []string{} Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=2) { - (string) "", - (string) (len=6) "banana" +([]string) { } Test: TestCheckSumDownload Messages: wrong differ result in run 4 check_test.go:384: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:384 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:422 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Not equal: expected: []string{} actual : []string{"", "banana"} Diff: --- Expected +++ Actual @@ -1,2 +1,4 @@ -([]string) { +([]string) (len=2) { + (string) "", + (string) (len=6) "banana" } Test: TestCheckSumDownload Messages: wrong error result in run 4 2025/08/24 03:46:51 DEBUG : pacer: Reducing sleep to 843.75ms 2025/08/24 03:46:51 DEBUG : test.sum: calculating gcid: failed to unwrap object from src: test.sum 2025/08/24 03:46:51 DEBUG : test.sum: gcid = c2c6d29ce2f4e1f6e3e830802ef4a15c32af89c4 2025/08/24 03:46:52 DEBUG : pacer: Reducing sleep to 632.8125ms 2025/08/24 03:46:52 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/08/24 03:46:53 DEBUG : pacer: Reducing sleep to 355.957031ms 2025/08/24 03:46:54 DEBUG : pacer: Reducing sleep to 266.967773ms 2025/08/24 03:46:54 DEBUG : pacer: Reducing sleep to 200.225829ms 2025/08/24 03:46:54 DEBUG : pacer: Reducing sleep to 150.169371ms === RUN TestCheckSumDownload/subtest5 2025/08/24 03:47:59 DEBUG : Saving config "captcha_token" in section "TestPikPak" of the config file 2025/08/24 03:47:59 DEBUG : pacer: Reducing sleep to 100ms 2025/08/24 03:47:59 DEBUG : test.sum: calculating gcid: failed to unwrap object from src: test.sum 2025/08/24 03:47:59 DEBUG : test.sum: gcid = 903d92580da389428c3eace6c6dce692463e75e8 === RUN TestCheckSumDownload/subtest6 === NAME TestCheckSumDownload check_test.go:409: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:409 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Not equal: expected: 2 actual : 3 Test: TestCheckSumDownload Messages: wrong error count in run 6 check_test.go:413: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:413 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: "2025/08/24 03:49:36 ERROR : banana: Failed to calculate hash: can't download: no link\n2025/08/24 03:49:38 ERROR : potato: Failed to calculate hash: can't download: no link\n2025/08/24 03:49:38 ERROR : orange: file not in PikPak root 'rclone-test-biwahip7seci/data'\n2025/08/24 03:49:38 NOTICE: PikPak root 'rclone-test-biwahip7seci/data': 1 files missing\n2025/08/24 03:49:38 NOTICE: PikPak root 'rclone-test-biwahip7seci/data': 0 differences found\n2025/08/24 03:49:38 NOTICE: PikPak root 'rclone-test-biwahip7seci/data': 3 errors while checking\n" does not contain "matching files" Test: TestCheckSumDownload Messages: missing matching files in run 6 check_test.go:384: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:384 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:417 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Not equal: expected: []string{"", "* potato", "+ orange", "= banana"} actual : []string{"", "! banana", "! potato", "+ orange"} Diff: --- Expected +++ Actual @@ -2,5 +2,5 @@ (string) "", - (string) (len=8) "* potato", - (string) (len=8) "+ orange", - (string) (len=8) "= banana" + (string) (len=8) "! banana", + (string) (len=8) "! potato", + (string) (len=8) "+ orange" } Test: TestCheckSumDownload Messages: wrong combined result in run 6 check_test.go:384: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:384 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:420 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Not equal: expected: []string{"", "banana"} actual : []string{} Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=2) { - (string) "", - (string) (len=6) "banana" +([]string) { } Test: TestCheckSumDownload Messages: wrong match result in run 6 check_test.go:384: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:384 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:421 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Not equal: expected: []string{"", "potato"} actual : []string{} Diff: --- Expected +++ Actual @@ -1,4 +1,2 @@ -([]string) (len=2) { - (string) "", - (string) (len=6) "potato" +([]string) { } Test: TestCheckSumDownload Messages: wrong differ result in run 6 check_test.go:384: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:384 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:422 /home/rclone/go/src/github.com/rclone/rclone/fs/operations/check_test.go:428 Error: Not equal: expected: []string{} actual : []string{"", "banana", "potato"} Diff: --- Expected +++ Actual @@ -1,2 +1,5 @@ -([]string) { +([]string) (len=3) { + (string) "", + (string) (len=6) "banana", + (string) (len=6) "potato" } Test: TestCheckSumDownload Messages: wrong error result in run 6 2025/08/24 03:49:39 DEBUG : pacer: Reducing sleep to 675ms 2025/08/24 03:49:39 DEBUG : data/banana: calculating gcid: failed to unwrap object from src: data/banana 2025/08/24 03:49:39 DEBUG : data/banana: gcid = 5a20dd2421f633d21da85b8911f9f37677f212d5 2025/08/24 03:49:41 DEBUG : pacer: Reducing sleep to 506.25ms 2025/08/24 03:49:41 DEBUG : pacer: Reducing sleep to 379.6875ms 2025/08/24 03:49:42 DEBUG : pacer: Reducing sleep to 284.765625ms 2025/08/24 03:49:42 DEBUG : pacer: Reducing sleep to 213.574218ms 2025/08/24 03:49:42 DEBUG : pacer: Reducing sleep to 160.180663ms 2025/08/24 03:49:42 DEBUG : data/potato: calculating gcid: failed to unwrap object from src: data/potato 2025/08/24 03:49:42 DEBUG : data/potato: gcid = 7a3c15f717358c93392def5ff0639db84c0d363b 2025/08/24 03:49:44 DEBUG : pacer: Reducing sleep to 120.135497ms 2025/08/24 03:49:44 DEBUG : pacer: Reducing sleep to 100ms 2025/08/24 03:49:45 DEBUG : test.sum: calculating gcid: failed to unwrap object from src: test.sum 2025/08/24 03:49:45 DEBUG : test.sum: gcid = 551b7ddca65803810ea668343a66646180a0c0b7 === RUN TestCheckSumDownload/subtest7 2025/08/24 03:51:03 DEBUG : pacer: Reducing sleep to 100ms 2025/08/24 03:51:07 DEBUG : data: Rmdir: contains trashed file: "potato" 2025/08/24 03:51:07 DEBUG : data: Rmdir: contains trashed file: "banana" 2025/08/24 03:51:07 DEBUG : data: Rmdir: contains trashed file: "potato" 2025/08/24 03:51:07 DEBUG : data: Rmdir: contains trashed file: "banana" --- FAIL: TestCheckSumDownload (621.72s) --- PASS: TestCheckSumDownload/subtest1 (63.22s) --- PASS: TestCheckSumDownload/subtest2 (64.37s) --- PASS: TestCheckSumDownload/subtest3 (109.95s) --- PASS: TestCheckSumDownload/subtest4 (99.09s) --- PASS: TestCheckSumDownload/subtest5 (63.68s) --- PASS: TestCheckSumDownload/subtest6 (95.45s) --- PASS: TestCheckSumDownload/subtest7 (73.80s) === RUN TestHashSums run.go:180: Remote "PikPak root 'rclone-test-biwahip7seci'", Local "Local file system at /tmp/rclone4051350482", Modify Window "876000h0m0s" 2025/08/24 03:51:09 DEBUG : potato2: calculating gcid: failed to unwrap object from src: potato2 2025/08/24 03:51:09 DEBUG : potato2: gcid = f284ca644cf64403b777451495ca659cc12415af 2025/08/24 03:51:10 DEBUG : empty space: calculating gcid: failed to unwrap object from src: empty space 2025/08/24 03:51:10 DEBUG : empty space: gcid = 09f49478af9c899f0e74bf1a8e2ec667345a178b === RUN TestHashSums/Md5Download 2025/08/24 03:51:18 DEBUG : pacer: low level retry 1/10 (error no link) 2025/08/24 03:51:18 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2025/08/24 03:51:18 DEBUG : pacer: low level retry 1/10 (error no link) 2025/08/24 03:51:18 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2025/08/24 03:51:25 DEBUG : pacer: low level retry 2/10 (error no link) 2025/08/24 03:51:25 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2025/08/24 03:51:25 DEBUG : pacer: low level retry 2/10 (error no link) 2025/08/24 03:51:25 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2025/08/24 03:51:31 DEBUG : pacer: low level retry 3/10 (error no link) 2025/08/24 03:51:31 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/08/24 03:51:32 DEBUG : pacer: low level retry 3/10 (error no link) 2025/08/24 03:51:37 DEBUG : pacer: low level retry 4/10 (error no link) 2025/08/24 03:51:39 DEBUG : pacer: low level retry 4/10 (error no link) 2025/08/24 03:51:44 DEBUG : pacer: low level retry 5/10 (error no link) 2025/08/24 03:51:46 DEBUG : pacer: low level retry 5/10 (error no link) 2025/08/24 03:51:50 DEBUG : pacer: low level retry 6/10 (error no link) 2025/08/24 03:51:52 DEBUG : pacer: low level retry 6/10 (error no link) 2025/08/24 03:51:56 DEBUG : pacer: low level retry 7/10 (error no link) 2025/08/24 03:51:58 DEBUG : pacer: low level retry 7/10 (error no link) 2025/08/24 03:51:59 DEBUG : pacer: Reducing sleep to 1.5s 2025/08/24 03:52:01 DEBUG : pacer: Reducing sleep to 1.125s 2025/08/24 03:52:02 DEBUG : pacer: low level retry 8/10 (error no link) 2025/08/24 03:52:02 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/08/24 03:52:03 DEBUG : pacer: Reducing sleep to 1.5s 2025/08/24 03:52:06 DEBUG : pacer: Reducing sleep to 1.125s 2025/08/24 03:52:06 DEBUG : pacer: Reducing sleep to 843.75ms 2025/08/24 03:52:07 DEBUG : pacer: Reducing sleep to 632.8125ms 2025/08/24 03:52:08 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/08/24 03:52:09 DEBUG : pacer: Reducing sleep to 355.957031ms 2025/08/24 03:52:10 DEBUG : pacer: Reducing sleep to 266.967773ms 2025/08/24 03:52:10 DEBUG : pacer: Reducing sleep to 200.225829ms --- PASS: TestHashSums (61.64s) --- PASS: TestHashSums/Md5Download (53.94s) === RUN TestCat run.go:180: Remote "PikPak root 'rclone-test-biwahip7seci'", Local "Local file system at /tmp/rclone4051350482", Modify Window "876000h0m0s" 2025/08/24 03:52:10 DEBUG : pacer: Reducing sleep to 150.169371ms 2025/08/24 03:52:10 DEBUG : file1: calculating gcid: failed to unwrap object from src: file1 2025/08/24 03:52:10 DEBUG : file1: gcid = 4d8356ed1af6fd7e9537777328c6d176effe38a0 2025/08/24 03:52:11 DEBUG : pacer: Reducing sleep to 112.627028ms 2025/08/24 03:52:11 DEBUG : pacer: Reducing sleep to 100ms 2025/08/24 03:52:11 DEBUG : file2: calculating gcid: failed to unwrap object from src: file2 2025/08/24 03:52:11 DEBUG : file2: gcid = 9e3614f5e363b3d1060c1e4d6738e7c26804ae41 2025/08/24 03:52:19 DEBUG : pacer: low level retry 1/10 (error no link) 2025/08/24 03:52:19 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2025/08/24 03:52:25 DEBUG : pacer: low level retry 2/10 (error no link) 2025/08/24 03:52:25 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2025/08/24 03:52:26 DEBUG : pacer: Reducing sleep to 300ms 2025/08/24 03:52:27 DEBUG : pacer: Reducing sleep to 225ms 2025/08/24 03:52:33 DEBUG : pacer: low level retry 1/10 (error no link) 2025/08/24 03:52:33 DEBUG : pacer: Rate limited, increasing sleep to 450ms 2025/08/24 03:52:40 DEBUG : pacer: low level retry 2/10 (error no link) 2025/08/24 03:52:40 DEBUG : pacer: Rate limited, increasing sleep to 900ms 2025/08/24 03:52:46 DEBUG : pacer: low level retry 3/10 (error no link) 2025/08/24 03:52:46 DEBUG : pacer: Rate limited, increasing sleep to 1.8s 2025/08/24 03:52:52 DEBUG : pacer: low level retry 4/10 (error no link) 2025/08/24 03:52:52 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/08/24 03:52:53 DEBUG : Saving config "captcha_token" in section "TestPikPak" of the config file 2025/08/24 03:53:00 DEBUG : pacer: low level retry 5/10 (error no link) 2025/08/24 03:53:06 DEBUG : pacer: low level retry 6/10 (error no link) 2025/08/24 03:53:06 DEBUG : pacer: Reducing sleep to 1.5s 2025/08/24 03:53:09 DEBUG : pacer: Reducing sleep to 1.125s 2025/08/24 03:53:10 DEBUG : pacer: Reducing sleep to 843.75ms 2025/08/24 03:53:17 DEBUG : pacer: low level retry 1/10 (error no link) 2025/08/24 03:53:17 DEBUG : pacer: Rate limited, increasing sleep to 1.6875s 2025/08/24 03:53:23 DEBUG : pacer: low level retry 2/10 (error no link) 2025/08/24 03:53:23 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/08/24 03:53:29 DEBUG : pacer: low level retry 3/10 (error no link) 2025/08/24 03:53:36 DEBUG : pacer: low level retry 4/10 (error no link) 2025/08/24 03:53:42 DEBUG : pacer: low level retry 5/10 (error no link) 2025/08/24 03:53:48 DEBUG : pacer: low level retry 6/10 (error no link) 2025/08/24 03:53:55 DEBUG : pacer: low level retry 7/10 (error no link) 2025/08/24 03:54:01 DEBUG : pacer: low level retry 8/10 (error no link) 2025/08/24 03:54:07 DEBUG : pacer: low level retry 9/10 (error no link) 2025/08/24 03:54:14 DEBUG : pacer: low level retry 10/10 (error no link) 2025/08/24 03:54:14 ERROR : file1: Failed to open: can't download: no link 2025/08/24 03:54:20 DEBUG : pacer: low level retry 1/10 (error no link) 2025/08/24 03:54:26 DEBUG : pacer: low level retry 2/10 (error no link) 2025/08/24 03:54:32 DEBUG : pacer: low level retry 3/10 (error no link) 2025/08/24 03:54:39 DEBUG : pacer: low level retry 4/10 (error no link) 2025/08/24 03:54:45 DEBUG : pacer: low level retry 5/10 (error no link) 2025/08/24 03:54:51 DEBUG : pacer: low level retry 6/10 (error no link) 2025/08/24 03:54:58 DEBUG : pacer: low level retry 7/10 (error no link) 2025/08/24 03:54:58 DEBUG : pacer: Reducing sleep to 1.5s 2025/08/24 03:55:00 DEBUG : pacer: Reducing sleep to 1.125s operations_test.go:566: Incorrect output from Cat(0,5,): "01234" 2025/08/24 03:55:01 DEBUG : pacer: Reducing sleep to 843.75ms 2025/08/24 03:55:09 DEBUG : pacer: low level retry 1/10 (error no link) 2025/08/24 03:55:09 DEBUG : pacer: Rate limited, increasing sleep to 1.6875s 2025/08/24 03:55:15 DEBUG : pacer: low level retry 2/10 (error no link) 2025/08/24 03:55:15 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/08/24 03:55:15 DEBUG : pacer: Reducing sleep to 1.5s 2025/08/24 03:55:18 DEBUG : pacer: Reducing sleep to 1.125s 2025/08/24 03:55:25 DEBUG : pacer: low level retry 1/10 (error no link) 2025/08/24 03:55:25 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/08/24 03:55:31 DEBUG : pacer: low level retry 2/10 (error no link) 2025/08/24 03:55:37 DEBUG : pacer: low level retry 3/10 (error no link) 2025/08/24 03:55:43 DEBUG : pacer: low level retry 4/10 (error no link) 2025/08/24 03:55:50 DEBUG : pacer: low level retry 5/10 (error no link) 2025/08/24 03:55:56 DEBUG : pacer: low level retry 6/10 (error no link) 2025/08/24 03:56:02 DEBUG : pacer: low level retry 7/10 (error no link) 2025/08/24 03:56:09 DEBUG : pacer: low level retry 8/10 (error no link) 2025/08/24 03:56:15 DEBUG : pacer: low level retry 9/10 (error no link) 2025/08/24 03:56:21 DEBUG : pacer: low level retry 10/10 (error no link) 2025/08/24 03:56:21 ERROR : file2: Failed to open: can't download: no link operations_test.go:566: Incorrect output from Cat(-3,-1,): "HIJ" 2025/08/24 03:56:22 DEBUG : pacer: Reducing sleep to 1.5s 2025/08/24 03:56:30 DEBUG : pacer: low level retry 1/10 (error no link) 2025/08/24 03:56:30 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/08/24 03:56:36 DEBUG : pacer: low level retry 2/10 (error no link) 2025/08/24 03:56:42 DEBUG : pacer: low level retry 3/10 (error no link) 2025/08/24 03:56:48 DEBUG : pacer: low level retry 4/10 (error no link) 2025/08/24 03:56:55 DEBUG : pacer: low level retry 5/10 (error no link) 2025/08/24 03:57:01 DEBUG : pacer: low level retry 6/10 (error no link) 2025/08/24 03:57:07 DEBUG : pacer: low level retry 7/10 (error no link) 2025/08/24 03:57:14 DEBUG : pacer: low level retry 8/10 (error no link) 2025/08/24 03:57:20 DEBUG : pacer: low level retry 9/10 (error no link) 2025/08/24 03:57:26 DEBUG : pacer: low level retry 10/10 (error no link) 2025/08/24 03:57:26 ERROR : file1: Failed to open: can't download: no link 2025/08/24 03:57:33 DEBUG : pacer: low level retry 1/10 (error no link) 2025/08/24 03:57:39 DEBUG : pacer: low level retry 2/10 (error no link) 2025/08/24 03:57:45 DEBUG : pacer: low level retry 3/10 (error no link) 2025/08/24 03:57:46 DEBUG : Saving config "captcha_token" in section "TestPikPak" of the config file 2025/08/24 03:57:52 DEBUG : pacer: low level retry 4/10 (error no link) 2025/08/24 03:57:59 DEBUG : pacer: low level retry 5/10 (error no link) 2025/08/24 03:58:05 DEBUG : pacer: low level retry 6/10 (error no link) 2025/08/24 03:58:11 DEBUG : pacer: low level retry 7/10 (error no link) 2025/08/24 03:58:12 DEBUG : pacer: Reducing sleep to 1.5s 2025/08/24 03:58:15 DEBUG : pacer: Reducing sleep to 1.125s operations_test.go:566: Incorrect output from Cat(1,3,): "123" 2025/08/24 03:58:15 DEBUG : pacer: Reducing sleep to 843.75ms 2025/08/24 03:58:22 DEBUG : pacer: low level retry 1/10 (error no link) 2025/08/24 03:58:22 DEBUG : pacer: Rate limited, increasing sleep to 1.6875s 2025/08/24 03:58:29 DEBUG : pacer: low level retry 2/10 (error no link) 2025/08/24 03:58:29 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/08/24 03:58:35 DEBUG : pacer: low level retry 3/10 (error no link) 2025/08/24 03:58:41 DEBUG : pacer: low level retry 4/10 (error no link) 2025/08/24 03:58:47 DEBUG : pacer: low level retry 5/10 (error no link) 2025/08/24 03:58:54 DEBUG : pacer: low level retry 6/10 (error no link) 2025/08/24 03:58:54 DEBUG : pacer: Reducing sleep to 1.5s 2025/08/24 03:58:57 DEBUG : pacer: Reducing sleep to 1.125s 2025/08/24 03:59:04 DEBUG : pacer: low level retry 1/10 (error no link) 2025/08/24 03:59:04 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/08/24 03:59:10 DEBUG : pacer: low level retry 2/10 (error no link) 2025/08/24 03:59:16 DEBUG : pacer: low level retry 3/10 (error no link) 2025/08/24 03:59:22 DEBUG : pacer: low level retry 4/10 (error no link) 2025/08/24 03:59:29 DEBUG : pacer: low level retry 5/10 (error no link) 2025/08/24 03:59:35 DEBUG : pacer: low level retry 6/10 (error no link) 2025/08/24 03:59:41 DEBUG : pacer: low level retry 7/10 (error no link) 2025/08/24 03:59:48 DEBUG : pacer: low level retry 8/10 (error no link) 2025/08/24 03:59:54 DEBUG : pacer: low level retry 9/10 (error no link) 2025/08/24 04:00:00 DEBUG : pacer: low level retry 10/10 (error no link) 2025/08/24 04:00:00 ERROR : file2: Failed to open: can't download: no link operations_test.go:566: Incorrect output from Cat(0,-1, ): "ABCDEFGHIJ\n" 2025/08/24 04:00:00 DEBUG : pacer: Reducing sleep to 1.5s 2025/08/24 04:00:02 DEBUG : pacer: Reducing sleep to 1.125s 2025/08/24 04:00:04 DEBUG : pacer: Reducing sleep to 843.75ms 2025/08/24 04:00:05 DEBUG : pacer: Reducing sleep to 632.8125ms 2025/08/24 04:00:06 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/08/24 04:00:07 DEBUG : pacer: Reducing sleep to 355.957031ms --- FAIL: TestCat (476.65s) FAIL 2025/08/24 04:00:07 DEBUG : PikPak root 'rclone-test-biwahip7seci': Purge remote 2025/08/24 04:00:07 DEBUG : pacer: Reducing sleep to 266.967773ms 2025/08/24 04:00:08 DEBUG : pacer: Reducing sleep to 200.225829ms "./operations.test -test.v -test.timeout 1h0m0s -remote TestPikPak: -verbose -test.run '^(TestCat|TestCheckSumDownload|TestParseSumFile)$|^TestHashSums$/^Md5Download$'" - Finished ERROR in 21m25.066774368s (try 2/5): exit status 1: Failed [TestParseSumFile TestCheckSumDownload TestCat]