"go test -v -timeout 1h0m0s -remote TestPikPak: -verbose -test.run '^TestIntegration$/^FsMkdir$/^FsEncoding$/^(URL_encoding|control_chars|dot|dot_dot|invalid_UTF-8|leading_CR|leading_HT|leading_LF|leading_VT|leading_dot|leading_space|leading_tilde|punctuation|trailing_CR|trailing_HT|trailing_LF|trailing_VT|trailing_dot|trailing_space)$|^TestIntegration$/^FsMkdir$/^FsPutFiles$/^(FsDirMove|FsListDirFile2|FsListLevel2|FsListR|FsPurge|FsPurgeRoot)$|^TestIntegration$/^FsMkdir$/^FsPutFiles$/^FromRoot$/^(List|ListEntries)$'" - Starting (try 2/5)
=== RUN   TestIntegration
    fstests.go:442: Using remote "TestPikPak:"
2025/01/25 01:36:59 DEBUG : Creating backend with remote "TestPikPak:rclone-test-besogil7zuxo"
2025/01/25 01:36:59 DEBUG : Using config file from "/home/rclone/.rclone.conf"
=== RUN   TestIntegration/FsMkdir
=== RUN   TestIntegration/FsMkdir/FsEncoding
=== RUN   TestIntegration/FsMkdir/FsEncoding/control_chars
    fstests.go:711: testing "␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡"
2025/01/25 01:37:02 DEBUG : ␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡/␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡: calculating gcid: failed to unwrap object from src: ␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡/␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡
2025/01/25 01:37:02 DEBUG : ␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡/␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡: gcid = 75180fde2f29d64f2db009212f07ef1b204d02d9
2025/01/25 01:37:04 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:37:04 DEBUG : pacer: Rate limited, increasing sleep to 200ms
2025/01/25 01:37:05 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:37:05 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2025/01/25 01:37:05 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:37:05 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2025/01/25 01:37:05 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:37:05 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2025/01/25 01:37:06 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:37:06 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/01/25 01:37:08 DEBUG : pacer: Reducing sleep to 1.5s
2025/01/25 01:37:10 DEBUG : pacer: Reducing sleep to 1.125s
2025/01/25 01:37:11 DEBUG : pacer: Reducing sleep to 843.75ms
2025/01/25 01:37:12 DEBUG : pacer: Reducing sleep to 632.8125ms
2025/01/25 01:37:13 DEBUG : pacer: Reducing sleep to 474.609375ms
2025/01/25 01:37:14 DEBUG : pacer: Reducing sleep to 355.957031ms
2025/01/25 01:37:14 DEBUG : pacer: Reducing sleep to 266.967773ms
2025/01/25 01:37:14 DEBUG : ␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡: Rmdir: contains trashed file: "␀␁␂␃␄␅␆␇␈␉␊␋␌␍␎␏␐␑␒␓␔␕␖␗␘␙␚␛␜␝␞␟␡"
2025/01/25 01:37:15 DEBUG : pacer: Reducing sleep to 200.225829ms
2025/01/25 01:37:15 DEBUG : pacer: Reducing sleep to 150.169371ms
2025/01/25 01:37:16 DEBUG : pacer: Reducing sleep to 112.627028ms
=== RUN   TestIntegration/FsMkdir/FsEncoding/dot
    fstests.go:711: testing "．"
2025/01/25 01:37:16 DEBUG : pacer: Reducing sleep to 100ms
2025/01/25 01:37:17 DEBUG : ．/．: calculating gcid: failed to unwrap object from src: ．/．
2025/01/25 01:37:17 DEBUG : ．/．: gcid = 9cf96820e9bbedf2b0f4bd55d14ab20028d27ba4
2025/01/25 01:37:21 DEBUG : ．: Rmdir: contains trashed file: "．"
=== RUN   TestIntegration/FsMkdir/FsEncoding/dot_dot
    fstests.go:711: testing "．．"
