"go test -v -timeout 1h0m0s -remote TestPikPak: -verbose -test.run '^TestIntegration$/^FsMkdir$/^FsEncoding$/^(URL_encoding|invalid_UTF-8|trailing_HT|trailing_LF|trailing_VT|trailing_dot)$|^TestIntegration$/^FsMkdir$/^FsPutFiles$/^(FsDirMove|FsListDirFile2|FsListLevel2|FsListR|FsPurge|FsPurgeRoot)$|^TestIntegration$/^FsMkdir$/^FsPutFiles$/^FromRoot$/^(List|ListEntries)$'" - Starting (try 3/5) === RUN TestIntegration fstests.go:442: Using remote "TestPikPak:" 2025/01/13 01:23:18 DEBUG : Creating backend with remote "TestPikPak:rclone-test-zelidog3reyo" 2025/01/13 01:23:18 DEBUG : Using config file from "/home/rclone/.rclone.conf" === RUN TestIntegration/FsMkdir === RUN TestIntegration/FsMkdir/FsEncoding === RUN TestIntegration/FsMkdir/FsEncoding/trailing_LF fstests.go:711: testing "trailing LF␊" 2025/01/13 01:23:22 DEBUG : trailing LF␊/trailing LF␊: calculating gcid: failed to unwrap object from src: trailing LF␊/trailing LF␊ 2025/01/13 01:23:22 DEBUG : trailing LF␊/trailing LF␊: gcid = ec1a6be5d88c586092bcf1c83b27f4594049b2ba 2025/01/13 01:23:24 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:23:24 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2025/01/13 01:23:24 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:23:24 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2025/01/13 01:23:24 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:23:24 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2025/01/13 01:23:25 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:23:25 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2025/01/13 01:23:26 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:23:26 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/01/13 01:23:27 DEBUG : pacer: Reducing sleep to 1.5s 2025/01/13 01:23:29 DEBUG : pacer: Reducing sleep to 1.125s 2025/01/13 01:23:31 DEBUG : pacer: Reducing sleep to 843.75ms 2025/01/13 01:23:32 DEBUG : pacer: Reducing sleep to 632.8125ms 2025/01/13 01:23:33 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/01/13 01:23:33 DEBUG : pacer: Reducing sleep to 355.957031ms 2025/01/13 01:23:34 DEBUG : pacer: Reducing sleep to 266.967773ms 2025/01/13 01:23:34 DEBUG : trailing LF␊: Rmdir: contains trashed file: "trailing LF␊" 2025/01/13 01:23:34 DEBUG : pacer: Reducing sleep to 200.225829ms 2025/01/13 01:23:35 DEBUG : pacer: Reducing sleep to 150.169371ms 2025/01/13 01:23:35 DEBUG : pacer: Reducing sleep to 112.627028ms === RUN TestIntegration/FsMkdir/FsEncoding/trailing_HT fstests.go:711: testing "trailing HT␉" 2025/01/13 01:23:36 DEBUG : pacer: Reducing sleep to 100ms 2025/01/13 01:23:36 DEBUG : trailing HT␉/trailing HT␉: calculating gcid: failed to unwrap object from src: trailing HT␉/trailing HT␉ 2025/01/13 01:23:36 DEBUG : trailing HT␉/trailing HT␉: gcid = fc22d48149b7c461f794513651d9c509c2c0910f 2025/01/13 01:23:38 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:23:38 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2025/01/13 01:23:39 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:23:39 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2025/01/13 01:23:39 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:23:39 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2025/01/13 01:23:39 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:23:39 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2025/01/13 01:23:40 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:23:40 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/01/13 01:23:42 DEBUG : pacer: Reducing sleep to 1.5s 2025/01/13 01:23:44 DEBUG : pacer: Reducing sleep to 1.125s 2025/01/13 01:23:45 DEBUG : pacer: Reducing sleep to 843.75ms 2025/01/13 01:23:46 DEBUG : pacer: Reducing sleep to 632.8125ms 2025/01/13 01:23:47 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/01/13 01:23:48 DEBUG : pacer: Reducing sleep to 355.957031ms 2025/01/13 01:23:48 DEBUG : pacer: Reducing sleep to 266.967773ms 2025/01/13 01:23:48 DEBUG : trailing HT␉: Rmdir: contains trashed file: "trailing HT␉" 2025/01/13 01:23:49 DEBUG : pacer: Reducing sleep to 200.225829ms 2025/01/13 01:23:49 DEBUG : pacer: Reducing sleep to 150.169371ms 2025/01/13 01:23:50 DEBUG : pacer: Reducing sleep to 112.627028ms === RUN TestIntegration/FsMkdir/FsEncoding/trailing_VT fstests.go:711: testing "trailing VT␋" 2025/01/13 01:23:50 DEBUG : pacer: Reducing sleep to 100ms 2025/01/13 01:23:51 DEBUG : trailing VT␋/trailing VT␋: calculating gcid: failed to unwrap object from src: trailing VT␋/trailing VT␋ 2025/01/13 01:23:51 DEBUG : trailing VT␋/trailing VT␋: gcid = c63ee4c7df209a7246c0840d32209f67bd0ea9ac 2025/01/13 01:23:53 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:23:53 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2025/01/13 01:23:53 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:23:53 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2025/01/13 01:23:53 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:23:53 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2025/01/13 01:23:54 DEBUG : pacer: Reducing sleep to 600ms 2025/01/13 01:23:55 DEBUG : pacer: Reducing sleep to 450ms 2025/01/13 01:23:55 DEBUG : pacer: Reducing sleep to 337.5ms 2025/01/13 01:23:56 DEBUG : pacer: Reducing sleep to 253.125ms 2025/01/13 01:23:56 DEBUG : pacer: Reducing sleep to 189.84375ms 2025/01/13 01:23:57 DEBUG : pacer: Reducing sleep to 142.382812ms 2025/01/13 01:23:57 DEBUG : pacer: Reducing sleep to 106.787109ms 2025/01/13 01:23:57 DEBUG : trailing VT␋: Rmdir: contains trashed file: "trailing VT␋" 2025/01/13 01:23:57 DEBUG : pacer: Reducing sleep to 100ms === RUN TestIntegration/FsMkdir/FsEncoding/trailing_dot fstests.go:711: testing "trailing dot." 2025/01/13 01:23:59 DEBUG : trailing dot./trailing dot.: calculating gcid: failed to unwrap object from src: trailing dot./trailing dot. 2025/01/13 01:23:59 DEBUG : trailing dot./trailing dot.: gcid = 223c71984759d4445d2c6411f8b20f55dacf2d19 2025/01/13 01:24:04 DEBUG : trailing dot.: Rmdir: contains trashed file: "trailing dot." === RUN TestIntegration/FsMkdir/FsEncoding/invalid_UTF-8 fstests.go:711: testing "invalid utf-8\xfe" 2025/01/13 01:24:06 DEBUG : invalid utf-8/invalid utf-8: calculating gcid: failed to unwrap object from src: invalid utf-8/invalid utf-8 2025/01/13 01:24:06 DEBUG : invalid utf-8/invalid utf-8: gcid = 4ad5d52d652778066d3d8e9af81e7495cbc6f07e 2025/01/13 01:24:08 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:08 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2025/01/13 01:24:08 DEBUG : pacer: Reducing sleep to 150ms 2025/01/13 01:24:09 DEBUG : pacer: Reducing sleep to 112.5ms 2025/01/13 01:24:09 DEBUG : pacer: Reducing sleep to 100ms 2025/01/13 01:24:11 DEBUG : invalid utf-8: Rmdir: contains trashed file: "invalid utf-8\xfe" === RUN TestIntegration/FsMkdir/FsEncoding/URL_encoding fstests.go:711: testing "test%46.txt" 2025/01/13 01:24:13 DEBUG : test%46.txt/test%46.txt: calculating gcid: failed to unwrap object from src: test%46.txt/test%46.txt 2025/01/13 01:24:13 DEBUG : test%46.txt/test%46.txt: gcid = 9d685655c677d0c52cac1723fd599c0f703fa8c8 2025/01/13 01:24:15 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:15 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2025/01/13 01:24:15 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:15 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2025/01/13 01:24:15 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:15 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2025/01/13 01:24:16 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:16 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2025/01/13 01:24:17 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:17 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/01/13 01:24:19 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:20 DEBUG : pacer: low level retry 7/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:22 DEBUG : pacer: low level retry 8/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:24 DEBUG : pacer: low level retry 9/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:26 DEBUG : pacer: low level retry 10/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:26 DEBUG : test%46.txt: canceling upload: can't verify the task is completed: &api.Task{Kind:"drive#task", ID:"VOGSFiTnxdBe5iOSqHK7mQhko1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc0004a0940), FileID:"VOGSFiTWxdBe5iOSqHK7mQhio1", FileName:"test%46.txt", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x15b23300, ext:63872328253, loc:(*time.Location)(0xc00021ea80)}, UpdatedTime:api.Time{wall:0x172fab40, ext:63872328253, loc:(*time.Location)(0xc00021ea80)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0d8b20b308a8f2fb094caba73cd2b809f7f3c636", Callback:"", ReferenceResource:interface {}(nil), Space:""} 2025/01/13 01:24:28 DEBUG : pacer: Reducing sleep to 1.5s 2025/01/13 01:24:30 DEBUG : pacer: Reducing sleep to 1.125s 2025/01/13 01:24:32 DEBUG : pacer: Reducing sleep to 843.75ms 2025/01/13 01:24:32 DEBUG : test%46.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:717 Error: Received unexpected error: can't verify the task is completed: &api.Task{Kind:"drive#task", ID:"VOGSFiTnxdBe5iOSqHK7mQhko1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc0004a0940), FileID:"VOGSFiTWxdBe5iOSqHK7mQhio1", FileName:"test%46.txt", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x15b23300, ext:63872328253, loc:(*time.Location)(0xc00021ea80)}, UpdatedTime:api.Time{wall:0x172fab40, ext:63872328253, loc:(*time.Location)(0xc00021ea80)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0d8b20b308a8f2fb094caba73cd2b809f7f3c636", Callback:"", ReferenceResource:interface {}(nil), Space:""} Test: TestIntegration/FsMkdir/FsEncoding/URL_encoding Messages: Put === RUN TestIntegration/FsMkdir/FsPutFiles 2025/01/13 01:24:33 DEBUG : pacer: Reducing sleep to 632.8125ms 2025/01/13 01:24:33 DEBUG : file name.txt: calculating gcid: failed to unwrap object from src: file name.txt 2025/01/13 01:24:33 DEBUG : file name.txt: gcid = a3e1afc402cb1a4f59950644839ceff046dd2a49 2025/01/13 01:24:34 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/01/13 01:24:36 DEBUG : pacer: Reducing sleep to 355.957031ms 2025/01/13 01:24:37 DEBUG : pacer: Reducing sleep to 266.967773ms 2025/01/13 01:24:37 DEBUG : pacer: Reducing sleep to 200.225829ms 2025/01/13 01:24:37 DEBUG : pacer: Reducing sleep to 150.169371ms 2025/01/13 01:24:37 DEBUG : pacer: Reducing sleep to 112.627028ms 2025/01/13 01:24:38 DEBUG : pacer: Reducing sleep to 100ms 2025/01/13 01:24:39 DEBUG : hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt: calculating gcid: failed to unwrap object from src: hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt 2025/01/13 01:24:39 DEBUG : hello? sausage/êé/Hello, 世界/ " ' @ < > & ? + ≠/z.txt: gcid = 31286ea06d5c1f4ecfed0fe989a9db0c4a505442 2025/01/13 01:24:41 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:41 DEBUG : pacer: Rate limited, increasing sleep to 200ms 2025/01/13 01:24:42 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:42 DEBUG : pacer: Rate limited, increasing sleep to 400ms 2025/01/13 01:24:42 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:42 DEBUG : pacer: Rate limited, increasing sleep to 800ms 2025/01/13 01:24:42 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:42 DEBUG : pacer: Rate limited, increasing sleep to 1.6s 2025/01/13 01:24:43 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:43 DEBUG : pacer: Rate limited, increasing sleep to 2s 2025/01/13 01:24:45 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:47 DEBUG : pacer: low level retry 7/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:49 DEBUG : pacer: low level retry 8/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:51 DEBUG : pacer: low level retry 9/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:53 DEBUG : pacer: low level retry 10/10 (error upload (upload) is still in PHASE_TYPE_PENDING) 2025/01/13 01:24:53 DEBUG : z.txt: canceling upload: can't verify the task is completed: &api.Task{Kind:"drive#task", ID:"VOGSFowC1Q3_tBKHFk4DQ3F_o1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc0003380c0), FileID:"VOGSFovv1Q3_tBKHFk4DQ3FYo1", FileName:"z.txt", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x30ef7740, ext:63872328279, loc:(*time.Location)(0xc00021ea80)}, UpdatedTime:api.Time{wall:0x324e6b00, ext:63872328279, loc:(*time.Location)(0xc00021ea80)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0d8b20b308a8f2fb094caba73cd2b809f7f3c636", Callback:"", ReferenceResource:interface {}(nil), Space:""} 2025/01/13 01:24:55 DEBUG : pacer: Reducing sleep to 1.5s 2025/01/13 01:24:57 DEBUG : pacer: Reducing sleep to 1.125s 2025/01/13 01:24:58 DEBUG : pacer: Reducing sleep to 843.75ms 2025/01/13 01:24:58 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:"VOGSFowC1Q3_tBKHFk4DQ3F_o1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc0003380c0), FileID:"VOGSFovv1Q3_tBKHFk4DQ3FYo1", FileName:"z.txt", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0x30ef7740, ext:63872328279, loc:(*time.Location)(0xc00021ea80)}, UpdatedTime:api.Time{wall:0x324e6b00, ext:63872328279, loc:(*time.Location)(0xc00021ea80)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0d8b20b308a8f2fb094caba73cd2b809f7f3c636", Callback:"", ReferenceResource:interface {}(nil), Space:""} Test: TestIntegration/FsMkdir/FsPutFiles Messages: Put 2025/01/13 01:24:59 DEBUG : pacer: Reducing sleep to 632.8125ms 2025/01/13 01:25:00 DEBUG : pacer: Reducing sleep to 474.609375ms 2025/01/13 01:25:01 DEBUG : pacer: Reducing sleep to 355.957031ms 2025/01/13 01:25:01 ERROR : : error listing: directory not found 2025/01/13 01:25:01 DEBUG : pacer: Reducing sleep to 266.967773ms --- FAIL: TestIntegration (103.35s) --- FAIL: TestIntegration/FsMkdir (101.18s) --- FAIL: TestIntegration/FsMkdir/FsEncoding (71.93s) --- PASS: TestIntegration/FsMkdir/FsEncoding/trailing_LF (14.61s) --- PASS: TestIntegration/FsMkdir/FsEncoding/trailing_HT (14.48s) --- PASS: TestIntegration/FsMkdir/FsEncoding/trailing_VT (8.58s) --- PASS: TestIntegration/FsMkdir/FsEncoding/trailing_dot (6.68s) --- PASS: TestIntegration/FsMkdir/FsEncoding/invalid_UTF-8 (6.83s) --- FAIL: TestIntegration/FsMkdir/FsEncoding/URL_encoding (20.48s) --- FAIL: TestIntegration/FsMkdir/FsPutFiles (26.42s) FAIL exit status 1 FAIL github.com/rclone/rclone/backend/pikpak 103.365s "go test -v -timeout 1h0m0s -remote TestPikPak: -verbose -test.run '^TestIntegration$/^FsMkdir$/^FsEncoding$/^(URL_encoding|invalid_UTF-8|trailing_HT|trailing_LF|trailing_VT|trailing_dot)$|^TestIntegration$/^FsMkdir$/^FsPutFiles$/^(FsDirMove|FsListDirFile2|FsListLevel2|FsListR|FsPurge|FsPurgeRoot)$|^TestIntegration$/^FsMkdir$/^FsPutFiles$/^FromRoot$/^(List|ListEntries)$'" - Finished ERROR in 1m44.094686021s (try 3/5): exit status 1: Failed [TestIntegration/FsMkdir/FsEncoding/URL_encoding TestIntegration/FsMkdir/FsPutFiles]