Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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.
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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.
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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 > 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.
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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 > 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.
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
On Tue, Jul 17, 2018 at 12:01 PM, Rasmus Villemoes 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
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
On Tue, Jul 17, 2018 at 12:01 PM, Rasmus Villemoes 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
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
Corrected Signed-off-by: addresses. >From 96d9d4d135994a081e54d33d23f5007c53d9b5dd Mon Sep 17 00:00:00 2001 From: Tetsuo Handa 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=139d342c40 Signed-off-by: Tetsuo Handa Signed-off-by: Rasmus Villemoes Cc: Borislav Petkov Cc: Thomas Gleixner Cc: Peter Zijlstra Cc: Josh Poimboeuf Cc: Linus Torvalds Cc: Andy Lutomirski --- 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, + [prologue + 1]); } void show_ip(struct pt_regs *regs, const char *loglvl) -- 1.8.3.1
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
Corrected Signed-off-by: addresses. >From 96d9d4d135994a081e54d33d23f5007c53d9b5dd Mon Sep 17 00:00:00 2001 From: Tetsuo Handa 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=139d342c40 Signed-off-by: Tetsuo Handa Signed-off-by: Rasmus Villemoes Cc: Borislav Petkov Cc: Thomas Gleixner Cc: Peter Zijlstra Cc: Josh Poimboeuf Cc: Linus Torvalds Cc: Andy Lutomirski --- 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, + [prologue + 1]); } void show_ip(struct pt_regs *regs, const char *loglvl) -- 1.8.3.1
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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 > 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=139d342c40 > > Signed-off-by: Tetsuo Handa > Signed-off-by: Rasmus Villemoes 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 li...@rasmusvillemoes.dk . I probably botched From header in the previous mail, not used to using Thunderbird... Rasmus
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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 > 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=139d342c40 > > Signed-off-by: Tetsuo Handa > Signed-off-by: Rasmus Villemoes 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 li...@rasmusvillemoes.dk . I probably botched From header in the previous mail, not used to using Thunderbird... Rasmus
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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 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=139d342c40 Signed-off-by: Tetsuo Handa Signed-off-by: Rasmus Villemoes Cc: Borislav Petkov Cc: Thomas Gleixner Cc: Peter Zijlstra Cc: Josh Poimboeuf Cc: Linus Torvalds Cc: Andy Lutomirski --- 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, + [prologue + 1]); } void show_ip(struct pt_regs *regs, const char *loglvl) -- 1.8.3.1
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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 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=139d342c40 Signed-off-by: Tetsuo Handa Signed-off-by: Rasmus Villemoes Cc: Borislav Petkov Cc: Thomas Gleixner Cc: Peter Zijlstra Cc: Josh Poimboeuf Cc: Linus Torvalds Cc: Andy Lutomirski --- 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, + [prologue + 1]); } void show_ip(struct pt_regs *regs, const char *loglvl) -- 1.8.3.1
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
On 2018-07-07 15:54, Tetsuo Handa wrote: > On 2018/07/07 20:12, Ingo Molnar wrote: >> >> * Tetsuo Handa wrote: >> >>> From: Tetsuo Handa >>> >>> 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=139d342c40 >> >> 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, [0], opcodes[prologue], + OPCODE_BUFSIZE - prologue - 1, [prologue + 1]); } void show_ip(struct pt_regs *regs, const char *loglvl) Not compile-tested, probably whitespace-damaged, but you get the idea. Rasmus
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
On 2018-07-07 15:54, Tetsuo Handa wrote: > On 2018/07/07 20:12, Ingo Molnar wrote: >> >> * Tetsuo Handa wrote: >> >>> From: Tetsuo Handa >>> >>> 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=139d342c40 >> >> 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, [0], opcodes[prologue], + OPCODE_BUFSIZE - prologue - 1, [prologue + 1]); } void show_ip(struct pt_regs *regs, const char *loglvl) Not compile-tested, probably whitespace-damaged, but you get the idea. Rasmus
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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 > 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=139d342c40 > > Signed-off-by: Tetsuo Handa > Cc: Borislav Petkov > Cc: Thomas Gleixner > Cc: Peter Zijlstra > Cc: Josh Poimboeuf > Cc: Linus Torvalds > Cc: Andy Lutomirski > --- > 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) >
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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 > 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=139d342c40 > > Signed-off-by: Tetsuo Handa > Cc: Borislav Petkov > Cc: Thomas Gleixner > Cc: Peter Zijlstra > Cc: Josh Poimboeuf > Cc: Linus Torvalds > Cc: Andy Lutomirski > --- > 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) >
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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.
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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.
RE: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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
RE: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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"
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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"
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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
RE: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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
RE: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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.
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
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.
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
On 2018/07/07 20:12, Ingo Molnar wrote: > > * Tetsuo Handa wrote: > >> From: Tetsuo Handa >> >> 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=139d342c40 > > 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 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=139d342c40 Signed-off-by: Tetsuo Handa Cc: Borislav Petkov Cc: Thomas Gleixner Cc: Peter Zijlstra Cc: Josh Poimboeuf Cc: Linus Torvalds Cc: Andy Lutomirski --- 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
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
On 2018/07/07 20:12, Ingo Molnar wrote: > > * Tetsuo Handa wrote: > >> From: Tetsuo Handa >> >> 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=139d342c40 > > 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 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=139d342c40 Signed-off-by: Tetsuo Handa Cc: Borislav Petkov Cc: Thomas Gleixner Cc: Peter Zijlstra Cc: Josh Poimboeuf Cc: Linus Torvalds Cc: Andy Lutomirski --- 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
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
* Tetsuo Handa wrote: > From: Tetsuo Handa > > 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=139d342c40 > > Signed-off-by: Tetsuo Handa > Cc: Borislav Petkov > Cc: Thomas Gleixner > Cc: Peter Zijlstra > Cc: Josh Poimboeuf > Cc: Linus Torvalds > Cc: Andy Lutomirski > --- > 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
Re: [PATCH] x86: Avoid pr_cont() in show_opcodes()
* Tetsuo Handa wrote: > From: Tetsuo Handa > > 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=139d342c40 > > Signed-off-by: Tetsuo Handa > Cc: Borislav Petkov > Cc: Thomas Gleixner > Cc: Peter Zijlstra > Cc: Josh Poimboeuf > Cc: Linus Torvalds > Cc: Andy Lutomirski > --- > 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
[PATCH] x86: Avoid pr_cont() in show_opcodes()
From: Tetsuo Handa 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=139d342c40 Signed-off-by: Tetsuo Handa Cc: Borislav Petkov Cc: Thomas Gleixner Cc: Peter Zijlstra Cc: Josh Poimboeuf Cc: Linus Torvalds Cc: Andy Lutomirski --- 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
[PATCH] x86: Avoid pr_cont() in show_opcodes()
From: Tetsuo Handa 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=139d342c40 Signed-off-by: Tetsuo Handa Cc: Borislav Petkov Cc: Thomas Gleixner Cc: Peter Zijlstra Cc: Josh Poimboeuf Cc: Linus Torvalds Cc: Andy Lutomirski --- 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