Re: [RFC PATCH v2 0/4] Improve stack unwind on ppc64

[lijiang <lijiang@xxxxxxxxxx>]

On Mon, Sep 4, 2023 at 7:38 PM Aditya Gupta <adityag@xxxxxxxxxxxxx> wrote:

Hi Lijiang,
Thanks for the reviews

> > Implications on Architectures:
> > ====================================
> >
> > No architecture other than PPC64 has been affected, other than in case of
> > 'frame' command
> >
> >
> BTW: Can this feature be implemented on other architectures such as X86 64,
> etc? Have you investigated?
>

Yes Lijiang, from my analysis, the key functionality is provide register value
to gdb, for any architecture

Basically, gdb needs register values for 'frame', 'bt', which it gets from the
target, ie. `crash_target::fetch_register`, which further calls
`machdep->get_cpu_reg` to get each register
And then with the register values and dwarf info, gdb can print backtraces, and
local variables

I did not do it, but logically that might help on x86_64.
I have put a diagram in patch #2.

 

Thank you for the explanation, Aditya. That sounds good if it's doable on other arches.

> > Git tree with this patch series applied:
> > https://github.com/adi-g15-ibm/crash/tree/stack-unwind-rfc2
> >
> > To test gdb passthroughs:
> >
> >         crash> set gdb on
> >         gdb> thread 3 # or any other thread number to change context in gdb
> >         gdb> bt
> >         gdb> frame
> >         gdb> up
> >         gdb> down
> >         gdb> info locals
> >
> >
> I did a simple test as below(kernel commit: 99d99825fc07):
>
> gdb> info threads
>   Id   Target Id         Frame
>   1    CPU 0             <unavailable> in ?? ()
>   2    CPU 1
> gdb> thread 2
> [Switching to thread 2 (CPU 1)]
> #0  0xc0000000002843f8 in crash_setup_regs (oldregs=<optimized out>,
> newregs=0xc00000003dbd7958) at ./arch/powerpc/include/asm/kexec.h:69
> 69                      ppc_save_regs(newregs);
> gdb> bt
> #0  0xc0000000002843f8 in crash_setup_regs (oldregs=<optimized out>,
> newregs=0xc00000003dbd7958) at ./arch/powerpc/include/asm/kexec.h:69
> #1  __crash_kexec (regs=<optimized out>) at kernel/kexec_core.c:1064
> #2  0xc00000000014e018 in panic (fmt=0xc000000001443d80 "sysrq triggered
> crash\n") at kernel/panic.c:359
> #3  0xc0000000009b8978 in sysrq_handle_crash (key=<optimized out>) at
> drivers/tty/sysrq.c:155
> #4  0xc0000000009b946c in __handle_sysrq (key=key@entry=99,
> check_mask=check_mask@entry=false) at drivers/tty/sysrq.c:602
> #5  0xc0000000009b9ce8 in write_sysrq_trigger (file=<optimized out>,
> buf=<optimized out>, count=2, ppos=<optimized out>) at
> drivers/tty/sysrq.c:1163
> #6  0xc0000000006919fc in pde_write (ppos=<optimized out>, count=<optimized
> out>, buf=<optimized out>, file=<optimized out>, pde=0xc00000000556fcc0) at
> fs/proc/inode.c:340
> #7  proc_reg_write (file=<optimized out>, buf=<optimized out>,
> count=<optimized out>, ppos=<optimized out>) at fs/proc/inode.c:352
> #8  0xc0000000005b7cb8 in vfs_write (file=file@entry=0xc000000036fa5f00,
> buf=buf@entry=0x10027835560 <error: Cannot access memory at address
> 0x10027835560>, count=count@entry=2, pos=pos@entry=0xc00000003dbd7de0) at
> fs/read_write.c:582
> #9  0xc0000000005b83a4 in ksys_write (fd=<optimized out>, buf=0x10027835560
> <error: Cannot access memory at address 0x10027835560>, count=2) at
> fs/read_write.c:637
> #10 0xc000000000031454 in system_call_exception (regs=0xc00000003dbd7e80,
> r0=<optimized out>) at arch/powerpc/kernel/syscall.c:153
> #11 0xc00000000000cedc in system_call_vectored_common () at
> arch/powerpc/kernel/interrupt_64.S:198
> Backtrace stopped: previous frame inner to this frame (corrupt stack?)
> gdb> frame 7
> #7  proc_reg_write (file=<optimized out>, buf=<optimized out>,
> count=<optimized out>, ppos=<optimized out>) at fs/proc/inode.c:352
> 352                     rv = pde_write(pde, file, buf, count, ppos);
> gdb> info rv
> gdb: gdb request failed: info rv
> gdb>
>
> Seems that the 'info locals' command is not working as expected. I haven't
> investigated the details.
>