2025/01/25 01:37:23 DEBUG : ．．/．．: calculating gcid: failed to unwrap object from src: ．．/．．
2025/01/25 01:37:23 DEBUG : ．．/．．: gcid = 6858251295fe3b649bb5c252f2bd3c5ac26e02e0
2025/01/25 01:37:25 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:37:25 DEBUG : pacer: Rate limited, increasing sleep to 200ms
2025/01/25 01:37:26 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:37:26 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2025/01/25 01:37:26 DEBUG : pacer: Reducing sleep to 300ms
2025/01/25 01:37:26 DEBUG : pacer: Reducing sleep to 225ms
2025/01/25 01:37:27 DEBUG : pacer: Reducing sleep to 168.75ms
2025/01/25 01:37:27 DEBUG : pacer: Reducing sleep to 126.5625ms
2025/01/25 01:37:27 DEBUG : pacer: Reducing sleep to 100ms
2025/01/25 01:37:28 DEBUG : ．．: Rmdir: contains trashed file: "．．"
=== RUN   TestIntegration/FsMkdir/FsEncoding/punctuation
    fstests.go:711: testing "!\"#$%&'()*+,-.／:;<=>?@[\\]^_`{|}~"
2025/01/25 01:37:30 DEBUG : !"#$%&'()*+,-.／:;<=>?@[\]^_`{|}~/!"#$%&'()*+,-.／:;<=>?@[\]^_`{|}~: calculating gcid: failed to unwrap object from src: !"#$%&'()*+,-.／:;<=>?@[\]^_`{|}~/!"#$%&'()*+,-.／:;<=>?@[\]^_`{|}~
2025/01/25 01:37:30 DEBUG : !"#$%&'()*+,-.／:;<=>?@[\]^_`{|}~/!"#$%&'()*+,-.／:;<=>?@[\]^_`{|}~: gcid = e2584f43a3332c0fab7656f61f45e893b40dbc0d
2025/01/25 01:37:32 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:37:32 DEBUG : pacer: Rate limited, increasing sleep to 200ms
2025/01/25 01:37:33 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:37:33 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2025/01/25 01:37:33 DEBUG : pacer: Reducing sleep to 300ms
2025/01/25 01:37:33 DEBUG : pacer: Reducing sleep to 225ms
2025/01/25 01:37:35 DEBUG : Saving config "captcha_token" in section "TestPikPak" of the config file
2025/01/25 01:37:35 DEBUG : pacer: Reducing sleep to 168.75ms
2025/01/25 01:37:35 DEBUG : pacer: Reducing sleep to 126.5625ms
2025/01/25 01:37:36 DEBUG : pacer: Reducing sleep to 100ms
2025/01/25 01:37:37 DEBUG : !"#$%&'()*+,-.／:;<=>?@[\]^_`{|}~: Rmdir: contains trashed file: "!\"#$%&'()*+,-.／:;<=>?@[\\]^_`{|}~"
=== RUN   TestIntegration/FsMkdir/FsEncoding/leading_space
    fstests.go:711: testing " leading space"
2025/01/25 01:37:39 DEBUG :  leading space/ leading space: calculating gcid: failed to unwrap object from src:  leading space/ leading space
2025/01/25 01:37:39 DEBUG :  leading space/ leading space: gcid = 9038512ef6300d97600fc67908c8fefdeb712d46
2025/01/25 01:37:43 DEBUG :  leading space: Rmdir: contains trashed file: " leading space"
=== RUN   TestIntegration/FsMkdir/FsEncoding/leading_tilde
    fstests.go:711: testing "~leading tilde"
