"go test -v -timeout 1h0m0s -remote TestOneDrive: -verbose" - Starting (try 5/5) 2025/10/24 06:46:24 DEBUG : Creating backend with remote "TestOneDrive:rclone-test-fagiveq1qeba" 2025/10/24 06:46:24 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/10/24 06:46:24 DEBUG : TestOneDrive: Token expired 2025/10/24 06:46:24 DEBUG : TestOneDrive: No updated token found in the config file 2025/10/24 06:46:25 DEBUG : TestOneDrive: Token refresh successful 2025/10/24 06:46:25 DEBUG : Saving config "token" in section "TestOneDrive" of the config file 2025/10/24 06:46:25 DEBUG : TestOneDrive: Saved new token in config file 2025/10/24 06:46:25 DEBUG : Too many requests. Trying again in 219600 seconds. 2025/10/24 06:46:25 DEBUG : pacer: low level retry 1/10 (error accessDenied: throttledRequest: Too Many Requests: trying again in 61h0m0s) 2025/10/24 06:46:25 DEBUG : pacer: Rate limited, increasing sleep to 61h0m0s 2025/10/24 06:46:25 DEBUG : Too many requests. Trying again in 219600 seconds. 2025/10/24 06:46:25 DEBUG : pacer: low level retry 2/10 (error accessDenied: throttledRequest: Too Many Requests: trying again in 61h0m0s) 2025/10/24 07:46:24 DEBUG : OneDrive root 'rclone-test-fagiveq1qeba': Background refresher detected expired token but no uploads in progress - doing nothing SIGQUIT: quit PC=0x485861 m=0 sigcode=0 goroutine 0 gp=0x141f580 m=0 mp=0x1420d00 [idle]: runtime.futex(0x1420e40, 0x80, 0x0, 0x0, 0x0, 0x0) /usr/local/go/src/runtime/sys_linux_amd64.s:557 +0x21 fp=0x7fff2e1687a8 sp=0x7fff2e1687a0 pc=0x485861 runtime.futexsleep(0x7fff2e168820?, 0x141f580?, 0x7fff2e168820?) /usr/local/go/src/runtime/os_linux.go:75 +0x30 fp=0x7fff2e1687f8 sp=0x7fff2e1687a8 pc=0x43fdf0 runtime.notesleep(0x1420e40) /usr/local/go/src/runtime/lock_futex.go:47 +0x87 fp=0x7fff2e168830 sp=0x7fff2e1687f8 pc=0x418c07 runtime.mPark(...) /usr/local/go/src/runtime/proc.go:1887 runtime.stoplockedm() /usr/local/go/src/runtime/proc.go:3165 +0x73 fp=0x7fff2e168888 sp=0x7fff2e168830 pc=0x44bd33 runtime.schedule() /usr/local/go/src/runtime/proc.go:3999 +0x3a fp=0x7fff2e1688c0 sp=0x7fff2e168888 pc=0x44e0fa runtime.park_m(0xc0001b8c40) /usr/local/go/src/runtime/proc.go:4144 +0x285 fp=0x7fff2e168920 sp=0x7fff2e1688c0 pc=0x44e625 runtime.mcall() /usr/local/go/src/runtime/asm_amd64.s:459 +0x4e fp=0x7fff2e168938 sp=0x7fff2e168920 pc=0x4819ee goroutine 1 gp=0xc000002380 m=nil [chan receive, 65 minutes]: runtime.gopark(0x814df9?, 0xc0003fa9a0?, 0x1?, 0x0?, 0xc00004cfa0?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc0000e96e8 sp=0xc0000e96c8 pc=0x47ba4e runtime.chanrecv(0xc000042e00, 0x0, 0x1) /usr/local/go/src/runtime/chan.go:664 +0x445 fp=0xc0000e9760 sp=0xc0000e96e8 pc=0x413805 runtime.chanrecv1(0xe9a570?, 0xe7db60?) /usr/local/go/src/runtime/chan.go:506 +0x12 fp=0xc0000e9788 sp=0xc0000e9760 pc=0x413392 github.com/rclone/rclone/lib/pacer.(*Pacer).beginCall(0xc0000995c0, 0x0) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:163 +0x26 fp=0xc0000e97c0 sp=0xc0000e9788 pc=0x8011a6 github.com/rclone/rclone/lib/pacer.(*Pacer).call(0xc0000995c0, 0xc0003dcb00, 0xa) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:231 +0xa5 fp=0xc0000e9818 sp=0xc0000e97c0 pc=0x801785 github.com/rclone/rclone/lib/pacer.(*Pacer).Call(0xc0000995c0, 0xc0003dcb00) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:251 +0x93 fp=0xc0000e9850 sp=0xc0000e9818 pc=0x8018b3 github.com/rclone/rclone/backend/onedrive.(*Fs).readMetaDataForPath(0xc0000d8900, {0xe84238, 0x1440ae0}, {0x0, 0x0}) /home/rclone/go/src/github.com/rclone/rclone/backend/onedrive/onedrive.go:949 +0x2d9 fp=0xc0000e9aa0 sp=0xc0000e9850 pc=0xb0a8f9 github.com/rclone/rclone/backend/onedrive.NewFs({0xe84238, 0x1440ae0}, {0xc0003aa150, 0xc}, {0xc0003aa15d, 0x18}, {0xe80748, 0xc0003d1200}) /home/rclone/go/src/github.com/rclone/rclone/backend/onedrive/onedrive.go:1139 +0xa39 fp=0xc0000e9c30 sp=0xc0000e9aa0 pc=0xb0bd19 github.com/rclone/rclone/fs.NewFs({0xe84238, 0x1440ae0}, {0xc0003aa150, 0x25}) /home/rclone/go/src/github.com/rclone/rclone/fs/newfs.go:75 +0x378 fp=0xc0000e9d90 sp=0xc0000e9c30 pc=0x8128d8 github.com/rclone/rclone/fstest.RandomRemote() /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:465 +0x51 fp=0xc0000e9df0 sp=0xc0000e9d90 pc=0xad7371 github.com/rclone/rclone/fstest.newRun() /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:96 +0x6e fp=0xc0000e9e78 sp=0xc0000e9df0 pc=0xad906e github.com/rclone/rclone/fstest.TestMain(0xc00036f7c0) /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:67 +0x76 fp=0xc0000e9eb0 sp=0xc0000e9e78 pc=0xad8f76 github.com/rclone/rclone/backend/onedrive.TestMain(...) /home/rclone/go/src/github.com/rclone/rclone/backend/onedrive/onedrive_internal_test.go:41 main.main() _testmain.go:53 +0xa9 fp=0xc0000e9f50 sp=0xc0000e9eb0 pc=0xb25f09 runtime.main() /usr/local/go/src/runtime/proc.go:283 +0x28b fp=0xc0000e9fe0 sp=0xc0000e9f50 pc=0x44670b runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000e9fe8 sp=0xc0000e9fe0 pc=0x483a21 goroutine 2 gp=0xc000002e00 m=nil [force gc (idle), 2 minutes]: runtime.gopark(0x2ae49a81c4b287?, 0x0?, 0x0?, 0x0?, 0x0?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc00006cfa8 sp=0xc00006cf88 pc=0x47ba4e runtime.goparkunlock(...) /usr/local/go/src/runtime/proc.go:441 runtime.forcegchelper() /usr/local/go/src/runtime/proc.go:348 +0xb3 fp=0xc00006cfe0 sp=0xc00006cfa8 pc=0x446a53 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00006cfe8 sp=0xc00006cfe0 pc=0x483a21 created by runtime.init.7 in goroutine 1 /usr/local/go/src/runtime/proc.go:336 +0x1a goroutine 3 gp=0xc000003340 m=nil [GC sweep wait]: runtime.gopark(0x1?, 0x0?, 0x0?, 0x0?, 0x0?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc00006d780 sp=0xc00006d760 pc=0x47ba4e runtime.goparkunlock(...) /usr/local/go/src/runtime/proc.go:441 runtime.bgsweep(0xc000048080) /usr/local/go/src/runtime/mgcsweep.go:316 +0xdf fp=0xc00006d7c8 sp=0xc00006d780 pc=0x42e65f runtime.gcenable.gowrap1() /usr/local/go/src/runtime/mgc.go:204 +0x25 fp=0xc00006d7e0 sp=0xc00006d7c8 pc=0x422985 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00006d7e8 sp=0xc00006d7e0 pc=0x483a21 created by runtime.gcenable in goroutine 1 /usr/local/go/src/runtime/mgc.go:204 +0x66 goroutine 4 gp=0xc000003500 m=nil [GC scavenge wait, 2 minutes]: runtime.gopark(0x1220e37a?, 0x121ce952?, 0x0?, 0x0?, 0x0?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc00006df78 sp=0xc00006df58 pc=0x47ba4e runtime.goparkunlock(...) /usr/local/go/src/runtime/proc.go:441 runtime.(*scavengerState).park(0x141eee0) /usr/local/go/src/runtime/mgcscavenge.go:425 +0x49 fp=0xc00006dfa8 sp=0xc00006df78 pc=0x42c0c9 runtime.bgscavenge(0xc000048080) /usr/local/go/src/runtime/mgcscavenge.go:658 +0x59 fp=0xc00006dfc8 sp=0xc00006dfa8 pc=0x42c659 runtime.gcenable.gowrap2() /usr/local/go/src/runtime/mgc.go:205 +0x25 fp=0xc00006dfe0 sp=0xc00006dfc8 pc=0x422925 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00006dfe8 sp=0xc00006dfe0 pc=0x483a21 created by runtime.gcenable in goroutine 1 /usr/local/go/src/runtime/mgc.go:205 +0xa5 goroutine 5 gp=0xc000003dc0 m=nil [finalizer wait, 63 minutes]: runtime.gopark(0x0?, 0xc0003f6108?, 0x0?, 0x40?, 0x1000000010?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc00006c630 sp=0xc00006c610 pc=0x47ba4e runtime.runfinq() /usr/local/go/src/runtime/mfinal.go:196 +0x107 fp=0xc00006c7e0 sp=0xc00006c630 pc=0x421947 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00006c7e8 sp=0xc00006c7e0 pc=0x483a21 created by runtime.createfing in goroutine 1 /usr/local/go/src/runtime/mfinal.go:166 +0x3d goroutine 6 gp=0xc0001b88c0 m=nil [chan receive, 2 minutes]: runtime.gopark(0xc0001bbb80?, 0xc000368198?, 0x60?, 0xe7?, 0x65ef48?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc00006e718 sp=0xc00006e6f8 pc=0x47ba4e runtime.chanrecv(0xc000042690, 0x0, 0x1) /usr/local/go/src/runtime/chan.go:664 +0x445 fp=0xc00006e790 sp=0xc00006e718 pc=0x413805 runtime.chanrecv1(0x0?, 0x0?) /usr/local/go/src/runtime/chan.go:506 +0x12 fp=0xc00006e7b8 sp=0xc00006e790 pc=0x413392 runtime.unique_runtime_registerUniqueMapCleanup.func2(...) /usr/local/go/src/runtime/mgc.go:1796 runtime.unique_runtime_registerUniqueMapCleanup.gowrap1() /usr/local/go/src/runtime/mgc.go:1799 +0x2f fp=0xc00006e7e0 sp=0xc00006e7b8 pc=0x425acf runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00006e7e8 sp=0xc00006e7e0 pc=0x483a21 created by unique.runtime_registerUniqueMapCleanup in goroutine 1 /usr/local/go/src/runtime/mgc.go:1794 +0x79 goroutine 8 gp=0xc0001b8c40 m=nil [select, 65 minutes, locked to thread]: runtime.gopark(0xc00006efa8?, 0x2?, 0xc?, 0x2e?, 0xc00006ef94?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc00006ee20 sp=0xc00006ee00 pc=0x47ba4e runtime.selectgo(0xc00006efa8, 0xc00006ef90, 0x0?, 0x0, 0xc00029e120?, 0x1) /usr/local/go/src/runtime/select.go:351 +0x837 fp=0xc00006ef58 sp=0xc00006ee20 pc=0x458f57 runtime.ensureSigM.func1() /usr/local/go/src/runtime/signal_unix.go:1085 +0x192 fp=0xc00006efe0 sp=0xc00006ef58 pc=0x475f12 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00006efe8 sp=0xc00006efe0 pc=0x483a21 created by runtime.ensureSigM in goroutine 1 /usr/local/go/src/runtime/signal_unix.go:1068 +0xc8 goroutine 9 gp=0xc0003996c0 m=5 mp=0xc000100008 [syscall, 65 minutes]: runtime.notetsleepg(0x14418a0, 0xffffffffffffffff) /usr/local/go/src/runtime/lock_futex.go:123 +0x29 fp=0xc00006f7a0 sp=0xc00006f778 pc=0x418ee9 os/signal.signal_recv() /usr/local/go/src/runtime/sigqueue.go:152 +0x29 fp=0xc00006f7c0 sp=0xc00006f7a0 pc=0x47dc69 os/signal.loop() /usr/local/go/src/os/signal/signal_unix.go:23 +0x13 fp=0xc00006f7e0 sp=0xc00006f7c0 pc=0x5c44b3 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00006f7e8 sp=0xc00006f7e0 pc=0x483a21 created by os/signal.Notify.func1.1 in goroutine 1 /usr/local/go/src/os/signal/signal.go:152 +0x1f goroutine 10 gp=0xc000399880 m=nil [chan receive, 65 minutes]: runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc00006ff10 sp=0xc00006fef0 pc=0x47ba4e runtime.chanrecv(0xc000380f50, 0x0, 0x1) /usr/local/go/src/runtime/chan.go:664 +0x445 fp=0xc00006ff88 sp=0xc00006ff10 pc=0x413805 runtime.chanrecv1(0x0?, 0x0?) /usr/local/go/src/runtime/chan.go:506 +0x12 fp=0xc00006ffb0 sp=0xc00006ff88 pc=0x413392 github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler.func1() /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:24 +0x27 fp=0xc00006ffe0 sp=0xc00006ffb0 pc=0x9b9cc7 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00006ffe8 sp=0xc00006ffe0 pc=0x483a21 created by github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler in goroutine 1 /home/rclone/go/src/github.com/rclone/rclone/fs/accounting/accounting_unix.go:21 +0xa7 goroutine 11 gp=0xc000399c00 m=nil [select, 6 minutes]: runtime.gopark(0xc0000e5f98?, 0x2?, 0x60?, 0x0?, 0xc0000e5f50?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc0004badd0 sp=0xc0004badb0 pc=0x47ba4e runtime.selectgo(0xc0004baf98, 0xc0000e5f4c, 0xc00004c010?, 0x0, 0x56?, 0x1) /usr/local/go/src/runtime/select.go:351 +0x837 fp=0xc0004baf08 sp=0xc0004badd0 pc=0x458f57 github.com/rclone/rclone/lib/oauthutil.(*Renew).renewOnExpiry(0xc0003dcac0) /home/rclone/go/src/github.com/rclone/rclone/lib/oauthutil/renew.go:43 +0x86 fp=0xc0004bafc8 sp=0xc0004baf08 pc=0xa62266 github.com/rclone/rclone/lib/oauthutil.NewRenew.gowrap1() /home/rclone/go/src/github.com/rclone/rclone/lib/oauthutil/renew.go:32 +0x25 fp=0xc0004bafe0 sp=0xc0004bafc8 pc=0xa621a5 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0004bafe8 sp=0xc0004bafe0 pc=0x483a21 created by github.com/rclone/rclone/lib/oauthutil.NewRenew in goroutine 1 /home/rclone/go/src/github.com/rclone/rclone/lib/oauthutil/renew.go:32 +0xe5 goroutine 48 gp=0xc0004881c0 m=nil [sleep, 65 minutes]: runtime.gopark(0x2ae100cb279ec2?, 0xc00012e930?, 0xa0?, 0xe9?, 0xc000284040?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000082f40 sp=0xc000082f20 pc=0x47ba4e time.Sleep(0xc7b99bfe2000) /usr/local/go/src/runtime/time.go:338 +0x165 fp=0xc000082f98 sp=0xc000082f40 pc=0x47fd45 github.com/rclone/rclone/lib/pacer.(*Pacer).beginCall.func1(0xc000396008?) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:171 +0x1c fp=0xc000082fc8 sp=0xc000082f98 pc=0x80133c github.com/rclone/rclone/lib/pacer.(*Pacer).beginCall.gowrap1() /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:173 +0x24 fp=0xc000082fe0 sp=0xc000082fc8 pc=0x8012e4 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000082fe8 sp=0xc000082fe0 pc=0x483a21 created by github.com/rclone/rclone/lib/pacer.(*Pacer).beginCall in goroutine 1 /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:170 +0xf6 goroutine 38 gp=0xc000402380 m=nil [GC worker (idle)]: runtime.gopark(0x2ae49a81eaa7ea?, 0x3?, 0x75?, 0x47?, 0x0?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000450738 sp=0xc000450718 pc=0x47ba4e runtime.gcBgMarkWorker(0xc000428380) /usr/local/go/src/runtime/mgc.go:1423 +0xe9 fp=0xc0004507c8 sp=0xc000450738 pc=0x424de9 runtime.gcBgMarkStartWorkers.gowrap1() /usr/local/go/src/runtime/mgc.go:1339 +0x25 fp=0xc0004507e0 sp=0xc0004507c8 pc=0x424cc5 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0004507e8 sp=0xc0004507e0 pc=0x483a21 created by runtime.gcBgMarkStartWorkers in goroutine 36 /usr/local/go/src/runtime/mgc.go:1339 +0x105 goroutine 39 gp=0xc000402540 m=nil [GC worker (idle), 65 minutes]: runtime.gopark(0x2ae100a7b877cd?, 0x0?, 0x0?, 0x0?, 0x0?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000450f38 sp=0xc000450f18 pc=0x47ba4e runtime.gcBgMarkWorker(0xc000428380) /usr/local/go/src/runtime/mgc.go:1423 +0xe9 fp=0xc000450fc8 sp=0xc000450f38 pc=0x424de9 runtime.gcBgMarkStartWorkers.gowrap1() /usr/local/go/src/runtime/mgc.go:1339 +0x25 fp=0xc000450fe0 sp=0xc000450fc8 pc=0x424cc5 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000450fe8 sp=0xc000450fe0 pc=0x483a21 created by runtime.gcBgMarkStartWorkers in goroutine 36 /usr/local/go/src/runtime/mgc.go:1339 +0x105 goroutine 40 gp=0xc000402700 m=nil [GC worker (idle), 65 minutes]: runtime.gopark(0x2ae100a88f4b80?, 0x0?, 0x0?, 0x0?, 0x0?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000451738 sp=0xc000451718 pc=0x47ba4e runtime.gcBgMarkWorker(0xc000428380) /usr/local/go/src/runtime/mgc.go:1423 +0xe9 fp=0xc0004517c8 sp=0xc000451738 pc=0x424de9 runtime.gcBgMarkStartWorkers.gowrap1() /usr/local/go/src/runtime/mgc.go:1339 +0x25 fp=0xc0004517e0 sp=0xc0004517c8 pc=0x424cc5 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0004517e8 sp=0xc0004517e0 pc=0x483a21 created by runtime.gcBgMarkStartWorkers in goroutine 36 /usr/local/go/src/runtime/mgc.go:1339 +0x105 goroutine 41 gp=0xc0004028c0 m=nil [GC worker (idle), 24 minutes]: runtime.gopark(0x2ae359b804f774?, 0x0?, 0x0?, 0x0?, 0x0?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000451f38 sp=0xc000451f18 pc=0x47ba4e runtime.gcBgMarkWorker(0xc000428380) /usr/local/go/src/runtime/mgc.go:1423 +0xe9 fp=0xc000451fc8 sp=0xc000451f38 pc=0x424de9 runtime.gcBgMarkStartWorkers.gowrap1() /usr/local/go/src/runtime/mgc.go:1339 +0x25 fp=0xc000451fe0 sp=0xc000451fc8 pc=0x424cc5 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000451fe8 sp=0xc000451fe0 pc=0x483a21 created by runtime.gcBgMarkStartWorkers in goroutine 36 /usr/local/go/src/runtime/mgc.go:1339 +0x105 rax 0xca rbx 0x0 rcx 0x485863 rdx 0x0 rdi 0x1420e40 rsi 0x80 rbp 0x7fff2e1687e8 rsp 0x7fff2e1687a0 r8 0x0 r9 0x0 r10 0x0 r11 0x286 r12 0x7fff2e1687c8 r13 0xc00006ef94 r14 0x141f580 r15 0xc00029eb40 rip 0x485861 rflags 0x286 cs 0x33 fs 0x0 gs 0x0 *** Test killed with quit: ran too long (1h6m0s). exit status 2 FAIL github.com/rclone/rclone/backend/onedrive 3960.111s "go test -v -timeout 1h0m0s -remote TestOneDrive: -verbose" - Finished ERROR in 1h6m1.042687073s (try 5/5): exit status 1: Failed []