osandov / drgn

Programmable debugger
Other
1.72k stars 157 forks source link

Crashed thread does not have a stack trace #421

Open jfernandez opened 1 month ago

jfernandez commented 1 month ago

I'm debugging a crash at boot time with a wifi driver. I captured the kdump and dmesg output with kdumpst, see below. The call trace shows that the failed task was 905.

I used drgn to load this vmcore with the corresponding vmlinux, and I can't see the same stack trace as the dmesg log:

>>> task = prog.crashed_thread()
>>> task.object.comm
(char [16])"NetworkManager"
>>> task.tid
905
>>> task.stack_trace()
#0  0xffffffffc10ff5f3
#1  0x0
#2  0x0
#3  0x0
#4  0x0
#5  0x203ff000f0000

Ultimately, what I'm trying to do is understand why the kernel could not read ffffffffffffff20. I've also tried to read that memory directly:

>>> prog.read(0xffffffffffffff20, 16)
Traceback (most recent call last):
  File "<console>", line 1, in <module>
_drgn.FaultError: could not read memory from kdump: Cannot get page I/O address: Page table not present: pmd[511] = 0x0: 0xffffffffffffff20

dmesg output for the crash:

[    4.667556] [    T905] BUG: unable to handle page fault for address: ffffffffffffff20
[    4.667573] [    T905] #PF: supervisor read access in kernel mode
[    4.667583] [    T905] #PF: error_code(0x0000) - not-present page
[    4.667593] [    T905] PGD 645627067 P4D 645627067 PUD 645629067 PMD 0 
[    4.667611] [    T905] Oops: Oops: 0000 [#1] PREEMPT SMP NOPTI
[    4.667624] [    T905] CPU: 15 UID: 0 PID: 905 Comm: NetworkManager Kdump: loaded Tainted: G           OE      6.11.0-rc1-00001-gb30fffe019cc-dirty #16 49d822ebaa47bf299b878cf80be44ddfa934f0d6
[    4.667652] [    T905] Tainted: [O]=OOT_MODULE, [E]=UNSIGNED_MODULE
[    4.667661] [    T905] Hardware name: LENOVO 21JX0027US/21JX0027US, BIOS N41ET53W (1.30 ) 06/20/2024
[    4.667673] [    T905] RIP: 0010:mt792x_mac_link_bss_remove+0xb3/0x1a2 [mt792x_lib]
[    4.667695] [    T905] Code: 6d 60 4c 89 fe 48 c7 c7 60 97 10 c1 44 89 ea e8 53 cd 8f f6 48 c7 c7 a8 97 10 c1 e8 47 cd 8f f6 44 89 ea 48 c7 c7 e0 97 10 c1 <4d> 8b b4 d6 20 ff ff ff e8 30 cd 8f f6 49 8d bc 24 60 81 00 00 48
[    4.667717] [    T905] RSP: 0018:ffffbd8680cef320 EFLAGS: 00010246
[    4.667728] [    T905] RAX: 0000000000000031 RBX: ffff9a2ea6c0e2c8 RCX: 0000000000000027
[    4.667739] [    T905] RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffffffffc11097e0
[    4.667749] [    T905] RBP: ffff9a2ea6c0e1e8 R08: 0000000000000000 R09: ffffbd8680cef1b0
[    4.667760] [    T905] R10: ffffffffb8cb3fa8 R11: 0000000000000003 R12: ffff9a2ea1e32000
[    4.667770] [    T905] R13: 0000000000000000 R14: 0000000000000000 R15: fffffffffffffb68
[    4.667781] [    T905] FS:  00007feb7ded6240(0000) GS:ffff9a3d9f180000(0000) knlGS:0000000000000000
[    4.667793] [    T905] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[    4.667804] [    T905] CR2: ffffffffffffff20 CR3: 0000000113018000 CR4: 0000000000f50ef0
[    4.667816] [    T905] PKRU: 55555554
[    4.667823] [    T905] Call Trace:
[    4.667831] [    T905]  <TASK>
[    4.667839] [    T905]  ? __die_body.cold+0x19/0x27
[    4.667857] [    T905]  ? page_fault_oops+0x15a/0x2d0
[    4.667872] [    T905]  ? search_bpf_extables+0x5f/0x80
[    4.667887] [    T905]  ? srso_alias_return_thunk+0x5/0xfbef5
[    4.667905] [    T905]  ? exc_page_fault+0x18a/0x190
[    4.667916] [    T905]  ? asm_exc_page_fault+0x26/0x30
[    4.667933] [    T905]  ? mt792x_mac_link_bss_remove+0xb3/0x1a2 [mt792x_lib a0c73653699a2320cd28bdf8bb75de40a17f8cca]
[    4.667957] [    T905]  mt792x_remove_interface+0x89/0xa6 [mt792x_lib a0c73653699a2320cd28bdf8bb75de40a17f8cca]
[    4.667982] [    T905]  drv_remove_interface+0x70/0x170 [mac80211 9a250447eb845213bc21a3385c8192e957080c4d]
[    4.668065] [    T905]  ieee80211_do_stop.cold+0x529/0x610 [mac80211 9a250447eb845213bc21a3385c8192e957080c4d]
[    4.668153] [    T905]  ? __pfx_autoremove_wake_function+0x10/0x10
osandov commented 1 month ago

Could you please share:

Ultimately, what I'm trying to do is understand why the kernel could not read ffffffffffffff20.

scripts/decodecode in the kernel tree disassembles the crashing instruction to:

4d 8b b4 d6 20 ff ff    mov    -0xe0(%r14,%rdx,8),%r14

And -0xe0 is 0xffffffffffffff20. Based on r14 and rdx in the register dump, I'm going to guess there's something like

container_of(foo, ...)->bar

in the code and foo is NULL.

osandov commented 1 month ago

Oh, a couple more things to check in drgn:

prog.symbol("mt792x_mac_link_bss_remove")
prog["mt792x_mac_link_bss_remove"]

I'm wondering if drgn couldn't find the debugging symbols for the driver module.

jfernandez commented 1 month ago

Full command:

sudo drgn -c /var/crash/kdumpst/crash/vmcore.202408031440 -s /usr/src/debug/linux-upstream/vmlinux

Full output. FYI, originally my modules were compressed, and I disabled compression.

❯ sudo drgn -c /var/crash/kdumpst/crash/vmcore.202408031440 -s /usr/src/debug/linux-upstream/vmlinux
drgn 0.0.27 (using Python 3.12.4, elfutils 0.191, with libkdumpfile)
warning: missing some debugging symbols (see https://drgn.readthedocs.io/en/latest/getting_debugging_symbols.html):
  /lib/modules/6.11.0-rc1-00001-gb30fffe019cc-dirty/kernel/fs/fat/vfat.ko (could not get section addresses: could not read memory from kdump: Excluded page: 0xffff9a2e84c5be70)
  /lib/modules/6.11.0-rc1-00001-gb30fffe019cc-dirty/kernel/drivers/input/joydev.ko (could not get section addresses: could not read memory from kdump: Excluded page: 0xffff9a2e8433e750)
  /lib/modules/6.11.0-rc1-00001-gb30fffe019cc-dirty/kernel/fs/fat/fat.ko (could not get section addresses: could not read memory from kdump: Excluded page: 0xffff9a2e97df8080)
  /lib/modules/6.11.0-rc1-00001-gb30fffe019cc-dirty/kernel/drivers/input/mousedev.ko (could not get section addresses: could not read memory from kdump: Excluded page: 0xffff9a2e816263c0)
  /lib/modules/6.11.0-rc1-00001-gb30fffe019cc-dirty/kernel/sound/soc/amd/ps/snd-soc-ps-mach.ko (could not get section addresses: could not read memory from kdump: Excluded page: 0xffff9a2e82140f50)
... 148 more
For help, type help(drgn).
>>> import drgn
>>> from drgn import FaultError, NULL, Object, cast, container_of, execscript, offsetof, reinterpret, sizeof, stack_trace
>>> from drgn.helpers.common import *
>>> from drgn.helpers.linux import *
>>> 

The output of running the following in drgn

>> task = prog.crashed_thread().object
>> print("pid =", task.pid)
pid = (pid_t)905
>> cpu = task_cpu(task)
>> print("cpu =", cpu)
cpu = 15
>> print("on_cpu =", task.on_cpu)
on_cpu = (int)1
>> print("curr =", cpu_curr(prog, cpu).pid)
curr = (pid_t)905
>> print(prog.stack_trace(task.pid))
#0  0xffffffffc10ff5f3
#1  0x0
#2  0x0
#3  0x0
#4  0x0
#5  0x203ff000f0000

The output of eu-readelf -n $your_vmcore. You may need to install elfutils.

❯ ls
vmcore.202408031440  vmcore.202408031605
❯ sudo eu-readelf -n vmcore.202408031440
eu-readelf: failed reading 'vmcore.202408031440': not a valid ELF file

I'm wondering if drgn couldn't find the debugging symbols for the driver module.

>> prog.symbol("mt792x_mac_link_bss_remove")
Traceback (most recent call last):
File "<console>", line 1, in <module>
LookupError: could not find symbol with name 'mt792x_mac_link_bss_remove'
>> prog["mt792x_mac_link_bss_remove"]
Traceback (most recent call last):
File "<console>", line 1, in <module>
KeyError: 'mt792x_mac_link_bss_remove'

And yes, you are absolutely right. mconf->vif is NULL below. I tracked it down using print statements, but I would love to be able to diagnose this with drgn:

struct ieee80211_vif *vif = container_of((void *)mconf->vif,
                         struct ieee80211_vif, drv_priv);
osandov commented 1 month ago

Ok these lines are the key:

/lib/modules/6.11.0-rc1-00001-gb30fffe019cc-dirty/kernel/fs/fat/vfat.ko (could not get section addresses: could not read memory from kdump: Excluded page: 0xffff9a2e84c5be70)

Either makedumpfile/kdumpst excluded some memory that drgn needs to find kernel modules, or drgn has a bug. I can dig in next week. If there's any chance you could share the core dump and your /lib/modules/6.11.0-rc1-00001-gb30fffe019cc-dirty/ directory, that would help, but I totally understand if you're not able to. Feel free to reach me via email if so.

jfernandez commented 1 month ago

These are my kdump settings for kdumpst:

#  Kdump controlling settings
#  Currently we only do local storage log collection (no network/iscsi dumps).
#  If FULL_COREDUMP is !=0, we collect a full compressed vmcore, which might
#  require a lot of disk space. The MAKEDUMPFILE_*_CMD settings refer to
#  tunings on makedumpfile - we rely on zstd compression and maximum page
#  exclusion for the full vmcore, mimic'ing Debian/Ubuntu kdump. We also
#  base on Debian/Ubuntu for the KDUMP_CMDLINE_APPEND option - this contains
#  the kernel parameters we append in the /proc/cmdline for the kdump kernel;
#  the most important parameters are nr_cpus=1 (to save RAM memory usage and
#  avoid some potential issues with SMP) and reset_devices (some drivers
#  rely on that for proper kdump).
FULL_COREDUMP=1
MAKEDUMPFILE_COREDUMP_CMD="-z -d 31"
MAKEDUMPFILE_DMESG_CMD="--dump-dmesg"
KDUMP_APPEND_CMDLINE="panic=-1 oops=panic fsck.mode=force fsck.repair=yes nr_cpus=1 reset_devices"

I will email you the core dump and the modules dir. Thank you!

brenns10 commented 1 month ago

Since this is a 6.11 based kernel, you may want to check your makedumpfile version. The following commit is required in order to include slab pages: https://github.com/makedumpfile/makedumpfile/commit/bad2a7c4fa75d37a41578441468584963028bdda

There is no makedumpfile release containing this commit yet, so you'd need to build it yourself.

jfernandez commented 1 month ago

@brenns10 thanks for surfacing that. I’ll build makedumpfile from HEAD and report back.

jfernandez commented 1 month ago

The CachyOS folks published a new version of makedumpfile with the patch. Unfortunately, this didn't seem to fix the issue, I still got the warnings about the kernel modules and no stack trace.

One thing I didn't catch before was this warning about the kernel not being supported, and the dump being possibly incomplete. It's unclear to me if this is kdump or kdumpst. image

jfernandez commented 1 month ago

It looks like that is coming from makedumpfile: https://github.com/makedumpfile/makedumpfile/blob/900190de6b67b2de410cfc8023c1b198a416ceb3/makedumpfile.c#L1185

brenns10 commented 1 week ago

I went ahead and used virtme-ng to build v6.11-rc5, and I also compiled makedumpfile from head. I ran with:

vng --rw --user root -a crashkernel=256M

Within the VM I loaded a panic kernel and then triggered a panic:

kexec -p arch/x86/boot/bzImage --append="$(cat /proc/cmdline)"
echo c >/proc/sysrq-trigger

The second kernel booted and then I used my build of makedumpfile to create a vmcore:

bash-5.1# /home/stepbren/repos/makedumpfile/makedumpfile -c -d 31 /proc/vmcore vmcore.img
The kernel version is not supported.
The makedumpfile operation may be incomplete.
Checking for memory holes                         : [  0.0 %] /                Checking for memory holes                         : [100.0 %] |                Excluding unnecessary pages                       : [100.0 %] \                Checking for memory holes                         : [100.0 %] -                Checking for memory holes                         : [100.0 %] /                Excluding unnecessary pages                       : [100.0 %] |                Copying data                                      : [ 25.4 %] \           eta: Copying data                                      : [ 57.8 %] -           eta: Copying data                                      : [ 75.8 %] /           eta: Copying data                                      : [100.0 %] |           eta: Copying data                                      : [100.0 %] \           eta: 0s

The dumpfile is saved to vmcore.img.

makedumpfile Completed.

With drgn 0.0.27 I had no trouble loading that vmcore and reading the crashed thread:

$ drgn -c vmcore.img -s vmlinux
drgn 0.0.27 (using Python 3.9.18, elfutils 0.190, with libkdumpfile)
For help, type help(drgn).
>>> import drgn
>>> from drgn import FaultError, NULL, Object, cast, container_of, execscript, offsetof, reinterpret, sizeof, stack_trace
>>> from drgn.helpers.common import *
>>> from drgn.helpers.linux import *
>>> prog.crashed_thread()
<_drgn.Thread object at 0x7f4235e8ccb0>
>>> prog.crashed_thread().stack_trace()
#0  crash_setup_regs (./arch/x86/include/asm/kexec.h:114:15)
#1  __crash_kexec (kernel/crash_core.c:119:4)
#2  panic (kernel/panic.c:373:3)
#3  sysrq_handle_crash (drivers/tty/sysrq.c:154:2)
#4  __handle_sysrq (drivers/tty/sysrq.c:612:4)
#5  write_sysrq_trigger (drivers/tty/sysrq.c:1181:4)
#6  pde_write (fs/proc/inode.c:334:10)
#7  proc_reg_write (fs/proc/inode.c:346:8)
#8  vfs_write (fs/read_write.c:588:9)
#9  ksys_write (fs/read_write.c:643:9)
#10 do_syscall_x64 (arch/x86/entry/common.c:52:14)
#11 do_syscall_64 (arch/x86/entry/common.c:83:7)
#12 entry_SYSCALL_64+0xb0/0x14d (arch/x86/entry/entry_64.S:121)
#13 0x7f86f150cad7
>>>

Obviously that's not to say that you're not still having an issue, but I don't think the issue is anywhere in general makedumpfile or drgn support for kernel 6.11. If you're still having an issue and you're comfortable sharing the core dump privately, I could probably take a look and see if I notice anything odd about it.

brenns10 commented 1 week ago

The "kernel version is not supported" message is definitely just a preemptive message that makedumpfile prints for kernels whose version is greater than the max they have tested. It doesn't indicate that anything has actually gone wrong, just that you're in uncharted territory.