2025/01/25 01:37:46 DEBUG : ~leading tilde/~leading tilde: calculating gcid: failed to unwrap object from src: ~leading tilde/~leading tilde
2025/01/25 01:37:46 DEBUG : ~leading tilde/~leading tilde: gcid = a3fe09906d1fec3082805b188b02f7907436250f
2025/01/25 01:37:48 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:37:48 DEBUG : pacer: Rate limited, increasing sleep to 200ms
2025/01/25 01:37:48 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:37:48 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2025/01/25 01:37:48 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:37:48 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2025/01/25 01:37:49 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:37:49 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2025/01/25 01:37:50 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:37:50 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/01/25 01:37:51 DEBUG : pacer: Reducing sleep to 1.5s
2025/01/25 01:37:53 DEBUG : pacer: Reducing sleep to 1.125s
2025/01/25 01:37:55 DEBUG : pacer: Reducing sleep to 843.75ms
2025/01/25 01:37:56 DEBUG : pacer: Reducing sleep to 632.8125ms
2025/01/25 01:37:57 DEBUG : pacer: Reducing sleep to 474.609375ms
2025/01/25 01:37:58 DEBUG : pacer: Reducing sleep to 355.957031ms
2025/01/25 01:37:58 DEBUG : pacer: Reducing sleep to 266.967773ms
2025/01/25 01:37:58 DEBUG : ~leading tilde: Rmdir: contains trashed file: "~leading tilde"
2025/01/25 01:37:59 DEBUG : pacer: Reducing sleep to 200.225829ms
2025/01/25 01:37:59 DEBUG : pacer: Reducing sleep to 150.169371ms
2025/01/25 01:38:00 DEBUG : pacer: Reducing sleep to 112.627028ms
=== RUN   TestIntegration/FsMkdir/FsEncoding/leading_CR
    fstests.go:711: testing "␍leading CR"
2025/01/25 01:38:00 DEBUG : pacer: Reducing sleep to 100ms
2025/01/25 01:38:00 DEBUG : ␍leading CR/␍leading CR: calculating gcid: failed to unwrap object from src: ␍leading CR/␍leading CR
2025/01/25 01:38:00 DEBUG : ␍leading CR/␍leading CR: gcid = ea37b7f37be1a25b03ab49ac01ad5f886899dc47
2025/01/25 01:38:03 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:03 DEBUG : pacer: Rate limited, increasing sleep to 200ms
2025/01/25 01:38:03 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:03 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2025/01/25 01:38:03 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:03 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2025/01/25 01:38:04 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:04 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2025/01/25 01:38:04 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:04 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/01/25 01:38:06 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:08 DEBUG : pacer: Reducing sleep to 1.5s
2025/01/25 01:38:10 DEBUG : pacer: Reducing sleep to 1.125s
2025/01/25 01:38:12 DEBUG : pacer: Reducing sleep to 843.75ms
2025/01/25 01:38:13 DEBUG : pacer: Reducing sleep to 632.8125ms
2025/01/25 01:38:13 DEBUG : pacer: Reducing sleep to 474.609375ms
2025/01/25 01:38:14 DEBUG : pacer: Reducing sleep to 355.957031ms
2025/01/25 01:38:15 DEBUG : pacer: Reducing sleep to 266.967773ms
2025/01/25 01:38:15 DEBUG : ␍leading CR: Rmdir: contains trashed file: "␍leading CR"
2025/01/25 01:38:15 DEBUG : pacer: Reducing sleep to 200.225829ms
2025/01/25 01:38:16 DEBUG : pacer: Reducing sleep to 150.169371ms
2025/01/25 01:38:16 DEBUG : pacer: Reducing sleep to 112.627028ms
=== RUN   TestIntegration/FsMkdir/FsEncoding/leading_LF
    fstests.go:711: testing "␊leading LF"
2025/01/25 01:38:16 DEBUG : pacer: Reducing sleep to 100ms
2025/01/25 01:38:17 DEBUG : ␊leading LF/␊leading LF: calculating gcid: failed to unwrap object from src: ␊leading LF/␊leading LF
2025/01/25 01:38:17 DEBUG : ␊leading LF/␊leading LF: gcid = 858e926359189cfe43123fca63e6532779d9997f
2025/01/25 01:38:21 DEBUG : ␊leading LF: Rmdir: contains trashed file: "␊leading LF"
=== RUN   TestIntegration/FsMkdir/FsEncoding/leading_HT
    fstests.go:711: testing "␉leading HT"
