Re: [RFC PATCH] powerpc: show registers when unwinding interrupt frames
On Sat, 7 Nov 2020 12:33:05 +1000, Nicholas Piggin wrote: > It's often useful to know the register state for interrupts in > the stack frame. In the below example (with this patch applied), > the important information is the state of the page fault. > > A blatant case like this probably rather should have the page > fault regs passed down to the warning, but quite often there are > less obvious cases where an interrupt shows up that might give > some more clues. > > [...] Applied to powerpc/next. [1/1] powerpc: show registers when unwinding interrupt frames https://git.kernel.org/powerpc/c/bf13718bc57ada25016d9fe80323238d0b94506e cheers
Re: [RFC PATCH] powerpc: show registers when unwinding interrupt frames
Christophe Leroy writes: > Le 07/11/2020 à 03:33, Nicholas Piggin a écrit : >> It's often useful to know the register state for interrupts in >> the stack frame. In the below example (with this patch applied), >> the important information is the state of the page fault. >> >> A blatant case like this probably rather should have the page >> fault regs passed down to the warning, but quite often there are >> less obvious cases where an interrupt shows up that might give >> some more clues. >> >> The downside is longer and more complex bug output. > > Do we want all interrupts, including system call ? I think we do. > I don't find the dump of the syscall interrupt so usefull, do you ? Yes :) Because it's consistent, ie. we always show the full chain back to userspace. I think it's also helpful for folks who are less familiar with how things work to show all the pieces, rather than hiding syscalls or treating them specially. Also I'm pretty sure I've had occasions where I've been debugging and wanted to see the values that came in from userspace. cheers > See below an (unexpected?) KUAP warning due to an expected NULL pointer > dereference in > copy_from_kernel_nofault() called from kthread_probe_data() > > > [ 1117.202054] [ cut here ] > [ 1117.202102] Bug: fault blocked by AP register ! > [ 1117.202261] WARNING: CPU: 0 PID: 377 at > arch/powerpc/include/asm/nohash/32/kup-8xx.h:66 > do_page_fault+0x4a8/0x5ec > [ 1117.202310] Modules linked in: > [ 1117.202428] CPU: 0 PID: 377 Comm: sh Tainted: GW > 5.10.0-rc5-s3k-dev-01340-g83f53be2de31-dirty #4175 > [ 1117.202499] NIP: c0012048 LR: c0012048 CTR: > [ 1117.202573] REGS: cacdbb88 TRAP: 0700 Tainted: GW > (5.10.0-rc5-s3k-dev-01340-g83f53be2de31-dirty) > [ 1117.202625] MSR: 00021032 CR: 2408 XER: 2000 > [ 1117.202899] > [ 1117.202899] GPR00: c0012048 cacdbc40 c2929290 0023 c092e554 0001 > c09865e8 c092e640 > [ 1117.202899] GPR08: 1032 00014efc 28082224 100d166a > 100a0920 > [ 1117.202899] GPR16: 100cac0c 100b 1080c3fc 1080d685 100d 100d > 100a0900 > [ 1117.202899] GPR24: 100d c07892ec c0921510 c21f4440 005c > c000 cacdbc80 > [ 1117.204362] NIP [c0012048] do_page_fault+0x4a8/0x5ec > [ 1117.204461] LR [c0012048] do_page_fault+0x4a8/0x5ec > [ 1117.204509] Call Trace: > [ 1117.204609] [cacdbc40] [c0012048] do_page_fault+0x4a8/0x5ec (unreliable) > [ 1117.204771] [cacdbc70] [c00112f0] handle_page_fault+0x8/0x34 > [ 1117.204911] --- interrupt: 301 at copy_from_kernel_nofault+0x70/0x1c0 > [ 1117.204979] NIP: c010dbec LR: c010dbac CTR: 0001 > [ 1117.205053] REGS: cacdbc80 TRAP: 0301 Tainted: GW > (5.10.0-rc5-s3k-dev-01340-g83f53be2de31-dirty) > [ 1117.205104] MSR: 9032 CR: 28082224 XER: > [ 1117.205416] DAR: 005c DSISR: c000 > [ 1117.205416] GPR00: c0045948 cacdbd38 c2929290 0001 0017 0017 > 0027 000f > [ 1117.205416] GPR08: c09926ec 3000 24082224 > [ 1117.206106] NIP [c010dbec] copy_from_kernel_nofault+0x70/0x1c0 > [ 1117.206202] LR [c010dbac] copy_from_kernel_nofault+0x30/0x1c0 > [ 1117.206258] --- interrupt: 301 > [ 1117.206372] [cacdbd38] [c004bbb0] kthread_probe_data+0x44/0x70 (unreliable) > [ 1117.206561] [cacdbd58] [c0045948] print_worker_info+0xe0/0x194 > [ 1117.206717] [cacdbdb8] [c00548ac] sched_show_task+0x134/0x168 > [ 1117.206851] [cacdbdd8] [c005a268] show_state_filter+0x70/0x100 > [ 1117.206989] [cacdbe08] [c039baa0] sysrq_handle_showstate+0x14/0x24 > [ 1117.207122] [cacdbe18] [c039bf18] __handle_sysrq+0xac/0x1d0 > [ 1117.207257] [cacdbe48] [c039c0c0] write_sysrq_trigger+0x4c/0x74 > [ 1117.207407] [cacdbe68] [c01fba48] proc_reg_write+0xb4/0x114 > [ 1117.207550] [cacdbe88] [c0179968] vfs_write+0x12c/0x478 > [ 1117.207686] [cacdbf08] [c0179e60] ksys_write+0x78/0x128 > [ 1117.207826] [cacdbf38] [c00110d0] ret_from_syscall+0x0/0x34 > [ 1117.207938] --- interrupt: c01 at 0xfd4e784 > [ 1117.208008] NIP: 0fd4e784 LR: 0fe0f244 CTR: 10048d38 > [ 1117.208083] REGS: cacdbf48 TRAP: 0c01 Tainted: GW > (5.10.0-rc5-s3k-dev-01340-g83f53be2de31-dirty) > [ 1117.208134] MSR: d032 CR: 4400 XER: > [ 1117.208470] > [ 1117.208470] GPR00: 0004 7fc34090 77bfb4e0 0001 1080fa40 0002 > 740f fefefeff > [ 1117.208470] GPR08: 7f7f7f7f 10048d38 1080c414 7fc343c0 > [ 1117.209104] NIP [0fd4e784] 0xfd4e784 > [ 1117.209180] LR [0fe0f244] 0xfe0f244 > [ 1117.209236] --- interrupt: c01 > [ 1117.209274] Instruction dump: > [ 1117.209353] 714a4000 418200f0 73ca0001 40820084 73ca0032 408200f8 73c90040 > 4082ff60 > [ 1117.209727] 0fe0 3c60c082 386399f4 48013b65 <0fe0> 80010034 > 386b 7c0803a6 > [ 1117.210102] ---[ end trace 1927c0323393af3e ]--- > > Christophe > > >> >>Bug: Write fault blocked by AMR! >>WARNING: CPU: 0 PID: 72 at >>
Re: [RFC PATCH] powerpc: show registers when unwinding interrupt frames
Le 07/11/2020 à 03:33, Nicholas Piggin a écrit : It's often useful to know the register state for interrupts in the stack frame. In the below example (with this patch applied), the important information is the state of the page fault. A blatant case like this probably rather should have the page fault regs passed down to the warning, but quite often there are less obvious cases where an interrupt shows up that might give some more clues. The downside is longer and more complex bug output. Do we want all interrupts, including system call ? I don't find the dump of the syscall interrupt so usefull, do you ? See below an (unexpected?) KUAP warning due to an expected NULL pointer dereference in copy_from_kernel_nofault() called from kthread_probe_data() [ 1117.202054] [ cut here ] [ 1117.202102] Bug: fault blocked by AP register ! [ 1117.202261] WARNING: CPU: 0 PID: 377 at arch/powerpc/include/asm/nohash/32/kup-8xx.h:66 do_page_fault+0x4a8/0x5ec [ 1117.202310] Modules linked in: [ 1117.202428] CPU: 0 PID: 377 Comm: sh Tainted: GW 5.10.0-rc5-s3k-dev-01340-g83f53be2de31-dirty #4175 [ 1117.202499] NIP: c0012048 LR: c0012048 CTR: [ 1117.202573] REGS: cacdbb88 TRAP: 0700 Tainted: GW (5.10.0-rc5-s3k-dev-01340-g83f53be2de31-dirty) [ 1117.202625] MSR: 00021032 CR: 2408 XER: 2000 [ 1117.202899] [ 1117.202899] GPR00: c0012048 cacdbc40 c2929290 0023 c092e554 0001 c09865e8 c092e640 [ 1117.202899] GPR08: 1032 00014efc 28082224 100d166a 100a0920 [ 1117.202899] GPR16: 100cac0c 100b 1080c3fc 1080d685 100d 100d 100a0900 [ 1117.202899] GPR24: 100d c07892ec c0921510 c21f4440 005c c000 cacdbc80 [ 1117.204362] NIP [c0012048] do_page_fault+0x4a8/0x5ec [ 1117.204461] LR [c0012048] do_page_fault+0x4a8/0x5ec [ 1117.204509] Call Trace: [ 1117.204609] [cacdbc40] [c0012048] do_page_fault+0x4a8/0x5ec (unreliable) [ 1117.204771] [cacdbc70] [c00112f0] handle_page_fault+0x8/0x34 [ 1117.204911] --- interrupt: 301 at copy_from_kernel_nofault+0x70/0x1c0 [ 1117.204979] NIP: c010dbec LR: c010dbac CTR: 0001 [ 1117.205053] REGS: cacdbc80 TRAP: 0301 Tainted: GW (5.10.0-rc5-s3k-dev-01340-g83f53be2de31-dirty) [ 1117.205104] MSR: 9032 CR: 28082224 XER: [ 1117.205416] DAR: 005c DSISR: c000 [ 1117.205416] GPR00: c0045948 cacdbd38 c2929290 0001 0017 0017 0027 000f [ 1117.205416] GPR08: c09926ec 3000 24082224 [ 1117.206106] NIP [c010dbec] copy_from_kernel_nofault+0x70/0x1c0 [ 1117.206202] LR [c010dbac] copy_from_kernel_nofault+0x30/0x1c0 [ 1117.206258] --- interrupt: 301 [ 1117.206372] [cacdbd38] [c004bbb0] kthread_probe_data+0x44/0x70 (unreliable) [ 1117.206561] [cacdbd58] [c0045948] print_worker_info+0xe0/0x194 [ 1117.206717] [cacdbdb8] [c00548ac] sched_show_task+0x134/0x168 [ 1117.206851] [cacdbdd8] [c005a268] show_state_filter+0x70/0x100 [ 1117.206989] [cacdbe08] [c039baa0] sysrq_handle_showstate+0x14/0x24 [ 1117.207122] [cacdbe18] [c039bf18] __handle_sysrq+0xac/0x1d0 [ 1117.207257] [cacdbe48] [c039c0c0] write_sysrq_trigger+0x4c/0x74 [ 1117.207407] [cacdbe68] [c01fba48] proc_reg_write+0xb4/0x114 [ 1117.207550] [cacdbe88] [c0179968] vfs_write+0x12c/0x478 [ 1117.207686] [cacdbf08] [c0179e60] ksys_write+0x78/0x128 [ 1117.207826] [cacdbf38] [c00110d0] ret_from_syscall+0x0/0x34 [ 1117.207938] --- interrupt: c01 at 0xfd4e784 [ 1117.208008] NIP: 0fd4e784 LR: 0fe0f244 CTR: 10048d38 [ 1117.208083] REGS: cacdbf48 TRAP: 0c01 Tainted: GW (5.10.0-rc5-s3k-dev-01340-g83f53be2de31-dirty) [ 1117.208134] MSR: d032 CR: 4400 XER: [ 1117.208470] [ 1117.208470] GPR00: 0004 7fc34090 77bfb4e0 0001 1080fa40 0002 740f fefefeff [ 1117.208470] GPR08: 7f7f7f7f 10048d38 1080c414 7fc343c0 [ 1117.209104] NIP [0fd4e784] 0xfd4e784 [ 1117.209180] LR [0fe0f244] 0xfe0f244 [ 1117.209236] --- interrupt: c01 [ 1117.209274] Instruction dump: [ 1117.209353] 714a4000 418200f0 73ca0001 40820084 73ca0032 408200f8 73c90040 4082ff60 [ 1117.209727] 0fe0 3c60c082 386399f4 48013b65 <0fe0> 80010034 386b 7c0803a6 [ 1117.210102] ---[ end trace 1927c0323393af3e ]--- Christophe Bug: Write fault blocked by AMR! WARNING: CPU: 0 PID: 72 at arch/powerpc/include/asm/book3s/64/kup-radix.h:164 __do_page_fault+0x880/0xa90 Modules linked in: CPU: 0 PID: 72 Comm: systemd-gpt-aut Not tainted NIP: c006e2f0 LR: c006e2ec CTR: REGS: ca4f3420 TRAP: 0700 MSR: 80021033 CR: 28002840 XER: 2004 CFAR: c0128be0 IRQMASK: 3 GPR00: c006e2ec ca4f36c0 c14f0700 0020 GPR04: 0001 c1290f50 0001 c1290f80 GPR08: c1612b08 e0f7 GPR12: 48002840 c16e c00c00021c80
Re: [RFC PATCH] powerpc: show registers when unwinding interrupt frames
Le 07/11/2020 à 03:33, Nicholas Piggin a écrit :
It's often useful to know the register state for interrupts in
the stack frame. In the below example (with this patch applied),
the important information is the state of the page fault.
A blatant case like this probably rather should have the page
fault regs passed down to the warning, but quite often there are
less obvious cases where an interrupt shows up that might give
some more clues.
I like it.
I was wondering about interrupts that do not save NV registers, but that seems
to be handled:
[0.455489] --- interrupt: 301 at cmpxchg_futex_value_locked+0x2c/0x58
[0.461886] NIP: c0089c08 LR: c0755df0 CTR: c02e59a4
[0.466889] REGS: c9023db0 TRAP: 0301 Not tainted
(5.10.0-rc2-s3k-dev-01371-gfb45a2414e96-dirty)
[0.475815] MSR: 9032 CR: 28000244 XER:
[0.482450] DAR: DSISR: c000
[0.482450] GPR00: c0755dc8 c9023e68 c210 c9023e78
[0.482450] GPR08: 1032 8000 0003 42000242
[0.500988] NIP [c0089c08] cmpxchg_futex_value_locked+0x2c/0x58
[0.506842] LR [c0755df0] futex_init+0x74/0xd0
[0.511194] --- interrupt: 301
Christophe
The downside is longer and more complex bug output.
Bug: Write fault blocked by AMR!
WARNING: CPU: 0 PID: 72 at
arch/powerpc/include/asm/book3s/64/kup-radix.h:164 __do_page_fault+0x880/0xa90
Modules linked in:
CPU: 0 PID: 72 Comm: systemd-gpt-aut Not tainted
NIP: c006e2f0 LR: c006e2ec CTR:
REGS: ca4f3420 TRAP: 0700
MSR: 80021033 CR: 28002840 XER: 2004
CFAR: c0128be0 IRQMASK: 3
GPR00: c006e2ec ca4f36c0 c14f0700 0020
GPR04: 0001 c1290f50 0001 c1290f80
GPR08: c1612b08 e0f7
GPR12: 48002840 c16e c00c00021c80 c0fd6f60
GPR16: ca104698 0003 c87f
GPR20: 0100 c70330b8 0004
GPR24: 0200 0300 0200 ca5b0c00
GPR28: 0a00 7fffb2a90038 ca4f3820
NIP [c006e2f0] __do_page_fault+0x880/0xa90
LR [c006e2ec] __do_page_fault+0x87c/0xa90
Call Trace:
[ca4f36c0] [c006e2ec] __do_page_fault+0x87c/0xa90
(unreliable)
[ca4f3780] [c0e1c034] do_page_fault+0x34/0x90
[ca4f37b0] [c0008908] data_access_common_virt+0x158/0x1b0
--- interrupt: 300 at __copy_tofrom_user_base+0x9c/0x5a4
NIP: c009b028 LR: c0802978 CTR: 0800
REGS: ca4f3820 TRAP: 0300
MSR: 8280b033 CR: 24004840 XER:
CFAR: c009aff4 DAR: 7fffb2a90038 DSISR: 0a00 IRQMASK: 0
GPR00: ca4f3ac0 c14f0700 7fffb2a90028
GPR04: c8720010 0001
GPR08: 0001
GPR12: 4000 c16e c00c00021c80 c0fd6f60
GPR16: ca104698 0003 c87f
GPR20: 0100 c70330b8 0004
GPR24: ca4f3c80 c872 0001
GPR28: 0001 0872 0001 c1515b98
NIP [c009b028] __copy_tofrom_user_base+0x9c/0x5a4
LR [c0802978] copyout+0x68/0xc0
--- interrupt: 300
[ca4f3af0] [c08074b8] copy_page_to_iter+0x188/0x540
[ca4f3b50] [c035c678] generic_file_buffered_read+0x358/0xd80
[ca4f3c40] [c04c1e90] blkdev_read_iter+0x50/0x80
[ca4f3c60] [c045733c] new_sync_read+0x12c/0x1c0
[ca4f3d00] [c045a1f0] vfs_read+0x1d0/0x240
[ca4f3d50] [c045a7f4] ksys_read+0x84/0x140
[ca4f3da0] [c0033a60] system_call_exception+0x100/0x280
[ca4f3e10] [c000c508] system_call_common+0xf8/0x2f8
Instruction dump:
eae10078 3beb 4bfff890 6042 792917e1 4182ff18 3c82ffab 3884a5e0
3c62ffab 3863a6e8 480ba891 6000 <0fe0> 3beb 4bfff860 e93c0938
Signed-off-by: Nicholas Piggin
---
arch/powerpc/kernel/process.c | 20 ++--
1 file changed, 14 insertions(+), 6 deletions(-)
diff --git a/arch/powerpc/kernel/process.c b/arch/powerpc/kernel/process.c
index ea36a29c8b01..799f00b32f74 100644
--- a/arch/powerpc/kernel/process.c
+++ b/arch/powerpc/kernel/process.c
@@ -1475,12 +1475,10 @@ static void print_msr_bits(unsigned long val)
#define LAST_VOLATILE 12
#endif
-void show_regs(struct pt_regs * regs)
+static void __show_regs(struct pt_regs *regs)
{
int i,
[RFC PATCH] powerpc: show registers when unwinding interrupt frames
It's often useful to know the register state for interrupts in
the stack frame. In the below example (with this patch applied),
the important information is the state of the page fault.
A blatant case like this probably rather should have the page
fault regs passed down to the warning, but quite often there are
less obvious cases where an interrupt shows up that might give
some more clues.
The downside is longer and more complex bug output.
Bug: Write fault blocked by AMR!
WARNING: CPU: 0 PID: 72 at arch/powerpc/include/asm/book3s/64/kup-radix.h:164
__do_page_fault+0x880/0xa90
Modules linked in:
CPU: 0 PID: 72 Comm: systemd-gpt-aut Not tainted
NIP: c006e2f0 LR: c006e2ec CTR:
REGS: ca4f3420 TRAP: 0700
MSR: 80021033 CR: 28002840 XER: 2004
CFAR: c0128be0 IRQMASK: 3
GPR00: c006e2ec ca4f36c0 c14f0700 0020
GPR04: 0001 c1290f50 0001 c1290f80
GPR08: c1612b08 e0f7
GPR12: 48002840 c16e c00c00021c80 c0fd6f60
GPR16: ca104698 0003 c87f
GPR20: 0100 c70330b8 0004
GPR24: 0200 0300 0200 ca5b0c00
GPR28: 0a00 7fffb2a90038 ca4f3820
NIP [c006e2f0] __do_page_fault+0x880/0xa90
LR [c006e2ec] __do_page_fault+0x87c/0xa90
Call Trace:
[ca4f36c0] [c006e2ec] __do_page_fault+0x87c/0xa90 (unreliable)
[ca4f3780] [c0e1c034] do_page_fault+0x34/0x90
[ca4f37b0] [c0008908] data_access_common_virt+0x158/0x1b0
--- interrupt: 300 at __copy_tofrom_user_base+0x9c/0x5a4
NIP: c009b028 LR: c0802978 CTR: 0800
REGS: ca4f3820 TRAP: 0300
MSR: 8280b033 CR: 24004840 XER:
CFAR: c009aff4 DAR: 7fffb2a90038 DSISR: 0a00 IRQMASK: 0
GPR00: ca4f3ac0 c14f0700 7fffb2a90028
GPR04: c8720010 0001
GPR08: 0001
GPR12: 4000 c16e c00c00021c80 c0fd6f60
GPR16: ca104698 0003 c87f
GPR20: 0100 c70330b8 0004
GPR24: ca4f3c80 c872 0001
GPR28: 0001 0872 0001 c1515b98
NIP [c009b028] __copy_tofrom_user_base+0x9c/0x5a4
LR [c0802978] copyout+0x68/0xc0
--- interrupt: 300
[ca4f3af0] [c08074b8] copy_page_to_iter+0x188/0x540
[ca4f3b50] [c035c678] generic_file_buffered_read+0x358/0xd80
[ca4f3c40] [c04c1e90] blkdev_read_iter+0x50/0x80
[ca4f3c60] [c045733c] new_sync_read+0x12c/0x1c0
[ca4f3d00] [c045a1f0] vfs_read+0x1d0/0x240
[ca4f3d50] [c045a7f4] ksys_read+0x84/0x140
[ca4f3da0] [c0033a60] system_call_exception+0x100/0x280
[ca4f3e10] [c000c508] system_call_common+0xf8/0x2f8
Instruction dump:
eae10078 3beb 4bfff890 6042 792917e1 4182ff18 3c82ffab 3884a5e0
3c62ffab 3863a6e8 480ba891 6000 <0fe0> 3beb 4bfff860 e93c0938
Signed-off-by: Nicholas Piggin
---
arch/powerpc/kernel/process.c | 20 ++--
1 file changed, 14 insertions(+), 6 deletions(-)
diff --git a/arch/powerpc/kernel/process.c b/arch/powerpc/kernel/process.c
index ea36a29c8b01..799f00b32f74 100644
--- a/arch/powerpc/kernel/process.c
+++ b/arch/powerpc/kernel/process.c
@@ -1475,12 +1475,10 @@ static void print_msr_bits(unsigned long val)
#define LAST_VOLATILE 12
#endif
-void show_regs(struct pt_regs * regs)
+static void __show_regs(struct pt_regs *regs)
{
int i, trap;
- show_regs_print_info(KERN_DEFAULT);
-
printk("NIP: "REG" LR: "REG" CTR: "REG"\n",
regs->nip, regs->link, regs->ctr);
printk("REGS: %px TRAP: %04lx %s (%s)\n",
@@ -1522,6 +1520,12 @@ void show_regs(struct pt_regs * regs)
printk("NIP ["REG"] %pS\n", regs->nip, (void *)regs->nip);
printk("LR ["REG"] %pS\n", regs->link, (void *)regs->link);
}
+}
+
+void show_regs(struct pt_regs *regs)
+{
+ show_regs_print_info(KERN_DEFAULT);
+ __show_regs(regs);
show_stack(current, (unsigned long *) regs->gpr[1], KERN_DEFAULT);
if (!user_mode(regs))
show_instructions(regs);
@@ -2192,10 +2196,14 @@ void show_stack(struct task_struct *tsk, unsigned long
*stack,
&& stack[STACK_FRAME_MARKER] == STACK_FRAME_REGS_MARKER) {
