"go test -v -timeout 1h0m0s -remote TestOneDrive: -verbose" - Starting (try 2/5)
2025/10/24 03:28:16 DEBUG : Creating backend with remote "TestOneDrive:rclone-test-sidibiv9gewo"
2025/10/24 03:28:16 DEBUG : Using config file from "/home/rclone/.rclone.conf"
2025/10/24 03:28:17 DEBUG : Too many requests. Trying again in 228398 seconds.
2025/10/24 03:28:17 DEBUG : pacer: low level retry 1/10 (error accessDenied: throttledRequest: Too Many Requests: trying again in 63h26m38s)
2025/10/24 03:28:17 DEBUG : pacer: Rate limited, increasing sleep to 63h26m38s
2025/10/24 03:28:17 DEBUG : Too many requests. Trying again in 228397 seconds.
2025/10/24 03:28:17 DEBUG : pacer: low level retry 2/10 (error accessDenied: throttledRequest: Too Many Requests: trying again in 63h26m37s)
2025/10/24 03:28:17 DEBUG : pacer: Rate limited, increasing sleep to 63h26m37s
2025/10/24 03:54:53 DEBUG : OneDrive root 'rclone-test-sidibiv9gewo': 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=0x7ffeb51e75a8 sp=0x7ffeb51e75a0 pc=0x485861
runtime.futexsleep(0x7ffeb51e7620?, 0x141f580?, 0x7ffeb51e7620?)
	/usr/local/go/src/runtime/os_linux.go:75 +0x30 fp=0x7ffeb51e75f8 sp=0x7ffeb51e75a8 pc=0x43fdf0
runtime.notesleep(0x1420e40)
	/usr/local/go/src/runtime/lock_futex.go:47 +0x87 fp=0x7ffeb51e7630 sp=0x7ffeb51e75f8 pc=0x418c07
runtime.mPark(...)
	/usr/local/go/src/runtime/proc.go:1887
runtime.stoplockedm()
	/usr/local/go/src/runtime/proc.go:3165 +0x73 fp=0x7ffeb51e7688 sp=0x7ffeb51e7630 pc=0x44bd33
runtime.schedule()
	/usr/local/go/src/runtime/proc.go:3999 +0x3a fp=0x7ffeb51e76c0 sp=0x7ffeb51e7688 pc=0x44e0fa
runtime.park_m(0xc0000a3880)
	/usr/local/go/src/runtime/proc.go:4144 +0x285 fp=0x7ffeb51e7720 sp=0x7ffeb51e76c0 pc=0x44e625
runtime.mcall()
	/usr/local/go/src/runtime/asm_amd64.s:459 +0x4e fp=0x7ffeb51e7738 sp=0x7ffeb51e7720 pc=0x4819ee

goroutine 1 gp=0xc000002380 m=nil [chan receive, 65 minutes]:
runtime.gopark(0x814e68?, 0xcfb9d20d8207?, 0x80?, 0x5b?, 0xe79cc0?)
	/usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc0001136e8 sp=0xc0001136c8 pc=0x47ba4e
runtime.chanrecv(0xc0002760e0, 0x0, 0x1)
	/usr/local/go/src/runtime/chan.go:664 +0x445 fp=0xc000113760 sp=0xc0001136e8 pc=0x413805
runtime.chanrecv1(0xe9a570?, 0xe7db60?)
	/usr/local/go/src/runtime/chan.go:506 +0x12 fp=0xc000113788 sp=0xc000113760 pc=0x413392
github.com/rclone/rclone/lib/pacer.(*Pacer).beginCall(0xc000200480, 0x0)
	/home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:163 +0x26 fp=0xc0001137c0 sp=0xc000113788 pc=0x8011a6
github.com/rclone/rclone/lib/pacer.(*Pacer).call(0xc000200480, 0xc000231b80, 0xa)
	/home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:231 +0xa5 fp=0xc000113818 sp=0xc0001137c0 pc=0x801785
github.com/rclone/rclone/lib/pacer.(*Pacer).Call(0xc000200480, 0xc000231b80)
	/home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:251 +0x93 fp=0xc000113850 sp=0xc000113818 pc=0x8018b3
github.com/rclone/rclone/backend/onedrive.(*Fs).readMetaDataForPath(0xc00044a000, {0xe84238, 0x1440ae0}, {0x0, 0x0})
	/home/rclone/go/src/github.com/rclone/rclone/backend/onedrive/onedrive.go:949 +0x2d9 fp=0xc000113aa0 sp=0xc000113850 pc=0xb0a8f9