2025/01/25 01:38:23 DEBUG : ␉leading HT/␉leading HT: calculating gcid: failed to unwrap object from src: ␉leading HT/␉leading HT
2025/01/25 01:38:23 DEBUG : ␉leading HT/␉leading HT: gcid = 92c4409316f092a1e3474d8bc3ee8b2c403aab6d
2025/01/25 01:38:25 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:25 DEBUG : pacer: Rate limited, increasing sleep to 200ms
2025/01/25 01:38:25 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:25 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2025/01/25 01:38:26 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:26 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2025/01/25 01:38:26 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:26 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2025/01/25 01:38:27 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:27 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/01/25 01:38:28 DEBUG : pacer: Reducing sleep to 1.5s
2025/01/25 01:38:30 DEBUG : pacer: Reducing sleep to 1.125s
2025/01/25 01:38:32 DEBUG : pacer: Reducing sleep to 843.75ms
2025/01/25 01:38:33 DEBUG : pacer: Reducing sleep to 632.8125ms
2025/01/25 01:38:34 DEBUG : pacer: Reducing sleep to 474.609375ms
2025/01/25 01:38:35 DEBUG : pacer: Reducing sleep to 355.957031ms
2025/01/25 01:38:35 DEBUG : pacer: Reducing sleep to 266.967773ms
2025/01/25 01:38:35 DEBUG : ␉leading HT: Rmdir: contains trashed file: "␉leading HT"
2025/01/25 01:38:35 DEBUG : pacer: Reducing sleep to 200.225829ms
2025/01/25 01:38:36 DEBUG : pacer: Reducing sleep to 150.169371ms
2025/01/25 01:38:36 DEBUG : pacer: Reducing sleep to 112.627028ms
=== RUN   TestIntegration/FsMkdir/FsEncoding/leading_VT
    fstests.go:711: testing "␋leading VT"
2025/01/25 01:38:37 DEBUG : pacer: Reducing sleep to 100ms
2025/01/25 01:38:37 DEBUG : ␋leading VT/␋leading VT: calculating gcid: failed to unwrap object from src: ␋leading VT/␋leading VT
2025/01/25 01:38:37 DEBUG : ␋leading VT/␋leading VT: gcid = f2a489d93d3978eed35cb80506afd286d784bfb9
2025/01/25 01:38:39 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:39 DEBUG : pacer: Rate limited, increasing sleep to 200ms
2025/01/25 01:38:40 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:40 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2025/01/25 01:38:40 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:40 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2025/01/25 01:38:40 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:40 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2025/01/25 01:38:41 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:41 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/01/25 01:38:43 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:45 DEBUG : pacer: Reducing sleep to 1.5s
2025/01/25 01:38:47 DEBUG : pacer: Reducing sleep to 1.125s
2025/01/25 01:38:48 DEBUG : pacer: Reducing sleep to 843.75ms
2025/01/25 01:38:49 DEBUG : pacer: Reducing sleep to 632.8125ms
2025/01/25 01:38:50 DEBUG : pacer: Reducing sleep to 474.609375ms
2025/01/25 01:38:51 DEBUG : pacer: Reducing sleep to 355.957031ms
2025/01/25 01:38:51 DEBUG : pacer: Reducing sleep to 266.967773ms
2025/01/25 01:38:51 DEBUG : ␋leading VT: Rmdir: contains trashed file: "␋leading VT"
2025/01/25 01:38:52 DEBUG : pacer: Reducing sleep to 200.225829ms
2025/01/25 01:38:52 DEBUG : pacer: Reducing sleep to 150.169371ms
2025/01/25 01:38:53 DEBUG : pacer: Reducing sleep to 112.627028ms
=== RUN   TestIntegration/FsMkdir/FsEncoding/leading_dot
    fstests.go:711: testing ".leading dot"