Oh, sure I will test this, meanwhile are you sure 'info rv' was the command you
ran, I guess that's not a valid gdb command, can you please check.

 

Ah, I misunderstood, I would like to display the result of a specified local variable such as "rv"(not all local variables).

For now I get the result of "info locals" command as below:

gdb> frame 7

#7  proc_reg_write (file=<optimized out>, buf=<optimized out>, count=<optimized out>, ppos=<optimized out>) at fs/proc/inode.c:352
352                     rv = pde_write(pde, file, buf, count, ppos);
gdb> info locals
pde = 0xc00000000556fcc0
rv = -5
gdb>

But the "info variables" command still hangs:

gdb> info variables
 -- MORE --  forward: <SPACE>, <ENTER> or j  backward: b or k  quit: q...skipping...
 -- MORE --  forward: <SPACE>, <ENTER> or j  backward: b or k  quit: q...skipping...

  

Anyway I'm not sure if this can support other "info" subcommands. Just tried it.

 

>
> Known Issues:
> > =============
> >
> > 1. In gdb mode, 'info threads' might hang for few seconds, and print only 2
> >    threads
> >
>
> Hmm, it only prints 2 threads, and one of which is unavailable on my side.
> Can you try to dig into the details?
>

Yes, the long time is due to gdb trying lot of unwinders, to unwind frame in each
thread.
This happens in gdb mode, and does not affect the default crash mode in any way.
And without this patch set also, gdb mode didn't recognise actual threads, and
would just print n threads (n being number of cpus), since that's what was added
in crash_target_init

I have tried to fix this earlier, but failed to. The following is my
speculation, but this might have been caused due to crash explicitly having
registered threads in crash_target_init, and since not all threads will be
alive, gdb is trying to unwind them and failing, so it goes and tries all
unwinders, and still fail

 

It seems worth looking into the details.

The current thread may be a panic thread by default. That would be more valuable if it supports showing the results of local variables or arguments(furthermore backtrace) in a panic thread.

 # ./crash vmlinux /var/crash/127.0.0.1-2023-09-03-23\:17\:53/vmcore

crash 8.0.3++
...
For help, type "help".
Type "apropos word" to search for commands related to "word"...

      KERNEL: vmlinux                          
    DUMPFILE: /var/crash/127.0.0.1-2023-09-03-23:17:53/vmcore
        CPUS: 8
        DATE: Sun Sep  3 23:17:17 EDT 2023
      UPTIME: 2 days, 18:28:40
LOAD AVERAGE: 0.61, 0.22, 0.08
       TASKS: 173
    NODENAME: ibm-p9z-16-lp9.khw3.lab.eng.bos.redhat.com
     RELEASE: 6.5.0+
     VERSION: #1 SMP Fri Sep  1 04:07:47 EDT 2023
     MACHINE: ppc64le  (2800 Mhz)
      MEMORY: 16 GB
       PANIC: "Kernel panic - not syncing: sysrq triggered crash"
         PID: 1453
     COMMAND: "bash"
        TASK: c00000000845b180  [THREAD_INFO: c00000000845b180]
         CPU: 0
       STATE: TASK_RUNNING (PANIC)

