"go test -v -timeout 1h0m0s -remote TestPikPak: -verbose -test.run '^TestIntegration$/^FsMkdir$/^FsEncoding$/^(URL_encoding|invalid_UTF-8|leading_CR|leading_HT|leading_LF|leading_VT|leading_dot|trailing_CR|trailing_HT|trailing_LF|trailing_VT|trailing_dot|trailing_space)$|^TestIntegration$/^FsMkdir$/^FsPutFiles$/^(FsDirMove|FsListDirFile2|FsListLevel2|FsListR|FsPurge|FsPurgeRoot|ObjectUpdate)$|^TestIntegration$/^FsMkdir$/^FsPutFiles$/^FromRoot$/^(List|ListEntries)$|^TestIntegration$/^FsMkdir$/^FsPutFiles$/^FromRoot$/^Put$/^Remove$|^TestIntegration$/^FsMkdir$/^FsUploadUnknownSize$/^FsUpdateUnknownSize$'" - Starting (try 2/5) === RUN TestIntegration fstests.go:442: Using remote "TestPikPak:" 2024/10/08 04:43:59 DEBUG : Creating backend with remote "TestPikPak:rclone-test-xawabat8fasu" 2024/10/08 04:43:59 DEBUG : Using config file from "/home/rclone/.rclone.conf" === RUN TestIntegration/FsMkdir === RUN TestIntegration/FsMkdir/FsEncoding === RUN TestIntegration/FsMkdir/FsEncoding/leading_CR fstests.go:711: testing "␍leading CR" 2024/10/08 04:44:02 DEBUG : ␍leading CR/␍leading CR: calculating gcid: failed to unwrap object from src: ␍leading CR/␍leading CR 2024/10/08 04:44:02 DEBUG : ␍leading CR/␍leading CR: gcid = 8f508c96e32cb9ea232d5f5c46176def5bfafc2f 2024/10/08 04:44:07 DEBUG : ␍leading CR: Rmdir: contains trashed file: "␍leading CR" === RUN TestIntegration/FsMkdir/FsEncoding/leading_LF fstests.go:711: testing "␊leading LF" 2024/10/08 04:44:09 DEBUG : ␊leading LF/␊leading LF: calculating gcid: failed to unwrap object from src: ␊leading LF/␊leading LF 2024/10/08 04:44:09 DEBUG : ␊leading LF/␊leading LF: gcid = d8753009dffeea612453525031147719d72d3f7f 2024/10/08 04:44:11 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:44:11 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/08 04:44:11 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:44:11 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/08 04:44:12 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:44:12 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/08 04:44:12 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:44:12 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/08 04:44:13 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:44:13 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/08 04:44:15 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:44:17 DEBUG : pacer: low level retry 7/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:44:19 DEBUG : pacer: low level retry 8/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:44:21 DEBUG : pacer: low level retry 9/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:44:23 DEBUG : pacer: low level retry 10/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:44:23 DEBUG : ␊leading LF: canceling upload: can't verify the task is completed: &api.Task{Kind:"drive#task", ID:"VO8eRGTrsDbKFBHfcqnZYMxVo1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc000340c40), FileID:"VO8eRGTdsDbKFBHfcqnZYMxTo1", FileName:"␊leading LF", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x1f6961c0, ext:63863959449, loc:(*time.Location)(0xc0000d8d20)}, UpdatedTime:api.Time{wall:0x20f61c40, ext:63863959449, loc:(*time.Location)(0xc0000d8d20)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0ed033dfc7b3862af92a52ef7e3e4d257223df81", Callback:"", ReferenceResource:interface {}(nil), Space:""} 2024/10/08 04:44:25 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/08 04:44:27 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/08 04:44:28 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/08 04:44:28 DEBUG : ␊leading LF: 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:"VO8eRGTrsDbKFBHfcqnZYMxVo1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc000340c40), FileID:"VO8eRGTdsDbKFBHfcqnZYMxTo1", FileName:"␊leading LF", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x1f6961c0, ext:63863959449, loc:(*time.Location)(0xc0000d8d20)}, UpdatedTime:api.Time{wall:0x20f61c40, ext:63863959449, loc:(*time.Location)(0xc0000d8d20)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0ed033dfc7b3862af92a52ef7e3e4d257223df81", Callback:"", ReferenceResource:interface {}(nil), Space:""} Test: TestIntegration/FsMkdir/FsEncoding/leading_LF Messages: Put === RUN TestIntegration/FsMkdir/FsEncoding/leading_HT fstests.go:711: testing "␉leading HT" 2024/10/08 04:44:29 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/08 04:44:30 DEBUG : pacer: Reducing sleep to 474.609375ms 2024/10/08 04:44:31 DEBUG : pacer: Reducing sleep to 355.957031ms 2024/10/08 04:44:31 DEBUG : ␉leading HT/␉leading HT: calculating gcid: failed to unwrap object from src: ␉leading HT/␉leading HT 2024/10/08 04:44:31 DEBUG : ␉leading HT/␉leading HT: gcid = 2ebbc667c1057057a7b2dd83841c05329e97d524 2024/10/08 04:44:31 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/08 04:44:33 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:44:33 DEBUG : pacer: Rate limited, increasing sleep to 533.935546ms 2024/10/08 04:44:34 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:44:34 DEBUG : pacer: Rate limited, increasing sleep to 1.067871092s 2024/10/08 04:44:34 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:44:34 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/08 04:44:35 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:44:37 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/08 04:44:39 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/08 04:44:41 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/08 04:44:42 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/08 04:44:43 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/08 04:44:44 DEBUG : pacer: Reducing sleep to 355.957031ms 2024/10/08 04:44:44 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/08 04:44:45 DEBUG : pacer: Reducing sleep to 200.225829ms 2024/10/08 04:44:45 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/08 04:44:47 DEBUG : pacer: Reducing sleep to 112.627028ms 2024/10/08 04:44:48 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", "␊leading LF"} Diff: --- Expected +++ Actual @@ -1,3 +1,4 @@ -([]string) (len=1) { - (string) (len=13) "␉leading HT" +([]string) (len=2) { + (string) (len=13) "␉leading HT", + (string) (len=13) "␊leading LF" } Test: TestIntegration/FsMkdir/FsEncoding/leading_HT Messages: directories 2024/10/08 04:44:55 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{"␊leading LF"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) { +([]string) (len=1) { + (string) (len=13) "␊leading LF" } Test: TestIntegration/FsMkdir/FsEncoding/leading_HT Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/leading_VT fstests.go:711: testing "␋leading VT" 2024/10/08 04:45:06 DEBUG : ␋leading VT/␋leading VT: calculating gcid: failed to unwrap object from src: ␋leading VT/␋leading VT 2024/10/08 04:45:06 DEBUG : ␋leading VT/␋leading VT: gcid = de8d2239d4169ac2924e378b28779f6559189f99 2024/10/08 04:45:08 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:45:08 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/08 04:45:08 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:45:08 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/08 04:45:09 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:45:09 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/08 04:45:09 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:45:09 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/08 04:45:10 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:45:10 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/08 04:45:11 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:45:13 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/08 04:45:15 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/08 04:45:17 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/08 04:45:18 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/08 04:45:19 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/08 04:45:20 DEBUG : pacer: Reducing sleep to 355.957031ms 2024/10/08 04:45:21 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/08 04:45:21 DEBUG : pacer: Reducing sleep to 200.225829ms 2024/10/08 04:45:21 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/08 04:45:24 DEBUG : pacer: Reducing sleep to 112.627028ms 2024/10/08 04:45:24 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 LF", "␋leading VT"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) (len=1) { +([]string) (len=2) { + (string) (len=13) "␊leading LF", (string) (len=13) "␋leading VT" Test: TestIntegration/FsMkdir/FsEncoding/leading_VT Messages: directories 2024/10/08 04:45:31 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{"␊leading LF"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) { +([]string) (len=1) { + (string) (len=13) "␊leading LF" } Test: TestIntegration/FsMkdir/FsEncoding/leading_VT Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/leading_dot fstests.go:711: testing ".leading dot" 2024/10/08 04:45:42 DEBUG : .leading dot/.leading dot: calculating gcid: failed to unwrap object from src: .leading dot/.leading dot 2024/10/08 04:45:42 DEBUG : .leading dot/.leading dot: gcid = 92826a7b66901a47c3b9dd92f0c8f06cc5b5c211 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 dot"} actual : []string{".leading dot", "␊leading LF"} Diff: --- Expected +++ Actual @@ -1,3 +1,4 @@ -([]string) (len=1) { - (string) (len=12) ".leading dot" +([]string) (len=2) { + (string) (len=12) ".leading dot", + (string) (len=13) "␊leading LF" } Test: TestIntegration/FsMkdir/FsEncoding/leading_dot Messages: directories 2024/10/08 04:45:56 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{"␊leading LF"} Diff: --- Expected +++ Actual @@ -1,2 +1,3 @@ -([]string) { +([]string) (len=1) { + (string) (len=13) "␊leading LF" } Test: TestIntegration/FsMkdir/FsEncoding/leading_dot Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/trailing_space fstests.go:711: testing "trailing space " 2024/10/08 04:46:07 DEBUG : trailing space /trailing space : calculating gcid: failed to unwrap object from src: trailing space /trailing space 2024/10/08 04:46:07 DEBUG : trailing space /trailing space : gcid = d08f4aab12628c8c5febbef54e6d9b4df84afd40 2024/10/08 04:46:09 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:46:09 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/08 04:46:10 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:46:10 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/08 04:46:10 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:46:10 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/08 04:46:10 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:46:10 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/08 04:46:11 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:46:11 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/08 04:46:13 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:46:15 DEBUG : pacer: low level retry 7/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:46:17 DEBUG : pacer: low level retry 8/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:46:19 DEBUG : pacer: low level retry 9/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:46:21 DEBUG : pacer: low level retry 10/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:46:21 DEBUG : trailing space : canceling upload: can't verify the task is completed: &api.Task{Kind:"drive#task", ID:"VO8eRiNXsDbKFBHfcqnZYQCJo1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc00045da40), FileID:"VO8eRiNHsDbKFBHfcqnZYQCGo1", FileName:"trailing space␠", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x36007680, ext:63863959567, loc:(*time.Location)(0xc0000d8d20)}, UpdatedTime:api.Time{wall:0x37f800c0, ext:63863959567, loc:(*time.Location)(0xc0000d8d20)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0ed033dfc7b3862af92a52ef7e3e4d257223df81", Callback:"", ReferenceResource:interface {}(nil), Space:""} 2024/10/08 04:46:23 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/08 04:46:25 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/08 04:46:26 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/08 04:46:26 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:"VO8eRiNXsDbKFBHfcqnZYQCJo1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc00045da40), FileID:"VO8eRiNHsDbKFBHfcqnZYQCGo1", FileName:"trailing space␠", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x36007680, ext:63863959567, loc:(*time.Location)(0xc0000d8d20)}, UpdatedTime:api.Time{wall:0x37f800c0, ext:63863959567, loc:(*time.Location)(0xc0000d8d20)}, 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/08 04:46:27 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/08 04:46:28 DEBUG : pacer: Reducing sleep to 474.609375ms 2024/10/08 04:46:29 DEBUG : pacer: Reducing sleep to 355.957031ms 2024/10/08 04:46:29 DEBUG : trailing CR␍/trailing CR␍: calculating gcid: failed to unwrap object from src: trailing CR␍/trailing CR␍ 2024/10/08 04:46:29 DEBUG : trailing CR␍/trailing CR␍: gcid = 3d11aa516b34aa25e34c4f447c8e7d7899abbfd5 2024/10/08 04:46:29 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/08 04:46:31 DEBUG : pacer: Reducing sleep to 200.225829ms 2024/10/08 04:46:32 DEBUG : pacer: Reducing sleep to 150.169371ms 2024/10/08 04:46:32 DEBUG : pacer: Reducing sleep to 112.627028ms 2024/10/08 04:46:32 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 ", "␊leading LF"} Diff: --- Expected +++ Actual @@ -1,3 +1,5 @@ -([]string) (len=1) { - (string) (len=14) "trailing CR␍" +([]string) (len=3) { + (string) (len=14) "trailing CR␍", + (string) (len=15) "trailing space ", + (string) (len=13) "␊leading LF" } Test: TestIntegration/FsMkdir/FsEncoding/trailing_CR Messages: directories 2024/10/08 04:46:45 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 ", "␊leading LF"} Diff: --- Expected +++ Actual @@ -1,2 +1,4 @@ -([]string) { +([]string) (len=2) { + (string) (len=15) "trailing space ", + (string) (len=13) "␊leading LF" } Test: TestIntegration/FsMkdir/FsEncoding/trailing_CR Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/trailing_LF fstests.go:711: testing "trailing LF␊" 2024/10/08 04:46:56 DEBUG : trailing LF␊/trailing LF␊: calculating gcid: failed to unwrap object from src: trailing LF␊/trailing LF␊ 2024/10/08 04:46:56 DEBUG : trailing LF␊/trailing LF␊: gcid = 5b29c25957b96b414f2b8fedd0ec99a2c51b62dd 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 ", "␊leading LF"} Diff: --- Expected +++ Actual @@ -1,3 +1,5 @@ -([]string) (len=1) { - (string) (len=14) "trailing LF␊" +([]string) (len=3) { + (string) (len=14) "trailing LF␊", + (string) (len=15) "trailing space ", + (string) (len=13) "␊leading LF" } Test: TestIntegration/FsMkdir/FsEncoding/trailing_LF Messages: directories 2024/10/08 04:47:11 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 ", "␊leading LF"} Diff: --- Expected +++ Actual @@ -1,2 +1,4 @@ -([]string) { +([]string) (len=2) { + (string) (len=15) "trailing space ", + (string) (len=13) "␊leading LF" } Test: TestIntegration/FsMkdir/FsEncoding/trailing_LF Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/trailing_HT fstests.go:711: testing "trailing HT␉" 2024/10/08 04:47:23 DEBUG : trailing HT␉/trailing HT␉: calculating gcid: failed to unwrap object from src: trailing HT␉/trailing HT␉ 2024/10/08 04:47:23 DEBUG : trailing HT␉/trailing HT␉: gcid = c17c507b27ca073276bd86333625202c4a186ccd 2024/10/08 04:47:25 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:47:25 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/08 04:47:25 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:47:25 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/08 04:47:26 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:47:26 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/08 04:47:26 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:47:26 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/08 04:47:27 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:47:27 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/08 04:47:28 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:47:30 DEBUG : pacer: low level retry 7/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:47:32 DEBUG : pacer: low level retry 8/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:47:34 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/08 04:47:36 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/08 04:47:38 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/08 04:47:39 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/08 04:47:40 DEBUG : pacer: Reducing sleep to 474.609375ms 2024/10/08 04:47:41 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/08 04:47:42 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/08 04:47:42 DEBUG : pacer: Reducing sleep to 200.225829ms 2024/10/08 04:47:42 DEBUG : pacer: Reducing sleep to 150.169371ms 2024/10/08 04:47:43 DEBUG : pacer: Reducing sleep to 112.627028ms 2024/10/08 04:47:43 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 HT␉"} actual : []string{"trailing HT␉", "trailing space ", "␊leading LF"} Diff: --- Expected +++ Actual @@ -1,3 +1,5 @@ -([]string) (len=1) { - (string) (len=14) "trailing HT␉" +([]string) (len=3) { + (string) (len=14) "trailing HT␉", + (string) (len=15) "trailing space ", + (string) (len=13) "␊leading LF" } Test: TestIntegration/FsMkdir/FsEncoding/trailing_HT Messages: directories 2024/10/08 04:47:53 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 ", "␊leading LF"} Diff: --- Expected +++ Actual @@ -1,2 +1,4 @@ -([]string) { +([]string) (len=2) { + (string) (len=15) "trailing space ", + (string) (len=13) "␊leading LF" } Test: TestIntegration/FsMkdir/FsEncoding/trailing_HT Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/trailing_VT fstests.go:711: testing "trailing VT␋" 2024/10/08 04:48:05 DEBUG : trailing VT␋/trailing VT␋: calculating gcid: failed to unwrap object from src: trailing VT␋/trailing VT␋ 2024/10/08 04:48:05 DEBUG : trailing VT␋/trailing VT␋: gcid = 06c501a33a54c80462edc0892d4042068399feeb 2024/10/08 04:48:07 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:48:07 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/08 04:48:07 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:48:07 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/08 04:48:07 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:48:07 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/08 04:48:08 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:48:08 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/08 04:48:08 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:48:08 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/08 04:48:10 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/08 04:48:12 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/08 04:48:14 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/08 04:48:15 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/08 04:48:16 DEBUG : pacer: Reducing sleep to 474.609375ms 2024/10/08 04:48:16 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/08 04:48:18 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/08 04:48:18 DEBUG : pacer: Reducing sleep to 200.225829ms 2024/10/08 04:48:18 DEBUG : pacer: Reducing sleep to 150.169371ms 2024/10/08 04:48:19 DEBUG : pacer: Reducing sleep to 112.627028ms 2024/10/08 04:48:19 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 ", "␊leading LF"} Diff: --- Expected +++ Actual @@ -1,3 +1,5 @@ -([]string) (len=1) { - (string) (len=14) "trailing VT␋" +([]string) (len=3) { + (string) (len=14) "trailing VT␋", + (string) (len=15) "trailing space ", + (string) (len=13) "␊leading LF" } Test: TestIntegration/FsMkdir/FsEncoding/trailing_VT Messages: directories 2024/10/08 04:48:27 DEBUG : Saving config "captcha_token" in section "TestPikPak" of the config file 2024/10/08 04:48:27 DEBUG : Config file has changed externally - reloading 2024/10/08 04:48:29 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 ", "␊leading LF"} Diff: --- Expected +++ Actual @@ -1,2 +1,4 @@ -([]string) { +([]string) (len=2) { + (string) (len=15) "trailing space ", + (string) (len=13) "␊leading LF" } Test: TestIntegration/FsMkdir/FsEncoding/trailing_VT Messages: directories === RUN TestIntegration/FsMkdir/FsEncoding/trailing_dot fstests.go:711: testing "trailing dot." 2024/10/08 04:48:40 DEBUG : trailing dot./trailing dot.: calculating gcid: failed to unwrap object from src: trailing dot./trailing dot. 2024/10/08 04:48:40 DEBUG : trailing dot./trailing dot.: gcid = fdf23e5350870ea837a3b91205b0e8d7c022d977 2024/10/08 04:48:43 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:48:43 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/08 04:48:43 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:48:43 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/08 04:48:43 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:48:43 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/08 04:48:43 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:48:43 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/08 04:48:44 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:48:44 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/08 04:48:46 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:48:48 DEBUG : pacer: low level retry 7/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:48:50 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/08 04:48:52 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/08 04:48:53 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/08 04:48:55 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/08 04:48:55 DEBUG : pacer: Reducing sleep to 474.609375ms 2024/10/08 04:48:56 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/08 04:48:57 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/08 04:48:58 DEBUG : pacer: Reducing sleep to 200.225829ms 2024/10/08 04:48:58 DEBUG : pacer: Reducing sleep to 150.169371ms 2024/10/08 04:48:58 DEBUG : pacer: Reducing sleep to 112.627028ms 2024/10/08 04:48:59 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 dot."} actual : []string{"trailing dot.", "trailing space ", "␊leading LF"} Diff: --- Expected +++ Actual @@ -1,3 +1,5 @@ -([]string) (len=1) { - (string) (len=13) "trailing dot." +([]string) (len=3) { + (string) (len=13) "trailing dot.", + (string) (len=15) "trailing space ", + (string) (len=13) "␊leading LF" } Test: TestIntegration/FsMkdir/FsEncoding/trailing_dot Messages: directories 2024/10/08 04:49:08 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 ", "␊leading LF"} Diff: --- Expected +++ Actual @@ -1,2 +1,4 @@ -([]string) { +([]string) (len=2) { + (string) (len=15) "trailing space ", + (string) (len=13) "␊leading LF" } 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/08 04:49:20 DEBUG : invalid utf-8/invalid utf-8: calculating gcid: failed to unwrap object from src: invalid utf-8/invalid utf-8 2024/10/08 04:49:20 DEBUG : invalid utf-8/invalid utf-8: gcid = e26a120951912ce91d4408d1ce25f25c0a4d7cc4 2024/10/08 04:49:23 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:23 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/08 04:49:23 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:23 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/08 04:49:23 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:23 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/08 04:49:23 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:23 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/08 04:49:24 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:24 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/08 04:49:26 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:28 DEBUG : pacer: low level retry 7/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:30 DEBUG : pacer: low level retry 8/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:32 DEBUG : pacer: low level retry 9/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:34 DEBUG : pacer: low level retry 10/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:34 DEBUG : invalid utf-8: canceling upload: can't verify the task is completed: &api.Task{Kind:"drive#task", ID:"VO8eSSVJMIyQFBWGY3rj4NQYo1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc000500cc0), FileID:"VO8eSSV3MIyQFBWGY3rj4NQRo1", FileName:"invalid utf-8‛FE", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x36990d00, ext:63863959760, loc:(*time.Location)(0xc0000d8d20)}, UpdatedTime:api.Time{wall:0x3825c780, ext:63863959760, loc:(*time.Location)(0xc0000d8d20)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0ed033dfc7b3862af92a52ef7e3e4d257223df81", Callback:"", ReferenceResource:interface {}(nil), Space:""} 2024/10/08 04:49:36 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/08 04:49:38 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/08 04:49:39 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/08 04:49:39 DEBUG : invalid utf-8: 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:"VO8eSSVJMIyQFBWGY3rj4NQYo1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc000500cc0), FileID:"VO8eSSV3MIyQFBWGY3rj4NQRo1", FileName:"invalid utf-8‛FE", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x36990d00, ext:63863959760, loc:(*time.Location)(0xc0000d8d20)}, UpdatedTime:api.Time{wall:0x3825c780, ext:63863959760, loc:(*time.Location)(0xc0000d8d20)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0ed033dfc7b3862af92a52ef7e3e4d257223df81", Callback:"", ReferenceResource:interface {}(nil), Space:""} Test: TestIntegration/FsMkdir/FsEncoding/invalid_UTF-8 Messages: Put === RUN TestIntegration/FsMkdir/FsEncoding/URL_encoding fstests.go:711: testing "test%46.txt" 2024/10/08 04:49:41 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/08 04:49:41 DEBUG : pacer: Reducing sleep to 474.609375ms 2024/10/08 04:49:42 DEBUG : pacer: Reducing sleep to 355.957031ms 2024/10/08 04:49:42 DEBUG : test%46.txt/test%46.txt: calculating gcid: failed to unwrap object from src: test%46.txt/test%46.txt 2024/10/08 04:49:42 DEBUG : test%46.txt/test%46.txt: gcid = 2e52643ce30280f337d5af5fdc7464c5f794d1c8 2024/10/08 04:49:43 DEBUG : pacer: Reducing sleep to 266.967773ms 2024/10/08 04:49:44 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:44 DEBUG : pacer: Rate limited, increasing sleep to 533.935546ms 2024/10/08 04:49:45 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:45 DEBUG : pacer: Rate limited, increasing sleep to 1.067871092s 2024/10/08 04:49:45 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:45 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/08 04:49:46 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:48 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:50 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:52 DEBUG : pacer: low level retry 7/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:54 DEBUG : pacer: low level retry 8/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:56 DEBUG : pacer: low level retry 9/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:49:58 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/08 04:50:00 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/08 04:50:02 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/08 04:50:03 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/08 04:50:04 DEBUG : pacer: Reducing sleep to 474.609375ms 2024/10/08 04:50:04 DEBUG : pacer: Reducing sleep to 355.957031ms 2024/10/08 04:50:05 DEBUG : pacer: Reducing sleep to 266.967773ms fstest.go:292: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Flushing the directory cache 2024/10/08 04:50:06 DEBUG : pacer: Reducing sleep to 200.225829ms 2024/10/08 04:50:06 DEBUG : pacer: Reducing sleep to 150.169371ms 2024/10/08 04:50:07 DEBUG : pacer: Reducing sleep to 112.627028ms 2024/10/08 04:50:07 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{"test%46.txt"} actual : []string{"invalid utf-8\xfe", "test%46.txt", "trailing space ", "␊leading LF"} Diff: --- Expected +++ Actual @@ -1,3 +1,6 @@ -([]string) (len=1) { - (string) (len=11) "test%46.txt" +([]string) (len=4) { + (string) (len=14) "invalid utf-8\xfe", + (string) (len=11) "test%46.txt", + (string) (len=15) "trailing space ", + (string) (len=13) "␊leading LF" } Test: TestIntegration/FsMkdir/FsEncoding/URL_encoding Messages: directories 2024/10/08 04:50:17 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{"invalid utf-8\xfe", "trailing space ", "␊leading LF"} Diff: --- Expected +++ Actual @@ -1,2 +1,5 @@ -([]string) { +([]string) (len=3) { + (string) (len=14) "invalid utf-8\xfe", + (string) (len=15) "trailing space ", + (string) (len=13) "␊leading LF" } Test: TestIntegration/FsMkdir/FsEncoding/URL_encoding Messages: directories === RUN TestIntegration/FsMkdir/FsPutFiles 2024/10/08 04:50:28 DEBUG : file name.txt: calculating gcid: failed to unwrap object from src: file name.txt 2024/10/08 04:50:28 DEBUG : file name.txt: gcid = 75b25fb4212607a24e36a2b9b4582205807fd41e 2024/10/08 04:50:30 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:50:30 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2024/10/08 04:50:31 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:50:31 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2024/10/08 04:50:31 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:50:31 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2024/10/08 04:50:31 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:50:31 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2024/10/08 04:50:32 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:50:32 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/08 04:50:34 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:50:36 DEBUG : pacer: low level retry 7/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:50:38 DEBUG : pacer: low level retry 8/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:50:40 DEBUG : pacer: low level retry 9/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:50:42 DEBUG : pacer: low level retry 10/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:50:42 DEBUG : file name.txt: canceling upload: can't verify the task is completed: &api.Task{Kind:"drive#task", ID:"VO8eSi34MIyQFBWGY3rj4Q5no1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc00045c680), FileID:"VO8eSi2pMIyQFBWGY3rj4Q5lo1", FileName:"file name.txt", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x2c2ac340, ext:63863959828, loc:(*time.Location)(0xc0000d8d20)}, UpdatedTime:api.Time{wall:0x2db77dc0, ext:63863959828, loc:(*time.Location)(0xc0000d8d20)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0d8b20b308a8f2fb094caba73cd2b809f7f3c636", Callback:"", ReferenceResource:interface {}(nil), Space:""} 2024/10/08 04:50:44 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/08 04:50:46 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/08 04:50:47 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/08 04:50:47 DEBUG : file name.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:957 Error: Received unexpected error: can't verify the task is completed: &api.Task{Kind:"drive#task", ID:"VO8eSi34MIyQFBWGY3rj4Q5no1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc00045c680), FileID:"VO8eSi2pMIyQFBWGY3rj4Q5lo1", FileName:"file name.txt", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x2c2ac340, ext:63863959828, loc:(*time.Location)(0xc0000d8d20)}, UpdatedTime:api.Time{wall:0x2db77dc0, ext:63863959828, loc:(*time.Location)(0xc0000d8d20)}, 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/FsUploadUnknownSize === RUN TestIntegration/FsMkdir/FsUploadUnknownSize/FsUpdateUnknownSize 2024/10/08 04:50:48 DEBUG : pacer: Reducing sleep to 632.8125ms 2024/10/08 04:50:48 DEBUG : unknown-size-update.txt: calculating gcid: failed to unwrap object from src: unknown-size-update.txt 2024/10/08 04:50:48 DEBUG : unknown-size-update.txt: gcid = cf57cf0fcb7cba2b61bab33d22374fbda89b8699 2024/10/08 04:50:49 DEBUG : pacer: Reducing sleep to 474.609375ms 2024/10/08 04:50:51 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:50:51 DEBUG : pacer: Rate limited, increasing sleep to 949.21875ms 2024/10/08 04:50:52 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:50:52 DEBUG : pacer: Rate limited, increasing sleep to 1.8984375s 2024/10/08 04:50:53 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:50:53 DEBUG : pacer: Rate limited, increasing sleep to 2s 2024/10/08 04:50:54 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:50:56 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:50:58 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:51:00 DEBUG : pacer: low level retry 7/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:51:02 DEBUG : pacer: low level retry 8/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:51:04 DEBUG : pacer: low level retry 9/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2024/10/08 04:51:06 DEBUG : pacer: Reducing sleep to 1.5s 2024/10/08 04:51:09 DEBUG : pacer: Reducing sleep to 1.125s 2024/10/08 04:51:10 DEBUG : pacer: Reducing sleep to 843.75ms 2024/10/08 04:51:10 DEBUG : unknown-size-update.txt: calculating gcid: failed to unwrap object from src: unknown-size-update.txt 2024/10/08 04:51:10 DEBUG : unknown-size-update.txt: gcid = b87658bfb9a2ffc45556568342e75e24606f2a05 2024/10/08 04:51:11 DEBUG : pacer: low level retry 1/10 (error Error "captcha_invalid" (9): Verification code is invalid) 2024/10/08 04:51:11 DEBUG : pacer: Rate limited, increasing sleep to 1.6875s 2024/10/08 04:51:13 DEBUG : Saving config "captcha_token" in section "TestPikPak" of the config file 2024/10/08 04:51:13 DEBUG : pacer: Reducing sleep to 1.265625s 2024/10/08 04:51:14 DEBUG : pacer: Reducing sleep to 949.21875ms 2024/10/08 04:51:15 DEBUG : pacer: Reducing sleep to 711.914062ms 2024/10/08 04:51:16 DEBUG : pacer: Reducing sleep to 533.935546ms 2024/10/08 04:51:16 ERROR : : error listing: directory not found 2024/10/08 04:51:17 DEBUG : pacer: Reducing sleep to 400.451659ms --- FAIL: TestIntegration (438.00s) --- FAIL: TestIntegration/FsMkdir (435.85s) --- FAIL: TestIntegration/FsMkdir/FsEncoding (386.64s) --- PASS: TestIntegration/FsMkdir/FsEncoding/leading_CR (6.77s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/leading_LF (20.52s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/leading_HT (36.09s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/leading_VT (35.90s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/leading_dot (25.45s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/trailing_space (20.81s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/trailing_CR (28.26s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/trailing_LF (26.83s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/trailing_HT (41.62s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/trailing_VT (35.79s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/trailing_dot (39.76s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/invalid_UTF-8 (20.81s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/URL_encoding (47.75s) --- FAIL: TestIntegration/FsMkdir/FsPutFiles (19.97s) --- PASS: TestIntegration/FsMkdir/FsUploadUnknownSize (25.47s) --- PASS: TestIntegration/FsMkdir/FsUploadUnknownSize/FsUpdateUnknownSize (25.47s) FAIL exit status 1 FAIL github.com/rclone/rclone/backend/pikpak 438.014s "go test -v -timeout 1h0m0s -remote TestPikPak: -verbose -test.run '^TestIntegration$/^FsMkdir$/^FsEncoding$/^(URL_encoding|invalid_UTF-8|leading_CR|leading_HT|leading_LF|leading_VT|leading_dot|trailing_CR|trailing_HT|trailing_LF|trailing_VT|trailing_dot|trailing_space)$|^TestIntegration$/^FsMkdir$/^FsPutFiles$/^(FsDirMove|FsListDirFile2|FsListLevel2|FsListR|FsPurge|FsPurgeRoot|ObjectUpdate)$|^TestIntegration$/^FsMkdir$/^FsPutFiles$/^FromRoot$/^(List|ListEntries)$|^TestIntegration$/^FsMkdir$/^FsPutFiles$/^FromRoot$/^Put$/^Remove$|^TestIntegration$/^FsMkdir$/^FsUploadUnknownSize$/^FsUpdateUnknownSize$'" - Finished ERROR in 7m19.083560743s (try 2/5): exit status 1: Failed [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]