github.com/rclone/rclone/backend/onedrive.NewFs({0xe84238, 0x1440ae0}, {0xc000218000, 0xc}, {0xc00021800d, 0x18}, {0xe80748, 0xc000223620})
	/home/rclone/go/src/github.com/rclone/rclone/backend/onedrive/onedrive.go:1139 +0xa39 fp=0xc000113c30 sp=0xc000113aa0 pc=0xb0bd19
github.com/rclone/rclone/fs.NewFs({0xe84238, 0x1440ae0}, {0xc000218000, 0x25})
	/home/rclone/go/src/github.com/rclone/rclone/fs/newfs.go:75 +0x378 fp=0xc000113d90 sp=0xc000113c30 pc=0x8128d8
github.com/rclone/rclone/fstest.RandomRemote()
	/home/rclone/go/src/github.com/rclone/rclone/fstest/fstest.go:465 +0x51 fp=0xc000113df0 sp=0xc000113d90 pc=0xad7371
github.com/rclone/rclone/fstest.newRun()
	/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:96 +0x6e fp=0xc000113e78 sp=0xc000113df0 pc=0xad906e
github.com/rclone/rclone/fstest.TestMain(0xc000326e60)
	/home/rclone/go/src/github.com/rclone/rclone/fstest/run.go:67 +0x76 fp=0xc000113eb0 sp=0xc000113e78 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=0xc000113f50 sp=0xc000113eb0 pc=0xb25f09
runtime.main()
	/usr/local/go/src/runtime/proc.go:283 +0x28b fp=0xc000113fe0 sp=0xc000113f50 pc=0x44670b
runtime.goexit({})
	/usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000113fe8 sp=0xc000113fe0 pc=0x483a21