2025/01/25 01:38:53 DEBUG : pacer: Reducing sleep to 100ms
2025/01/25 01:38:53 DEBUG : .leading dot/.leading dot: calculating gcid: failed to unwrap object from src: .leading dot/.leading dot
2025/01/25 01:38:53 DEBUG : .leading dot/.leading dot: gcid = 7d9e77254920b095cd40b17021be1091da296124
2025/01/25 01:38:55 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:55 DEBUG : pacer: Rate limited, increasing sleep to 200ms
2025/01/25 01:38:56 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:56 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2025/01/25 01:38:56 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:56 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2025/01/25 01:38:56 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:56 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2025/01/25 01:38:57 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:38:57 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/01/25 01:38:59 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:39:01 DEBUG : pacer: low level retry 7/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:39:03 DEBUG : pacer: Reducing sleep to 1.5s
2025/01/25 01:39:05 DEBUG : pacer: Reducing sleep to 1.125s
2025/01/25 01:39:06 DEBUG : pacer: Reducing sleep to 843.75ms
2025/01/25 01:39:07 DEBUG : pacer: Reducing sleep to 632.8125ms
2025/01/25 01:39:08 DEBUG : pacer: Reducing sleep to 474.609375ms
2025/01/25 01:39:09 DEBUG : pacer: Reducing sleep to 355.957031ms
2025/01/25 01:39:09 DEBUG : pacer: Reducing sleep to 266.967773ms
2025/01/25 01:39:09 DEBUG : .leading dot: Rmdir: contains trashed file: ".leading dot"
2025/01/25 01:39:10 DEBUG : pacer: Reducing sleep to 200.225829ms
2025/01/25 01:39:11 DEBUG : pacer: Reducing sleep to 150.169371ms
2025/01/25 01:39:11 DEBUG : pacer: Reducing sleep to 112.627028ms
=== RUN   TestIntegration/FsMkdir/FsEncoding/trailing_space
    fstests.go:711: testing "trailing space "
2025/01/25 01:39:11 DEBUG : pacer: Reducing sleep to 100ms
2025/01/25 01:39:12 DEBUG : trailing space /trailing space : calculating gcid: failed to unwrap object from src: trailing space /trailing space 
2025/01/25 01:39:12 DEBUG : trailing space /trailing space : gcid = b672da79f190b43e63e18b71227c9e50e321890e
2025/01/25 01:39:14 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:39:14 DEBUG : pacer: Rate limited, increasing sleep to 200ms
2025/01/25 01:39:15 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:39:15 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2025/01/25 01:39:15 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:39:15 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2025/01/25 01:39:15 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:39:15 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2025/01/25 01:39:16 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:39:16 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/01/25 01:39:18 DEBUG : pacer: Reducing sleep to 1.5s
2025/01/25 01:39:20 DEBUG : pacer: Reducing sleep to 1.125s
2025/01/25 01:39:21 DEBUG : pacer: Reducing sleep to 843.75ms
2025/01/25 01:39:22 DEBUG : pacer: Reducing sleep to 632.8125ms
2025/01/25 01:39:23 DEBUG : pacer: Reducing sleep to 474.609375ms
2025/01/25 01:39:24 DEBUG : pacer: Reducing sleep to 355.957031ms
2025/01/25 01:39:24 DEBUG : pacer: Reducing sleep to 266.967773ms
2025/01/25 01:39:24 DEBUG : trailing space : Rmdir: contains trashed file: "trailing space "
2025/01/25 01:39:25 DEBUG : pacer: Reducing sleep to 200.225829ms
2025/01/25 01:39:25 DEBUG : pacer: Reducing sleep to 150.169371ms
2025/01/25 01:39:26 DEBUG : pacer: Reducing sleep to 112.627028ms
=== RUN   TestIntegration/FsMkdir/FsEncoding/trailing_CR
    fstests.go:711: testing "trailing CR␍"
