"go test -v -timeout 1h0m0s -remote TestOneDrive: -verbose" - Starting (try 2/5) 2025/08/03 02:08:40 DEBUG : Creating backend with remote "TestOneDrive:rclone-test-ridepal3xume" 2025/08/03 02:08:40 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/08/03 02:08:41 DEBUG : Too many requests. Trying again in 129136 seconds. 2025/08/03 02:08:41 DEBUG : pacer: low level retry 1/10 (error accessDenied: throttledRequest: Too Many Requests: trying again in 35h52m16s) 2025/08/03 02:08:41 DEBUG : pacer: Rate limited, increasing sleep to 35h52m16s 2025/08/03 02:08:41 DEBUG : Too many requests. Trying again in 129136 seconds. 2025/08/03 02:08:41 DEBUG : pacer: low level retry 2/10 (error accessDenied: throttledRequest: Too Many Requests: trying again in 35h52m16s) 2025/08/03 03:00:55 DEBUG : OneDrive root 'rclone-test-ridepal3xume': Token expired but no uploads in progress - doing nothing SIGQUIT: quit PC=0x485861 m=0 sigcode=0 goroutine 0 gp=0x13a8360 m=0 mp=0x13a96e0 [idle]: runtime.futex(0x13a9820, 0x80, 0x0, 0x0, 0x0, 0x0) /usr/local/go/src/runtime/sys_linux_amd64.s:557 +0x21 fp=0x7ffc906bd978 sp=0x7ffc906bd970 pc=0x485861 runtime.futexsleep(0x7ffc906bd9f0?, 0x13a8360?, 0x7ffc906bd9f0?) /usr/local/go/src/runtime/os_linux.go:75 +0x30 fp=0x7ffc906bd9c8 sp=0x7ffc906bd978 pc=0x43fdf0 runtime.notesleep(0x13a9820) /usr/local/go/src/runtime/lock_futex.go:47 +0x87 fp=0x7ffc906bda00 sp=0x7ffc906bd9c8 pc=0x418c07 runtime.mPark(...) /usr/local/go/src/runtime/proc.go:1887 runtime.stoplockedm() /usr/local/go/src/runtime/proc.go:3165 +0x73 fp=0x7ffc906bda58 sp=0x7ffc906bda00 pc=0x44bd33 runtime.schedule() /usr/local/go/src/runtime/proc.go:3999 +0x3a fp=0x7ffc906bda90 sp=0x7ffc906bda58 pc=0x44e0fa runtime.park_m(0xc000103340) /usr/local/go/src/runtime/proc.go:4144 +0x285 fp=0x7ffc906bdaf0 sp=0x7ffc906bda90 pc=0x44e625 runtime.mcall() /usr/local/go/src/runtime/asm_amd64.s:459 +0x4e fp=0x7ffc906bdb08 sp=0x7ffc906bdaf0 pc=0x4819ee goroutine 1 gp=0xc000002380 m=nil [chan receive, 65 minutes]: runtime.gopark(0x812bb9?, 0xc00044f480?, 0x1?, 0x0?, 0xc000320340?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc00019f6f0 sp=0xc00019f6d0 pc=0x47ba4e runtime.chanrecv(0xc0002d6700, 0x0, 0x1) /usr/local/go/src/runtime/chan.go:664 +0x445 fp=0xc00019f768 sp=0xc00019f6f0 pc=0x413805 runtime.chanrecv1(0xe4a090?, 0xe2eb00?) /usr/local/go/src/runtime/chan.go:506 +0x12 fp=0xc00019f790 sp=0xc00019f768 pc=0x413392 github.com/rclone/rclone/lib/pacer.(*Pacer).beginCall(0xc0002a1860) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:161 +0x25 fp=0xc00019f7c8 sp=0xc00019f790 pc=0x7ff965 github.com/rclone/rclone/lib/pacer.(*Pacer).call(0xc0002a1860, 0xc000434840, 0xa) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:198 +0x5c fp=0xc00019f818 sp=0xc00019f7c8 pc=0x7ffcfc github.com/rclone/rclone/lib/pacer.(*Pacer).Call(0xc0002a1860, 0xc000434840) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:218 +0x93 fp=0xc00019f850 sp=0xc00019f818 pc=0x7ffe33 github.com/rclone/rclone/backend/onedrive.(*Fs).readMetaDataForPath(0xc0002d4300, {0xe34c08, 0x13c94c0}, {0x0, 0x0}) /home/rclone/go/src/github.com/rclone/rclone/backend/onedrive/onedrive.go:949 +0x2d9 fp=0xc00019faa0 sp=0xc00019f850 pc=0xad12f9 github.com/rclone/rclone/backend/onedrive.NewFs({0xe34c08, 0x13c94c0}, {0xc00038cc30, 0xc}, {0xc00038cc3d, 0x18}, {0xe31508, 0xc00043e000}) /home/rclone/go/src/github.com/rclone/rclone/backend/onedrive/onedrive.go:1139 +0xa39 fp=0xc00019fc30 sp=0xc00019faa0 pc=0xad2719 github.com/rclone/rclone/fs.NewFs({0xe34c08, 0x13c94c0}, {0xc00038cc30, 0x25}) /home/rclone/go/src/github.com/rclone/rclone/fs/newfs.go:75 +0x378 fp=0xc00019fd90 sp=0xc00019fc30 pc=0x810698 github.com/rclone/rclone/fstest.RandomRemote() /home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:462 +0x51 fp=0xc00019fdf0 sp=0xc00019fd90 pc=0xa9e5d1 github.com/rclone/rclone/fstest.newRun() /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:96 +0x6e fp=0xc00019fe78 sp=0xc00019fdf0 pc=0xaa026e github.com/rclone/rclone/fstest.TestMain(0xc000397ea0) /home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:67 +0x76 fp=0xc00019feb0 sp=0xc00019fe78 pc=0xaa0176 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=0xc00019ff50 sp=0xc00019feb0 pc=0xaec949 runtime.main() /usr/local/go/src/runtime/proc.go:283 +0x28b fp=0xc00019ffe0 sp=0xc00019ff50 pc=0x44670b runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00019ffe8 sp=0xc00019ffe0 pc=0x483a21 goroutine 2 gp=0xc000002e00 m=nil [force gc (idle), 2 minutes]: runtime.gopark(0x11a9d210a76ce9?, 0x0?, 0x0?, 0x0?, 0x0?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000068fa8 sp=0xc000068f88 pc=0x47ba4e runtime.goparkunlock(...) /usr/local/go/src/runtime/proc.go:441 runtime.forcegchelper() /usr/local/go/src/runtime/proc.go:348 +0xb3 fp=0xc000068fe0 sp=0xc000068fa8 pc=0x446a53 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000068fe8 sp=0xc000068fe0 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=0xc000069780 sp=0xc000069760 pc=0x47ba4e runtime.goparkunlock(...) /usr/local/go/src/runtime/proc.go:441 runtime.bgsweep(0xc000090000) /usr/local/go/src/runtime/mgcsweep.go:316 +0xdf fp=0xc0000697c8 sp=0xc000069780 pc=0x42e65f runtime.gcenable.gowrap1() /usr/local/go/src/runtime/mgc.go:204 +0x25 fp=0xc0000697e0 sp=0xc0000697c8 pc=0x422985 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000697e8 sp=0xc0000697e0 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(0x124607?, 0xb57f1?, 0x0?, 0x0?, 0x0?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000069f78 sp=0xc000069f58 pc=0x47ba4e runtime.goparkunlock(...) /usr/local/go/src/runtime/proc.go:441 runtime.(*scavengerState).park(0x13a7ce0) /usr/local/go/src/runtime/mgcscavenge.go:425 +0x49 fp=0xc000069fa8 sp=0xc000069f78 pc=0x42c0c9 runtime.bgscavenge(0xc000090000) /usr/local/go/src/runtime/mgcscavenge.go:658 +0x59 fp=0xc000069fc8 sp=0xc000069fa8 pc=0x42c659 runtime.gcenable.gowrap2() /usr/local/go/src/runtime/mgc.go:205 +0x25 fp=0xc000069fe0 sp=0xc000069fc8 pc=0x422925 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000069fe8 sp=0xc000069fe0 pc=0x483a21 created by runtime.gcenable in goroutine 1 /usr/local/go/src/runtime/mgc.go:205 +0xa5 goroutine 18 gp=0xc000102700 m=nil [finalizer wait, 65 minutes]: runtime.gopark(0x1b8?, 0xc000002380?, 0x1?, 0x23?, 0xc000068688?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000068630 sp=0xc000068610 pc=0x47ba4e runtime.runfinq() /usr/local/go/src/runtime/mfinal.go:196 +0x107 fp=0xc0000687e0 sp=0xc000068630 pc=0x421947 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000687e8 sp=0xc0000687e0 pc=0x483a21 created by runtime.createfing in goroutine 1 /usr/local/go/src/runtime/mfinal.go:166 +0x3d goroutine 19 gp=0xc000102fc0 m=nil [chan receive, 2 minutes]: runtime.gopark(0xc00012fc20?, 0xc00012c0c0?, 0x60?, 0x47?, 0x65e908?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000064718 sp=0xc0000646f8 pc=0x47ba4e runtime.chanrecv(0xc000110460, 0x0, 0x1) /usr/local/go/src/runtime/chan.go:664 +0x445 fp=0xc000064790 sp=0xc000064718 pc=0x413805 runtime.chanrecv1(0x0?, 0x0?) /usr/local/go/src/runtime/chan.go:506 +0x12 fp=0xc0000647b8 sp=0xc000064790 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=0xc0000647e0 sp=0xc0000647b8 pc=0x425acf runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000647e8 sp=0xc0000647e0 pc=0x483a21 created by unique.runtime_registerUniqueMapCleanup in goroutine 1 /usr/local/go/src/runtime/mgc.go:1794 +0x79 goroutine 35 gp=0xc000103340 m=nil [select, 65 minutes, locked to thread]: runtime.gopark(0xc000064fa8?, 0x2?, 0xc?, 0x2e?, 0xc000064f94?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000064e20 sp=0xc000064e00 pc=0x47ba4e runtime.selectgo(0xc000064fa8, 0xc000064f90, 0x0?, 0x0, 0xc0002a0120?, 0x1) /usr/local/go/src/runtime/select.go:351 +0x837 fp=0xc000064f58 sp=0xc000064e20 pc=0x458f57 runtime.ensureSigM.func1() /usr/local/go/src/runtime/signal_unix.go:1085 +0x192 fp=0xc000064fe0 sp=0xc000064f58 pc=0x475f12 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000064fe8 sp=0xc000064fe0 pc=0x483a21 created by runtime.ensureSigM in goroutine 1 /usr/local/go/src/runtime/signal_unix.go:1068 +0xc8 goroutine 36 gp=0xc0003e28c0 m=5 mp=0xc000100008 [syscall, 65 minutes]: runtime.notetsleepg(0x13ca220, 0xffffffffffffffff) /usr/local/go/src/runtime/lock_futex.go:123 +0x29 fp=0xc0004087a0 sp=0xc000408778 pc=0x418ee9 os/signal.signal_recv() /usr/local/go/src/runtime/sigqueue.go:152 +0x29 fp=0xc0004087c0 sp=0xc0004087a0 pc=0x47dc69 os/signal.loop() /usr/local/go/src/os/signal/signal_unix.go:23 +0x13 fp=0xc0004087e0 sp=0xc0004087c0 pc=0x5c4193 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0004087e8 sp=0xc0004087e0 pc=0x483a21 created by os/signal.Notify.func1.1 in goroutine 1 /usr/local/go/src/os/signal/signal.go:152 +0x1f goroutine 37 gp=0xc0003e2a80 m=nil [chan receive, 65 minutes]: runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000408f10 sp=0xc000408ef0 pc=0x47ba4e runtime.chanrecv(0xc0003f84d0, 0x0, 0x1) /usr/local/go/src/runtime/chan.go:664 +0x445 fp=0xc000408f88 sp=0xc000408f10 pc=0x413805 runtime.chanrecv1(0x0?, 0x0?) /usr/local/go/src/runtime/chan.go:506 +0x12 fp=0xc000408fb0 sp=0xc000408f88 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=0xc000408fe0 sp=0xc000408fb0 pc=0x9a3847 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000408fe8 sp=0xc000408fe0 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 38 gp=0xc0003e2e00 m=nil [select, 14 minutes]: runtime.gopark(0xc00019df98?, 0x2?, 0x40?, 0xe9?, 0xc00019df50?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc00007bdd0 sp=0xc00007bdb0 pc=0x47ba4e runtime.selectgo(0xc00007bf98, 0xc00019df4c, 0xc0002f8000?, 0x0, 0x38?, 0x1) /usr/local/go/src/runtime/select.go:351 +0x837 fp=0xc00007bf08 sp=0xc00007bdd0 pc=0x458f57 github.com/rclone/rclone/lib/oauthutil.(*Renew).renewOnExpiry(0xc000434800) /home/rclone/go/src/github.com/rclone/rclone/lib/oauthutil/renew.go:43 +0x86 fp=0xc00007bfc8 sp=0xc00007bf08 pc=0xa297a6 github.com/rclone/rclone/lib/oauthutil.NewRenew.gowrap1() /home/rclone/go/src/github.com/rclone/rclone/lib/oauthutil/renew.go:32 +0x25 fp=0xc00007bfe0 sp=0xc00007bfc8 pc=0xa296e5 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00007bfe8 sp=0xc00007bfe0 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 66 gp=0xc0003e2fc0 m=nil [sleep, 65 minutes]: runtime.gopark(0x11a642ba1f379b?, 0x0?, 0x0?, 0x0?, 0xc000409f88?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000409f40 sp=0xc000409f20 pc=0x47ba4e time.Sleep(0x7572d1686000) /usr/local/go/src/runtime/time.go:338 +0x165 fp=0xc000409f98 sp=0xc000409f40 pc=0x47fd45 github.com/rclone/rclone/lib/pacer.(*Pacer).beginCall.func1(0x0?) /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:169 +0x1c fp=0xc000409fc8 sp=0xc000409f98 pc=0x7ffafc github.com/rclone/rclone/lib/pacer.(*Pacer).beginCall.gowrap1() /home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:171 +0x24 fp=0xc000409fe0 sp=0xc000409fc8 pc=0x7ffaa4 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000409fe8 sp=0xc000409fe0 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:168 +0xef goroutine 48 gp=0xc0003e3500 m=nil [GC worker (idle)]: runtime.gopark(0x11a9d210d74191?, 0x0?, 0x0?, 0x0?, 0x0?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc00040b738 sp=0xc00040b718 pc=0x47ba4e runtime.gcBgMarkWorker(0xc0002d6ee0) /usr/local/go/src/runtime/mgc.go:1423 +0xe9 fp=0xc00040b7c8 sp=0xc00040b738 pc=0x424de9 runtime.gcBgMarkStartWorkers.gowrap1() /usr/local/go/src/runtime/mgc.go:1339 +0x25 fp=0xc00040b7e0 sp=0xc00040b7c8 pc=0x424cc5 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00040b7e8 sp=0xc00040b7e0 pc=0x483a21 created by runtime.gcBgMarkStartWorkers in goroutine 46 /usr/local/go/src/runtime/mgc.go:1339 +0x105 goroutine 49 gp=0xc0003e3880 m=nil [GC worker (idle), 65 minutes]: runtime.gopark(0x11a64299efdeee?, 0x0?, 0x0?, 0x0?, 0x0?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc00040bf38 sp=0xc00040bf18 pc=0x47ba4e runtime.gcBgMarkWorker(0xc0002d6ee0) /usr/local/go/src/runtime/mgc.go:1423 +0xe9 fp=0xc00040bfc8 sp=0xc00040bf38 pc=0x424de9 runtime.gcBgMarkStartWorkers.gowrap1() /usr/local/go/src/runtime/mgc.go:1339 +0x25 fp=0xc00040bfe0 sp=0xc00040bfc8 pc=0x424cc5 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00040bfe8 sp=0xc00040bfe0 pc=0x483a21 created by runtime.gcBgMarkStartWorkers in goroutine 46 /usr/local/go/src/runtime/mgc.go:1339 +0x105 goroutine 50 gp=0xc0003e3a40 m=nil [GC worker (idle), 65 minutes]: runtime.gopark(0x11a6429a00ba5a?, 0x0?, 0x0?, 0x0?, 0x0?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000404738 sp=0xc000404718 pc=0x47ba4e runtime.gcBgMarkWorker(0xc0002d6ee0) /usr/local/go/src/runtime/mgc.go:1423 +0xe9 fp=0xc0004047c8 sp=0xc000404738 pc=0x424de9 runtime.gcBgMarkStartWorkers.gowrap1() /usr/local/go/src/runtime/mgc.go:1339 +0x25 fp=0xc0004047e0 sp=0xc0004047c8 pc=0x424cc5 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0004047e8 sp=0xc0004047e0 pc=0x483a21 created by runtime.gcBgMarkStartWorkers in goroutine 46 /usr/local/go/src/runtime/mgc.go:1339 +0x105 goroutine 51 gp=0xc0003e3c00 m=nil [GC worker (idle), 65 minutes]: runtime.gopark(0x11a6429a012bb1?, 0x0?, 0x0?, 0x0?, 0x0?) /usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000404f38 sp=0xc000404f18 pc=0x47ba4e runtime.gcBgMarkWorker(0xc0002d6ee0) /usr/local/go/src/runtime/mgc.go:1423 +0xe9 fp=0xc000404fc8 sp=0xc000404f38 pc=0x424de9 runtime.gcBgMarkStartWorkers.gowrap1() /usr/local/go/src/runtime/mgc.go:1339 +0x25 fp=0xc000404fe0 sp=0xc000404fc8 pc=0x424cc5 runtime.goexit({}) /usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000404fe8 sp=0xc000404fe0 pc=0x483a21 created by runtime.gcBgMarkStartWorkers in goroutine 46 /usr/local/go/src/runtime/mgc.go:1339 +0x105 rax 0xca rbx 0x0 rcx 0x485863 rdx 0x0 rdi 0x13a9820 rsi 0x80 rbp 0x7ffc906bd9b8 rsp 0x7ffc906bd970 r8 0x0 r9 0x0 r10 0x0 r11 0x286 r12 0x7ffc906bd998 r13 0xc000064f94 r14 0x13a8360 r15 0xc000094180 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.088s "go test -v -timeout 1h0m0s -remote TestOneDrive: -verbose" - Finished ERROR in 1h6m1.047434446s (try 2/5): exit status 1: Failed []