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.
We can add more informative messages, like informing what each code of a
SIGSEGV signal means. We are open to suggestions.
Before this series:
pandafault[5815]: unhandled signal 11 at 00000000100007d0 nip 000000001000061c lr 00003fff87ff5100 code 2
After this series:
pandafault[10850]: segfault (11) at 00000000100007d0 nip 000000001000061c lr 00007fff9f3e5100 code 2 in pandafault[10000000+10000]
pandafault[10850]: code: 4bfffeec 4bfffee8 3c401002 38427f00 fbe1fff8 f821ffc1 7c3f0b78 3d22fffe
pandafault[10850]: code: 392988d0 f93f0020 e93f0020 39400048 <99490000> 39200000 7d234b78 383f0040
Link to v1:
https://lore.kernel.org/lkml/20180724192720.32417-1-muriloo@linux.ibm.com/
v1..v2:
- Broke patch 7 down into patches 7-9
- Added proper copyright in arch/powerpc/include/asm/stacktrace.h
- show_instructions(): prefixed lines with current->comm and current->pid
Cheers!
Murilo Opsfelder Araujo (10):
powerpc/traps: Print unhandled signals in a separate function
powerpc/traps: Return early in show_signal_msg()
powerpc/reg: Add REG_FMT definition
powerpc/traps: Use REG_FMT in show_signal_msg()
powerpc/traps: Print VMA for unhandled signals
powerpc/traps: Print signal name for unhandled signals
powerpc: Do not call __kernel_text_address() in show_instructions()
powerpc: Add stacktrace.h header
powerpc/traps: Show instructions on exceptions
powerpc/traps: Add line prefix in show_instructions()
arch/powerpc/include/asm/reg.h | 6 +++
arch/powerpc/include/asm/stacktrace.h | 13 +++++
arch/powerpc/kernel/process.c | 35 ++++++-------
arch/powerpc/kernel/traps.c | 73 +++++++++++++++++++++++----
4 files changed, 100 insertions(+), 27 deletions(-)
create mode 100644 arch/powerpc/include/asm/stacktrace.h
--
2.17.1
Modify the logic of show_signal_msg() to return early, if possible.
Replace printk_ratelimited() by printk() and a default rate limit burst to
limit displaying unhandled signals messages.
Mainly reason of this change is to improve readability of the function.
The conditions to display the message were coupled together in one single
`if` statement.
Splitting out the rate limit check outside show_signal_msg() makes it
easier to the caller decide if it wants to respect a printk rate limit or
not.
Signed-off-by: Murilo Opsfelder Araujo <redacted>
---
arch/powerpc/kernel/traps.c | 21 +++++++++++++++------
1 file changed, 15 insertions(+), 6 deletions(-)
Make REG definition, in arch/powerpc/kernel/process.c, generic enough by
renaming it to REG_FMT and placing it in arch/powerpc/include/asm/reg.h to
be used elsewhere.
Replace occurrences of REG by REG_FMT in arch/powerpc/kernel/process.c.
Signed-off-by: Murilo Opsfelder Araujo <redacted>
---
arch/powerpc/include/asm/reg.h | 6 ++++++
arch/powerpc/kernel/process.c | 22 ++++++++++------------
2 files changed, 16 insertions(+), 12 deletions(-)
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 00000000100007d0 nip 000000001000061c lr 00007fff8d185100 code 2
After this patch, a page fault looks like:
pandafault[6303]: unhandled signal 11 at 00000000100007d0 nip 000000001000061c lr 00007fff93c55100 code 2 in pandafault[10000000+10000]
Signed-off-by: Murilo Opsfelder Araujo <redacted>
---
arch/powerpc/kernel/traps.c | 6 +++++-
1 file changed, 5 insertions(+), 1 deletion(-)
Simplify the message format by using REG_FMT as the register format. This
avoids having two different formats and avoids checking for MSR_64BIT.
Signed-off-by: Murilo Opsfelder Araujo <redacted>
---
arch/powerpc/kernel/traps.c | 12 ++++--------
1 file changed, 4 insertions(+), 8 deletions(-)
This adds a human-readable name in the unhandled signal message.
Before this patch, a page fault looked like:
pandafault[6303]: unhandled signal 11 at 00000000100007d0 nip 000000001000061c lr 00007fff93c55100 code 2 in pandafault[10000000+10000]
After this patch, a page fault looks like:
pandafault[6352]: segfault (11) at 000000013a2a09f8 nip 000000013a2a086c lr 00007fffb63e5100 code 2 in pandafault[13a2a0000+10000]
Signed-off-by: Murilo Opsfelder Araujo <redacted>
---
arch/powerpc/kernel/traps.c | 43 +++++++++++++++++++++++++++++++++----
1 file changed, 39 insertions(+), 4 deletions(-)
Move show_instructions() declaration to
arch/powerpc/include/asm/stacktrace.h and include asm/stracktrace.h in
arch/powerpc/kernel/process.c, which contains the implementation.
This allows show_instructions() to be called on, for example,
show_signal_msg().
Signed-off-by: Murilo Opsfelder Araujo <redacted>
---
arch/powerpc/include/asm/stacktrace.h | 13 +++++++++++++
arch/powerpc/kernel/process.c | 3 ++-
2 files changed, 15 insertions(+), 1 deletion(-)
create mode 100644 arch/powerpc/include/asm/stacktrace.h
Remove "Instruction dump:" line by adding a prefix to display current->comm
and current->pid, along with the instructions dump.
The prefix can serve as a glue that links the instructions dump to its
originator, allowing messages to be interleaved in the logs.
Before this patch, a page fault looked like:
pandafault[10524]: segfault (11) at 00000000100007d0 nip 000000001000061c lr 00007fffbd295100 code 2 in pandafault[10000000+10000]
Instruction dump:
4bfffeec 4bfffee8 3c401002 38427f00 fbe1fff8 f821ffc1 7c3f0b78 3d22fffe
392988d0 f93f0020 e93f0020 39400048 <99490000> 39200000 7d234b78 383f0040
After this patch, it looks like:
pandafault[10850]: segfault (11) at 00000000100007d0 nip 000000001000061c lr 00007fff9f3e5100 code 2 in pandafault[10000000+10000]
pandafault[10850]: code: 4bfffeec 4bfffee8 3c401002 38427f00 fbe1fff8 f821ffc1 7c3f0b78 3d22fffe
pandafault[10850]: code: 392988d0 f93f0020 e93f0020 39400048 <99490000> 39200000 7d234b78 383f0040
Signed-off-by: Murilo Opsfelder Araujo <redacted>
---
arch/powerpc/kernel/process.c | 7 +++++--
1 file changed, 5 insertions(+), 2 deletions(-)
@@ -1265,16 +1265,19 @@ static int instructions_to_print = 16;voidshow_instructions(structpt_regs*regs){inti;+constchar*prefix=KERN_INFO"%s[%d]: code: ";unsignedlongpc=regs->nip-(instructions_to_print*3/4*sizeof(int));-printk("Instruction dump:");+printk(prefix,current->comm,current->pid);for(i=0;i<instructions_to_print;i++){intinstr;-if(!(i%8))+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
@@ -311,17 +311,13 @@ static bool show_unhandled_signals_ratelimited(void) static void show_signal_msg(int signr, struct pt_regs *regs, int code, unsigned long addr) {- const char fmt32[] = KERN_INFO "%s[%d]: unhandled signal %d " \- "at %08lx nip %08lx lr %08lx code %x\n";- const char fmt64[] = KERN_INFO "%s[%d]: unhandled signal %d " \- "at %016lx nip %016lx lr %016lx code %x\n";- if (!unhandled_signal(current, signr)) return;- printk(regs->msr & MSR_64BIT ? fmt64 : fmt32,- current->comm, current->pid, signr,- addr, regs->nip, regs->link, code);+ pr_info("%s[%d]: unhandled signal %d at "REG_FMT \
I think it better to use a space after the close "
and also the line continuation is unnecessary.
quoted
+ " nip "REG_FMT" lr "REG_FMT" code %x\n",
And spaces before the open quotes too.
I'd also prefer the format on a single line:
pr_info("%s[%d]: unhandled signal %d at " REG_FMT " nip " REG_FMT " lr " REG_FMT " code %x\n",
Seeing as these are all unsigned long, a better way to do
this is to use %p and cast to pointer.
This might be better anyway as this output exposes pointer
addresses and instead would now use pointer hashed output.
pr_info("%s[%d]: unhandled signal %d at %p nip %p lr %p code %x\n",
current->comm, current->pid, signr,
(void *)addr, (void *)regs->nip, (void *)regs->link, code);
Use %px if you _really_ need to emit unhashed addresses.
see: Documentation/core-api/printk-formats.rst
Hi, Christophe.
On Fri, Jul 27, 2018 at 06:40:23PM +0200, LEROY Christophe wrote:
Murilo Opsfelder Araujo [off-list ref] a écrit :
quoted
Simplify the message format by using REG_FMT as the register format. This
avoids having two different formats and avoids checking for MSR_64BIT.
Are you sure it is what we want ?
Yes.
Won't it change the behaviour for a 32 bits app running on a 64bits kernel ?
In fact, this changes how many zeroes are prefixed when displaying the registers
(%016lx vs. %08lx format). For example, 32-bits userspace, 64-bits kernel:
before this series:
[66475.002900] segv[4599]: unhandled signal 11 at 00000000 nip 10000420 lr 0fe61854 code 1
after this series:
[ 73.414535] segv[3759]: segfault (11) at 0000000000000000 nip 0000000010000420 lr 000000000fe61854 code 1 in segv[10000000+10000]
[ 73.414641] segv[3759]: code: 4e800421 80010014 38210010 7c0803a6 4bffff30 9421ffd0 93e1002c 7c3f0b78
[ 73.414665] segv[3759]: code: 39200000 913f001c 813f001c 39400001 <91490000> 39200000 7d234b78 397f0030
Have you spotted any other behaviour change?
Cheers
Murilo
Murilo Opsfelder Araujo [off-list ref] a =C3=A9crit=C2=A0:
Hi, Christophe.
On Fri, Jul 27, 2018 at 06:40:23PM +0200, LEROY Christophe wrote:
quoted
Murilo Opsfelder Araujo [off-list ref] a =C3=A9crit=C2=A0:
quoted
Simplify the message format by using REG_FMT as the register format. =
This
quoted
quoted
avoids having two different formats and avoids checking for MSR_64BIT.
Are you sure it is what we want ?
Yes.
quoted
Won't it change the behaviour for a 32 bits app running on a 64bits kern=
el ?
In fact, this changes how many zeroes are prefixed when displaying=20=20
=20the registers
(%016lx vs. %08lx format). For example, 32-bits userspace, 64-bits kerne=
l:
Indeed that's what I suspected. What is the real benefit of this=20=20
change=20? Why not keep the current format for 32bits userspace ? All=20=20
those=20leading zeroes are pointless to me.
before this series:
[66475.002900] segv[4599]: unhandled signal 11 at 00000000 nip=20=20
=2010000420 lr 0fe61854 code 1
after this series:
[ 73.414535] segv[3759]: segfault (11) at 0000000000000000 nip=20=20
=200000000010000420 lr 000000000fe61854 code 1 in segv[10000000+10000]
[ 73.414641] segv[3759]: code: 4e800421 80010014 38210010=20=20
=207c0803a6 4bffff30 9421ffd0 93e1002c 7c3f0b78
[ 73.414665] segv[3759]: code: 39200000 913f001c 813f001c=20=20
=2039400001 <91490000> 39200000 7d234b78 397f0030
Have you spotted any other behaviour change?
Hi, Christophe.
On Mon, Jul 30, 2018 at 06:30:47PM +0200, LEROY Christophe wrote:
Murilo Opsfelder Araujo [off-list ref] a écrit :
quoted
Hi, Christophe.
On Fri, Jul 27, 2018 at 06:40:23PM +0200, LEROY Christophe wrote:
quoted
Murilo Opsfelder Araujo [off-list ref] a écrit :
quoted
Simplify the message format by using REG_FMT as the register format. This
avoids having two different formats and avoids checking for MSR_64BIT.
Are you sure it is what we want ?
Yes.
quoted
Won't it change the behaviour for a 32 bits app running on a 64bits kernel ?
In fact, this changes how many zeroes are prefixed when displaying the
registers
(%016lx vs. %08lx format). For example, 32-bits userspace, 64-bits kernel:
Indeed that's what I suspected. What is the real benefit of this change ?
Why not keep the current format for 32bits userspace ? All those leading
zeroes are pointless to me.
One of the benefits is simplifying the code by removing some checks. Another is
deduplicating almost identical format strings in favor of a unified one.
After reading Joe's comment [1], %px seems to be the format we're looking for.
An extract from Documentation/core-api/printk-formats.rst:
"%px is functionally equivalent to %lx (or %lu). %px is preferred because it
is more uniquely grep'able."
So I guess we don't need to worry about the format (%016lx vs. %08lx), let's
just use %px, as per the guideline.
[1] https://lore.kernel.org/lkml/26f07092cdde378ebb42c1034badde1b56521c36.camel@perches.com/
Cheers
Murilo
From: Michael Ellerman <mpe@ellerman.id.au> Date: 2018-07-31 09:32:40
Murilo Opsfelder Araujo [off-list ref] writes:
On Mon, Jul 30, 2018 at 06:30:47PM +0200, LEROY Christophe wrote:
quoted
Murilo Opsfelder Araujo [off-list ref] a =C3=A9crit=C2=A0:
quoted
On Fri, Jul 27, 2018 at 06:40:23PM +0200, LEROY Christophe wrote:
quoted
Murilo Opsfelder Araujo [off-list ref] a =C3=A9crit=C2=A0:
quoted
Simplify the message format by using REG_FMT as the register forma=
t. This
quoted
quoted
quoted
quoted
avoids having two different formats and avoids checking for MSR_64=
BIT.
quoted
quoted
quoted
Are you sure it is what we want ?
Yes.
quoted
Won't it change the behaviour for a 32 bits app running on a 64bits =
kernel ?
quoted
quoted
In fact, this changes how many zeroes are prefixed when displaying the
registers
(%016lx vs. %08lx format). For example, 32-bits userspace, 64-bits ke=
rnel:
quoted
Indeed that's what I suspected. What is the real benefit of this change ?
Why not keep the current format for 32bits userspace ? All those leading
zeroes are pointless to me.
One of the benefits is simplifying the code by removing some checks. Ano=
ther is
deduplicating almost identical format strings in favor of a unified one.
After reading Joe's comment [1], %px seems to be the format we're looking=
for.
An extract from Documentation/core-api/printk-formats.rst:
"%px is functionally equivalent to %lx (or %lu). %px is preferred becau=
se it
is more uniquely grep'able."
So I guess we don't need to worry about the format (%016lx vs. %08lx), le=
t's
just use %px, as per the guideline.
I don't think I like %px.
It makes the format string cleaner, but it means we have to cast
everything to void * which is ugly as heck.
I actually don't think the leading zeroes are helpful at all in the
signal message, ie. we should just use %lx there.
They are useful in show_regs() because we want everything to line up.
So I think I'll drop patch 3 and use 0x%lx in show_signal_msg(), meaning
we end up with, eg:
[ 73.414535] segv[3759]: segfault (11) at 0x0 nip 0x10000420 lr 0xfe618=
54 code 0x1 in segv[10000000+10000]
[ 73.414641] segv[3759]: code: 4e800421 80010014 38210010 7c0803a6 4bff=
ff30 9421ffd0 93e1002c 7c3f0b78
[ 73.414665] segv[3759]: code: 39200000 913f001c 813f001c 39400001 <914=
90000> 39200000 7d234b78 397f0030
I'll do that unless anyone screams loudly, because it would be nice to
get this into 4.19.
cheers
-----Original Message-----
From: Michael Ellerman <mpe@ellerman.id.au>
Sent: Tuesday, 31 July 2018 7:32 PM
To: Murilo Opsfelder Araujo <redacted>; LEROY Christophe
[off-list ref]
Cc: linux-kernel@vger.kernel.org; Alastair D'Silva =
[off-list ref];
Andrew Donnellan [off-list ref]; Balbir Singh
[off-list ref]; Benjamin Herrenschmidt
[off-list ref]; Cyril Bur [off-list ref]; Eric W .
Biederman [off-list ref]; Joe Perches [off-list ref];
Michael Neuling [off-list ref]; Nicholas Piggin
[off-list ref]; Paul Mackerras [off-list ref]; Simon Guo
[off-list ref]; Sukadev Bhattiprolu
[off-list ref]; Tobin C . Harding [off-list ref]; =
linuxppc-
dev@lists.ozlabs.org
Subject: Re: [PATCH v2 04/10] powerpc/traps: Use REG_FMT in
show_signal_msg()
=20
Murilo Opsfelder Araujo [off-list ref] writes:
quoted
On Mon, Jul 30, 2018 at 06:30:47PM +0200, LEROY Christophe wrote:
quoted
Murilo Opsfelder Araujo [off-list ref] a =C3=A9crit :
quoted
On Fri, Jul 27, 2018 at 06:40:23PM +0200, LEROY Christophe wrote:
quoted
Murilo Opsfelder Araujo [off-list ref] a =C3=A9crit :
quoted
Simplify the message format by using REG_FMT as the register
format. This avoids having two different formats and avoids
checking for MSR_64BIT.
quoted
quoted
quoted
quoted
Are you sure it is what we want ?
Yes.
quoted
Won't it change the behaviour for a 32 bits app running on a =
64bits
kernel ?
quoted
quoted
quoted
In fact, this changes how many zeroes are prefixed when =
displaying
quoted
quoted
quoted
the registers (%016lx vs. %08lx format). For example, 32-bits
userspace, 64-bits kernel:
Indeed that's what I suspected. What is the real benefit of this =
change ?
quoted
quoted
Why not keep the current format for 32bits userspace ? All those
leading zeroes are pointless to me.
One of the benefits is simplifying the code by removing some checks.
Another is deduplicating almost identical format strings in favor of =
a unified
one.
quoted
After reading Joe's comment [1], %px seems to be the format we're
looking for.
quoted
An extract from Documentation/core-api/printk-formats.rst:
"%px is functionally equivalent to %lx (or %lu). %px is preferred =
because it
quoted
is more uniquely grep'able."
So I guess we don't need to worry about the format (%016lx vs. =
%08lx),
quoted
let's just use %px, as per the guideline.
=20
I don't think I like %px.
Me neither, semantically, it's for pointers, and the data being =
displayed is not a pointer.
It makes the format string cleaner, but it means we have to cast =
everything
to void * which is ugly as heck.
=20
I actually don't think the leading zeroes are helpful at all in the =
signal
message, ie. we should just use %lx there.
=20
They are useful in show_regs() because we want everything to line up.
=20
So I think I'll drop patch 3 and use 0x%lx in show_signal_msg(), =
meaning we
end up with, eg:
=20
[ 73.414535] segv[3759]: segfault (11) at 0x0 nip 0x10000420 lr =
Or better yet, "%#lx" - the hash adds the appropriate prefix in the =
right case for the format.
--=20
Alastair D'Silva mob: 0423 762 819
skype: alastair_dsilva msn: alastair@d-silva.org
blog: http://alastair.d-silva.org Twitter: @EvilDeece