From 21d289c28fbcb63b83b5ffc23c2e7944dad31b96 Mon Sep 17 00:00:00 2001 From: Dmitry Vyukov Date: Sat, 12 Sep 2020 11:22:03 +0200 Subject: pkg/report: add gvisor "stuck task" pattern --- pkg/report/testdata/gvisor/report/25 | 66 +++++++++++++++++++++++++++++++++++ pkg/report/testdata/gvisor/report/26 | 67 ++++++++++++++++++++++++++++++++++++ 2 files changed, 133 insertions(+) create mode 100644 pkg/report/testdata/gvisor/report/25 create mode 100644 pkg/report/testdata/gvisor/report/26 (limited to 'pkg/report/testdata') diff --git a/pkg/report/testdata/gvisor/report/25 b/pkg/report/testdata/gvisor/report/25 new file mode 100644 index 000000000..bb71a8f8d --- /dev/null +++ b/pkg/report/testdata/gvisor/report/25 @@ -0,0 +1,66 @@ +TITLE: panic: Sentry detected stuck tasks + +panic: Sentry detected 15 stuck task(s): + Task tid: 7045 (0x1b85), entered RunSys state 3m41.68s ago. + Task tid: 10 (0xa), entered RunSys state 3m40.87s ago. + Task tid: 2 (0x2), entered RunSys state 3m40.87s ago. + Task tid: 7018 (0x1b6a), entered RunSys state 3m41.58s ago. + Task tid: 7004 (0x1b5c), entered RunSys state 3m39.61s ago. + Task tid: 7044 (0x1b84), entered RunSys state 3m41.72s ago. + Task tid: 7042 (0x1b82), entered RunSys state 3m41.63s ago. + Task tid: 7041 (0x1b81), entered RunSys state 3m41.68s ago. + Task tid: 5 (0x5), entered RunSys state 3m40.87s ago. + Task tid: 7035 (0x1b7b), entered RunSys state 3m39.73s ago. + Task tid: 2160 (0x870), entered RunSys state 3m40.87s ago. + Task tid: 7040 (0x1b80), entered RunSys state 3m41.64s ago. + Task tid: 4818 (0x12d2), entered RunSys state 3m40.87s ago. + Task tid: 6 (0x6), entered RunSys state 3m40.87s ago. + Task tid: 7043 (0x1b83), entered RunSys state 3m41.64s ago. +Search for '(*Task).run(0x..., 0x)' in the stack dump to find the offending goroutine +Stack for running G's are skipped while panicking. + +goroutine 170 [running]: +panic(0x15191e0, 0xc01f804220) + GOROOT/src/runtime/panic.go:1064 +0x46d fp=0xc0022e7b48 sp=0xc0022e7a90 pc=0x43611d +gvisor.dev/gvisor/pkg/sentry/watchdog.(*Watchdog).doAction(0xc000199b80, 0x1, 0x1, 0xc0022e7d10) + pkg/sentry/watchdog/watchdog.go:386 +0x737 fp=0xc0022e7c78 sp=0xc0022e7b48 pc=0xe54dc7 +gvisor.dev/gvisor/pkg/sentry/watchdog.(*Watchdog).report(0xc000199b80, 0xc01fd4a450, 0x7601, 0x7d26b04c00) + pkg/sentry/watchdog/watchdog.go:345 +0x3ff fp=0xc0022e7dd8 sp=0xc0022e7c78 pc=0xe5459f +gvisor.dev/gvisor/pkg/sentry/watchdog.(*Watchdog).runTurn(0xc000199b80) + pkg/sentry/watchdog/watchdog.go:326 +0x770 fp=0xc0022e7f30 sp=0xc0022e7dd8 pc=0xe540a0 +gvisor.dev/gvisor/pkg/sentry/watchdog.(*Watchdog).loop(0xc000199b80) + pkg/sentry/watchdog/watchdog.go:261 +0x53 fp=0xc0022e7fd8 sp=0xc0022e7f30 pc=0xe537c3 +runtime.goexit() + src/runtime/asm_amd64.s:1373 +0x1 fp=0xc0022e7fe0 sp=0xc0022e7fd8 pc=0x46b9a1 +created by gvisor.dev/gvisor/pkg/sentry/watchdog.(*Watchdog).Start + pkg/sentry/watchdog/watchdog.go:212 +0x32d + +goroutine 172 [select, 9 minutes]: +runtime.gopark(0x171cf40, 0x0, 0x1809, 0x1) + GOROOT/src/runtime/proc.go:304 +0xe0 fp=0xc000021268 sp=0xc000021248 pc=0x438fb0 +runtime.selectgo(0xc0000213f8, 0xc0000213d4, 0x3, 0x6, 0x226f420) + GOROOT/src/runtime/select.go:316 +0xe69 fp=0xc000021398 sp=0xc000021268 pc=0x44a899 +gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).block(0xc00026a000, 0xc0000fe7e0, 0x0, 0xc0002e6370, 0xc0ffffffff) + pkg/sentry/kernel/task_block.go:138 +0x1db fp=0xc000021480 sp=0xc000021398 pc=0xb8bddb +gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).BlockWithTimeout(0xc00026a000, 0xc0000fe7e0, 0x1924a00, 0x0, 0x4a4e8e8, 0x26a701, 0xc0ffffffff) + pkg/sentry/kernel/task_block.go:37 +0x2f4 fp=0xc000021508 sp=0xc000021480 pc=0xb8b894 +gvisor.dev/gvisor/pkg/sentry/syscalls/linux.futexWaitDuration(0xc00026a000, 0x0, 0xc00026a001, 0x4a4e8e8, 0x1a9701, 0xffffffff, 0x1, 0x0, 0x0) + pkg/sentry/syscalls/linux/sys_futex.go:97 +0x13d fp=0xc000021590 sp=0xc000021508 pc=0xc4b44d +gvisor.dev/gvisor/pkg/sentry/syscalls/linux.Futex(0xc00026a000, 0x4a4e8e8, 0x80, 0x0, 0x0, 0x0, 0x0, 0x44055f, 0xc000050800, 0xc0000217c0, ...) + pkg/sentry/syscalls/linux/sys_futex.go:206 +0x125 fp=0xc000021740 sp=0xc000021590 pc=0xc4c075 +gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).executeSyscall(0xc00026a000, 0xca, 0x4a4e8e8, 0x80, 0x0, 0x0, 0x0, 0x0, 0x340, 0x0, ...) + pkg/sentry/kernel/task_syscall.go:103 +0x44e fp=0xc0000219e0 sp=0xc000021740 pc=0xbb8dce +gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallInvoke(0xc00026a000, 0xca, 0x4a4e8e8, 0x80, 0x0, 0x0, 0x0, 0x0, 0x407baa, 0xc00026a8d7) + pkg/sentry/kernel/task_syscall.go:238 +0xb5 fp=0xc000021ac0 sp=0xc0000219e0 pc=0xbba485 +gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallEnter(0xc00026a000, 0xca, 0x4a4e8e8, 0x80, 0x0, 0x0, 0x0, 0x0, 0x116bce2, 0x2c26c72) + pkg/sentry/kernel/task_syscall.go:198 +0x10a fp=0xc000021b70 sp=0xc000021ac0 pc=0xbb9dea +gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscall(0xc00026a000, 0x2, 0xc00026a000) + pkg/sentry/kernel/task_syscall.go:173 +0x1e8 fp=0xc000021cb0 sp=0xc000021b70 pc=0xbb95d8 +gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute(0x0, 0xc00026a000, 0x18efe60, 0x0) + pkg/sentry/kernel/task_run.go:275 +0x11d9 fp=0xc000021ee8 sp=0xc000021cb0 pc=0xba5f29 +gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run(0xc00026a000, 0x1) + pkg/sentry/kernel/task_run.go:93 +0x31d fp=0xc000021fd0 sp=0xc000021ee8 pc=0xba40fd +runtime.goexit() + src/runtime/asm_amd64.s:1373 +0x1 fp=0xc000021fd8 sp=0xc000021fd0 pc=0x46b9a1 +created by gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).Start + pkg/sentry/kernel/task_start.go:318 +0x19e diff --git a/pkg/report/testdata/gvisor/report/26 b/pkg/report/testdata/gvisor/report/26 new file mode 100644 index 000000000..08ba161fb --- /dev/null +++ b/pkg/report/testdata/gvisor/report/26 @@ -0,0 +1,67 @@ +TITLE: panic: Sentry detected stuck tasks + +panic: Sentry detected 10 stuck task(s): + Task tid: 46 (0x2e), entered RunSys state 3m33.39s ago. + Task tid: 12 (0xc), entered RunSys state 3m33.37s ago. + Task tid: 16 (0x10), entered RunSys state 3m33.37s ago. + Task tid: 26 (0x1a), entered RunSys state 3m33.37s ago. + Task tid: 16296 (0x3fa8), entered RunSys state 3m33.39s ago. + Task tid: 16297 (0x3fa9), entered RunSys state 3m33.39s ago. + Task tid: 16291 (0x3fa3), entered RunSys state 3m33.39s ago. + Task tid: 16295 (0x3fa7), entered RunSys state 3m32.67s ago. + Task tid: 47 (0x2f), entered RunSys state 3m33.39s ago. + Task tid: 16285 (0x3f9d), entered RunSys state 3m32.67s ago. +Search for '(*Task).run(0x..., 0x)' in the stack dump to find the offending goroutine +Stack for running G's are skipped while panicking. + +goroutine 110 [running]: +panic(0xeb0780, 0xc00089a0a0) + GOROOT/src/runtime/panic.go:1064 +0x46d fp=0xc0004b3c08 sp=0xc0004b3b50 pc=0x43438d +gvisor.dev/gvisor/pkg/sentry/watchdog.(*Watchdog).doAction(0xc0003a2080, 0x1, 0x1, 0xc0004b3d70) + pkg/sentry/watchdog/watchdog.go:386 +0x57d fp=0xc0004b3d00 sp=0xc0004b3c08 pc=0xa9308d +gvisor.dev/gvisor/pkg/sentry/watchdog.(*Watchdog).report(0xc0003a2080, 0xc00e5143c0, 0x7a01, 0x7c93771680) + pkg/sentry/watchdog/watchdog.go:345 +0x311 fp=0xc0004b3e38 sp=0xc0004b3d00 pc=0xa92a51 +gvisor.dev/gvisor/pkg/sentry/watchdog.(*Watchdog).runTurn(0xc0003a2080) + pkg/sentry/watchdog/watchdog.go:326 +0x4b4 fp=0xc0004b3f40 sp=0xc0004b3e38 pc=0xa92664 +gvisor.dev/gvisor/pkg/sentry/watchdog.(*Watchdog).loop(0xc0003a2080) + pkg/sentry/watchdog/watchdog.go:261 +0x42 fp=0xc0004b3fd8 sp=0xc0004b3f40 pc=0xa920d2 +runtime.goexit() + src/runtime/asm_amd64.s:1373 +0x1 fp=0xc0004b3fe0 sp=0xc0004b3fd8 pc=0x467da1 +created by gvisor.dev/gvisor/pkg/sentry/watchdog.(*Watchdog).Start + pkg/sentry/watchdog/watchdog.go:212 +0x1b7 + +goroutine 13 [semacquire]: +runtime.gopark(0x10ade88, 0x1a6b5a0, 0xc0005a1912, 0x4) + GOROOT/src/runtime/proc.go:304 +0xe0 fp=0xc00f3e76c8 sp=0xc00f3e76a8 pc=0x4371d0 +runtime.goparkunlock(...) + GOROOT/src/runtime/proc.go:310 +runtime.semacquire1(0xc0000287f4, 0x0, 0x1, 0x0) + GOROOT/src/runtime/sema.go:144 +0x1c0 fp=0xc00f3e7730 sp=0xc00f3e76c8 pc=0x448580 +sync.runtime_Semacquire(0xc0000287f4) + GOROOT/src/runtime/sema.go:56 +0x42 fp=0xc00f3e7760 sp=0xc00f3e7730 pc=0x4481d2 +gvisor.dev/gvisor/pkg/sync.(*RWMutex).RLock(...) + pkg/sync/rwmutex_unsafe.go:76 +gvisor.dev/gvisor/pkg/sentry/mm.(*MemoryManager).withInternalMappings(0xc000028000, 0x123ef80, 0x1a55130, 0xc0000fdbf0, 0xc0000fdc70, 0x100, 0xc00f3e78b0, 0xc00fef2290, 0x191, 0x70) + pkg/sentry/mm/io.go:504 +0x7e4 fp=0xc00f3e7860 sp=0xc00f3e7760 pc=0x74f834 +gvisor.dev/gvisor/pkg/sentry/mm.(*MemoryManager).CopyOut(0xc000028000, 0x123ef80, 0x1a55130, 0xc0000fdbf0, 0xc010a6e080, 0x80, 0x80, 0x0, 0x80, 0x103b1e0, ...) + pkg/sentry/mm/io.go:119 +0x12d fp=0xc00f3e78f0 sp=0xc00f3e7860 pc=0x74cc2d +gvisor.dev/gvisor/pkg/usermem.(*IOReadWriter).Write(0xc00f3e79b0, 0xc010a6e080, 0x80, 0x80, 0x1a90a80, 0x103b1e0, 0xc00fef2280) + pkg/usermem/usermem.go:173 +0x87 fp=0xc00f3e7958 sp=0xc00f3e78f0 pc=0x567dd7 +gvisor.dev/gvisor/pkg/usermem.CopyObjectOut(0x123ef80, 0x1a55130, 0x1237760, 0xc000028000, 0xc0000fdbf0, 0x103b1e0, 0xc00fef2280, 0xea0000, 0xc000382528, 0xc0106f0001, ...) + pkg/usermem/usermem.go:206 +0x160 fp=0xc00f3e79f0 sp=0xc00f3e7958 pc=0x567fb0 +gvisor.dev/gvisor/pkg/sentry/arch.(*Stack).Push(0xc0054fe120, 0xc00f3e7b50, 0x1, 0x1, 0xc000135680, 0x41f6da, 0xc000844e00) + pkg/sentry/arch/stack.go:100 +0x175 fp=0xc00f3e7ac8 sp=0xc00f3e79f0 pc=0x5e6eb5 +gvisor.dev/gvisor/pkg/sentry/arch.(*context64).SignalSetup(0xc000135680, 0xc0054fe120, 0xc000594060, 0xc00fef2280, 0xc000594080, 0x0, 0x1, 0xc0106ee000) + pkg/sentry/arch/signal_amd64.go:198 +0x30a fp=0xc00f3e7b70 sp=0xc00f3e7ac8 pc=0x5e650a +gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).deliverSignalToHandler(0xc0001fca80, 0xc00fef2280, 0x468ed0, 0x1c000004, 0x469000, 0xfffffffffffbfeff, 0xc00f3e7c58, 0x40) + pkg/sentry/kernel/task_signals.go:280 +0x24a fp=0xc00f3e7c08 sp=0xc00f3e7b70 pc=0x8caaaa +gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).deliverSignal(0xc0001fca80, 0xc00fef2280, 0x468ed0, 0x1c000004, 0x469000, 0xfffffffffffbfeff, 0xc00f3e7f50, 0x8c52d6) + pkg/sentry/kernel/task_signals.go:221 +0x4e2 fp=0xc00f3e7e88 sp=0xc00f3e7c08 pc=0x8ca032 +gvisor.dev/gvisor/pkg/sentry/kernel.(*runInterrupt).execute(0x0, 0xc0001fca80, 0x1210be0, 0x0) + pkg/sentry/kernel/task_signals.go:1076 +0xad2 fp=0xc00f3e7f60 sp=0xc00f3e7e88 pc=0x8ce5a2 +gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run(0xc0001fca80, 0x3) + pkg/sentry/kernel/task_run.go:93 +0x18b fp=0xc00f3e7fd0 sp=0xc00f3e7f60 pc=0x8c50db +runtime.goexit() + src/runtime/asm_amd64.s:1373 +0x1 fp=0xc00f3e7fd8 sp=0xc00f3e7fd0 pc=0x467da1 +created by gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).Start + pkg/sentry/kernel/task_start.go:318 +0xfe -- cgit mrf-deployment