From: Tetsuo Handa <[email protected]>
Since syzbot is confused by concurrent printk() messages [1],
this patch changes show_opcodes() to use snprintf().
When we start adding prefix to each line of printk() output,
we will be able to handle concurrent printk() messages.
[1] https://syzkaller.appspot.com/text?tag=CrashReport&x=139d342c400000
Signed-off-by: Tetsuo Handa <[email protected]>
Cc: Borislav Petkov <[email protected]>
Cc: Thomas Gleixner <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Cc: Josh Poimboeuf <[email protected]>
Cc: Linus Torvalds <[email protected]>
Cc: Andy Lutomirski <[email protected]>
---
arch/x86/kernel/dumpstack.c | 14 ++++++++------
1 file changed, 8 insertions(+), 6 deletions(-)
diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
index 666a284..bb47426 100644
--- a/arch/x86/kernel/dumpstack.c
+++ b/arch/x86/kernel/dumpstack.c
@@ -97,22 +97,24 @@ void show_opcodes(u8 *rip, const char *loglvl)
u8 opcodes[OPCODE_BUFSIZE];
u8 *ip;
int i;
-
- printk("%sCode: ", loglvl);
+ int pos = 0;
+ char buf[(3 * OPCODE_BUFSIZE + 2) + 1];
ip = (u8 *)rip - code_prologue;
if (probe_kernel_read(opcodes, ip, OPCODE_BUFSIZE)) {
- pr_cont("Bad RIP value.\n");
+ printk("%sCode: Bad RIP value.\n", loglvl);
return;
}
for (i = 0; i < OPCODE_BUFSIZE; i++, ip++) {
if (ip == rip)
- pr_cont("<%02x> ", opcodes[i]);
+ pos += snprintf(buf + pos, sizeof(buf) - pos,
+ "<%02x> ", opcodes[i]);
else
- pr_cont("%02x ", opcodes[i]);
+ pos += snprintf(buf + pos, sizeof(buf) - pos,
+ "%02x ", opcodes[i]);
}
- pr_cont("\n");
+ printk("%sCode: %s\n", loglvl, buf);
}
void show_ip(struct pt_regs *regs, const char *loglvl)
--
2.7.4
* Tetsuo Handa <[email protected]> wrote:
> From: Tetsuo Handa <[email protected]>
>
> Since syzbot is confused by concurrent printk() messages [1],
> this patch changes show_opcodes() to use snprintf().
>
> When we start adding prefix to each line of printk() output,
> we will be able to handle concurrent printk() messages.
>
> [1] https://syzkaller.appspot.com/text?tag=CrashReport&x=139d342c400000
>
> Signed-off-by: Tetsuo Handa <[email protected]>
> Cc: Borislav Petkov <[email protected]>
> Cc: Thomas Gleixner <[email protected]>
> Cc: Peter Zijlstra <[email protected]>
> Cc: Josh Poimboeuf <[email protected]>
> Cc: Linus Torvalds <[email protected]>
> Cc: Andy Lutomirski <[email protected]>
> ---
> arch/x86/kernel/dumpstack.c | 14 ++++++++------
> 1 file changed, 8 insertions(+), 6 deletions(-)
>
> diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
> index 666a284..bb47426 100644
> --- a/arch/x86/kernel/dumpstack.c
> +++ b/arch/x86/kernel/dumpstack.c
> @@ -97,22 +97,24 @@ void show_opcodes(u8 *rip, const char *loglvl)
> u8 opcodes[OPCODE_BUFSIZE];
> u8 *ip;
> int i;
> -
> - printk("%sCode: ", loglvl);
> + int pos = 0;
> + char buf[(3 * OPCODE_BUFSIZE + 2) + 1];
>
> ip = (u8 *)rip - code_prologue;
> if (probe_kernel_read(opcodes, ip, OPCODE_BUFSIZE)) {
> - pr_cont("Bad RIP value.\n");
> + printk("%sCode: Bad RIP value.\n", loglvl);
> return;
> }
>
> for (i = 0; i < OPCODE_BUFSIZE; i++, ip++) {
> if (ip == rip)
> - pr_cont("<%02x> ", opcodes[i]);
> + pos += snprintf(buf + pos, sizeof(buf) - pos,
> + "<%02x> ", opcodes[i]);
> else
> - pr_cont("%02x ", opcodes[i]);
> + pos += snprintf(buf + pos, sizeof(buf) - pos,
> + "%02x ", opcodes[i]);
> }
> - pr_cont("\n");
> + printk("%sCode: %s\n", loglvl, buf);
Does this change the output?
- If yes, could you show the before/after output in the changelog,
- If not (i.e. if only the number of printk calls is changed, the output is the
same), could you say so in the changelog?
Also, 3*OPCODE_BUFSIZE+2+1 is 195 bytes - isn't that a bit too much on-stack
footprint?
Thanks,
Ingo
On 2018/07/07 20:12, Ingo Molnar wrote:
>
> * Tetsuo Handa <[email protected]> wrote:
>
>> From: Tetsuo Handa <[email protected]>
>>
>> Since syzbot is confused by concurrent printk() messages [1],
>> this patch changes show_opcodes() to use snprintf().
>>
>> When we start adding prefix to each line of printk() output,
>> we will be able to handle concurrent printk() messages.
>>
>> [1] https://syzkaller.appspot.com/text?tag=CrashReport&x=139d342c400000
>
> Does this change the output?
>
> - If yes, could you show the before/after output in the changelog,
>
> - If not (i.e. if only the number of printk calls is changed, the output is the
> same), could you say so in the changelog?
This patch will not change the output unless multiple threads concurrently
call printk(). The purpose of this patch is to help parsing kernel messages
when multiple threads are concurrently calling printk() for multiple times
(e.g. backtrace) by reducing pr_cont()/KERN_CONT usage.
>
> Also, 3*OPCODE_BUFSIZE+2+1 is 195 bytes - isn't that a bit too much on-stack
> footprint?
Then, we can reduce it by OPCODE_BUFSIZE bytes by unionizing opcodes[] and buf[].
From 61752cef56fad2a910f6bfd277e1b9b028aeab43 Mon Sep 17 00:00:00 2001
From: Tetsuo Handa <[email protected]>
Date: Sat, 7 Jul 2018 22:45:30 +0900
Subject: [PATCH v2] x86: Avoid pr_cont() in show_opcodes()
Since syzbot is confused by concurrent printk() messages [1], this patch
changes show_opcodes() to use snprintf(). By this change, the Code: line
will always be printed as one line even if multiple threads concurrently
called printk().
To save on-stack footprint, this patch shares opcodes[] and buf[] because
we sequentially reads from opcodes[] and sequentially writes to buf[].
When we start adding prefix to each line of printk() output,
we will be able to handle concurrent printk() messages.
[1] https://syzkaller.appspot.com/text?tag=CrashReport&x=139d342c400000
Signed-off-by: Tetsuo Handa <[email protected]>
Cc: Borislav Petkov <[email protected]>
Cc: Thomas Gleixner <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Cc: Josh Poimboeuf <[email protected]>
Cc: Linus Torvalds <[email protected]>
Cc: Andy Lutomirski <[email protected]>
---
arch/x86/kernel/dumpstack.c | 16 +++++++++-------
1 file changed, 9 insertions(+), 7 deletions(-)
diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
index 666a284..6408123 100644
--- a/arch/x86/kernel/dumpstack.c
+++ b/arch/x86/kernel/dumpstack.c
@@ -94,25 +94,27 @@ static void printk_stack_address(unsigned long address, int reliable,
void show_opcodes(u8 *rip, const char *loglvl)
{
unsigned int code_prologue = OPCODE_BUFSIZE * 2 / 3;
- u8 opcodes[OPCODE_BUFSIZE];
u8 *ip;
int i;
-
- printk("%sCode: ", loglvl);
+ int pos = 0;
+ char buf[(3 * OPCODE_BUFSIZE + 2) + 1];
+ u8 *opcodes = (u8 *) buf + sizeof(buf) - OPCODE_BUFSIZE;
ip = (u8 *)rip - code_prologue;
if (probe_kernel_read(opcodes, ip, OPCODE_BUFSIZE)) {
- pr_cont("Bad RIP value.\n");
+ printk("%sCode: Bad RIP value.\n", loglvl);
return;
}
for (i = 0; i < OPCODE_BUFSIZE; i++, ip++) {
if (ip == rip)
- pr_cont("<%02x> ", opcodes[i]);
+ pos += snprintf(buf + pos, sizeof(buf) - pos,
+ "<%02x> ", opcodes[i]);
else
- pr_cont("%02x ", opcodes[i]);
+ pos += snprintf(buf + pos, sizeof(buf) - pos,
+ "%02x ", opcodes[i]);
}
- pr_cont("\n");
+ printk("%sCode: %s\n", loglvl, buf);
}
void show_ip(struct pt_regs *regs, const char *loglvl)
--
1.8.3.1
On Sat, Jul 07, 2018 at 10:54:28PM +0900, Tetsuo Handa wrote:
> >> Since syzbot is confused by concurrent printk() messages [1],
> >> this patch changes show_opcodes() to use snprintf().
But how big of a problem is that really? We can't very well remove all
pr_cont stuff from the kernel.
From: Peter Zijlstra
> Sent: 09 July 2018 09:50
> On Sat, Jul 07, 2018 at 10:54:28PM +0900, Tetsuo Handa wrote:
> > >> Since syzbot is confused by concurrent printk() messages [1],
> > >> this patch changes show_opcodes() to use snprintf().
snprintf() is probably the wrong function.
You want the variant that always returns the number of characters
added to the buffer - not the number that would have been added
were the buffer infinite length.
> But how big of a problem is that really? We can't very well remove all
> pr_cont stuff from the kernel.
On my ubuntu 17.10 system with a 4.13 kernel some messages printed with
pr_cont end up split when displayed by dmesg.
(These are from one of our drivers, I've not looked very hard at it though.)
So maybe removing pr_cont isn't a bad idea.
David
On Mon, Jul 09, 2018 at 10:49:53AM +0200, Peter Zijlstra wrote:
> On Sat, Jul 07, 2018 at 10:54:28PM +0900, Tetsuo Handa wrote:
> > >> Since syzbot is confused by concurrent printk() messages [1],
> > >> this patch changes show_opcodes() to use snprintf().
>
> But how big of a problem is that really? We can't very well remove all
> pr_cont stuff from the kernel.
I'd say we should try to make oopses as legible as possible.
Also KERN_CONT is inherently broken, and we should avoid using it in
general, IMO.
--
Josh
On 2018/07/10 4:11, Josh Poimboeuf wrote:
> On Mon, Jul 09, 2018 at 10:49:53AM +0200, Peter Zijlstra wrote:
>> On Sat, Jul 07, 2018 at 10:54:28PM +0900, Tetsuo Handa wrote:
>>>>> Since syzbot is confused by concurrent printk() messages [1],
>>>>> this patch changes show_opcodes() to use snprintf().
>>
>> But how big of a problem is that really? We can't very well remove all
>> pr_cont stuff from the kernel.
>
> I'd say we should try to make oopses as legible as possible.
>
> Also KERN_CONT is inherently broken, and we should avoid using it in
> general, IMO.
>
We can't afford removing all pr_cont()/KERN_CONT.
But show_opcodes() is an example of function which is expected to be SMP-safe.
/*
* Annotation for a "continued" line of log printout (only done after a
* line that had no enclosing \n). Only to be used by core/arch code
* during early bootup (a continued line is not SMP-safe otherwise).
*/
#define KERN_CONT KERN_SOH "c"
From: Josh Poimboeuf
> Sent: 09 July 2018 20:12
> On Mon, Jul 09, 2018 at 10:49:53AM +0200, Peter Zijlstra wrote:
> > On Sat, Jul 07, 2018 at 10:54:28PM +0900, Tetsuo Handa wrote:
> > > >> Since syzbot is confused by concurrent printk() messages [1],
> > > >> this patch changes show_opcodes() to use snprintf().
> >
> > But how big of a problem is that really? We can't very well remove all
> > pr_cont stuff from the kernel.
>
> I'd say we should try to make oopses as legible as possible.
To make oopses legible you need to lock the output between output lines.
Which would require a 'KERN_CONTINUED' marker on the previous print.
> Also KERN_CONT is inherently broken, and we should avoid using it in
> general, IMO.
I'm sure something semi-automatic could be done to expect a further
print if the line doesn't end in '\n'.
A per-cpu line buffer is probably excessive, but some kind of
timing out lock might work (release expecting re-acquire).
David
On 2018/07/11 1:51, David Laight wrote:
> From: Josh Poimboeuf
>> Sent: 09 July 2018 20:12
>> On Mon, Jul 09, 2018 at 10:49:53AM +0200, Peter Zijlstra wrote:
>>> On Sat, Jul 07, 2018 at 10:54:28PM +0900, Tetsuo Handa wrote:
>>>>>> Since syzbot is confused by concurrent printk() messages [1],
>>>>>> this patch changes show_opcodes() to use snprintf().
>>>
>>> But how big of a problem is that really? We can't very well remove all
>>> pr_cont stuff from the kernel.
>>
>> I'd say we should try to make oopses as legible as possible.
>
> To make oopses legible you need to lock the output between output lines.
> Which would require a 'KERN_CONTINUED' marker on the previous print.
There is an attempt to prefix context identifier to each line of output
( https://groups.google.com/d/msg/syzkaller/ttZehjXiHTU/JR67pXz3BAAJ ).
Therefore, I expect oops messages can stop using pr_cont()/KERN_CONT.
Ingo, is this patch acceptable?
On 2018/07/07 22:54, Tetsuo Handa wrote:
>From 61752cef56fad2a910f6bfd277e1b9b028aeab43 Mon Sep 17 00:00:00 2001
> From: Tetsuo Handa <[email protected]>
> Date: Sat, 7 Jul 2018 22:45:30 +0900
> Subject: [PATCH v2] x86: Avoid pr_cont() in show_opcodes()
>
> Since syzbot is confused by concurrent printk() messages [1], this patch
> changes show_opcodes() to use snprintf(). By this change, the Code: line
> will always be printed as one line even if multiple threads concurrently
> called printk().
>
> To save on-stack footprint, this patch shares opcodes[] and buf[] because
> we sequentially reads from opcodes[] and sequentially writes to buf[].
>
> When we start adding prefix to each line of printk() output,
> we will be able to handle concurrent printk() messages.
>
> [1] https://syzkaller.appspot.com/text?tag=CrashReport&x=139d342c400000
>
> Signed-off-by: Tetsuo Handa <[email protected]>
> Cc: Borislav Petkov <[email protected]>
> Cc: Thomas Gleixner <[email protected]>
> Cc: Peter Zijlstra <[email protected]>
> Cc: Josh Poimboeuf <[email protected]>
> Cc: Linus Torvalds <[email protected]>
> Cc: Andy Lutomirski <[email protected]>
> ---
> arch/x86/kernel/dumpstack.c | 16 +++++++++-------
> 1 file changed, 9 insertions(+), 7 deletions(-)
>
> diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
> index 666a284..6408123 100644
> --- a/arch/x86/kernel/dumpstack.c
> +++ b/arch/x86/kernel/dumpstack.c
> @@ -94,25 +94,27 @@ static void printk_stack_address(unsigned long address, int reliable,
> void show_opcodes(u8 *rip, const char *loglvl)
> {
> unsigned int code_prologue = OPCODE_BUFSIZE * 2 / 3;
> - u8 opcodes[OPCODE_BUFSIZE];
> u8 *ip;
> int i;
> -
> - printk("%sCode: ", loglvl);
> + int pos = 0;
> + char buf[(3 * OPCODE_BUFSIZE + 2) + 1];
> + u8 *opcodes = (u8 *) buf + sizeof(buf) - OPCODE_BUFSIZE;
>
> ip = (u8 *)rip - code_prologue;
> if (probe_kernel_read(opcodes, ip, OPCODE_BUFSIZE)) {
> - pr_cont("Bad RIP value.\n");
> + printk("%sCode: Bad RIP value.\n", loglvl);
> return;
> }
>
> for (i = 0; i < OPCODE_BUFSIZE; i++, ip++) {
> if (ip == rip)
> - pr_cont("<%02x> ", opcodes[i]);
> + pos += snprintf(buf + pos, sizeof(buf) - pos,
> + "<%02x> ", opcodes[i]);
> else
> - pr_cont("%02x ", opcodes[i]);
> + pos += snprintf(buf + pos, sizeof(buf) - pos,
> + "%02x ", opcodes[i]);
> }
> - pr_cont("\n");
> + printk("%sCode: %s\n", loglvl, buf);
> }
>
> void show_ip(struct pt_regs *regs, const char *loglvl)
>
On 2018-07-07 15:54, Tetsuo Handa wrote:
> On 2018/07/07 20:12, Ingo Molnar wrote:
>>
>> * Tetsuo Handa <[email protected]> wrote:
>>
>>> From: Tetsuo Handa <[email protected]>
>>>
>>> Since syzbot is confused by concurrent printk() messages [1],
>>> this patch changes show_opcodes() to use snprintf().
>>>
>>> When we start adding prefix to each line of printk() output,
>>> we will be able to handle concurrent printk() messages.
>>>
>>> [1] https://syzkaller.appspot.com/text?tag=CrashReport&x=139d342c400000
>>
>> Does this change the output?
>>
>> - If yes, could you show the before/after output in the changelog,
>>
>> - If not (i.e. if only the number of printk calls is changed, the output is the
>> same), could you say so in the changelog?
>
> This patch will not change the output unless multiple threads concurrently
> call printk(). The purpose of this patch is to help parsing kernel messages
> when multiple threads are concurrently calling printk() for multiple times
> (e.g. backtrace) by reducing pr_cont()/KERN_CONT usage.
>
>>
>> Also, 3*OPCODE_BUFSIZE+2+1 is 195 bytes - isn't that a bit too much on-stack
>> footprint?
>
> Then, we can reduce it by OPCODE_BUFSIZE bytes by unionizing opcodes[] and buf[].
Why not this instead? Less stack use, less code, no intermediary
snprintfs, no pr_cont...
diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
index 666a284116ac..c881e8a757d9 100644
--- a/arch/x86/kernel/dumpstack.c
+++ b/arch/x86/kernel/dumpstack.c
@@ -93,26 +93,16 @@ static void printk_stack_address(unsigned long
address, int reliable,
*/
void show_opcodes(u8 *rip, const char *loglvl)
{
- unsigned int code_prologue = OPCODE_BUFSIZE * 2 / 3;
+ unsigned int prologue = OPCODE_BUFSIZE * 2 / 3;
u8 opcodes[OPCODE_BUFSIZE];
- u8 *ip;
- int i;
- printk("%sCode: ", loglvl);
-
- ip = (u8 *)rip - code_prologue;
- if (probe_kernel_read(opcodes, ip, OPCODE_BUFSIZE)) {
- pr_cont("Bad RIP value.\n");
+ if (probe_kernel_read(opcodes, rip - prologue, OPCODE_BUFSIZE)) {
+ printk("%sCode: Bad RIP value.\n", loglvl);
return;
}
-
- for (i = 0; i < OPCODE_BUFSIZE; i++, ip++) {
- if (ip == rip)
- pr_cont("<%02x> ", opcodes[i]);
- else
- pr_cont("%02x ", opcodes[i]);
- }
- pr_cont("\n");
+ printk("%sCode: %*ph <%02x> %*ph\n", loglvl,
+ prologue, &opcodes[0], opcodes[prologue],
+ OPCODE_BUFSIZE - prologue - 1, &opcodes[prologue + 1]);
}
void show_ip(struct pt_regs *regs, const char *loglvl)
Not compile-tested, probably whitespace-damaged, but you get the idea.
Rasmus
On 2018/07/17 18:01, Rasmus Villemoes wrote:
> Why not this instead? Less stack use, less code, no intermediary
> snprintfs, no pr_cont...
Excellent! I didn't notice %ph extension.
> Not compile-tested, probably whitespace-damaged, but you get the idea.
Yes, it works well.
From 96d9d4d135994a081e54d33d23f5007c53d9b5dd Mon Sep 17 00:00:00 2001
From: Tetsuo Handa <[email protected]>
Date: Tue, 17 Jul 2018 22:47:11 +0900
Subject: [PATCH v3] x86: Avoid pr_cont() in show_opcodes()
Since syzbot is confused by concurrent printk() messages [1],
this patch changes show_opcodes() to use %*ph format string.
When we start adding prefix to each line of printk() output,
we will be able to handle concurrent printk() messages.
[1] https://syzkaller.appspot.com/text?tag=CrashReport&x=139d342c400000
Signed-off-by: Tetsuo Handa <[email protected]>
Signed-off-by: Rasmus Villemoes <[email protected]>
Cc: Borislav Petkov <[email protected]>
Cc: Thomas Gleixner <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Cc: Josh Poimboeuf <[email protected]>
Cc: Linus Torvalds <[email protected]>
Cc: Andy Lutomirski <[email protected]>
---
arch/x86/kernel/dumpstack.c | 25 +++++++------------------
1 file changed, 7 insertions(+), 18 deletions(-)
diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
index 666a284..ffdd484 100644
--- a/arch/x86/kernel/dumpstack.c
+++ b/arch/x86/kernel/dumpstack.c
@@ -93,26 +93,15 @@ static void printk_stack_address(unsigned long address, int reliable,
*/
void show_opcodes(u8 *rip, const char *loglvl)
{
- unsigned int code_prologue = OPCODE_BUFSIZE * 2 / 3;
+ const unsigned int prologue = OPCODE_BUFSIZE * 2 / 3;
u8 opcodes[OPCODE_BUFSIZE];
- u8 *ip;
- int i;
- printk("%sCode: ", loglvl);
-
- ip = (u8 *)rip - code_prologue;
- if (probe_kernel_read(opcodes, ip, OPCODE_BUFSIZE)) {
- pr_cont("Bad RIP value.\n");
- return;
- }
-
- for (i = 0; i < OPCODE_BUFSIZE; i++, ip++) {
- if (ip == rip)
- pr_cont("<%02x> ", opcodes[i]);
- else
- pr_cont("%02x ", opcodes[i]);
- }
- pr_cont("\n");
+ if (probe_kernel_read(opcodes, rip - prologue, OPCODE_BUFSIZE))
+ printk("%sCode: Bad RIP value.\n", loglvl);
+ else
+ printk("%sCode: %*ph <%02x> %*ph\n", loglvl, prologue, opcodes,
+ opcodes[prologue], OPCODE_BUFSIZE - prologue - 1,
+ &opcodes[prologue + 1]);
}
void show_ip(struct pt_regs *regs, const char *loglvl)
--
1.8.3.1
On 2018-07-17 15:53, Tetsuo Handa wrote:
> On 2018/07/17 18:01, Rasmus Villemoes wrote:
>> Why not this instead? Less stack use, less code, no intermediary
>> snprintfs, no pr_cont...
>
> Excellent! I didn't notice %ph extension.
>
>> Not compile-tested, probably whitespace-damaged, but you get the idea.
>
> Yes, it works well.
>
>
>
> From 96d9d4d135994a081e54d33d23f5007c53d9b5dd Mon Sep 17 00:00:00 2001
> From: Tetsuo Handa <[email protected]>
> Date: Tue, 17 Jul 2018 22:47:11 +0900
> Subject: [PATCH v3] x86: Avoid pr_cont() in show_opcodes()
>
> Since syzbot is confused by concurrent printk() messages [1],
> this patch changes show_opcodes() to use %*ph format string.
>
> When we start adding prefix to each line of printk() output,
> we will be able to handle concurrent printk() messages.
>
> [1] https://syzkaller.appspot.com/text?tag=CrashReport&x=139d342c400000
>
> Signed-off-by: Tetsuo Handa <[email protected]>
> Signed-off-by: Rasmus Villemoes <[email protected]>
I'm not sure that SoB-chain is correct. Anyway, however which way, and
if at all, you want to credit me, please use the email address
[email protected] . I probably botched From header in the
previous mail, not used to using Thunderbird...
Rasmus
Corrected Signed-off-by: addresses.
From 96d9d4d135994a081e54d33d23f5007c53d9b5dd Mon Sep 17 00:00:00 2001
From: Tetsuo Handa <[email protected]>
Date: Tue, 17 Jul 2018 22:47:11 +0900
Subject: [PATCH v4] x86: Avoid pr_cont() in show_opcodes()
Since syzbot is confused by concurrent printk() messages [1],
this patch changes show_opcodes() to use %*ph format string.
When we start adding prefix to each line of printk() output,
we will be able to handle concurrent printk() messages.
[1] https://syzkaller.appspot.com/text?tag=CrashReport&x=139d342c400000
Signed-off-by: Tetsuo Handa <[email protected]>
Signed-off-by: Rasmus Villemoes <[email protected]>
Cc: Borislav Petkov <[email protected]>
Cc: Thomas Gleixner <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Cc: Josh Poimboeuf <[email protected]>
Cc: Linus Torvalds <[email protected]>
Cc: Andy Lutomirski <[email protected]>
---
arch/x86/kernel/dumpstack.c | 25 +++++++------------------
1 file changed, 7 insertions(+), 18 deletions(-)
diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
index 666a284..ffdd484 100644
--- a/arch/x86/kernel/dumpstack.c
+++ b/arch/x86/kernel/dumpstack.c
@@ -93,26 +93,15 @@ static void printk_stack_address(unsigned long address, int reliable,
*/
void show_opcodes(u8 *rip, const char *loglvl)
{
- unsigned int code_prologue = OPCODE_BUFSIZE * 2 / 3;
+ const unsigned int prologue = OPCODE_BUFSIZE * 2 / 3;
u8 opcodes[OPCODE_BUFSIZE];
- u8 *ip;
- int i;
- printk("%sCode: ", loglvl);
-
- ip = (u8 *)rip - code_prologue;
- if (probe_kernel_read(opcodes, ip, OPCODE_BUFSIZE)) {
- pr_cont("Bad RIP value.\n");
- return;
- }
-
- for (i = 0; i < OPCODE_BUFSIZE; i++, ip++) {
- if (ip == rip)
- pr_cont("<%02x> ", opcodes[i]);
- else
- pr_cont("%02x ", opcodes[i]);
- }
- pr_cont("\n");
+ if (probe_kernel_read(opcodes, rip - prologue, OPCODE_BUFSIZE))
+ printk("%sCode: Bad RIP value.\n", loglvl);
+ else
+ printk("%sCode: %*ph <%02x> %*ph\n", loglvl, prologue, opcodes,
+ opcodes[prologue], OPCODE_BUFSIZE - prologue - 1,
+ &opcodes[prologue + 1]);
}
void show_ip(struct pt_regs *regs, const char *loglvl)
--
1.8.3.1
On Tue, Jul 17, 2018 at 12:01 PM, Rasmus Villemoes
<[email protected]> wrote:
> + printk("%sCode: %*ph <%02x> %*ph\n", loglvl,
Ah, I had looked at this code and thought about %ph, but didn't get
through how to split it correctly.
Thanks for the hint!
P.S. I see the result, pretty nice and doesn't use pr_cont() at all.
--
With Best Regards,
Andy Shevchenko
On Wed, 2018-07-18 at 05:54 +0900, Tetsuo Handa wrote:
> Corrected Signed-off-by: addresses.
>
> From 96d9d4d135994a081e54d33d23f5007c53d9b5dd Mon Sep 17 00:00:00 2001
> From: Tetsuo Handa <[email protected]>
> Date: Tue, 17 Jul 2018 22:47:11 +0900
> Subject: [PATCH v4] x86: Avoid pr_cont() in show_opcodes()
>
> Since syzbot is confused by concurrent printk() messages [1],
> this patch changes show_opcodes() to use %*ph format string.
>
> When we start adding prefix to each line of printk() output,
> we will be able to handle concurrent printk() messages.
If this were applied via git am, the commit would include
all the content from "Corrected Signed-off-by:"
Perhaps it would be better to send this as a new patch without
the leading 7 lines after the email header
> diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
[]
> @@ -93,26 +93,15 @@ static void printk_stack_address(unsigned long address, int reliable,
> */
> void show_opcodes(u8 *rip, const char *loglvl)
> {
> - unsigned int code_prologue = OPCODE_BUFSIZE * 2 / 3;
> + const unsigned int prologue = OPCODE_BUFSIZE * 2 / 3;
And this might be better as a #define to avoid
a few more bytes of stack consumption.
On Tue, 2018-07-17 at 14:19 -0700, Joe Perches wrote:
> diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
> []
> > @@ -93,26 +93,15 @@ static void printk_stack_address(unsigned long address, int reliable,
> > */
> > void show_opcodes(u8 *rip, const char *loglvl)
> > {
> > - unsigned int code_prologue = OPCODE_BUFSIZE * 2 / 3;
> > + const unsigned int prologue = OPCODE_BUFSIZE * 2 / 3;
>
> And this might be better as a #define to avoid
> a few more bytes of stack consumption.
Apologies for this silly suggestion.
automatics are not structs and gcc will eliminate
this declaration at all compiler optimization levels.