2025/01/25 01:39:26 DEBUG : pacer: Reducing sleep to 100ms
2025/01/25 01:39:27 DEBUG : trailing CR␍/trailing CR␍: calculating gcid: failed to unwrap object from src: trailing CR␍/trailing CR␍
2025/01/25 01:39:27 DEBUG : trailing CR␍/trailing CR␍: gcid = 04bdf0bbc68ea6346242de2383f0a17753ec0f99
2025/01/25 01:39:31 DEBUG : trailing CR␍: Rmdir: contains trashed file: "trailing CR␍"
=== RUN   TestIntegration/FsMkdir/FsEncoding/trailing_LF
    fstests.go:711: testing "trailing LF␊"
2025/01/25 01:39:33 DEBUG : trailing LF␊/trailing LF␊: calculating gcid: failed to unwrap object from src: trailing LF␊/trailing LF␊
2025/01/25 01:39:33 DEBUG : trailing LF␊/trailing LF␊: gcid = a70cd6b6784f543cbec973963958477df09f6b4d
2025/01/25 01:39:37 DEBUG : trailing LF␊: Rmdir: contains trashed file: "trailing LF␊"
=== RUN   TestIntegration/FsMkdir/FsEncoding/trailing_HT
    fstests.go:711: testing "trailing HT␉"
2025/01/25 01:39:39 DEBUG : trailing HT␉/trailing HT␉: calculating gcid: failed to unwrap object from src: trailing HT␉/trailing HT␉
2025/01/25 01:39:39 DEBUG : trailing HT␉/trailing HT␉: gcid = bc794971bb4e97e65a9685c8a93e56b64d17d476
2025/01/25 01:39:42 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:39:42 DEBUG : pacer: Rate limited, increasing sleep to 200ms
2025/01/25 01:39:42 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:39:42 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2025/01/25 01:39:42 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:39:42 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2025/01/25 01:39:42 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:39:42 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2025/01/25 01:39:43 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:39:43 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/01/25 01:39:45 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:39:47 DEBUG : pacer: low level retry 7/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:39:49 DEBUG : pacer: Reducing sleep to 1.5s
2025/01/25 01:39:51 DEBUG : pacer: Reducing sleep to 1.125s
2025/01/25 01:39:52 DEBUG : pacer: Reducing sleep to 843.75ms
2025/01/25 01:39:53 DEBUG : pacer: Reducing sleep to 632.8125ms
2025/01/25 01:39:54 DEBUG : pacer: Reducing sleep to 474.609375ms
2025/01/25 01:39:55 DEBUG : pacer: Reducing sleep to 355.957031ms
2025/01/25 01:39:56 DEBUG : pacer: Reducing sleep to 266.967773ms
2025/01/25 01:39:56 DEBUG : trailing HT␉: Rmdir: contains trashed file: "trailing HT␉"
2025/01/25 01:39:56 DEBUG : pacer: Reducing sleep to 200.225829ms
2025/01/25 01:39:57 DEBUG : pacer: Reducing sleep to 150.169371ms
2025/01/25 01:39:57 DEBUG : pacer: Reducing sleep to 112.627028ms
=== RUN   TestIntegration/FsMkdir/FsEncoding/trailing_VT
    fstests.go:711: testing "trailing VT␋"
2025/01/25 01:39:57 DEBUG : pacer: Reducing sleep to 100ms
2025/01/25 01:39:58 DEBUG : trailing VT␋/trailing VT␋: calculating gcid: failed to unwrap object from src: trailing VT␋/trailing VT␋
2025/01/25 01:39:58 DEBUG : trailing VT␋/trailing VT␋: gcid = f6e45242e3dbe751a2735c1cbaae5c595e2fe2c9
2025/01/25 01:40:00 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:40:00 DEBUG : pacer: Rate limited, increasing sleep to 200ms
2025/01/25 01:40:00 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:40:00 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2025/01/25 01:40:00 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:40:00 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2025/01/25 01:40:01 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:40:01 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2025/01/25 01:40:02 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:40:02 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/01/25 01:40:03 DEBUG : pacer: Reducing sleep to 1.5s
2025/01/25 01:40:05 DEBUG : pacer: Reducing sleep to 1.125s
2025/01/25 01:40:07 DEBUG : pacer: Reducing sleep to 843.75ms
2025/01/25 01:40:08 DEBUG : pacer: Reducing sleep to 632.8125ms
2025/01/25 01:40:09 DEBUG : pacer: Reducing sleep to 474.609375ms
2025/01/25 01:40:09 DEBUG : pacer: Reducing sleep to 355.957031ms
2025/01/25 01:40:10 DEBUG : pacer: Reducing sleep to 266.967773ms
2025/01/25 01:40:10 DEBUG : trailing VT␋: Rmdir: contains trashed file: "trailing VT␋"
2025/01/25 01:40:10 DEBUG : pacer: Reducing sleep to 200.225829ms
2025/01/25 01:40:11 DEBUG : pacer: Reducing sleep to 150.169371ms
2025/01/25 01:40:11 DEBUG : pacer: Reducing sleep to 112.627028ms
=== RUN   TestIntegration/FsMkdir/FsEncoding/trailing_dot
    fstests.go:711: testing "trailing dot."
