debugging – How to use decode_stacktrace.sh?

Yes, you will need CONFIG_DEBUG_INFO=y in order for decode_stacktrace.sh to extract useful debugging information (such as file names and line numbers) from the kernel image (vmlinux). In theory, the script will run fine even without debug info, but it will give you less information (no file names and line numbers).

NOTE: in recent kernels (>= v5.12) a multiple choice option for the DWARF version was added (CONFIG_DEBUG_INFO_DWARF{4,5,_TOOLCHAIN_DEFAULT}). Then, in v5.18 CONFIG_DEBUG_INFO was completely removed, and the multiple choice option is now the one responsible for enabling debug info. Any choice except CONFIG_DEBUG_INFO_NONE is fine as long as your toolchain supports it.

Where can I find the input.log?

The “log” they are referring to is simply the kernel log. This will be available regardless of CONFIG_DEBUG_INFO. Kernel panics and other OOPSes will usually write stack traces to the kernel log. You can take this directly from the console (if console logging is enabled), or using the dmesg command. See also this doc page for more info. Once you have the log, simply copy-paste it into a text file (input.log), and pass that file to the script’s standard input with < input.log.

For an actual panic on the same system you are working on (and not simply inside QEMU or a VM), chances are that the logging can only be done to console, so you might want to enable that:

$ dmesg --console-level 7
$ dmesg --console-on

Take a look at Where are kernel panic logs? on Ask Ubuntu for more ways to capture the log in case of a panic.

As an example, here’s the log for a crash generated running echo c > /proc/sysrq-trigger as root on a system running inside QEMU on my machine. I copy-pasted the kernel log into input.logwhich contains the following:

[    7.952685] sysrq: Trigger a crash
[    7.952850] Kernel panic - not syncing: sysrq triggered crash
[    7.953098] CPU: 0 PID: 71 Comm: linuxrc Not tainted 5.19.0-rc2 #1
[    7.953259] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.14.0-2 04/01/2014
[    7.953655] Call Trace:
[    7.954133]  <TASK>
[    7.954332]  dump_stack_lvl+0x34/0x44
[    7.954651]  panic+0x102/0x27b
[    7.954756]  ? _printk+0x53/0x6a
[    7.954847]  sysrq_handle_crash+0x11/0x20
[    7.954953]  __handle_sysrq.cold+0x43/0x11b
[    7.955065]  write_sysrq_trigger+0x1f/0x30
[    7.955167]  proc_reg_write+0x4c/0x90
[    7.955267]  vfs_write+0xb4/0x290
[    7.955362]  ksys_write+0x5a/0xd0
[    7.955453]  do_syscall_64+0x3b/0x90
[    7.955553]  entry_SYSCALL_64_after_hwframe+0x46/0xb0
[    7.955773] RIP: 0033:0x4a8531
[    7.955999] Code: e0 ff ff ff f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b3 0f 1f 80 00 00 00 00 8b 05 d2 26 1e 00 85 c0 75 16 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 57 c3 66 0f 1f 44 00 00 8
[    7.956427] RSP: 002b:00007ffde8168508 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[    7.956625] RAX: ffffffffffffffda RBX: 000000000101a8a0 RCX: 00000000004a8531
[    7.956787] RDX: 0000000000000002 RSI: 00000000010201e0 RDI: 0000000000000001
[    7.956949] RBP: 0000000000000001 R08: fefefefefefefeff R09: fefefefefefeff62
[    7.957113] R10: 00000000000001b6 R11: 0000000000000246 R12: 00000000010201e0
[    7.957275] R13: 0000000000000002 R14: 00007ffde8168701 R15: 00007ffde8168578
[    7.957467]  </TASK>
[    7.957806] Kernel Offset: 0x34a00000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
[    7.958215] ---[ end Kernel panic - not syncing: sysrq triggered crash ]---

The only section that you really need to extract from the above is the following:

[    7.954332]  dump_stack_lvl+0x34/0x44
[    7.954651]  panic+0x102/0x27b
[    7.954756]  ? _printk+0x53/0x6a
[    7.954847]  sysrq_handle_crash+0x11/0x20
[    7.954953]  __handle_sysrq.cold+0x43/0x11b
[    7.955065]  write_sysrq_trigger+0x1f/0x30
[    7.955167]  proc_reg_write+0x4c/0x90
[    7.955267]  vfs_write+0xb4/0x290
[    7.955362]  ksys_write+0x5a/0xd0
[    7.955453]  do_syscall_64+0x3b/0x90
[    7.955553]  entry_SYSCALL_64_after_hwframe+0x46/0xb0
[    7.955773] RIP: 0033:0x4a8531
[    7.955999] Code: e0 ff ff ff f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b3 0f 1f 80 00 00 00 00 8b 05 d2 26 1e 00 85 c0 75 16 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 57 c3 66 0f 1f 44 00 00 8

