13714 2012-02-20 06:29:00 +0000 panic when sampling backtrace() in timer.profile 2012-02-21 23:15:00 +0000 1 1 1 Unclassified systemtap runtime unspecified All All RESOLVED FIXED P2 normal --- 1 brendan.gregg mjw mjw 53317 brendan.gregg 2012-02-20 06:29:39 +0000 The kernel can panic when profiling stack traces on Fedora 16. window1 (sample workload): # while :; do tar cf /dev/null /usr; done window2 (profiling): # stap -D MAXTRACE=100 -D MAXSTRINGLEN=4096 -ve 'global s; probe timer.profile { s[backtrace()] <<< 1; } probe end { foreach (i in s+) { print_stack(i); printf("\t%d\n", @count(s[i])); } }' This was tried about a dozen times, and paniced on four of them. The system had kdump configured and collected a crash dump. Some details: # crash /var/crash/2012-02-19-23\:08/vmcore /usr/lib/debug/lib/modules/3.2.6-3.fc16.x86_64/vmlinux [...] KERNEL: /usr/lib/debug/lib/modules/3.2.6-3.fc16.x86_64/vmlinux DUMPFILE: /var/crash/2012-02-19-23:08/vmcore CPUS: 1 DATE: Sun Feb 19 15:04:50 2012 UPTIME: 00:05:41 LOAD AVERAGE: 1.39, 0.78, 0.32 TASKS: 72 NODENAME: 9d219ce8-cf52-409f-a14a-b210850f3231 RELEASE: 3.2.6-3.fc16.x86_64 VERSION: #1 SMP Mon Feb 13 20:35:42 UTC 2012 MACHINE: x86_64 (2393 Mhz) MEMORY: 1 GB PANIC: "[ 341.694043] Oops: 0000 [#1] SMP " (check log for details) PID: 3922 COMMAND: "tar" TASK: ffff880037878000 [THREAD_INFO: ffff88001783e000] CPU: 0 STATE: TASK_RUNNING (PANIC) [...] crash> bt -a PID: 3922 TASK: ffff880037878000 CPU: 0 COMMAND: "tar" #0 [ffff88003fc037b0] machine_kexec at ffffffff81038bda #1 [ffff88003fc03820] crash_kexec at ffffffff810b8482 #2 [ffff88003fc038f0] oops_end at ffffffff815e2b08 #3 [ffff88003fc03920] no_context at ffffffff815d6a05 #4 [ffff88003fc03980] __bad_area_nosemaphore at ffffffff815d6bdd #5 [ffff88003fc039e0] bad_area_nosemaphore at ffffffff815d6c0f #6 [ffff88003fc039f0] do_page_fault at ffffffff815e55e6 #7 [ffff88003fc03b00] page_fault at ffffffff815e20b5 [exception RIP: get_uleb128+83] RIP: ffffffffa00773f3 RSP: ffff88003fc03bb8 RFLAGS: 00010046 RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000 RDX: 0000000000000007 RSI: ffffffffffffffff RDI: ffff88003fc03bf0 RBP: ffff88003fc03bb8 R8: 0000000000000030 R9: 0000000000000007 R10: 0000000000000001 R11: 0000000000000040 R12: ffff88003aae1088 R13: ffff88001783ffd8 R14: 0000000000000000 R15: ffff88003aae1088 ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0000 #8 [ffff88003fc03bc0] compute_expr at ffffffffa007c63f [stap_ddfda8cbbf4994e727c76bf533732ecf_3874] #9 [ffff88003fc03c70] unwind_frame at ffffffffa007df6c [stap_ddfda8cbbf4994e727c76bf533732ecf_3874] #10 [ffff88003fc03dc0] probe_1993 at ffffffffa007fcc6 [stap_ddfda8cbbf4994e727c76bf533732ecf_3874] #11 [ffff88003fc03e40] enter_profile_probes at ffffffffa007b2c5 [stap_ddfda8cbbf4994e727c76bf533732ecf_3874] #12 [ffff88003fc03e70] profile_tick at ffffffff81098ea9 #13 [ffff88003fc03e90] tick_sched_timer at ffffffff810a0e4e #14 [ffff88003fc03ec0] __run_hrtimer at ffffffff81093e90 #15 [ffff88003fc03f20] hrtimer_interrupt at ffffffff8109480b #16 [ffff88003fc03f90] smp_apic_timer_interrupt at ffffffff815ec589 #17 [ffff88003fc03fb0] apic_timer_interrupt at ffffffff815ea45e --- <IRQ stack> --- #18 [ffff88001783fed0] apic_timer_interrupt at ffffffff815ea45e RIP: ffffffffffffff10 RSP: 0000000000000203 RFLAGS: 00000010 RAX: ffff88003fc13780 RBX: 00000000008c2ed0 RCX: 0000000000000000 RDX: ffff88001783e000 RSI: 0000000000000008 RDI: ffff88001783ff78 RBP: ffffffff8119691f R8: 0000000000000001 R9: 0000000000000001 R10: 0000000000000001 R11: ffffffff811839f2 R12: ffff88001783fef8 R13: 00007fff549ffff0 R14: ffff88001783ff40 R15: ffffffff81196824 ORIG_RAX: 000000000000fe2e CS: ffffffff815e1e8d SS: ffff88001783ff88 bt: WARNING: possibly bogus exception frame crash> dis get_uleb128+83 0xffffffffa00773f3 <get_uleb128+83>: movzbl (%rdx),%r10d Version and system details: # stap -V Systemtap translator/driver (version 1.6/0.152 non-git sources) Copyright (C) 2005-2011 Red Hat, Inc. and others This is free software; see the source for copying conditions. enabled features: AVAHI LIBRPM LIBSQLITE3 NSS BOOST_SHARED_PTR TR1_UNORDERED_MAP NLS # uname -a Linux 9d219ce8-cf52-409f-a14a-b210850f3231 3.2.6-3.fc16.x86_64 #1 SMP Mon Feb 13 20:35:42 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux # cat /etc/redhat-release Fedora release 16 (Verne) This is Fedora as a guest running under KVM. SystemTap was installed via yum. 53322 mjw 2012-02-20 14:26:42 +0000 After some poking (also needed to increase MAXMAPENTRIES) I could finally replicate it on 3.3.0-0.rc1.git6.1.fc17.x86_64 with systemtap-devel-1.7-1.fc17.x86_64 [ 1305.976762] stap_e93c7971f27dbaecad41f45add08f2ea_2319: systemtap: 1.7/0.152, base: ffffffffa0662000, memory: 4291data/40text/86ctx/2058net/244893alloc kb, probes: 2 [ 1309.808090] BUG: unable to handle kernel NULL pointer dereference at 0000000000000007 [ 1309.809029] IP: [<ffffffffa06620c4>] get_uleb128+0x54/0x80 [stap_e93c7971f27dbaecad41f45add08f2ea_2319] 53335 mjw 2012-02-20 22:08:21 +0000 Found the root cause of this issue. It happens when a DW_CFA operation that defines the CFA as dwarf expression is followed by a DW_CFA operation that (re)defined the CFA as register+offset. In that case we forgot the reset the REG_STATE.cfa_is_expr flag which made compute_expr() interpret the reg/offset as expr pointer (because they share their values in a union). While adding more sanity checks to make sure we catch such issues I found what looks like bad CFI in the x86_64 kernel in common_interrupt (arch/x86/kernel/entry_64.S) which defines CFI "by hand" and has a CFI_DEF_CFA_REGISTER following a def_cfa_expression, which is invalid. 53356 6233 mjw 2012-02-21 10:28:56 +0000 Created attachment 6233 Make sure REG_STATE.cfa_is_expr is always set correctly add more sanity checks Testing the following patch on the systemtap runtime side. 53357 6234 mjw 2012-02-21 12:50:07 +0000 Created attachment 6234 x86 entry_64.S cfi fixup This is the kernel patch that fixes the cfi for common_interrupt on x86_64. 53362 mjw 2012-02-21 14:45:38 +0000 commit 64b0cff3bee6b00cb4193ed887439c66055f85b4 Author: Mark Wielaard <mjw@redhat.com> Date: Tue Feb 21 15:08:58 2012 +0100 PR13714 - Make sure REG_STATE.cfa_is_expr is always set correctly. runtime/unwind.c (processCFI): Always set REG_STATE.cfa_is_expr and add new sanity checks to make sure the cfa definition rules are sane. Since the cfa expr pointer and cfa register/offset rule shared a union not setting REG_STATE.cfa_is_expr could result in compute_expr () wrongly being called and using the register/offset as expr pointer. Kernel patch send upstream: https://lkml.org/lkml/2012/2/21/154 Note that with the systemtap runtime patch any wrong DW_CFA_def sequence is detected. So you don't need an updated kernel. You do need the systemtap runtime patch however also with a kernel that has the kernel-cfi-fix patch applied. There could be other (correct) CFI sequences that did trigger the bug. 53392 brendan.gregg 2012-02-21 23:15:00 +0000 Great - thanks for the quick fix! 6233 2012-02-21 10:28:00 +0000 2012-02-21 10:28:56 +0000 Make sure REG_STATE.cfa_is_expr is always set correctly add more sanity checks def_cfa_is_expr.patch text/plain 3303 mjw ZGlmZiAtLWdpdCBhL3J1bnRpbWUvdW53aW5kLmMgYi9ydW50aW1lL3Vud2luZC5jCmluZGV4IGMw ZmM5YzIuLmU0NDAxNzcgMTAwNjQ0Ci0tLSBhL3J1bnRpbWUvdW53aW5kLmMKKysrIGIvcnVudGlt ZS91bndpbmQuYwpAQCAtMzg1LDYgKzM4NSw3IEBAIHN0YXRpYyB2b2lkIHNldF9leHByX3J1bGUo dWxlYjEyOF90IHJlZywgZW51bSBpdGVtX2xvY2F0aW9uIHdoZXJlLAogCXVsZWIxMjhfdCBsZW4g PSBnZXRfdWxlYjEyOChleHByLCBlbmQpOwogCWRidWdfdW53aW5kKDEsICJyZWc9JWx4LCB3aGVy ZT0lZCwgZXhwcj0lbHVAJXBcbiIsCiAJCSAgICByZWcsIHdoZXJlLCBsZW4sICpleHByKTsKKwkv KiBTYW5pdHkgY2hlY2sgdGhhdCBleHByIGZhbGxzIGNvbXBsZXRlbHkgaW5zaWRlIGtub3duIGRh dGEuICovCiAJaWYgKGVuZCAtICpleHByID49IGxlbiAmJiByZWcgPCBBUlJBWV9TSVpFKFJFR19T VEFURS5yZWdzKSkgewogCQlSRUdfU1RBVEUucmVnc1tyZWddLndoZXJlID0gd2hlcmU7CiAJCVJF R19TVEFURS5yZWdzW3JlZ10uZXhwciA9IHN0YXJ0OwpAQCAtNTI0LDMwICs1MjUsNDYgQEAgc3Rh dGljIGludCBwcm9jZXNzQ0ZJKGNvbnN0IHU4ICpzdGFydCwgY29uc3QgdTggKmVuZCwgdW5zaWdu ZWQgbG9uZyB0YXJnZXRMb2MsCiAJCQljYXNlIERXX0NGQV9kZWZfY2ZhOgogCQkJCXZhbHVlID0g Z2V0X3VsZWIxMjgoJnB0ci5wOCwgZW5kKTsKIAkJCQlkYnVnX3Vud2luZCgxLCAibWFwIERXX0NG QV9kZWZfY2ZhIHZhbHVlICVsZCB0byByZWdfaW5mbyBpZHggJWxkXG4iLCB2YWx1ZSwgRFdBUkZf UkVHX01BUCh2YWx1ZSkpOworCQkJCVJFR19TVEFURS5jZmFfaXNfZXhwciA9IDA7CiAJCQkJUkVH X1NUQVRFLmNmYS5yZWcgPSB2YWx1ZTsKIAkJCQlkYnVnX3Vud2luZCgxLCAiRFdfQ0ZBX2RlZl9j ZmEgcmVnPSVsZFxuIiwgUkVHX1NUQVRFLmNmYS5yZWcpOwogCQkJCS8qbm9icmVhayAqLwogCQkJ Y2FzZSBEV19DRkFfZGVmX2NmYV9vZmZzZXQ6Ci0JCQkJUkVHX1NUQVRFLmNmYS5vZmZzID0gZ2V0 X3VsZWIxMjgoJnB0ci5wOCwgZW5kKTsKLQkJCQlkYnVnX3Vud2luZCgxLCAiRFdfQ0ZBX2RlZl9j ZmFfb2Zmc2V0IG9mZnM9JWx4XG4iLCBSRUdfU1RBVEUuY2ZhLm9mZnMpOworCQkJCWlmIChSRUdf U1RBVEUuY2ZhX2lzX2V4cHIgIT0gMCkgeworCQkJCQlfc3RwX3dhcm4oIlVuZXhwZWN0ZWQgRFdf Q0ZBX2RlZl9jZmFfb2Zmc2V0XG4iKTsKKwkJCQl9IGVsc2UgeworCQkJCQlSRUdfU1RBVEUuY2Zh Lm9mZnMgPSBnZXRfdWxlYjEyOCgmcHRyLnA4LCBlbmQpOworCQkJCQlkYnVnX3Vud2luZCgxLCAi RFdfQ0ZBX2RlZl9jZmFfb2Zmc2V0IG9mZnM9JWx4XG4iLCBSRUdfU1RBVEUuY2ZhLm9mZnMpOwor CQkJCX0KIAkJCQlicmVhazsKIAkJCWNhc2UgRFdfQ0ZBX2RlZl9jZmFfc2Y6CiAJCQkJdmFsdWUg PSBnZXRfdWxlYjEyOCgmcHRyLnA4LCBlbmQpOwogCQkJCWRidWdfdW53aW5kKDEsICJtYXAgRFdf Q0ZBX2RlZl9jZmFfc2YgdmFsdWUgJWxkIHRvIHJlZ19pbmZvIGlkeCAlbGRcbiIsIHZhbHVlLCBE V0FSRl9SRUdfTUFQKHZhbHVlKSk7CisJCQkJUkVHX1NUQVRFLmNmYV9pc19leHByID0gMDsKIAkJ CQlSRUdfU1RBVEUuY2ZhLnJlZyA9IHZhbHVlOwogCQkJCS8qbm9icmVhayAqLwogCQkJY2FzZSBE V19DRkFfZGVmX2NmYV9vZmZzZXRfc2Y6Ci0JCQkJUkVHX1NUQVRFLmNmYS5vZmZzID0gZ2V0X3Ns ZWIxMjgoJnB0ci5wOCwgZW5kKSAqIHN0YXRlLT5kYXRhQWxpZ247Ci0JCQkJZGJ1Z191bndpbmQo MSwgIkRXX0NGQV9kZWZfY2ZhX29mZnNldF9zZiBvZmZzPSVseFxuIiwgUkVHX1NUQVRFLmNmYS5v ZmZzKTsKKwkJCQlpZiAoUkVHX1NUQVRFLmNmYV9pc19leHByICE9IDApIHsKKwkJCQkJX3N0cF93 YXJuKCJVbmV4cGVjdGVkIERXX0NGQV9kZWZfY2ZhX29mZnNldF9zZlxuIik7CisJCQkJfSBlbHNl IHsKKwkJCQkJUkVHX1NUQVRFLmNmYS5vZmZzID0gZ2V0X3NsZWIxMjgoJnB0ci5wOCwgZW5kKSAq IHN0YXRlLT5kYXRhQWxpZ247CisJCQkJCWRidWdfdW53aW5kKDEsICJEV19DRkFfZGVmX2NmYV9v ZmZzZXRfc2Ygb2Zmcz0lbHhcbiIsIFJFR19TVEFURS5jZmEub2Zmcyk7CisJCQkJfQogCQkJCWJy ZWFrOwogCQkJY2FzZSBEV19DRkFfZGVmX2NmYV9yZWdpc3RlcjoKLQkJCQl2YWx1ZSA9IGdldF91 bGViMTI4KCZwdHIucDgsIGVuZCk7Ci0JCQkJZGJ1Z191bndpbmQoMSwgIm1hcCBEV19DRkFfZGVm X2NmYV9yZWdpc3RlciB2YWx1ZSAlbGQgdG8gcmVnX2luZm8gaWR4ICVsZFxuIiwgdmFsdWUsIERX QVJGX1JFR19NQVAodmFsdWUpKTsKLQkJCQlSRUdfU1RBVEUuY2ZhLnJlZyA9IHZhbHVlOworCQkJ CWlmIChSRUdfU1RBVEUuY2ZhX2lzX2V4cHIgIT0gMCkgeworCQkJCQlfc3RwX3dhcm4oIlVuZXhw ZWN0ZWQgRFdfQ0ZBX2RlZl9jZmFfcmVnaXN0ZXJcbiIpOworCQkJCX0gZWxzZSB7CisJCQkJCXZh bHVlID0gZ2V0X3VsZWIxMjgoJnB0ci5wOCwgZW5kKTsKKwkJCQkJZGJ1Z191bndpbmQoMSwgIm1h cCBEV19DRkFfZGVmX2NmYV9yZWdpc3RlciB2YWx1ZSAlbGQgdG8gcmVnX2luZm8gaWR4ICVsZFxu IiwgdmFsdWUsIERXQVJGX1JFR19NQVAodmFsdWUpKTsKKwkJCQkJUkVHX1NUQVRFLmNmYS5yZWcg PSB2YWx1ZTsKKwkJCQl9CiAJCQkJYnJlYWs7CiAJCQljYXNlIERXX0NGQV9kZWZfY2ZhX2V4cHJl c3Npb246IHsKIAkJCQljb25zdCB1OCAqY2ZhX2V4cHIgPSBwdHIucDg7CiAJCQkJdmFsdWUgPSBn ZXRfdWxlYjEyOCgmcHRyLnA4LCBlbmQpOworCQkJCS8qIFNhbml0eSBjaGVjayB0aGF0IGNmYV9l eHByIGZhbGxzIGNvbXBsZXRlbHkKKwkJCQkgICBpbnNpZGUga25vd24gZGF0YS4gKi8KIAkJCQlp ZiAocHRyLnA4IDwgZW5kICYmIGVuZCAtIHB0ci5wOCA+PSB2YWx1ZSkgewogCQkJCQlSRUdfU1RB VEUuY2ZhX2lzX2V4cHIgPSAxOwogCQkJCQlSRUdfU1RBVEUuY2ZhX2V4cHIgPSBjZmFfZXhwcjsK QEAgLTgwMSw2ICs4MTgsNyBAQCBzdGF0aWMgaW50IGNvbXB1dGVfZXhwcihjb25zdCB1OCAqZXhw ciwgc3RydWN0IHVud2luZF9mcmFtZV9pbmZvICpmcmFtZSwKIHsKIAkvKgogCSAqIFdlIHByZXZp b3VzbHkgdmFsaWRhdGVkIHRoZSBsZW5ndGgsIHNvIHdlIHdvbid0IHJlYWQgb2ZmIHRoZSBlbmQu CisJICogU2VlIHNhbml0eSBjaGVja3MgaW4gc2V0X2V4cHIoKSBhbmQgZm9yIERXX0NGQV9kZWZf Y2ZhX2V4cHJlc3Npb24uCiAJICovCiAJdWxlYjEyOF90IGxlbiA9IGdldF91bGViMTI4KCZleHBy LCAoY29uc3QgdTggKikgLTFVTCk7CiAJY29uc3QgdTggKmNvbnN0IHN0YXJ0ID0gZXhwcjsK 6234 2012-02-21 12:50:00 +0000 2012-02-21 12:50:07 +0000 x86 entry_64.S cfi fixup x86-entry_64-cfi-fixup.patch text/plain 434 mjw ZGlmZiAtLWdpdCBhL2FyY2gveDg2L2tlcm5lbC9lbnRyeV82NC5TIGIvYXJjaC94ODYva2VybmVs L2VudHJ5XzY0LlMKaW5kZXggM2ZlODIzOS4uZTAwZWY1NSAxMDA2NDQKLS0tIGEvYXJjaC94ODYv a2VybmVsL2VudHJ5XzY0LlMKKysrIGIvYXJjaC94ODYva2VybmVsL2VudHJ5XzY0LlMKQEAgLTgx Myw3ICs4MTMsNyBAQCByZXRfZnJvbV9pbnRyOgogCiAJLyogUmVzdG9yZSBzYXZlZCBwcmV2aW91 cyBzdGFjayAqLwogCXBvcHEgJXJzaQotCUNGSV9ERUZfQ0ZBX1JFR0lTVEVSCXJzaQorCUNGSV9E RUZfQ0ZBIHJzaSwwCS8qIG5lZWRlZCBhZnRlciBkZWZfY2ZhX2V4cHJlc3Npb24gKi8KIAlsZWFx IEFSR09GRlNFVC1SQlAoJXJzaSksICVyc3AKIAlDRklfREVGX0NGQV9SRUdJU1RFUglyc3AKIAlD RklfQURKVVNUX0NGQV9PRkZTRVQJUkJQLUFSR09GRlNFVAo=