"go test -v -timeout 1h0m0s -remote TestPikPak: -verbose" - Starting (try 1/5) === RUN TestIntegration fstests.go:442: Using remote "TestPikPak:" 2024/10/04 03:29:04 DEBUG : Creating backend with remote "TestPikPak:rclone-test-jitavup3pada" 2024/10/04 03:29:04 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2024/10/04 03:29:05 DEBUG : Saving config "captcha_token" in section "TestPikPak" of the config file === RUN TestIntegration/FsCheckWrap fstests.go:483: Not a wrapping Fs === RUN TestIntegration/FsCommand === RUN TestIntegration/FsRmdirNotFound === RUN TestIntegration/FsString === RUN TestIntegration/FsName === RUN TestIntegration/FsRoot === RUN TestIntegration/FsRmdirEmpty === RUN TestIntegration/FsMkdir === RUN TestIntegration/FsMkdir/FsMkdirRmdirSubdir 2024/10/04 03:29:08 DEBUG : dir/subdir: Making directory 2024/10/04 03:29:10 INFO : dir/subdir: Removing directory 2024/10/04 03:29:12 INFO : dir: Removing directory 2024/10/04 03:29:12 DEBUG : dir: Rmdir: contains trashed file: "subdir" === RUN TestIntegration/FsMkdir/FsListEmpty === RUN TestIntegration/FsMkdir/FsListDirEmpty === RUN TestIntegration/FsMkdir/FsListRDirEmpty fstests.go:403: FS has no ListR interface === RUN TestIntegration/FsMkdir/FsListDirNotFound 2024/10/04 03:29:14 ERROR : does not exist: error listing: directory not found === RUN TestIntegration/FsMkdir/FsListRDirNotFound fstests.go:403: FS has no ListR interface === RUN TestIntegration/FsMkdir/FsEncoding === RUN TestIntegration/FsMkdir/FsEncoding/control_chars fstests.go:711: testing "␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡" 2024/10/04 03:29:15 DEBUG : ␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡/␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡: calculating gcid: failed to unwrap object from src: ␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡/␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡ 2024/10/04 03:29:15 DEBUG : ␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡/␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡: gcid = e8a742ad1c44d908c3f1ae0f639e285c8ae94b33 2024/10/04 03:29:19 DEBUG : ␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡: Rmdir: contains trashed file: "␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡" === RUN TestIntegration/FsMkdir/FsEncoding/dot fstests.go:711: testing "." 2024/10/04 03:29:21 DEBUG : ./.: calculating gcid: failed to unwrap object from src: ./. 2024/10/04 03:29:21 DEBUG : ./.: gcid = 0aec493bb5fe64eb8bad71c48e175365e5724d65 2024/10/04 03:29:24 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:29:24 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/04 03:29:24 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:29:24 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/04 03:29:25 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:29:25 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/04 03:29:25 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:29:25 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/04 03:29:26 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:29:26 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/04 03:29:28 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/04 03:29:30 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/04 03:29:31 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/04 03:29:32 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/04 03:29:33 DEBUG : pacer: Reducing sleep to 474.609375ms 2024/10/04 03:29:34 DEBUG : pacer: Reducing sleep to 355.957031ms 2024/10/04 03:29:34 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/04 03:29:34 DEBUG : .: Rmdir: contains trashed file: "." 2024/10/04 03:29:35 DEBUG : pacer: Reducing sleep to 200.225829ms 2024/10/04 03:29:35 DEBUG : pacer: Reducing sleep to 150.169371ms 2024/10/04 03:29:36 DEBUG : pacer: Reducing sleep to 112.627028ms === RUN TestIntegration/FsMkdir/FsEncoding/dot_dot fstests.go:711: testing ".." 2024/10/04 03:29:36 DEBUG : pacer: Reducing sleep to 100ms 2024/10/04 03:29:36 DEBUG : ../..: calculating gcid: failed to unwrap object from src: ../.. 2024/10/04 03:29:36 DEBUG : ../..: gcid = 735ca8f83a938220989ca3b3000914b7fd777a24 2024/10/04 03:29:39 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:29:39 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/04 03:29:39 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:29:39 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/04 03:29:39 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:29:39 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/04 03:29:39 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:29:39 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/04 03:29:40 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:29:40 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/04 03:29:42 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/04 03:29:44 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/04 03:29:45 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/04 03:29:46 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/04 03:29:47 DEBUG : pacer: Reducing sleep to 474.609375ms 2024/10/04 03:29:48 DEBUG : pacer: Reducing sleep to 355.957031ms 2024/10/04 03:29:49 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/04 03:29:49 DEBUG : ..: Rmdir: contains trashed file: ".." 2024/10/04 03:29:49 DEBUG : pacer: Reducing sleep to 200.225829ms 2024/10/04 03:29:50 DEBUG : pacer: Reducing sleep to 150.169371ms 2024/10/04 03:29:50 DEBUG : pacer: Reducing sleep to 112.627028ms === RUN TestIntegration/FsMkdir/FsEncoding/punctuation fstests.go:711: testing "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~" 2024/10/04 03:29:50 DEBUG : pacer: Reducing sleep to 100ms 2024/10/04 03:29:51 DEBUG : !"#$%&'()*+,-./:;<=>?@[\]^_`{|}~/!"#$%&'()*+,-./:;<=>?@[\]^_`{|}~: calculating gcid: failed to unwrap object from src: !"#$%&'()*+,-./:;<=>?@[\]^_`{|}~/!"#$%&'()*+,-./:;<=>?@[\]^_`{|}~ 2024/10/04 03:29:51 DEBUG : !"#$%&'()*+,-./:;<=>?@[\]^_`{|}~/!"#$%&'()*+,-./:;<=>?@[\]^_`{|}~: gcid = 286663e6b67adc64559868eacf17844cd894e622 2024/10/04 03:29:53 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:29:53 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/04 03:29:53 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:29:53 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/04 03:29:54 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:29:54 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/04 03:29:54 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:29:54 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/04 03:29:55 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:29:55 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/04 03:29:56 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:29:58 DEBUG : pacer: low level retry 7/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:30:00 DEBUG : pacer: low level retry 8/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:30:02 DEBUG : pacer: low level retry 9/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:30:04 DEBUG : pacer: low level retry 10/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:30:04 DEBUG : !"#$%&'()*+,-./:;<=>?@[\]^_`{|}~: canceling upload: can't verify the task is completed: &api.Task{Kind:"drive#task", ID:"VO8KZu4NVDGucNN_axdjSk_go1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc000266dc0), FileID:"VO8KZu44VDGucNN_axdjSk_eo1", FileName:"!"#$%&'()*+,-./:;<=>?@[\]^_`{|}~", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x1ab3f000, ext:63863609391, loc:(*time.Location)(0xc00021cd90)}, UpdatedTime:api.Time{wall:0x1c12e3c0, ext:63863609391, loc:(*time.Location)(0xc00021cd90)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0ed033dfc7b3862af92a52ef7e3e4d257223df81", Callback:"", ReferenceResource:interface {}(nil), Space:""} 2024/10/04 03:30:06 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/04 03:30:08 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/04 03:30:10 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/04 03:30:10 DEBUG : !"#$%&'()*+,-./:;<=>?@[\]^_`{|}~: waiting 500ms for the cancellation to be effective fstests.go:145: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:145 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:161 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:223 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:213 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:717 Error: Received unexpected error: can't verify the task is completed: &api.Task{Kind:"drive#task", ID:"VO8KZu4NVDGucNN_axdjSk_go1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc000266dc0), FileID:"VO8KZu44VDGucNN_axdjSk_eo1", FileName:"!"#$%&'()*+,-./:;<=>?@[\]^_`{|}~", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x1ab3f000, ext:63863609391, loc:(*time.Location)(0xc00021cd90)}, UpdatedTime:api.Time{wall:0x1c12e3c0, ext:63863609391, loc:(*time.Location)(0xc00021cd90)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0ed033dfc7b3862af92a52ef7e3e4d257223df81", Callback:"", ReferenceResource:interface {}(nil), Space:""} Test: TestIntegration/FsMkdir/FsEncoding/punctuation Messages: Put === RUN TestIntegration/FsMkdir/FsEncoding/leading_space fstests.go:711: testing " leading space" 2024/10/04 03:30:11 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/04 03:30:12 DEBUG : pacer: Reducing sleep to 474.609375ms 2024/10/04 03:30:12 DEBUG : pacer: Reducing sleep to 355.957031ms 2024/10/04 03:30:12 DEBUG : leading space/ leading space: calculating gcid: failed to unwrap object from src: leading space/ leading space 2024/10/04 03:30:12 DEBUG : leading space/ leading space: gcid = e747497cf4fc7e3fef2f73b411ce03a54bac9eac 2024/10/04 03:30:13 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/04 03:30:15 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:30:15 DEBUG : pacer: Rate limited, increasing sleep to 533.935546ms 2024/10/04 03:30:15 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:30:15 DEBUG : pacer: Rate limited, increasing sleep to 1.067871092s 2024/10/04 03:30:16 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:30:16 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/04 03:30:17 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:30:19 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:30:21 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/04 03:30:23 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/04 03:30:24 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/04 03:30:26 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/04 03:30:26 DEBUG : pacer: Reducing sleep to 474.609375ms fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache 2024/10/04 03:30:28 DEBUG : pacer: Reducing sleep to 355.957031ms 2024/10/04 03:30:28 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/04 03:30:28 DEBUG : pacer: Reducing sleep to 200.225829ms 2024/10/04 03:30:29 DEBUG : pacer: Reducing sleep to 150.169371ms fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache 2024/10/04 03:30:31 DEBUG : pacer: Reducing sleep to 112.627028ms 2024/10/04 03:30:31 DEBUG : pacer: Reducing sleep to 100ms fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:718 Error: Not equal: expected: []string{" leading space"} actual : []string{" leading space", "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~"} Diff: --- Expected +++ Actual @@ -1,3 +1,4 @@ -([]string) (len=1) { - (string) (len=14) " leading space" +([]string) (len=2) { + (string) (len=14) " leading space", + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~" } Test: TestIntegration/FsMkdir/FsEncoding/leading_space Messages: directories 2024/10/04 03:30:38 DEBUG : leading space: Rmdir: contains trashed file: " leading space" fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:721 Error: Not equal: expected: []string{} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) { +([]string) (len=1) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~" } Test: TestIntegration/FsMkdir/FsEncoding/leading_space Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/leading_tilde fstests.go:711: testing "~leading tilde" 2024/10/04 03:30:49 DEBUG : ~leading tilde/~leading tilde: calculating gcid: failed to unwrap object from src: ~leading tilde/~leading tilde 2024/10/04 03:30:49 DEBUG : ~leading tilde/~leading tilde: gcid = 93baa844e594fdc734ea51ac7d8f9e9790664b0f fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:718 Error: Not equal: expected: []string{"~leading tilde"} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "~leading tilde"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) (len=1) { +([]string) (len=2) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", (string) (len=14) "~leading tilde" Test: TestIntegration/FsMkdir/FsEncoding/leading_tilde Messages: directories 2024/10/04 03:31:03 DEBUG : ~leading tilde: Rmdir: contains trashed file: "~leading tilde" fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:721 Error: Not equal: expected: []string{} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) { +([]string) (len=1) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~" } Test: TestIntegration/FsMkdir/FsEncoding/leading_tilde Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/leading_CR fstests.go:711: testing "␍leading CR" 2024/10/04 03:31:15 DEBUG : ␍leading CR/␍leading CR: calculating gcid: failed to unwrap object from src: ␍leading CR/␍leading CR 2024/10/04 03:31:15 DEBUG : ␍leading CR/␍leading CR: gcid = f1361f52132d13b6aed4983bb01f6491e8236acc fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:718 Error: Not equal: expected: []string{"␍leading CR"} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "␍leading CR"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) (len=1) { +([]string) (len=2) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", (string) (len=13) "␍leading CR" Test: TestIntegration/FsMkdir/FsEncoding/leading_CR Messages: directories 2024/10/04 03:31:30 DEBUG : ␍leading CR: Rmdir: contains trashed file: "␍leading CR" fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:721 Error: Not equal: expected: []string{} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) { +([]string) (len=1) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~" } Test: TestIntegration/FsMkdir/FsEncoding/leading_CR Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/leading_LF fstests.go:711: testing "␊leading LF" 2024/10/04 03:31:41 DEBUG : ␊leading LF/␊leading LF: calculating gcid: failed to unwrap object from src: ␊leading LF/␊leading LF 2024/10/04 03:31:41 DEBUG : ␊leading LF/␊leading LF: gcid = 5191b014ac0fbce5c6433a10a83e33fce6f583a7 2024/10/04 03:31:43 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:31:43 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/04 03:31:43 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:31:43 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/04 03:31:43 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:31:43 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/04 03:31:44 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:31:44 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/04 03:31:45 DEBUG : pacer: Reducing sleep to 1.2s 2024/10/04 03:31:46 DEBUG : pacer: Reducing sleep to 900ms 2024/10/04 03:31:48 DEBUG : pacer: Reducing sleep to 675ms 2024/10/04 03:31:48 DEBUG : pacer: Reducing sleep to 506.25ms 2024/10/04 03:31:49 DEBUG : pacer: Reducing sleep to 379.6875ms fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache 2024/10/04 03:31:50 DEBUG : pacer: Reducing sleep to 284.765625ms 2024/10/04 03:31:51 DEBUG : pacer: Reducing sleep to 213.574218ms 2024/10/04 03:31:51 DEBUG : pacer: Reducing sleep to 160.180663ms 2024/10/04 03:31:52 DEBUG : pacer: Reducing sleep to 120.135497ms fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache 2024/10/04 03:31:54 DEBUG : pacer: Reducing sleep to 100ms fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:718 Error: Not equal: expected: []string{"␊leading LF"} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "␊leading LF"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) (len=1) { +([]string) (len=2) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", (string) (len=13) "␊leading LF" Test: TestIntegration/FsMkdir/FsEncoding/leading_LF Messages: directories 2024/10/04 03:32:01 DEBUG : ␊leading LF: Rmdir: contains trashed file: "␊leading LF" fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:721 Error: Not equal: expected: []string{} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) { +([]string) (len=1) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~" } Test: TestIntegration/FsMkdir/FsEncoding/leading_LF Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/leading_HT fstests.go:711: testing "␉leading HT" 2024/10/04 03:32:12 DEBUG : ␉leading HT/␉leading HT: calculating gcid: failed to unwrap object from src: ␉leading HT/␉leading HT 2024/10/04 03:32:12 DEBUG : ␉leading HT/␉leading HT: gcid = af755c2996f555007066034277d86246c73f218e 2024/10/04 03:32:14 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:32:14 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/04 03:32:14 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:32:14 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/04 03:32:15 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:32:15 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/04 03:32:15 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:32:15 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/04 03:32:16 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:32:16 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/04 03:32:17 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:32:19 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/04 03:32:21 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/04 03:32:23 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/04 03:32:24 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/04 03:32:25 DEBUG : pacer: Reducing sleep to 474.609375ms fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache 2024/10/04 03:32:26 DEBUG : pacer: Reducing sleep to 355.957031ms 2024/10/04 03:32:27 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/04 03:32:27 DEBUG : pacer: Reducing sleep to 200.225829ms 2024/10/04 03:32:27 DEBUG : pacer: Reducing sleep to 150.169371ms fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache 2024/10/04 03:32:30 DEBUG : pacer: Reducing sleep to 112.627028ms 2024/10/04 03:32:30 DEBUG : pacer: Reducing sleep to 100ms fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:718 Error: Not equal: expected: []string{"␉leading HT"} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "␉leading HT"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) (len=1) { +([]string) (len=2) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", (string) (len=13) "␉leading HT" Test: TestIntegration/FsMkdir/FsEncoding/leading_HT Messages: directories 2024/10/04 03:32:36 DEBUG : ␉leading HT: Rmdir: contains trashed file: "␉leading HT" fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:721 Error: Not equal: expected: []string{} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) { +([]string) (len=1) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~" } Test: TestIntegration/FsMkdir/FsEncoding/leading_HT Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/leading_VT fstests.go:711: testing "␋leading VT" 2024/10/04 03:32:47 DEBUG : ␋leading VT/␋leading VT: calculating gcid: failed to unwrap object from src: ␋leading VT/␋leading VT 2024/10/04 03:32:47 DEBUG : ␋leading VT/␋leading VT: gcid = 16f4e6df7caac0c69de7d3ef6bc6925e976e2637 2024/10/04 03:32:49 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:32:49 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/04 03:32:50 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:32:50 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/04 03:32:50 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:32:50 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/04 03:32:50 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:32:50 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/04 03:32:51 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:32:51 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/04 03:32:53 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/04 03:32:55 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/04 03:32:56 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/04 03:32:57 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/04 03:32:58 DEBUG : pacer: Reducing sleep to 474.609375ms fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache 2024/10/04 03:32:59 DEBUG : pacer: Reducing sleep to 355.957031ms 2024/10/04 03:33:00 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/04 03:33:00 DEBUG : pacer: Reducing sleep to 200.225829ms 2024/10/04 03:33:01 DEBUG : pacer: Reducing sleep to 150.169371ms fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache 2024/10/04 03:33:03 DEBUG : pacer: Reducing sleep to 112.627028ms 2024/10/04 03:33:03 DEBUG : pacer: Reducing sleep to 100ms fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:718 Error: Not equal: expected: []string{"␋leading VT"} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "␋leading VT"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) (len=1) { +([]string) (len=2) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", (string) (len=13) "␋leading VT" Test: TestIntegration/FsMkdir/FsEncoding/leading_VT Messages: directories 2024/10/04 03:33:10 DEBUG : ␋leading VT: Rmdir: contains trashed file: "␋leading VT" fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:721 Error: Not equal: expected: []string{} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) { +([]string) (len=1) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~" } Test: TestIntegration/FsMkdir/FsEncoding/leading_VT Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/leading_dot fstests.go:711: testing ".leading dot" 2024/10/04 03:33:21 DEBUG : .leading dot/.leading dot: calculating gcid: failed to unwrap object from src: .leading dot/.leading dot 2024/10/04 03:33:21 DEBUG : .leading dot/.leading dot: gcid = 4039eee2e4785061c9013a83a6443e0ab24445d6 2024/10/04 03:33:23 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:33:23 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/04 03:33:23 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:33:23 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/04 03:33:24 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:33:24 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/04 03:33:24 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:33:24 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/04 03:33:25 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:33:25 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/04 03:33:27 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/04 03:33:29 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/04 03:33:30 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/04 03:33:31 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/04 03:33:32 DEBUG : pacer: Reducing sleep to 474.609375ms fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache 2024/10/04 03:33:33 DEBUG : pacer: Reducing sleep to 355.957031ms 2024/10/04 03:33:34 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/04 03:33:34 DEBUG : pacer: Reducing sleep to 200.225829ms 2024/10/04 03:33:34 DEBUG : pacer: Reducing sleep to 150.169371ms fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache 2024/10/04 03:33:37 DEBUG : pacer: Reducing sleep to 112.627028ms 2024/10/04 03:33:37 DEBUG : pacer: Reducing sleep to 100ms fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:718 Error: Not equal: expected: []string{".leading dot"} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", ".leading dot"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) (len=1) { +([]string) (len=2) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", (string) (len=12) ".leading dot" Test: TestIntegration/FsMkdir/FsEncoding/leading_dot Messages: directories 2024/10/04 03:33:44 DEBUG : .leading dot: Rmdir: contains trashed file: ".leading dot" fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:721 Error: Not equal: expected: []string{} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) { +([]string) (len=1) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~" } Test: TestIntegration/FsMkdir/FsEncoding/leading_dot Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/trailing_space fstests.go:711: testing "trailing space " 2024/10/04 03:33:54 DEBUG : trailing space /trailing space : calculating gcid: failed to unwrap object from src: trailing space /trailing space 2024/10/04 03:33:54 DEBUG : trailing space /trailing space : gcid = 7a55662273099a16614c87c1894b9c4216ccfc42 2024/10/04 03:33:57 DEBUG : Saving config "captcha_token" in section "TestPikPak" of the config file 2024/10/04 03:33:58 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:33:58 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/04 03:33:58 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:33:58 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/04 03:33:58 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:33:58 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/04 03:33:58 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:33:58 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/04 03:33:59 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:33:59 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/04 03:34:01 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:34:03 DEBUG : pacer: low level retry 7/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:34:05 DEBUG : pacer: low level retry 8/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:34:07 DEBUG : pacer: low level retry 9/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:34:09 DEBUG : pacer: low level retry 10/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:34:09 DEBUG : trailing space : canceling upload: can't verify the task is completed: &api.Task{Kind:"drive#task", ID:"VO8K_pYnmjGyD8kZl05vhKwno1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc001012100), FileID:"VO8K_pYXmjGyD8kZl05vhKwfo1", FileName:"trailing space␠", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x38444c0, ext:63863609635, loc:(*time.Location)(0xc00021cd90)}, UpdatedTime:api.Time{wall:0x496ed40, ext:63863609635, loc:(*time.Location)(0xc00021cd90)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0ed033dfc7b3862af92a52ef7e3e4d257223df81", Callback:"", ReferenceResource:interface {}(nil), Space:""} 2024/10/04 03:34:11 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/04 03:34:13 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/04 03:34:14 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/04 03:34:14 DEBUG : trailing space : waiting 500ms for the cancellation to be effective fstests.go:145: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:145 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:161 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:223 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:213 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:717 Error: Received unexpected error: can't verify the task is completed: &api.Task{Kind:"drive#task", ID:"VO8K_pYnmjGyD8kZl05vhKwno1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc001012100), FileID:"VO8K_pYXmjGyD8kZl05vhKwfo1", FileName:"trailing space␠", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x38444c0, ext:63863609635, loc:(*time.Location)(0xc00021cd90)}, UpdatedTime:api.Time{wall:0x496ed40, ext:63863609635, loc:(*time.Location)(0xc00021cd90)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0ed033dfc7b3862af92a52ef7e3e4d257223df81", Callback:"", ReferenceResource:interface {}(nil), Space:""} Test: TestIntegration/FsMkdir/FsEncoding/trailing_space Messages: Put === RUN TestIntegration/FsMkdir/FsEncoding/trailing_CR fstests.go:711: testing "trailing CR␍" 2024/10/04 03:34:16 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/04 03:34:16 DEBUG : pacer: Reducing sleep to 474.609375ms 2024/10/04 03:34:17 DEBUG : pacer: Reducing sleep to 355.957031ms 2024/10/04 03:34:17 DEBUG : trailing CR␍/trailing CR␍: calculating gcid: failed to unwrap object from src: trailing CR␍/trailing CR␍ 2024/10/04 03:34:17 DEBUG : trailing CR␍/trailing CR␍: gcid = 85489f21256556f460d4119a4baf8b6f38c31324 2024/10/04 03:34:17 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/04 03:34:19 DEBUG : pacer: Reducing sleep to 200.225829ms 2024/10/04 03:34:20 DEBUG : pacer: Reducing sleep to 150.169371ms 2024/10/04 03:34:20 DEBUG : pacer: Reducing sleep to 112.627028ms 2024/10/04 03:34:20 DEBUG : pacer: Reducing sleep to 100ms fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:718 Error: Not equal: expected: []string{"trailing CR␍"} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "trailing CR␍", "trailing space "} Diff: --- Expected +++ Actual @@ -1,3 +1,5 @@ -([]string) (len=1) { - (string) (len=14) "trailing CR␍" +([]string) (len=3) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", + (string) (len=14) "trailing CR␍", + (string) (len=15) "trailing space " } Test: TestIntegration/FsMkdir/FsEncoding/trailing_CR Messages: directories 2024/10/04 03:34:32 DEBUG : trailing CR␍: Rmdir: contains trashed file: "trailing CR␍" fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:721 Error: Not equal: expected: []string{} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "trailing space "} Diff: --- Expected +++ Actual @@ -1,2 +1,4 @@ -([]string) { +([]string) (len=2) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", + (string) (len=15) "trailing space " } Test: TestIntegration/FsMkdir/FsEncoding/trailing_CR Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/trailing_LF fstests.go:711: testing "trailing LF␊" 2024/10/04 03:34:44 DEBUG : trailing LF␊/trailing LF␊: calculating gcid: failed to unwrap object from src: trailing LF␊/trailing LF␊ 2024/10/04 03:34:44 DEBUG : trailing LF␊/trailing LF␊: gcid = 521207a6f2659c0c4ea622e12dd7330fb74297e6 fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:718 Error: Not equal: expected: []string{"trailing LF␊"} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "trailing LF␊", "trailing space "} Diff: --- Expected +++ Actual @@ -1,3 +1,5 @@ -([]string) (len=1) { - (string) (len=14) "trailing LF␊" +([]string) (len=3) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", + (string) (len=14) "trailing LF␊", + (string) (len=15) "trailing space " } Test: TestIntegration/FsMkdir/FsEncoding/trailing_LF Messages: directories 2024/10/04 03:34:59 DEBUG : trailing LF␊: Rmdir: contains trashed file: "trailing LF␊" fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:721 Error: Not equal: expected: []string{} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "trailing space "} Diff: --- Expected +++ Actual @@ -1,2 +1,4 @@ -([]string) { +([]string) (len=2) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", + (string) (len=15) "trailing space " } Test: TestIntegration/FsMkdir/FsEncoding/trailing_LF Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/trailing_HT fstests.go:711: testing "trailing HT␉" 2024/10/04 03:35:10 DEBUG : trailing HT␉/trailing HT␉: calculating gcid: failed to unwrap object from src: trailing HT␉/trailing HT␉ 2024/10/04 03:35:10 DEBUG : trailing HT␉/trailing HT␉: gcid = 8758bb2d17f611573a24395108039dc032cb5232 fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:718 Error: Not equal: expected: []string{"trailing HT␉"} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "trailing HT␉", "trailing space "} Diff: --- Expected +++ Actual @@ -1,3 +1,5 @@ -([]string) (len=1) { - (string) (len=14) "trailing HT␉" +([]string) (len=3) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", + (string) (len=14) "trailing HT␉", + (string) (len=15) "trailing space " } Test: TestIntegration/FsMkdir/FsEncoding/trailing_HT Messages: directories 2024/10/04 03:35:25 DEBUG : trailing HT␉: Rmdir: contains trashed file: "trailing HT␉" fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:721 Error: Not equal: expected: []string{} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "trailing space "} Diff: --- Expected +++ Actual @@ -1,2 +1,4 @@ -([]string) { +([]string) (len=2) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", + (string) (len=15) "trailing space " } Test: TestIntegration/FsMkdir/FsEncoding/trailing_HT Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/trailing_VT fstests.go:711: testing "trailing VT␋" 2024/10/04 03:35:36 DEBUG : trailing VT␋/trailing VT␋: calculating gcid: failed to unwrap object from src: trailing VT␋/trailing VT␋ 2024/10/04 03:35:36 DEBUG : trailing VT␋/trailing VT␋: gcid = 1238397e7361b0190f4a7df031085c730b4868f6 2024/10/04 03:35:39 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:35:39 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/04 03:35:39 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:35:39 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/04 03:35:39 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:35:39 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/04 03:35:39 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:35:39 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/04 03:35:40 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:35:40 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/04 03:35:42 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/04 03:35:44 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/04 03:35:45 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/04 03:35:46 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/04 03:35:47 DEBUG : pacer: Reducing sleep to 474.609375ms 2024/10/04 03:35:48 DEBUG : pacer: Reducing sleep to 355.957031ms fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache 2024/10/04 03:35:49 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/04 03:35:50 DEBUG : pacer: Reducing sleep to 200.225829ms 2024/10/04 03:35:50 DEBUG : pacer: Reducing sleep to 150.169371ms 2024/10/04 03:35:50 DEBUG : pacer: Reducing sleep to 112.627028ms 2024/10/04 03:35:51 DEBUG : pacer: Reducing sleep to 100ms fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:718 Error: Not equal: expected: []string{"trailing VT␋"} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "trailing VT␋", "trailing space "} Diff: --- Expected +++ Actual @@ -1,3 +1,5 @@ -([]string) (len=1) { - (string) (len=14) "trailing VT␋" +([]string) (len=3) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", + (string) (len=14) "trailing VT␋", + (string) (len=15) "trailing space " } Test: TestIntegration/FsMkdir/FsEncoding/trailing_VT Messages: directories 2024/10/04 03:35:59 DEBUG : trailing VT␋: Rmdir: contains trashed file: "trailing VT␋" fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:721 Error: Not equal: expected: []string{} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "trailing space "} Diff: --- Expected +++ Actual @@ -1,2 +1,4 @@ -([]string) { +([]string) (len=2) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", + (string) (len=15) "trailing space " } Test: TestIntegration/FsMkdir/FsEncoding/trailing_VT Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/trailing_dot fstests.go:711: testing "trailing dot." 2024/10/04 03:36:10 DEBUG : trailing dot./trailing dot.: calculating gcid: failed to unwrap object from src: trailing dot./trailing dot. 2024/10/04 03:36:10 DEBUG : trailing dot./trailing dot.: gcid = 452e5b3437151d1e6c7b4e09f868c3d2fe910f40 fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:718 Error: Not equal: expected: []string{"trailing dot."} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "trailing dot.", "trailing space "} Diff: --- Expected +++ Actual @@ -1,3 +1,5 @@ -([]string) (len=1) { - (string) (len=13) "trailing dot." +([]string) (len=3) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", + (string) (len=13) "trailing dot.", + (string) (len=15) "trailing space " } Test: TestIntegration/FsMkdir/FsEncoding/trailing_dot Messages: directories 2024/10/04 03:36:25 DEBUG : trailing dot.: Rmdir: contains trashed file: "trailing dot." fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:721 Error: Not equal: expected: []string{} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "trailing space "} Diff: --- Expected +++ Actual @@ -1,2 +1,4 @@ -([]string) { +([]string) (len=2) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", + (string) (len=15) "trailing space " } Test: TestIntegration/FsMkdir/FsEncoding/trailing_dot Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/invalid_UTF-8 fstests.go:711: testing "invalid utf-8\xfe" 2024/10/04 03:36:37 DEBUG : invalid utf-8/invalid utf-8: calculating gcid: failed to unwrap object from src: invalid utf-8/invalid utf-8 2024/10/04 03:36:37 DEBUG : invalid utf-8/invalid utf-8: gcid = 618fee21db6832284cbf1da0c9abca11ce538c9b 2024/10/04 03:36:39 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:36:39 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/04 03:36:39 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:36:39 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/04 03:36:39 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:36:39 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/04 03:36:40 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:36:40 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/04 03:36:41 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:36:41 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/04 03:36:42 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/04 03:36:44 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/04 03:36:46 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/04 03:36:47 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/04 03:36:48 DEBUG : pacer: Reducing sleep to 474.609375ms 2024/10/04 03:36:48 DEBUG : pacer: Reducing sleep to 355.957031ms fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache 2024/10/04 03:36:50 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/04 03:36:50 DEBUG : pacer: Reducing sleep to 200.225829ms 2024/10/04 03:36:50 DEBUG : pacer: Reducing sleep to 150.169371ms 2024/10/04 03:36:50 DEBUG : pacer: Reducing sleep to 112.627028ms 2024/10/04 03:36:51 DEBUG : pacer: Reducing sleep to 100ms fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:718 Error: Not equal: expected: []string{"invalid utf-8\xfe"} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "invalid utf-8\xfe", "trailing space "} Diff: --- Expected +++ Actual @@ -1,3 +1,5 @@ -([]string) (len=1) { - (string) (len=14) "invalid utf-8\xfe" +([]string) (len=3) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", + (string) (len=14) "invalid utf-8\xfe", + (string) (len=15) "trailing space " } Test: TestIntegration/FsMkdir/FsEncoding/invalid_UTF-8 Messages: directories 2024/10/04 03:37:00 DEBUG : invalid utf-8: Rmdir: contains trashed file: "invalid utf-8\xfe" fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:721 Error: Not equal: expected: []string{} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "trailing space "} Diff: --- Expected +++ Actual @@ -1,2 +1,4 @@ -([]string) { +([]string) (len=2) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", + (string) (len=15) "trailing space " } Test: TestIntegration/FsMkdir/FsEncoding/invalid_UTF-8 Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/URL_encoding fstests.go:711: testing "test%46.txt" 2024/10/04 03:37:11 DEBUG : test%46.txt/test%46.txt: calculating gcid: failed to unwrap object from src: test%46.txt/test%46.txt 2024/10/04 03:37:11 DEBUG : test%46.txt/test%46.txt: gcid = be2e7aa5b5716225489833ccfab8e21a2ed9f84f fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:718 Error: Not equal: expected: []string{"test%46.txt"} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "test%46.txt", "trailing space "} Diff: --- Expected +++ Actual @@ -1,3 +1,5 @@ -([]string) (len=1) { - (string) (len=11) "test%46.txt" +([]string) (len=3) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", + (string) (len=11) "test%46.txt", + (string) (len=15) "trailing space " } Test: TestIntegration/FsMkdir/FsEncoding/URL_encoding Messages: directories 2024/10/04 03:37:26 DEBUG : test%46.txt: Rmdir: contains trashed file: "test%46.txt" fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Flushing the directory cache fstest.go:292: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:295: Flushing the directory cache fstest.go:321: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:321 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:332 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:721 Error: Not equal: expected: []string{} actual : []string{"!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", "trailing space "} Diff: --- Expected +++ Actual @@ -1,2 +1,4 @@ -([]string) { +([]string) (len=2) { + (string) (len=34) "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~", + (string) (len=15) "trailing space " } Test: TestIntegration/FsMkdir/FsEncoding/URL_encoding Messages: directories === RUN TestIntegration/FsMkdir/FsNewObjectNotFound === RUN TestIntegration/FsMkdir/FsPutError 2024/10/04 03:37:39 DEBUG : hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt: calculating gcid: failed to unwrap object from src: hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt === RUN TestIntegration/FsMkdir/FsPutZeroLength 2024/10/04 03:37:39 DEBUG : zero-length-file: calculating gcid: failed to unwrap object from src: zero-length-file 2024/10/04 03:37:39 DEBUG : zero-length-file: gcid = da39a3ee5e6b4b0d3255bfef95601890afd80709 2024/10/04 03:37:40 DEBUG : pacer: low level retry 1/10 (error Error "captcha_invalid" (9): Verification code is invalid) 2024/10/04 03:37:40 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/04 03:37:41 DEBUG : Saving config "captcha_token" in section "TestPikPak" of the config file 2024/10/04 03:37:41 DEBUG : Config file has changed externally - reloading 2024/10/04 03:37:41 DEBUG : pacer: Reducing sleep to 150ms 2024/10/04 03:37:41 DEBUG : pacer: Reducing sleep to 112.5ms 2024/10/04 03:37:41 DEBUG : pacer: Reducing sleep to 100ms === RUN TestIntegration/FsMkdir/FsOpenWriterAt fstests.go:790: FS has no OpenWriterAt interface === RUN TestIntegration/FsMkdir/FsOpenChunkWriter fstests.go:823: FS has no OpenChunkWriter interface === RUN TestIntegration/FsMkdir/FsChangeNotify fstests.go:872: FS has no ChangeNotify interface === RUN TestIntegration/FsMkdir/FsPutFiles 2024/10/04 03:37:42 DEBUG : file name.txt: calculating gcid: failed to unwrap object from src: file name.txt 2024/10/04 03:37:42 DEBUG : file name.txt: gcid = 15eab47087009368e63911bbeb16d7e3cd281eca 2024/10/04 03:37:45 DEBUG : hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt: calculating gcid: failed to unwrap object from src: hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt 2024/10/04 03:37:45 DEBUG : hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt: gcid = 2c20a0e9ebd72c96086fc420e947214cdfdba411 2024/10/04 03:37:47 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:37:47 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/04 03:37:47 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:37:47 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/04 03:37:47 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:37:47 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/04 03:37:48 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:37:48 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/04 03:37:49 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:37:49 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/04 03:37:50 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:37:52 DEBUG : pacer: low level retry 7/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:37:54 DEBUG : pacer: low level retry 8/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:37:57 DEBUG : pacer: low level retry 9/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:37:58 DEBUG : pacer: low level retry 10/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:37:58 DEBUG : z.txt: canceling upload: can't verify the task is completed: &api.Task{Kind:"drive#task", ID:"VO8KahpAmjGyD8kZl05vhc7fo1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc00044e800), FileID:"VO8KahovmjGyD8kZl05vhbsFo1", FileName:"z.txt", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x209a8ec0, ext:63863609865, loc:(*time.Location)(0xc00021cd90)}, UpdatedTime:api.Time{wall:0x21bc7980, ext:63863609865, loc:(*time.Location)(0xc00021cd90)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0d8b20b308a8f2fb094caba73cd2b809f7f3c636", Callback:"", ReferenceResource:interface {}(nil), Space:""} 2024/10/04 03:38:00 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/04 03:38:02 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/04 03:38:04 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/04 03:38:04 DEBUG : z.txt: waiting 500ms for the cancellation to be effective fstests.go:145: Error Trace: /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:145 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:161 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:223 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:213 /home/rclone/go/src/github.com/rclone/rclone/fstest/fstests/fstests.go:958 Error: Received unexpected error: can't verify the task is completed: &api.Task{Kind:"drive#task", ID:"VO8KahpAmjGyD8kZl05vhc7fo1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc00044e800), FileID:"VO8KahovmjGyD8kZl05vhbsFo1", FileName:"z.txt", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x209a8ec0, ext:63863609865, loc:(*time.Location)(0xc00021cd90)}, UpdatedTime:api.Time{wall:0x21bc7980, ext:63863609865, loc:(*time.Location)(0xc00021cd90)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0d8b20b308a8f2fb094caba73cd2b809f7f3c636", Callback:"", ReferenceResource:interface {}(nil), Space:""} Test: TestIntegration/FsMkdir/FsPutFiles Messages: Put === RUN TestIntegration/FsMkdir/FsPutChunked fstests.go:2230: *pikpak.Fs does not implement SetUploadChunkSizer === RUN TestIntegration/FsMkdir/FsCopyChunked fstests.go:2357: *pikpak.Fs does not implement SetCopyCutoff === RUN TestIntegration/FsMkdir/FsUploadUnknownSize === RUN TestIntegration/FsMkdir/FsUploadUnknownSize/FsPutUnknownSize 2024/10/04 03:38:05 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/04 03:38:05 DEBUG : unknown-size-put.txt: calculating gcid: failed to unwrap object from src: unknown-size-put.txt 2024/10/04 03:38:05 DEBUG : unknown-size-put.txt: gcid = de0611fae6ebd40e60066f090bb70a320718a135 2024/10/04 03:38:06 DEBUG : pacer: Reducing sleep to 474.609375ms === RUN TestIntegration/FsMkdir/FsUploadUnknownSize/FsUpdateUnknownSize 2024/10/04 03:38:07 DEBUG : pacer: Reducing sleep to 355.957031ms 2024/10/04 03:38:07 DEBUG : unknown-size-update.txt: calculating gcid: failed to unwrap object from src: unknown-size-update.txt 2024/10/04 03:38:07 DEBUG : unknown-size-update.txt: gcid = 3a5d64c48dad2123f6f5cb865c6419efa50220fa 2024/10/04 03:38:07 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/04 03:38:09 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:38:09 DEBUG : pacer: Rate limited, increasing sleep to 533.935546ms 2024/10/04 03:38:09 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:38:09 DEBUG : pacer: Rate limited, increasing sleep to 1.067871092s 2024/10/04 03:38:10 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/04 03:38:10 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/04 03:38:11 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/04 03:38:13 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/04 03:38:14 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/04 03:38:14 DEBUG : unknown-size-update.txt: calculating gcid: failed to unwrap object from src: unknown-size-update.txt 2024/10/04 03:38:14 DEBUG : unknown-size-update.txt: gcid = b21012f5fdcab126d6f78024b3b26eb2fc85d997 2024/10/04 03:38:15 DEBUG : pacer: Reducing sleep to 632.8125ms === RUN TestIntegration/FsMkdir/FsRootCollapse 2024/10/04 03:38:15 DEBUG : Creating backend with remote "TestPikPak:rclone-test-jitavup3pada/deeper/nonexisting/directory" === RUN TestIntegration/FsMkdir/FsDirSetModTime fstests.go:2500: FS has no DirSetModTime interface === RUN TestIntegration/FsMkdir/FsMkdirMetadata fstests.go:2543: FS has no MkdirMetadata interface === RUN TestIntegration/FsMkdir/FsDirectory fstests.go:2600: FS has no Directory methods and doesn't Wrap 2024/10/04 03:38:17 DEBUG : pacer: Reducing sleep to 474.609375ms 2024/10/04 03:38:18 DEBUG : pacer: Reducing sleep to 355.957031ms 2024/10/04 03:38:19 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/04 03:38:19 ERROR : : error listing: directory not found 2024/10/04 03:38:19 DEBUG : pacer: Reducing sleep to 200.225829ms === RUN TestIntegration/FsShutdown fstests.go:2706: Shutdown method not supported --- FAIL: TestIntegration (555.23s) --- SKIP: TestIntegration/FsCheckWrap (0.00s) --- PASS: TestIntegration/FsCommand (0.00s) --- PASS: TestIntegration/FsRmdirNotFound (0.24s) --- PASS: TestIntegration/FsString (0.00s) --- PASS: TestIntegration/FsName (0.00s) --- PASS: TestIntegration/FsRoot (0.00s) --- PASS: TestIntegration/FsRmdirEmpty (1.22s) --- FAIL: TestIntegration/FsMkdir (551.33s) --- PASS: TestIntegration/FsMkdir/FsMkdirRmdirSubdir (5.07s) --- PASS: TestIntegration/FsMkdir/FsListEmpty (0.22s) --- PASS: TestIntegration/FsMkdir/FsListDirEmpty (0.22s) --- SKIP: TestIntegration/FsMkdir/FsListRDirEmpty (0.00s) --- PASS: TestIntegration/FsMkdir/FsListDirNotFound (0.24s) --- SKIP: TestIntegration/FsMkdir/FsListRDirNotFound (0.00s) --- FAIL: TestIntegration/FsMkdir/FsEncoding (501.75s) --- PASS: TestIntegration/FsMkdir/FsEncoding/control_chars (6.16s) --- PASS: TestIntegration/FsMkdir/FsEncoding/dot (15.07s) --- PASS: TestIntegration/FsMkdir/FsEncoding/dot_dot (14.31s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/punctuation (20.47s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/leading_space (37.31s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/leading_tilde (26.07s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/leading_CR (25.92s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/leading_LF (31.14s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/leading_HT (35.29s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/leading_VT (33.84s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/leading_dot (33.47s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/trailing_space (21.40s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/trailing_CR (27.77s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/trailing_LF (26.40s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/trailing_HT (26.24s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/trailing_VT (34.20s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/trailing_dot (26.28s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/invalid_UTF-8 (33.97s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/URL_encoding (26.20s) --- PASS: TestIntegration/FsMkdir/FsNewObjectNotFound (0.77s) --- PASS: TestIntegration/FsMkdir/FsPutError (2.48s) --- PASS: TestIntegration/FsMkdir/FsPutZeroLength (2.81s) --- SKIP: TestIntegration/FsMkdir/FsOpenWriterAt (0.00s) --- SKIP: TestIntegration/FsMkdir/FsOpenChunkWriter (0.00s) --- SKIP: TestIntegration/FsMkdir/FsChangeNotify (0.00s) --- FAIL: TestIntegration/FsMkdir/FsPutFiles (22.35s) --- SKIP: TestIntegration/FsMkdir/FsPutChunked (0.00s) --- SKIP: TestIntegration/FsMkdir/FsCopyChunked (0.00s) --- PASS: TestIntegration/FsMkdir/FsUploadUnknownSize (11.21s) --- PASS: TestIntegration/FsMkdir/FsUploadUnknownSize/FsPutUnknownSize (1.48s) --- PASS: TestIntegration/FsMkdir/FsUploadUnknownSize/FsUpdateUnknownSize (9.72s) --- PASS: TestIntegration/FsMkdir/FsRootCollapse (1.67s) --- SKIP: TestIntegration/FsMkdir/FsDirSetModTime (0.00s) --- SKIP: TestIntegration/FsMkdir/FsMkdirMetadata (0.00s) --- SKIP: TestIntegration/FsMkdir/FsDirectory (0.00s) --- SKIP: TestIntegration/FsShutdown (0.00s) FAIL exit status 1 FAIL github.com/rclone/rclone/backend/pikpak 555.241s "go test -v -timeout 1h0m0s -remote TestPikPak: -verbose" - Finished ERROR in 9m16.173889427s (try 1/5): exit status 1: Failed [TestIntegration/FsMkdir/FsEncoding/punctuation TestIntegration/FsMkdir/FsEncoding/leading_space TestIntegration/FsMkdir/FsEncoding/leading_tilde TestIntegration/FsMkdir/FsEncoding/leading_CR TestIntegration/FsMkdir/FsEncoding/leading_LF TestIntegration/FsMkdir/FsEncoding/leading_HT TestIntegration/FsMkdir/FsEncoding/leading_VT TestIntegration/FsMkdir/FsEncoding/leading_dot TestIntegration/FsMkdir/FsEncoding/trailing_space TestIntegration/FsMkdir/FsEncoding/trailing_CR TestIntegration/FsMkdir/FsEncoding/trailing_LF TestIntegration/FsMkdir/FsEncoding/trailing_HT TestIntegration/FsMkdir/FsEncoding/trailing_VT TestIntegration/FsMkdir/FsEncoding/trailing_dot TestIntegration/FsMkdir/FsEncoding/invalid_UTF-8 TestIntegration/FsMkdir/FsEncoding/URL_encoding TestIntegration/FsMkdir/FsPutFiles]