Running decode_stacktrace.sh poiting it to my vmlinux and the kernel source directory yields more info:

$ ./scripts/decode_stacktrace.sh /path/to/vmlinux /path/to/kernel-source-dir < input.log

[    7.952685] sysrq: Trigger a crash
[    7.952850] Kernel panic - not syncing: sysrq triggered crash
[    7.953098] CPU: 0 PID: 71 Comm: linuxrc Not tainted 5.19.0-rc2 #1
[    7.953259] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.14.0-2 04/01/2014
[    7.953655] Call Trace:
[    7.954133]  <TASK>
[    7.954332] dump_stack_lvl (/path/to/kernel-source-dir/lib/dump_stack.c:107 (discriminator 1))
[    7.954651] panic (/path/to/kernel-source-dir/kernel/panic.c:292)
[    7.954756] ? _printk (/path/to/kernel-source-dir/kernel/printk/printk.c:2426)
[    7.954847] sysrq_handle_crash (/path/to/kernel-source-dir/drivers/tty/sysrq.c:155)
[    7.954953] __handle_sysrq.cold (/path/to/kernel-source-dir/drivers/tty/sysrq.c:626)
[    7.955065] write_sysrq_trigger (/path/to/kernel-source-dir/drivers/tty/sysrq.c:1168)
[    7.955167] proc_reg_write (/path/to/kernel-source-dir/fs/proc/inode.c:335 /path/to/kernel-source-dir/fs/proc/inode.c:347)
[    7.955267] vfs_write (/path/to/kernel-source-dir/fs/read_write.c:589)
[    7.955362] ksys_write (/path/to/kernel-source-dir/fs/read_write.c:644)
[    7.955453] do_syscall_64 (/path/to/kernel-source-dir/arch/x86/entry/common.c:50 /path/to/kernel-source-dir/arch/x86/entry/common.c:80)
[    7.955553] entry_SYSCALL_64_after_hwframe (/path/to/kernel-source-dir/arch/x86/entry/entry_64.S:115)
[    7.955773] RIP: 0033:0x4a8531
[ 7.955999] Code: e0 ff ff ff f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b3 0f 1f 80 00 00 00 00 8b 05 d2 26 1e 00 85 c0 75 16 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 57 c3 66 0f 1f 44 00 00 8
All code
========
   0:   e0 ff                   loopne 0x1
   2:   ff                      (bad)
   3:   ff f7                   push   %rdi
   5:   d8 64 89 02             fsubs  0x2(%rcx,%rcx,4)
   9:   48 c7 c0 ff ff ff ff    mov    $0xffffffffffffffff,%rax
  10:   eb b3                   jmp    0xffffffffffffffc5
  12:   0f 1f 80 00 00 00 00    nopl   0x0(%rax)
  19:   8b 05 d2 26 1e 00       mov    0x1e26d2(%rip),%eax        # 0x1e26f1
  1f:   85 c0                   test   %eax,%eax
  21:   75 16                   jne    0x39
  23:   b8 01 00 00 00          mov    $0x1,%eax
  28:   0f 05                   syscall
  2a:*  48 3d 00 f0 ff ff       cmp    $0xfffffffffffff000,%rax         <-- trapping instruction
  30:   77 57                   ja     0x89
  32:   c3                      retq
  33:   66 0f 1f 44 00 00       nopw   0x0(%rax,%rax,1)
  39:   08                      .byte 0x8

Code starting with the faulting instruction
===========================================
   0:   48 3d 00 f0 ff ff       cmp    $0xfffffffffffff000,%rax
   6:   77 57                   ja     0x5f
   8:   c3                      retq
   9:   66 0f 1f 44 00 00       nopw   0x0(%rax,%rax,1)
   f:   08                      .byte 0x8
[    7.956427] RSP: 002b:00007ffde8168508 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[    7.956625] RAX: ffffffffffffffda RBX: 000000000101a8a0 RCX: 00000000004a8531
[    7.956787] RDX: 0000000000000002 RSI: 00000000010201e0 RDI: 0000000000000001
[    7.956949] RBP: 0000000000000001 R08: fefefefefefefeff R09: fefefefefefeff62
[    7.957113] R10: 00000000000001b6 R11: 0000000000000246 R12: 00000000010201e0
[    7.957275] R13: 0000000000000002 R14: 00007ffde8168701 R15: 00007ffde8168578
[    7.957467]  </TASK>
[    7.957806] Kernel Offset: 0x34a00000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
[    7.958215] ---[ end Kernel panic - not syncing: sysrq triggered crash ]---

Leave a Comment