2025/01/25 01:40:11 DEBUG : pacer: Reducing sleep to 100ms
2025/01/25 01:40:12 DEBUG : trailing dot./trailing dot.: calculating gcid: failed to unwrap object from src: trailing dot./trailing dot.
2025/01/25 01:40:12 DEBUG : trailing dot./trailing dot.: gcid = 3b81057f313d87844142d577f39760110676cc53
2025/01/25 01:40:16 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/25 01:40:19 DEBUG : invalid utf-8�/invalid utf-8�: calculating gcid: failed to unwrap object from src: invalid utf-8�/invalid utf-8�
2025/01/25 01:40:19 DEBUG : invalid utf-8�/invalid utf-8�: gcid = 94094050f527b26d7dba7c99edc3b79f8145fd75
2025/01/25 01:40:23 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/25 01:40:26 DEBUG : test%46.txt/test%46.txt: calculating gcid: failed to unwrap object from src: test%46.txt/test%46.txt
2025/01/25 01:40:26 DEBUG : test%46.txt/test%46.txt: gcid = d4c6930a039b46f24054e7643c64d3cb0509294d
2025/01/25 01:40:30 DEBUG : test%46.txt: Rmdir: contains trashed file: "test%46.txt"
=== RUN   TestIntegration/FsMkdir/FsPutFiles
2025/01/25 01:40:32 DEBUG : file name.txt: calculating gcid: failed to unwrap object from src: file name.txt
2025/01/25 01:40:32 DEBUG : file name.txt: gcid = b1e7ce2c5f5cc8e21b1e048aa49e1ebab4c0a220
2025/01/25 01:40:34 DEBUG : pacer: low level retry 1/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:40:34 DEBUG : pacer: Rate limited, increasing sleep to 200ms
2025/01/25 01:40:34 DEBUG : pacer: low level retry 2/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:40:34 DEBUG : pacer: Rate limited, increasing sleep to 400ms
2025/01/25 01:40:34 DEBUG : pacer: low level retry 3/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:40:34 DEBUG : pacer: Rate limited, increasing sleep to 800ms
2025/01/25 01:40:35 DEBUG : pacer: low level retry 4/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:40:35 DEBUG : pacer: Rate limited, increasing sleep to 1.6s
2025/01/25 01:40:35 DEBUG : pacer: low level retry 5/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:40:35 DEBUG : pacer: Rate limited, increasing sleep to 2s
2025/01/25 01:40:37 DEBUG : pacer: low level retry 6/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:40:39 DEBUG : pacer: low level retry 7/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:40:41 DEBUG : pacer: low level retry 8/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:40:43 DEBUG : pacer: low level retry 9/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:40:45 DEBUG : pacer: low level retry 10/10 (error upload (upload) is still in PHASE_TYPE_PENDING)
2025/01/25 01:40:45 DEBUG : file name.txt: canceling upload: can't verify the task is completed: &api.Task{Kind:"drive#task", ID:"VOHQ6XS-uejti-akKE6YXsTWo1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc0005ce0c0), FileID:"VOHQ6XRguejti-akKE6YXsTPo1", FileName:"file name.txt", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0xb71b000, ext:63873366032, loc:(*time.Location)(0xc00021cbd0)}, UpdatedTime:api.Time{wall:0xca2dd00, ext:63873366032, loc:(*time.Location)(0xc00021cbd0)}, ThirdTaskID:"", Phase:"PHASE_TYPE_PENDING", Progress:0, IconLink:"https://static.mypikpak.com/0d8b20b308a8f2fb094caba73cd2b809f7f3c636", Callback:"", ReferenceResource:interface {}(nil), Space:""}
2025/01/25 01:40:47 DEBUG : pacer: Reducing sleep to 1.5s
2025/01/25 01:40:49 DEBUG : pacer: Reducing sleep to 1.125s
2025/01/25 01:40:50 DEBUG : pacer: Reducing sleep to 843.75ms
2025/01/25 01:40:50 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:"VOHQ6XS-uejti-akKE6YXsTWo1", Name:"upload", Type:"upload", UserID:"ZB7KFqZKGnYUJW_K", Statuses:[]interface {}{}, StatusSize:0, Params:(*api.TaskParams)(0xc0005ce0c0), FileID:"VOHQ6XRguejti-akKE6YXsTPo1", FileName:"file name.txt", FileSize:"100", Message:"Pending", CreatedTime:api.Time{wall:0xb71b000, ext:63873366032, loc:(*time.Location)(0xc00021cbd0)}, UpdatedTime:api.Time{wall:0xca2dd00, ext:63873366032, loc:(*time.Location)(0xc00021cbd0)}, 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/25 01:40:52 DEBUG : pacer: Reducing sleep to 632.8125ms
2025/01/25 01:40:52 DEBUG : pacer: Reducing sleep to 474.609375ms
2025/01/25 01:40:53 DEBUG : pacer: Reducing sleep to 355.957031ms
2025/01/25 01:40:53 ERROR : : error listing: directory not found
2025/01/25 01:40:53 DEBUG : pacer: Reducing sleep to 266.967773ms
--- FAIL: TestIntegration (234.86s)
    --- FAIL: TestIntegration/FsMkdir (232.71s)
        --- PASS: TestIntegration/FsMkdir/FsEncoding (210.18s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/control_chars (14.42s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/dot (6.67s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/dot_dot (7.12s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/punctuation (8.38s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/leading_space (6.74s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/leading_tilde (14.92s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/leading_CR (16.47s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/leading_LF (6.16s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/leading_HT (14.20s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/leading_VT (16.25s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/leading_dot (18.19s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/trailing_space (14.89s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/trailing_CR (6.43s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/trailing_LF (6.42s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/trailing_HT (18.28s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/trailing_VT (14.30s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/trailing_dot (6.47s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/invalid_UTF-8 (7.10s)
            --- PASS: TestIntegration/FsMkdir/FsEncoding/URL_encoding (6.49s)
        --- FAIL: TestIntegration/FsMkdir/FsPutFiles (19.69s)
FAIL
exit status 1
FAIL	github.com/rclone/rclone/backend/pikpak	234.876s
"go test -v -timeout 1h0m0s -remote TestPikPak: -verbose -test.run '^TestIntegration$/^FsMkdir$/^FsEncoding$/^(URL_encoding|control_chars|dot|dot_dot|invalid_UTF-8|leading_CR|leading_HT|leading_LF|leading_VT|leading_dot|leading_space|leading_tilde|punctuation|trailing_CR|trailing_HT|trailing_LF|trailing_VT|trailing_dot|trailing_space)$|^TestIntegration$/^FsMkdir$/^FsPutFiles$/^(FsDirMove|FsListDirFile2|FsListLevel2|FsListR|FsPurge|FsPurgeRoot)$|^TestIntegration$/^FsMkdir$/^FsPutFiles$/^FromRoot$/^(List|ListEntries)$'" - Finished ERROR in 3m55.592657781s (try 2/5): exit status 1: Failed [TestIntegration/FsMkdir/FsPutFiles]