goroutine 2 gp=0xc000002e00 m=nil [force gc (idle), 3 minutes]:
runtime.gopark(0x2ad9b7594940c0?, 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 18 gp=0xc0000a2380 m=nil [GC sweep wait]:
runtime.gopark(0x141db01?, 0x0?, 0x0?, 0x0?, 0x0?)
	/usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000068780 sp=0xc000068760 pc=0x47ba4e
runtime.goparkunlock(...)
	/usr/local/go/src/runtime/proc.go:441
runtime.bgsweep(0xc0000b0000)
	/usr/local/go/src/runtime/mgcsweep.go:316 +0xdf fp=0xc0000687c8 sp=0xc000068780 pc=0x42e65f
runtime.gcenable.gowrap1()
	/usr/local/go/src/runtime/mgc.go:204 +0x25 fp=0xc0000687e0 sp=0xc0000687c8 pc=0x422985
runtime.goexit({})
	/usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0000687e8 sp=0xc0000687e0 pc=0x483a21
created by runtime.gcenable in goroutine 1
	/usr/local/go/src/runtime/mgc.go:204 +0x66

goroutine 19 gp=0xc0000a2540 m=nil [GC scavenge wait]:
runtime.gopark(0x116191?, 0xc0c75?, 0x0?, 0x0?, 0x0?)
	/usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000068f78 sp=0xc000068f58 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=0xc000068fa8 sp=0xc000068f78 pc=0x42c0c9
runtime.bgscavenge(0xc0000b0000)
	/usr/local/go/src/runtime/mgcscavenge.go:658 +0x59 fp=0xc000068fc8 sp=0xc000068fa8 pc=0x42c659
runtime.gcenable.gowrap2()
	/usr/local/go/src/runtime/mgc.go:205 +0x25 fp=0xc000068fe0 sp=0xc000068fc8 pc=0x422925
runtime.goexit({})
	/usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000068fe8 sp=0xc000068fe0 pc=0x483a21
created by runtime.gcenable in goroutine 1
	/usr/local/go/src/runtime/mgc.go:205 +0xa5

goroutine 20 gp=0xc0000a2a80 m=nil [finalizer wait, 66 minutes]:
runtime.gopark(0x1b8?, 0xc000002380?, 0x1?, 0x23?, 0xc00006c688?)
	/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 21 gp=0xc0000a3500 m=nil [chan receive, 3 minutes]:
runtime.gopark(0xc0001bc000?, 0xc00010e1f8?, 0x60?, 0x6f?, 0x65ef48?)
	/usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000086f18 sp=0xc000086ef8 pc=0x47ba4e
runtime.chanrecv(0xc0000b8620, 0x0, 0x1)
	/usr/local/go/src/runtime/chan.go:664 +0x445 fp=0xc000086f90 sp=0xc000086f18 pc=0x413805
runtime.chanrecv1(0x0?, 0x0?)
	/usr/local/go/src/runtime/chan.go:506 +0x12 fp=0xc000086fb8 sp=0xc000086f90 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=0xc000086fe0 sp=0xc000086fb8 pc=0x425acf
runtime.goexit({})
	/usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000086fe8 sp=0xc000086fe0 pc=0x483a21
created by unique.runtime_registerUniqueMapCleanup in goroutine 1
	/usr/local/go/src/runtime/mgc.go:1794 +0x79

goroutine 24 gp=0xc0000a3880 m=nil [select, 66 minutes, locked to thread]:
runtime.gopark(0xc000069fa8?, 0x2?, 0xc?, 0x2e?, 0xc000069f94?)
	/usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000069e20 sp=0xc000069e00 pc=0x47ba4e
runtime.selectgo(0xc000069fa8, 0xc000069f90, 0x0?, 0x0, 0xc0000b6960?, 0x1)
	/usr/local/go/src/runtime/select.go:351 +0x837 fp=0xc000069f58 sp=0xc000069e20 pc=0x458f57
runtime.ensureSigM.func1()
	/usr/local/go/src/runtime/signal_unix.go:1085 +0x192 fp=0xc000069fe0 sp=0xc000069f58 pc=0x475f12
runtime.goexit({})
	/usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000069fe8 sp=0xc000069fe0 pc=0x483a21
created by runtime.ensureSigM in goroutine 1
	/usr/local/go/src/runtime/signal_unix.go:1068 +0xc8

goroutine 34 gp=0xc000202000 m=3 mp=0xc000073008 [syscall, 66 minutes]:
runtime.notetsleepg(0x14418a0, 0xffffffffffffffff)
	/usr/local/go/src/runtime/lock_futex.go:123 +0x29 fp=0xc0002087a0 sp=0xc000208778 pc=0x418ee9
os/signal.signal_recv()
	/usr/local/go/src/runtime/sigqueue.go:152 +0x29 fp=0xc0002087c0 sp=0xc0002087a0 pc=0x47dc69
os/signal.loop()
	/usr/local/go/src/os/signal/signal_unix.go:23 +0x13 fp=0xc0002087e0 sp=0xc0002087c0 pc=0x5c44b3
runtime.goexit({})
	/usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0002087e8 sp=0xc0002087e0 pc=0x483a21
created by os/signal.Notify.func1.1 in goroutine 1
	/usr/local/go/src/os/signal/signal.go:152 +0x1f

goroutine 35 gp=0xc0002021c0 m=nil [chan receive, 66 minutes]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
	/usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000208f10 sp=0xc000208ef0 pc=0x47ba4e
runtime.chanrecv(0xc00033ef50, 0x0, 0x1)
	/usr/local/go/src/runtime/chan.go:664 +0x445 fp=0xc000208f88 sp=0xc000208f10 pc=0x413805
runtime.chanrecv1(0x0?, 0x0?)
	/usr/local/go/src/runtime/chan.go:506 +0x12 fp=0xc000208fb0 sp=0xc000208f88 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=0xc000208fe0 sp=0xc000208fb0 pc=0x9b9cc7
runtime.goexit({})
	/usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000208fe8 sp=0xc000208fe0 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 36 gp=0xc000202540 m=nil [select, 39 minutes]:
runtime.gopark(0xc000111f98?, 0x2?, 0x60?, 0xa3?, 0xc000111f50?)
	/usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000080dd0 sp=0xc000080db0 pc=0x47ba4e
runtime.selectgo(0xc000080f98, 0xc000111f4c, 0xc000214000?, 0x0, 0x56?, 0x1)
	/usr/local/go/src/runtime/select.go:351 +0x837 fp=0xc000080f08 sp=0xc000080dd0 pc=0x458f57
github.com/rclone/rclone/lib/oauthutil.(*Renew).renewOnExpiry(0xc000231b40)
	/home/rclone/go/src/github.com/rclone/rclone/lib/oauthutil/renew.go:43 +0x86 fp=0xc000080fc8 sp=0xc000080f08 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=0xc000080fe0 sp=0xc000080fc8 pc=0xa621a5
runtime.goexit({})
	/usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000080fe8 sp=0xc000080fe0 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 50 gp=0xc000202700 m=nil [GC worker (idle), 65 minutes]:
runtime.gopark(0x2ad630ccc45a97?, 0x2ad630c5d0201d?, 0x0?, 0x0?, 0x0?)
	/usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000209f38 sp=0xc000209f18 pc=0x47ba4e
runtime.gcBgMarkWorker(0xc0003a8070)
	/usr/local/go/src/runtime/mgc.go:1423 +0xe9 fp=0xc000209fc8 sp=0xc000209f38 pc=0x424de9
runtime.gcBgMarkStartWorkers.gowrap1()
	/usr/local/go/src/runtime/mgc.go:1339 +0x25 fp=0xc000209fe0 sp=0xc000209fc8 pc=0x424cc5
runtime.goexit({})
	/usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000209fe8 sp=0xc000209fe0 pc=0x483a21
created by runtime.gcBgMarkStartWorkers in goroutine 44
	/usr/local/go/src/runtime/mgc.go:1339 +0x105

goroutine 3 gp=0xc0002028c0 m=nil [sleep, 65 minutes]:
runtime.gopark(0x2ad630dab6f5c6?, 0x0?, 0x0?, 0x0?, 0x0?)
	/usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000205740 sp=0xc000205720 pc=0x47ba4e
time.Sleep(0xcfba0da84c00)
	/usr/local/go/src/runtime/time.go:338 +0x165 fp=0xc000205798 sp=0xc000205740 pc=0x47fd45
github.com/rclone/rclone/lib/pacer.(*Pacer).beginCall.func1(0x0?)
	/home/rclone/go/src/github.com/rclone/rclone/lib/pacer/pacer.go:171 +0x1c fp=0xc0002057c8 sp=0xc000205798 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=0xc0002057e0 sp=0xc0002057c8 pc=0x8012e4
runtime.goexit({})
	/usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0002057e8 sp=0xc0002057e0 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 51 gp=0xc000202e00 m=nil [GC worker (idle), 65 minutes]:
runtime.gopark(0x2ad630cc693e8d?, 0x0?, 0x0?, 0xa5?, 0x5?)
	/usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc00020a738 sp=0xc00020a718 pc=0x47ba4e
runtime.gcBgMarkWorker(0xc0003a8070)
	/usr/local/go/src/runtime/mgc.go:1423 +0xe9 fp=0xc00020a7c8 sp=0xc00020a738 pc=0x424de9
runtime.gcBgMarkStartWorkers.gowrap1()
	/usr/local/go/src/runtime/mgc.go:1339 +0x25 fp=0xc00020a7e0 sp=0xc00020a7c8 pc=0x424cc5
runtime.goexit({})
	/usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc00020a7e8 sp=0xc00020a7e0 pc=0x483a21
created by runtime.gcBgMarkStartWorkers in goroutine 44
	/usr/local/go/src/runtime/mgc.go:1339 +0x105

goroutine 52 gp=0xc000382380 m=nil [GC worker (idle), 65 minutes]:
runtime.gopark(0x2ad630cc663346?, 0x0?, 0x0?, 0x0?, 0x0?)
	/usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000204738 sp=0xc000204718 pc=0x47ba4e
runtime.gcBgMarkWorker(0xc0003a8070)
	/usr/local/go/src/runtime/mgc.go:1423 +0xe9 fp=0xc0002047c8 sp=0xc000204738 pc=0x424de9
runtime.gcBgMarkStartWorkers.gowrap1()
	/usr/local/go/src/runtime/mgc.go:1339 +0x25 fp=0xc0002047e0 sp=0xc0002047c8 pc=0x424cc5
runtime.goexit({})
	/usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc0002047e8 sp=0xc0002047e0 pc=0x483a21
created by runtime.gcBgMarkStartWorkers in goroutine 44
	/usr/local/go/src/runtime/mgc.go:1339 +0x105

goroutine 53 gp=0xc000382540 m=nil [GC worker (idle)]:
runtime.gopark(0x2ad9b75978c74f?, 0x0?, 0x0?, 0x0?, 0x0?)
	/usr/local/go/src/runtime/proc.go:435 +0xce fp=0xc000204f38 sp=0xc000204f18 pc=0x47ba4e
runtime.gcBgMarkWorker(0xc0003a8070)
	/usr/local/go/src/runtime/mgc.go:1423 +0xe9 fp=0xc000204fc8 sp=0xc000204f38 pc=0x424de9
runtime.gcBgMarkStartWorkers.gowrap1()
	/usr/local/go/src/runtime/mgc.go:1339 +0x25 fp=0xc000204fe0 sp=0xc000204fc8 pc=0x424cc5
runtime.goexit({})
	/usr/local/go/src/runtime/asm_amd64.s:1700 +0x1 fp=0xc000204fe8 sp=0xc000204fe0 pc=0x483a21
created by runtime.gcBgMarkStartWorkers in goroutine 44
	/usr/local/go/src/runtime/mgc.go:1339 +0x105

rax    0xca
rbx    0x0
rcx    0x485863
rdx    0x0
rdi    0x1420e40
rsi    0x80
rbp    0x7ffeb51e75e8
rsp    0x7ffeb51e75a0
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0x7ffeb51e75c8
r13    0xc000069f94
r14    0x141f580
r15    0xc0000b7e00
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.236458688s (try 2/5): exit status 1: Failed []