crash> bt
PID: 1453     TASK: c00000000845b180  CPU: 0    COMMAND: "bash"
 R0:  c00000000014e018    R1:  c00000003dbd7930    R2:  c0000000015a2500  
 R3:  c00000003dbd7928    R4:  c00000000845b180    R5:  0000000000000020  
 R6:  c000000002e32500    R7:  0000000000000000    R8:  0000000000000001  
 R9:  c00000000b6e1000    R10: 0000000000000000    R11: 0000000000000001  
 R12: 0000000000000000    R13: c000000002f60000    R14: 0000000000000000  
 R15: 0000000000000000    R16: 0000000000000000    R17: 0000000000000000  
 R18: 0000000000000000    R19: 0000000000000000    R20: 0000000000000000  
 R21: 0000000000000000    R22: 0000000000000000    R23: 0000000000000000  
 R24: 0000000000000000    R25: c000000001110920    R26: 0000000000000000  
 R27: c00000000276e510    R28: c000000002d1a660    R29: c000000002d1a698  
 R30: c000000002c62500    R31: c00000003dbd7958  
 NIP: c0000000002843f8    MSR: 8000000000009033    OR3: 0000000000000000
 CTR: 000000000074d2f4    LR:  c00000000014e018    XER: 0000000020040005
 CCR: 0000000028422282    MQ:  0000000000000001    DAR: c000000002d1a660
 DSISR: c000000002d1a698     Syscall Result: 0000000000000001
 [NIP  : __crash_kexec+248]
 [LR   : panic+412]
 #0 [c00000003dbd7930] __crash_kexec at c0000000002843f8
 #1 [c00000003dbd7af0] panic at c00000000014e018
 #2 [c00000003dbd7b90] sysrq_handle_crash at c0000000009b8978
 #3 [c00000003dbd7bf0] __handle_sysrq at c0000000009b946c
 #4 [c00000003dbd7c90] write_sysrq_trigger at c0000000009b9ce8
 #5 [c00000003dbd7cd0] proc_reg_write at c0000000006919fc
 #6 [c00000003dbd7d00] vfs_write at c0000000005b7cb8
 #7 [c00000003dbd7dc0] ksys_write at c0000000005b83a4
 #8 [c00000003dbd7e10] system_call_exception at c000000000031454
 #9 [c00000003dbd7e50] system_call_vectored_common at c00000000000cedc
crash> set gdb on
gdb: on
gdb> info thread
  Id   Target Id         Frame
* 1    CPU 0             <unavailable> in ?? ()
  2    CPU 1            
gdb> bt
#0  <unavailable> in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
gdb> thread 1
[Switching to thread 1 (CPU 0)]
#0  <unavailable> in ?? ()
gdb> bt
#0  <unavailable> in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Although it only displays two threads, still supports switching to other threads:

gdb> thread 6
[Switching to thread 6 (CPU 5)]
#0  0xc0000000002843f8 in crash_setup_regs (oldregs=<optimized out>, newregs=0xc00000003dbd7958) at ./arch/powerpc/include/asm/kexec.h:69
69                      ppc_save_regs(newregs);
gdb>

For live debugging, I only see one thread, and I can not switch to other threads. They have different behaviors.

gdb> info thread
  Id   Target Id         Frame
* 1    CPU 0             <unavailable> in ?? ()

gdb> thread 6
gdb: gdb request failed: thread 6
gdb>

 

 >
> > 2. In gdb mode, 'bt' might fail to show backtrace in few vmcores collected
> >    from older kernels. This is a known issue due to register mismatch, and
> >    its fix has been merged upstream:
> >
> > Commit:
> > https://github.com/torvalds/linux/commit/b684c09f09e7a6af3794d4233ef785819e72db79
> >
> > TODO:
> > =====
> >
> > 1. Introduce automatic thread selection in gdb mode, to select the crashing
> >    thread in gdb, eliminating the need to manually run "thread <id>" after
> >    switching to gdb mode.

Just a note here, I will include this in next version I send.

Ok, thanks. And let's see if it is better.

 

> >
> > Changelog:
> > ==========
> >
> > RFC V2:
> >   - removed patch implementing 'frame', 'up', 'down' in crash
> >   - updated the cover letter by removing the mention of those commands
> > other
> >         than the respective gdb passthrough
> >
> >
> In addition, the get_dumpfile_regs() is not invoked in the [patch 1], I
> would suggest moving it into the [patch 2]. Just a glance, I haven't looked
> at the patchset carefully.

Yeah, you are correct. That can be merged into patch #2. I had kept it separate
on purpose, so to introduce that logic separately as it was architecture
independent.

Thanks.

Lianbo

 

Thanks,
Aditya Gupta

--
Crash-utility mailing list
Crash-utility@xxxxxxxxxx
https://listman.redhat.com/mailman/listinfo/crash-utility
Contribution Guidelines: https://github.com/crash-utility/crash/wiki