Hi, everyone.
This series was inspired by the need to modernize and display more
informative messages about unhandled signals.
The "unhandled signal NN" is not very informative. We thought it would
be helpful adding a human-readable message describing what the signal
number means, printing the VMA address, and dumping the instructions.
Before this series:
pandafault32[4724]: unhandled signal 11 at 100005e4 nip 10000444 lr 0fe31ef4 code 2
pandafault64[4725]: unhandled signal 11 at 0000000010000718 nip 0000000010000574 lr 00007fff7faa7a6c code 2
After this series:
pandafault32[4753]: segfault (11) at 100005e4 nip 10000444 lr fe31ef4 code 2 in pandafault32[10000000+10000]
pandafault32[4753]: code: 4bffff3c 60000000 60420000 4bffff30 9421ffd0 93e1002c 7c3f0b78 3d201000
pandafault32[4753]: code: 392905e4 913f0008 813f0008 39400048 <99490000> 39200000 7d234b78 397f0030
pandafault64[4754]: segfault (11) at 10000718 nip 10000574 lr 7fffb0007a6c code 2 in pandafault64[10000000+10000]
pandafault64[4754]: code: e8010010 7c0803a6 4bfffef4 4bfffef0 fbe1fff8 f821ffb1 7c3f0b78 3d22fffe
pandafault64[4754]: code: 39298818 f93f0030 e93f0030 39400048 <99490000> 39200000 7d234b78 383f0050
Link to v3:
https://lore.kernel.org/lkml/20180731145020.14009-1-muriloo@linux.ibm.com/
v3..v4:
- Added new show_user_instructions() based on the existing
show_instructions()
- Updated commit messages
- Replaced signals names table with a tiny function that returns a
literal string for each signal number
Cheers!
Murilo Opsfelder Araujo (6):
powerpc/traps: Print unhandled signals in a separate function
powerpc/traps: Use an explicit ratelimit state for show_signal_msg()
powerpc/traps: Use %lx format in show_signal_msg()
powerpc/traps: Print VMA for unhandled signals
powerpc: Add show_user_instructions()
powerpc/traps: Show instructions on exceptions
arch/powerpc/include/asm/stacktrace.h | 13 +++++++
arch/powerpc/kernel/process.c | 40 +++++++++++++++++++++
arch/powerpc/kernel/traps.c | 52 +++++++++++++++++++++------
3 files changed, 95 insertions(+), 10 deletions(-)
create mode 100644 arch/powerpc/include/asm/stacktrace.h
--
2.17.1
Replace printk_ratelimited() by printk() and a default rate limit
burst to limit displaying unhandled signals messages.
This will allow us to call print_vma_addr() in a future patch, which
does not work with printk_ratelimited().
Signed-off-by: Murilo Opsfelder Araujo <redacted>
---
arch/powerpc/kernel/traps.c | 21 ++++++++++++++++-----
1 file changed, 16 insertions(+), 5 deletions(-)
Use %lx format to print registers. This avoids having two different
formats and avoids checking for MSR_64BIT, improving readability of the
function.
Even though we could have used %px, which is functionally equivalent to %lx
as per Documentation/core-api/printk-formats.rst, it is not semantically
correct because the data printed are not pointers. And using %px requires
casting data to (void *).
Besides that, %lx matches the format used in show_regs().
Before this patch:
pandafault[4808]: unhandled signal 11 at 0000000010000718 nip 0000000010000574 lr 00007fff935e7a6c code 2
After this patch:
pandafault[4732]: unhandled signal 11 at 10000718 nip 10000574 lr 7fff86697a6c code 2
Signed-off-by: Murilo Opsfelder Araujo <redacted>
---
arch/powerpc/kernel/traps.c | 11 +++--------
1 file changed, 3 insertions(+), 8 deletions(-)
show_user_instructions() is a slightly modified version of
show_instructions() that allows userspace instruction dump.
This will be useful within show_signal_msg() to dump userspace
instructions of the faulty location.
Here is a sample of what show_user_instructions() outputs:
pandafault[10850]: code: 4bfffeec 4bfffee8 3c401002 38427f00 fbe1fff8 f821ffc1 7c3f0b78 3d22fffe
pandafault[10850]: code: 392988d0 f93f0020 e93f0020 39400048 <99490000> 39200000 7d234b78 383f0040
The current->comm and current->pid printed can serve as a glue that
links the instructions dump to its originator, allowing messages to be
interleaved in the logs.
Signed-off-by: Murilo Opsfelder Araujo <redacted>
---
arch/powerpc/include/asm/stacktrace.h | 13 +++++++++
arch/powerpc/kernel/process.c | 40 +++++++++++++++++++++++++++
2 files changed, 53 insertions(+)
create mode 100644 arch/powerpc/include/asm/stacktrace.h
This adds VMA address in the message printed for unhandled signals,
similarly to what other architectures, like x86, print.
Before this patch, a page fault looked like:
pandafault[61470]: unhandled signal 11 at 100007d0 nip 1000061c lr 7fff8d185100 code 2
After this patch, a page fault looks like:
pandafault[6303]: segfault 11 at 100007d0 nip 1000061c lr 7fff93c55100 code 2 in pandafault[10000000+10000]
Signed-off-by: Murilo Opsfelder Araujo <redacted>
---
arch/powerpc/kernel/traps.c | 21 +++++++++++++++++++--
1 file changed, 19 insertions(+), 2 deletions(-)
Le 01/08/2018 à 23:33, Murilo Opsfelder Araujo a écrit :
quoted hunk
show_user_instructions() is a slightly modified version of
show_instructions() that allows userspace instruction dump.
This will be useful within show_signal_msg() to dump userspace
instructions of the faulty location.
Here is a sample of what show_user_instructions() outputs:
pandafault[10850]: code: 4bfffeec 4bfffee8 3c401002 38427f00 fbe1fff8 f821ffc1 7c3f0b78 3d22fffe
pandafault[10850]: code: 392988d0 f93f0020 e93f0020 39400048 <99490000> 39200000 7d234b78 383f0040
The current->comm and current->pid printed can serve as a glue that
links the instructions dump to its originator, allowing messages to be
interleaved in the logs.
Signed-off-by: Murilo Opsfelder Araujo <redacted>
---
arch/powerpc/include/asm/stacktrace.h | 13 +++++++++
arch/powerpc/kernel/process.c | 40 +++++++++++++++++++++++++++
2 files changed, 53 insertions(+)
create mode 100644 arch/powerpc/include/asm/stacktrace.h
Why not use pr_info() and remove KERN_INFO from *prefix ?
+
+ for (i = 0; i < instructions_to_print; i++) {
+ int instr;
+
+ if (!(i % 8) && (i > 0)) {
+ pr_cont("\n");
+ printk(prefix, current->comm, current->pid);
+ }
+
+#if !defined(CONFIG_BOOKE)
+ /* If executing with the IMMU off, adjust pc rather
+ * than print XXXXXXXX.
+ */
+ if (!(regs->msr & MSR_IR))
+ pc = (unsigned long)phys_to_virt(pc);
Shouldn't this be done outside of the loop, only once ?
Christophe
Hi, Christophe.
On Thu, Aug 02, 2018 at 07:26:20AM +0200, Christophe LEROY wrote:
Le 01/08/2018 à 23:33, Murilo Opsfelder Araujo a écrit :
quoted
show_user_instructions() is a slightly modified version of
show_instructions() that allows userspace instruction dump.
This will be useful within show_signal_msg() to dump userspace
instructions of the faulty location.
Here is a sample of what show_user_instructions() outputs:
pandafault[10850]: code: 4bfffeec 4bfffee8 3c401002 38427f00 fbe1fff8 f821ffc1 7c3f0b78 3d22fffe
pandafault[10850]: code: 392988d0 f93f0020 e93f0020 39400048 <99490000> 39200000 7d234b78 383f0040
The current->comm and current->pid printed can serve as a glue that
links the instructions dump to its originator, allowing messages to be
interleaved in the logs.
Signed-off-by: Murilo Opsfelder Araujo <redacted>
---
arch/powerpc/include/asm/stacktrace.h | 13 +++++++++
arch/powerpc/kernel/process.c | 40 +++++++++++++++++++++++++++
2 files changed, 53 insertions(+)
create mode 100644 arch/powerpc/include/asm/stacktrace.h
Why not use pr_info() and remove KERN_INFO from *prefix ?
Because it doesn't compile:
arch/powerpc/kernel/process.c:1317:10: error: expected ‘)’ before ‘prefix’
pr_info(prefix, current->comm, current->pid);
^
./include/linux/printk.h:288:21: note: in definition of macro ‘pr_fmt’
#define pr_fmt(fmt) fmt
^
`pr_info(prefix, ...)` expands to `printk("\001" "6" prefix, ...)`,
which is an invalid string concatenation.
`pr_info("%s", ...)` expands to `printk("\001" "6" "%s", ...)`, which is
valid.
quoted
+
+ for (i = 0; i < instructions_to_print; i++) {
+ int instr;
+
+ if (!(i % 8) && (i > 0)) {
+ pr_cont("\n");
+ printk(prefix, current->comm, current->pid);
+ }
+
+#if !defined(CONFIG_BOOKE)
+ /* If executing with the IMMU off, adjust pc rather
+ * than print XXXXXXXX.
+ */
+ if (!(regs->msr & MSR_IR))
+ pc = (unsigned long)phys_to_virt(pc);
Shouldn't this be done outside of the loop, only once ?
I don't think so.
pc gets incremented at the bottom of the loop:
pc += sizeof(int);
Adjusting pc is necessary at each iteration. Leaving this block inside
the loop seems correct.
Cheers
Murilo
Why not use pr_info() and remove KERN_INFO from *prefix ?
Because it doesn't compile:
arch/powerpc/kernel/process.c:1317:10: error: expected ‘)’ before ‘prefix’
pr_info(prefix, current->comm, current->pid);
^
./include/linux/printk.h:288:21: note: in definition of macro ‘pr_fmt’
#define pr_fmt(fmt) fmt
^
What being suggested is using:
pr_info("%s[%d]: code: ", current->comm, current->pid);
Hi Murilo,
Le 03/08/2018 à 02:42, Murilo Opsfelder Araujo a écrit :
Hi, Christophe.
On Thu, Aug 02, 2018 at 07:26:20AM +0200, Christophe LEROY wrote:
quoted
Le 01/08/2018 à 23:33, Murilo Opsfelder Araujo a écrit :
quoted
show_user_instructions() is a slightly modified version of
show_instructions() that allows userspace instruction dump.
This will be useful within show_signal_msg() to dump userspace
instructions of the faulty location.
Here is a sample of what show_user_instructions() outputs:
pandafault[10850]: code: 4bfffeec 4bfffee8 3c401002 38427f00 fbe1fff8 f821ffc1 7c3f0b78 3d22fffe
pandafault[10850]: code: 392988d0 f93f0020 e93f0020 39400048 <99490000> 39200000 7d234b78 383f0040
The current->comm and current->pid printed can serve as a glue that
links the instructions dump to its originator, allowing messages to be
interleaved in the logs.
Signed-off-by: Murilo Opsfelder Araujo <redacted>
---
arch/powerpc/include/asm/stacktrace.h | 13 +++++++++
arch/powerpc/kernel/process.c | 40 +++++++++++++++++++++++++++
2 files changed, 53 insertions(+)
create mode 100644 arch/powerpc/include/asm/stacktrace.h
Why not use pr_info() and remove KERN_INFO from *prefix ?
Because it doesn't compile:
arch/powerpc/kernel/process.c:1317:10: error: expected ‘)’ before ‘prefix’
pr_info(prefix, current->comm, current->pid);
^
./include/linux/printk.h:288:21: note: in definition of macro ‘pr_fmt’
#define pr_fmt(fmt) fmt
^
`pr_info(prefix, ...)` expands to `printk("\001" "6" prefix, ...)`,
which is an invalid string concatenation.
`pr_info("%s", ...)` expands to `printk("\001" "6" "%s", ...)`, which is
valid.
Then what about using directly:
pr_info("%s[%d]: code: ", ...);
quoted
quoted
+
+ for (i = 0; i < instructions_to_print; i++) {
+ int instr;
+
+ if (!(i % 8) && (i > 0)) {
+ pr_cont("\n");
+ printk(prefix, current->comm, current->pid);
+ }
+
+#if !defined(CONFIG_BOOKE)
+ /* If executing with the IMMU off, adjust pc rather
+ * than print XXXXXXXX.
+ */
+ if (!(regs->msr & MSR_IR))
+ pc = (unsigned long)phys_to_virt(pc);
Shouldn't this be done outside of the loop, only once ?
I don't think so.
pc gets incremented at the bottom of the loop:
pc += sizeof(int);
Adjusting pc is necessary at each iteration. Leaving this block inside
the loop seems correct.
This looks pretty strange.
The first time, pc is a physical address, that you change to a virtual
address. Then when you increment it it is still a virtual address.
So when you call phys_to_virt(pc) for the second time, pc is already a
virt address, so what happens indeed ?
Christophe
From: Michael Ellerman <mpe@ellerman.id.au> Date: 2018-08-03 08:45:03
Christophe LEROY [off-list ref] writes:
Le 03/08/2018 =C3=A0 02:42, Murilo Opsfelder Araujo a =C3=A9crit=C2=A0:
quoted
Hi, Christophe.
On Thu, Aug 02, 2018 at 07:26:20AM +0200, Christophe LEROY wrote:
quoted
Le 01/08/2018 =C3=A0 23:33, Murilo Opsfelder Araujo a =C3=A9crit=C2=A0:
quoted
show_user_instructions() is a slightly modified version of
show_instructions() that allows userspace instruction dump.
This will be useful within show_signal_msg() to dump userspace
instructions of the faulty location.
Here is a sample of what show_user_instructions() outputs:
pandafault[10850]: code: 4bfffeec 4bfffee8 3c401002 38427f00 fbe1f=
The current->comm and current->pid printed can serve as a glue that
links the instructions dump to its originator, allowing messages to be
interleaved in the logs.
Why not use pr_info() and remove KERN_INFO from *prefix ?
=20
Because it doesn't compile:
=20
arch/powerpc/kernel/process.c:1317:10: error: expected =E2=80=98)=E2=
=80=99 before =E2=80=98prefix=E2=80=99
quoted
pr_info(prefix, current->comm, current->pid);
^
./include/linux/printk.h:288:21: note: in definition of macro =E2=80=
=98pr_fmt=E2=80=99
quoted
#define pr_fmt(fmt) fmt
^
=20
`pr_info(prefix, ...)` expands to `printk("\001" "6" prefix, ...)`,
which is an invalid string concatenation.
=20
`pr_info("%s", ...)` expands to `printk("\001" "6" "%s", ...)`, which is
valid.
Then what about using directly:
pr_info("%s[%d]: code: ", ...);
Yeah that's better, I'll fix it up when applying.
quoted
quoted
quoted
+#if !defined(CONFIG_BOOKE)
+ /* If executing with the IMMU off, adjust pc rather
+ * than print XXXXXXXX.
+ */
+ if (!(regs->msr & MSR_IR))
+ pc =3D (unsigned long)phys_to_virt(pc);
Shouldn't this be done outside of the loop, only once ?
=20
I don't think so.
=20
pc gets incremented at the bottom of the loop:
=20
pc +=3D sizeof(int);
=20
Adjusting pc is necessary at each iteration. Leaving this block inside
the loop seems correct.
This looks pretty strange.
The first time, pc is a physical address, that you change to a virtual=20
address. Then when you increment it it is still a virtual address.
So when you call phys_to_virt(pc) for the second time, pc is already a=20
virt address, so what happens indeed ?
Yeah that's a bit fishy.
On 64-bit it works because phys_to_virt() =3D=3D __va() which is:
#define __va(x) ((void *)(unsigned long)((phys_addr_t)(x) | PAGE_OFFSET))
ie. it uses bitwise or, so __va(__va(x)) =3D=3D __va(x).
But it looks like on 32-bit it's going to do the wrong thing. Do we ever
actually hit that case though, I'm not sure?
However for this patch I'll just remove the whole thing, because we
don't expect to be dumping user instructions in realmode.
cheers
From: Michael Ellerman <hidden> Date: 2018-08-08 14:26:51
On Wed, 2018-08-01 at 21:33:15 UTC, Murilo Opsfelder Araujo wrote:
Isolate the logic of printing unhandled signals out of _exception_pkey().
No functional change, only code rearrangement.
Signed-off-by: Murilo Opsfelder Araujo <redacted>
Le 03/08/2018 à 13:31, Murilo Opsfelder Araujo a écrit :
Hi, everyone.
I'd like to thank you all that contributed to refining and making this
series better. I did appreciate.
Thank you!
You are welcome.
It seems that nested segfaults don't print very well. The code line is
split in two, le second half being alone on one line. Any way to avoid
that ?
[ 4.365317] init[1]: segfault (11) at 0 nip 0 lr 0 code 1
[ 4.370452] init[1]: code: XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX
[ 4.372042] init[74]: segfault (11) at 10a74 nip 1000c198 lr 100078c8
code 1 in sh[10000000+14000]
[ 4.386829] XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX
[ 4.391542] init[1]: code: XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX
XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX
[ 4.400863] init[74]: code: 90010024 bf61000c 91490a7c 3fa01002
3be00000 7d3e4b78 3bbd0c20 3b600000
[ 4.409867] init[74]: code: 3b9d0040 7c7fe02e 2f830000 419e0028
<89230000> 2f890000 41be001c 4b7f6e79
Christophe
Hi, Christophe.
On Fri, Aug 10, 2018 at 11:29:43AM +0200, Christophe LEROY wrote:
Le 03/08/2018 à 13:31, Murilo Opsfelder Araujo a écrit :
quoted
Hi, everyone.
I'd like to thank you all that contributed to refining and making this
series better. I did appreciate.
Thank you!
You are welcome.
It seems that nested segfaults don't print very well. The code line is split
in two, le second half being alone on one line. Any way to avoid that ?
What do you mean by "nested segfaults"? I'd guess it's related to nested
virtualization, e.g.: host (kvm hv) -> guest1 (kvm pr) -> guest2? So the
segfault would have been originated in guest2?
Can you provide us with more details about how to reproduce that?
Anyway, is "XXXXXXXX" so important that it needs to be printed at all? Can't we
just discard it and not print it?
Murilo