Re: [PATCH] printk: fix buffer overflow potential for print_text()
On 2021-02-26, Alexander Gordeev wrote: > I am seeing KASAN reporting incorrect 1-byte access in exactly > same location Sven has identified before. In case there no > fix for it yet, please see below what happens in case of pretty > large buffer - WARN_ONCE() invocation in my case. It looks like you have not applied the fix yet: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=08d60e5999540110576e7c1346d486220751b7f9 John Ogness
Re: [PATCH] printk: fix buffer overflow potential for print_text()
On Thu, Jan 14, 2021 at 06:10:12PM +0106, John Ogness wrote:
> Before commit b6cf8b3f3312 ("printk: add lockless ringbuffer"),
> msg_print_text() would only write up to size-1 bytes into the
> provided buffer. Some callers expect this behavior and append
> a terminator to returned string. In particular:
>
> arch/powerpc/xmon/xmon.c:dump_log_buf()
> arch/um/kernel/kmsg_dump.c:kmsg_dumper_stdout()
>
> msg_print_text() has been replaced by record_print_text(), which
> currently fills the full size of the buffer. This causes a
> buffer overflow for the above callers.
>
> Change record_print_text() so that it will only use size-1 bytes
> for text data. Also, for paranoia sakes, add a terminator after
> the text data.
>
> And finally, document this behavior so that it is clear that only
> size-1 bytes are used and a terminator is added.
Hi John,
I am seeing KASAN reporting incorrect 1-byte access in exactly
same location Sven has identified before. In case there no
fix for it yet, please see below what happens in case of pretty
large buffer - WARN_ONCE() invocation in my case.
>
> Fixes: b6cf8b3f3312 ("printk: add lockless ringbuffer")
> Signed-off-by: John Ogness
> ---
> kernel/printk/printk.c | 35 +++
> 1 file changed, 27 insertions(+), 8 deletions(-)
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index ffdd0dc7ec6d..73f9eae19f05 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1293,9 +1293,15 @@ static size_t info_print_prefix(const struct
> printk_info *info, bool syslog,
> * - Add prefix for each line.
> * - Add the trailing newline that has been removed in vprintk_store().
> * - Drop truncated lines that do not longer fit into the buffer.
> + * - Add a trailing newline.
> + * - Add a string terminator.
> + *
> + * Since the produced string is always terminated, the maximum possible
> + * return value is @r->text_buf_size - 1;
> *
> * Return: The length of the updated/prepared text, including the added
> - * prefixes and the newline. The dropped line(s) are not counted.
> + * prefixes and the newline. The terminator is not counted. The dropped
> + * line(s) are not counted.
> */
> static size_t record_print_text(struct printk_record *r, bool syslog,
> bool time)
> @@ -1338,26 +1344,31 @@ static size_t record_print_text(struct printk_record
> *r, bool syslog,
>
> /*
>* Truncate the text if there is not enough space to add the
> - * prefix and a trailing newline.
> + * prefix and a trailing newline and a terminator.
>*/
> - if (len + prefix_len + text_len + 1 > buf_size) {
> + if (len + prefix_len + text_len + 1 + 1 > buf_size) {
> /* Drop even the current line if no space. */
> - if (len + prefix_len + line_len + 1 > buf_size)
> + if (len + prefix_len + line_len + 1 + 1 > buf_size)
> break;
>
> - text_len = buf_size - len - prefix_len - 1;
> + text_len = buf_size - len - prefix_len - 1 - 1;
> truncated = true;
> }
>
> memmove(text + prefix_len, text, text_len);
> memcpy(text, prefix, prefix_len);
>
> + /*
> + * Increment the prepared length to include the text and
> + * prefix that were just moved+copied. Also increment for the
> + * newline at the end of this line. If this is the last line,
> + * there is no newline, but it will be added immediately below.
> + */
> len += prefix_len + line_len + 1;
(1) the next iteration of would-be-length stored in len
> -
> if (text_len == line_len) {
(2) but the buffer is processed, so we get here
> /*
> - * Add the trailing newline removed in
> - * vprintk_store().
> + * This is the last line. Add the trailing newline
> + * removed in vprintk_store().
>*/
> text[prefix_len + line_len] = '\n';
> break;
(3) and bail out from the loop
> @@ -1382,6 +1393,14 @@ static size_t record_print_text(struct printk_record
> *r, bool syslog,
> text_len -= line_len + 1;
> }
>
> + /*
> + * If a buffer was provided, it will be terminated. Space for the
> + * string terminator is guaranteed to be available. The terminator is
> + * not counted in the return value.
> + */
> + if (buf_size > 0)
> + text[len] = 0;
(4) trying to terminate, but len is beyond the buffer
BUG: KASAN: global-out-of-bounds in record_print_text+0x1d4/0x248
Write of size 1 at addr bf9e6992 by task swapper/0/1
Reverting the
Re: [PATCH] printk: fix buffer overflow potential for print_text()
John Ogness writes: > Hi Sven, > > Thanks for the outstanding analysis! > > On 2021-01-23, Sven Schnelle wrote: >>> 1401if (buf_size > 0) >>> 1402text[len] = 0; >> >> I don't think i have really understood how all the printk magic works, >> but using r->text_buf[len] seems to be the correct place to put the >> zero byte in that case? > > Yes, you are correct! @text is pointing to the beginning of the > currently processed line, not the beginning of the buffer. > > I will submit a patch to fix our recent fix (unless you would like to do > that). Please go ahead, thank you!
Re: [PATCH] printk: fix buffer overflow potential for print_text()
Hi Sven, Thanks for the outstanding analysis! On 2021-01-23, Sven Schnelle wrote: >> 1401 if (buf_size > 0) >> 1402 text[len] = 0; > > I don't think i have really understood how all the printk magic works, > but using r->text_buf[len] seems to be the correct place to put the > zero byte in that case? Yes, you are correct! @text is pointing to the beginning of the currently processed line, not the beginning of the buffer. I will submit a patch to fix our recent fix (unless you would like to do that). Thank you for all your help with this! John Ogness
Re: [PATCH] printk: fix buffer overflow potential for print_text()
Sven Schnelle writes: > John Ogness writes: > >> On 2021-01-22, Sven Schnelle wrote: > I was able to reproduce it in a virtual machine where i have a few more > ways to debug. What i got was: > > 01: -> 001B8814" MVI 92001000 >> 0163F1CD CC 2 > > That's a watchpoint telling me that the code at 0x1b8814 wants to store > one byte to 0x163f1cd, which is the second byte of console_drivers. > > gdb tells me about 0x1b8814: > > (gdb) list *(0x1b8814) > 0x1b8814 is in record_print_text > (/home/svens/ibmgit/linux/kernel/printk/printk.c:1402). > 1397 * If a buffer was provided, it will be terminated. Space for > the > 1398 * string terminator is guaranteed to be available. The > terminator is > 1399 * not counted in the return value. > 1400 */ > 1401 if (buf_size > 0) > 1402 text[len] = 0; I don't think i have really understood how all the printk magic works, but using r->text_buf[len] seems to be the correct place to put the zero byte in that case? > 1403 > 1404 return len; > 1405 } > 1406 >
Re: [PATCH] printk: fix buffer overflow potential for print_text()
John Ogness writes: > On 2021-01-22, Sven Schnelle wrote: >> >> So somehow the pointer for console_drivers changes. >> >> I can't provide the normal kernel crash output as printk is no longer >> working, > > I don't understand what you mean here. The crash tool can dump the > printk buffer. > > I would be curious to see what the messages look like. It would also be > helpful to know the last message you saw on the console. > The last message is: [ 1845.640466] User process fault: interruption code 0007 ilc:2 in libm.so[7d78c000+a3000] [ 1845.640474] CPU: 9 PID: 859915 Comm: ld.so.1 Not tainted 5.11.0-20210122.rc4.git0.9f29bd8b2e71.300.fc33.s390x+git #1 [ 1845.640476] Hardware name: IBM 8561 T01 703 (LPAR) [ 1845.640478] User PSW : 070530008000 7d7983b2 [ 1845.640480]R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:1 AS:0 CC:3 PM:0 RI:0 EA:1 [ 1845.640483] User GPRS: 7d798360 0010 03ff0004 [ 1845.640485]7f854dd0 7d7e9788 03ff00401b30 7f854ff8 [ 1845.640487]03ff 03ff7d5b4da0 03ff 03ff0010 [ 1845.640489]03ff004022c6 03ff004024b0 80401796 7f854de8 That's also what's written to the console. Please note the the output above is expected. It's only reporting that a user space program performed an invalid FPU operation. The kernel crash is neither written to the console nor the dmesg buffer. >> kmsg_dump_rewind+290 is: >> >> if (!(con->flags & CON_ENABLED)) >> continue; >> >> in kernel/printk/printk.c:1845 >> >> I haven't dived into whether our show_code() is doing something wrong >> which was covered in the past or whether that's because of the patch >> above but wanted to make you aware of that in case you have an idea. >> Otherwise i have to dig into the code. > > Unless we are dealing with very long printk messages that normally get > truncated (800+ characters) this patch simply adds a string > terminator. I do not see how that could possibly cause this kind of > damage. > > When this triggers, there is nothing happening with consoles registering > or deregistering, right? That's correct. No registering/unregistering taking place. > The string terminator (kernel/printk/printk.c:1402) is only added for > paranoia. If you comment that out, this patch will have no effect (for > "normal" length lines). I would be curious if that somehow makes a > difference for you. I was able to reproduce it in a virtual machine where i have a few more ways to debug. What i got was: 01: -> 001B8814" MVI 92001000 >> 0163F1CD CC 2 That's a watchpoint telling me that the code at 0x1b8814 wants to store one byte to 0x163f1cd, which is the second byte of console_drivers. gdb tells me about 0x1b8814: (gdb) list *(0x1b8814) 0x1b8814 is in record_print_text (/home/svens/ibmgit/linux/kernel/printk/printk.c:1402). 1397 * If a buffer was provided, it will be terminated. Space for the 1398 * string terminator is guaranteed to be available. The terminator is 1399 * not counted in the return value. 1400 */ 1401if (buf_size > 0) 1402text[len] = 0; 1403 1404return len; 1405} 1406 In s390 assembly, this is the store: 0x001b8810 <+0x130>: la %r1,0(%r7,%r9) 0x001b8814 <+0x134>: mvi 0(%r1),0 The cpu registers at the time of write: 01: GRG 0 = 0020 0163F1CD 01: GRG 2 = 0042 03E000623A98 01: GRG 4 = 000E 0087BB70 01: GRG 6 = 0400 *0224* 01: GRG 8 = 000F *0163EFA9* 01: GRG 10 = 0033 01: GRG 12 = 809AE000 03E000623A98 01: GRG 14 = 001B884C 03E0006239E8 So r9 is 0163EFA9 - seems to be the start of the current message: 0163EFA9: *[ 24.069514]7d7af3c2: b30d0002..debr.%f0,%f2.debr.%f0,%f2 while r7 is the offset, and that one is way to big: 0224 If you add that to 0163EFA9, you'll see that we're outside of the buffer and overwriting space after, which is console_drivers. The message it's trying to print is rather long, so the 0x224 could be the size of the whole line: This is not from the same crash, but this is how the message looks like it's trying to print: [ 23.960773] User Code: 7d7af3ba: 78005000le %f0,0(%r5) [ 23.960773]7d7af3be: 78205004le %f2,4(%r5) [ 23.960773] #7d7af3c2: b30d0002debr%f0,%f2 [ 23.960773] >7d7af3c6: a728lhi %r2,0 [ 23.960773]7d7af3ca: 07febcr 15,%r14 [ 23.960773]7d7af3cc: 0707bcr 0,%r7 [
Re: [PATCH] printk: fix buffer overflow potential for print_text()
On 2021-01-22, Sven Schnelle wrote:
> I'm seeing crashes on s390x with this patch while running the glibc
> testsuite. The glibc test suite triggers a few FPU exceptions which
> are printed to the kernel log by default. Looking at the crash dump,
> i see that the console_drivers pointer seems to be overwritten while
> printing that (user space) warning:
>
> crash> print *console_drivers
> $1 = {
> name = "\247\071\377\373\354!\004\214\000\331\300\345\000\033\353_",
> write = 0xa7190001eb119078,
> read = 0xe6e320b0050090,
> device = 0xa51e0010a7210001,
> unblank = 0xa7291000b9e28012,
> setup = 0xe320f0a4e320,
> exit = 0x208e0094eb112000,
> match = 0xcec1c006e017f,
> flags = -4984,
> index = 133,
> cflag = 8143136,
> data = 0x800458108004ec12,
> next = 0x5007eaf00
> }
>
> crash> x/16i console_drivers
>0x79009700: lghi%r3,-5
>0x79009704: aghik %r2,%r1,1164
>0x7900970a: brasl %r14,0x79386dc8
>0x79009710: lghi%r1,1
>0x79009714: laog%r1,%r1,120(%r9)
>0x7900971a: llgc%r2,5(%r11)
>0x79009720: llilh %r1,16
>0x79009724: tmll%r2,1
>0x79009728: lghi%r2,4096
>0x7900972c: locgre %r1,%r2
>0x79009730: lg %r2,160(%r15)
>0x79009736: llc %r2,142(%r2)
>0x7900973c: srlg%r1,%r1,0(%r2)
>0x79009742: clij%r1,1,12,0x7900981e
>0x79009748: cgij%r8,0,8,0x79009852
>0x7900974e: la %r2,4(%r8)
>
> crash> sym 0x79009700
> 79009700 (t) iomap_finish_ioend+192
> /usr/src/debug/kernel-5.10.fc33/linux-5.11.0-20210122.rc4.git0.9f29bd8b2e71.300.fc33.s390x/./include/linux/pagemap.h:
> 59
>
> So somehow the pointer for console_drivers changes.
>
> I can't provide the normal kernel crash output as printk is no longer
> working,
I don't understand what you mean here. The crash tool can dump the
printk buffer.
I would be curious to see what the messages look like. It would also be
helpful to know the last message you saw on the console.
> but in crash the backtrace looks like this:
> crash> bt
> PID: 859915 TASK: dad24000 CPU: 9 COMMAND: "ld.so.1"
> LOWCORE INFO:
> -psw : 0x000200018000 0x78c8400e
> -function : stop_run at 78c8400e
> -prefix : 0x0041e000
> -cpu timer: 0x7953a957e166
> -clock cmp: 0xd92876863ac66b00
> -general registers:
> 0xf0f0f0f0 0x78c8400e
> 0x79984830 0x79984830
> 0x79ac62c0 0x0002
> 0x0038 00
> 0x7a19157e 00
> 0xfffa 00
> 0xdad24000 00
> 0x78c8416e 0x0380033136f0
> -access registers:
> 0x7d5b4da0 0xa2a795c0 00 00
> 00 00 00 00
> 00 00 00 00
> 00 00 00 00
> -control registers:
> 0x00a014966a10 0x7a15c007
> 0x0001d0a0 00
> 0x 0x0001d080
> 0x3b00 0x0001f29b81c7
> 0x8000 00
> 00 00
> 00 0x7a15c007
> 0xdb00 0x0001d0c0
> -floating point registers:
> 0x5fabeb67f92f 0x0007fff8
> 0x4040eb67f000 00
> 0x0007 0x0064
> 0x02aa2a63f028 0x0963cf85
> 0x2a642c60 00
> 0x7f85516ceb67f222 0x03ffeb67f528
> 0x03ffeb67f230 0x0001
> 0x03ffeb67f21d 0x02aa28d2d970
>
> #0 [38003313710] stop_run at 78c8400e
> #1 [38003313728] atomic_notifier_call_chain at 78ced536
> #2 [38003313778] panic at 7974aeca
> #3 [38003313818] die at 78c897ea
> #4 [38003313880] do_no_context at 78c9b230
> #5 [380033138b8] pgm_check_handler at 7976438c
> PSW: 0404c0018000 78d304ba (kmsg_dump_rewind+290)
> GPRS: 0020 ec88
>000e 793f4800 0224
> 0224 0005007eaf00
>dad24000 038003313a68 038003313a18
> #0 [38003313a68] console_unlock at 78d3158e
> #1 [38003313b48] vprintk_emit at 78d32f50
> #2 [38003313ba8] vprintk_default at 78d32f9e
> #3 [38003313c00] printk at 7974bfae
> #4 [38003313c90] show_code at 78c8588e
> #5 [38003313de0] show_registers at 7974a26e
> #6 [38003313e70] show_regs at 78c8961e
> #7 [38003313ea0] pgm_check_handler at 7976438c
> PSW: 070530008000 7d7983b2 (user space)
> GPRS: 7d798360 0010 03ff0004
>7f854dd0 7d7e9788 03ff00401b30 7f854ff8
>03ff 03ff7d5b4da0
Re: [PATCH] printk: fix buffer overflow potential for print_text()
John Ogness writes:
> Before commit b6cf8b3f3312 ("printk: add lockless ringbuffer"),
> msg_print_text() would only write up to size-1 bytes into the
> provided buffer. Some callers expect this behavior and append
> a terminator to returned string. In particular:
>
> arch/powerpc/xmon/xmon.c:dump_log_buf()
> arch/um/kernel/kmsg_dump.c:kmsg_dumper_stdout()
>
> msg_print_text() has been replaced by record_print_text(), which
> currently fills the full size of the buffer. This causes a
> buffer overflow for the above callers.
>
> Change record_print_text() so that it will only use size-1 bytes
> for text data. Also, for paranoia sakes, add a terminator after
> the text data.
>
> And finally, document this behavior so that it is clear that only
> size-1 bytes are used and a terminator is added.
>
> Fixes: b6cf8b3f3312 ("printk: add lockless ringbuffer")
> Signed-off-by: John Ogness
> ---
> [..]
I'm seeing crashes on s390x with this patch while running the glibc
testsuite. The glibc test suite triggers a few FPU exceptions which
are printed to the kernel log by default. Looking at the crash dump,
i see that the console_drivers pointer seems to be overwritten while
printing that (user space) warning:
crash> print *console_drivers
$1 = {
name = "\247\071\377\373\354!\004\214\000\331\300\345\000\033\353_",
write = 0xa7190001eb119078,
read = 0xe6e320b0050090,
device = 0xa51e0010a7210001,
unblank = 0xa7291000b9e28012,
setup = 0xe320f0a4e320,
exit = 0x208e0094eb112000,
match = 0xcec1c006e017f,
flags = -4984,
index = 133,
cflag = 8143136,
data = 0x800458108004ec12,
next = 0x5007eaf00
}
crash> x/16i console_drivers
0x79009700: lghi%r3,-5
0x79009704: aghik %r2,%r1,1164
0x7900970a: brasl %r14,0x79386dc8
0x79009710: lghi%r1,1
0x79009714: laog%r1,%r1,120(%r9)
0x7900971a: llgc%r2,5(%r11)
0x79009720: llilh %r1,16
0x79009724: tmll%r2,1
0x79009728: lghi%r2,4096
0x7900972c: locgre %r1,%r2
0x79009730: lg %r2,160(%r15)
0x79009736: llc %r2,142(%r2)
0x7900973c: srlg%r1,%r1,0(%r2)
0x79009742: clij%r1,1,12,0x7900981e
0x79009748: cgij%r8,0,8,0x79009852
0x7900974e: la %r2,4(%r8)
crash> sym 0x79009700
79009700 (t) iomap_finish_ioend+192
/usr/src/debug/kernel-5.10.fc33/linux-5.11.0-20210122.rc4.git0.9f29bd8b2e71.300.fc33.s390x/./include/linux/pagemap.h:
59
So somehow the pointer for console_drivers changes.
I can't provide the normal kernel crash output as printk is no longer
working, but in crash the backtrace looks like this:
crash> bt
PID: 859915 TASK: dad24000 CPU: 9 COMMAND: "ld.so.1"
LOWCORE INFO:
-psw : 0x000200018000 0x78c8400e
-function : stop_run at 78c8400e
-prefix : 0x0041e000
-cpu timer: 0x7953a957e166
-clock cmp: 0xd92876863ac66b00
-general registers:
0xf0f0f0f0 0x78c8400e
0x79984830 0x79984830
0x79ac62c0 0x0002
0x0038 00
0x7a19157e 00
0xfffa 00
0xdad24000 00
0x78c8416e 0x0380033136f0
-access registers:
0x7d5b4da0 0xa2a795c0 00 00
00 00 00 00
00 00 00 00
00 00 00 00
-control registers:
0x00a014966a10 0x7a15c007
0x0001d0a0 00
0x 0x0001d080
0x3b00 0x0001f29b81c7
0x8000 00
00 00
00 0x7a15c007
0xdb00 0x0001d0c0
-floating point registers:
0x5fabeb67f92f 0x0007fff8
0x4040eb67f000 00
0x0007 0x0064
0x02aa2a63f028 0x0963cf85
0x2a642c60 00
0x7f85516ceb67f222 0x03ffeb67f528
0x03ffeb67f230 0x0001
0x03ffeb67f21d 0x02aa28d2d970
#0 [38003313710] stop_run at 78c8400e
#1 [38003313728] atomic_notifier_call_chain at 78ced536
#2 [38003313778] panic at 7974aeca
#3 [38003313818] die at 78c897ea
#4 [38003313880] do_no_context at 78c9b230
#5 [380033138b8] pgm_check_handler at 7976438c
PSW: 0404c0018000 78d304ba (kmsg_dump_rewind+290)
GPRS: 0020 ec88
000e 793f4800 0224
0224 0005007eaf00
dad24000 038003313a68 038003313a18
#0 [38003313a68] console_unlock at 78d3158e
#1 [38003313b48] vprintk_emit at 78d32f50
#2 [38003313ba8] vprintk_default at 78d32f9e
#3 [38003313c00] printk at
Re: [PATCH] printk: fix buffer overflow potential for print_text()
On Tue 2021-01-19 12:50:47, John Ogness wrote: > On 2021-01-19, Sergey Senozhatsky wrote: > >>> John, how did you spot these problems? > >> > >> I am preparing my series to remove the logbuf_lock, which also > >> refactors and consolidates code from syslog_print_all() and > >> kmsg_dump_get_buffer(). While testing/verifying my series, I noticed > >> the these oddities in the semantics and decided I should research > >> where they came from and if they were actually necessary. > > > > Any chance you can put those tests somewhere public so that we can > > run them regularly? Great idea. > I have a collection of hacked-together tools that I use to test most of > the various interfaces of printk. I would need to clean them up if they > should be used for any kind of automated regression testing. Sounds good. We could even help with the clean up. This kind of code always need it when it was not written for public use from scratch. > And where should I make such things available? I could put them in a > repo in the Linutronix github account (like I did for the ringbuffer > stress testing tool). (??) Sounds good as well. Best Regards, Petr
Re: [PATCH] printk: fix buffer overflow potential for print_text()
On 2021-01-19, Sergey Senozhatsky wrote: >>> John, how did you spot these problems? >> >> I am preparing my series to remove the logbuf_lock, which also >> refactors and consolidates code from syslog_print_all() and >> kmsg_dump_get_buffer(). While testing/verifying my series, I noticed >> the these oddities in the semantics and decided I should research >> where they came from and if they were actually necessary. > > Any chance you can put those tests somewhere public so that we can > run them regularly? I have a collection of hacked-together tools that I use to test most of the various interfaces of printk. I would need to clean them up if they should be used for any kind of automated regression testing. And where should I make such things available? I could put them in a repo in the Linutronix github account (like I did for the ringbuffer stress testing tool). (??) John
Re: [PATCH] printk: fix buffer overflow potential for print_text()
On Tue 2021-01-19 09:44:56, Sergey Senozhatsky wrote:
> On (21/01/15 13:07), Petr Mladek wrote:
> > On Fri 2021-01-15 13:04:37, Petr Mladek wrote:
> > > On Thu 2021-01-14 18:10:12, John Ogness wrote:
> > > > Before commit b6cf8b3f3312 ("printk: add lockless ringbuffer"),
> > > > msg_print_text() would only write up to size-1 bytes into the
> > > > provided buffer. Some callers expect this behavior and append
> > > > a terminator to returned string. In particular:
> > > >
> > > > arch/powerpc/xmon/xmon.c:dump_log_buf()
> > > > arch/um/kernel/kmsg_dump.c:kmsg_dumper_stdout()
> > > >
> > > > msg_print_text() has been replaced by record_print_text(), which
> > > > currently fills the full size of the buffer. This causes a
> > > > buffer overflow for the above callers.
> > > >
> > > > Change record_print_text() so that it will only use size-1 bytes
> > > > for text data. Also, for paranoia sakes, add a terminator after
> > > > the text data.
> > > >
> > > > And finally, document this behavior so that it is clear that only
> > > > size-1 bytes are used and a terminator is added.
> > > >
> > > > Fixes: b6cf8b3f3312 ("printk: add lockless ringbuffer")
> > > > Signed-off-by: John Ogness
>
> John, how did you spot these problems?
>
> FWIW, Acked-by: Sergey Senozhatsky
The patch has been committed into printk/linux.git, branch
printk-rework.
Best Regards,
Petr
Re: [PATCH] printk: fix buffer overflow potential for print_text()
On (21/01/19 10:00), John Ogness wrote: > On 2021-01-19, Sergey Senozhatsky wrote: > > John, how did you spot these problems? > > I am preparing my series to remove the logbuf_lock, which also refactors > and consolidates code from syslog_print_all() and > kmsg_dump_get_buffer(). While testing/verifying my series, I noticed the > these oddities in the semantics and decided I should research where they > came from and if they were actually necessary. Any chance you can put those tests somewhere public so that we can run them regularly? (say, before Petr sends out a pull request to Linus.) > I wouldn't say the oddities are necessary (in fact, they are quite > annoying), but we have decided to keep them in out of fear of breaking > out-of-tree modules and/or interesting userspace code. Sure. > One positive effect of the rework is that we are finding these oddities > and documenting them. Absolutely agree. -ss
Re: [PATCH] printk: fix buffer overflow potential for print_text()
On 2021-01-19, Sergey Senozhatsky wrote: > John, how did you spot these problems? I am preparing my series to remove the logbuf_lock, which also refactors and consolidates code from syslog_print_all() and kmsg_dump_get_buffer(). While testing/verifying my series, I noticed the these oddities in the semantics and decided I should research where they came from and if they were actually necessary. I wouldn't say the oddities are necessary (in fact, they are quite annoying), but we have decided to keep them in out of fear of breaking out-of-tree modules and/or interesting userspace code. One positive effect of the rework is that we are finding these oddities and documenting them. I think you and Petr are going down a similar path with the console registration stuff now. John
Re: [PATCH] printk: fix buffer overflow potential for print_text()
On (21/01/15 13:07), Petr Mladek wrote:
> On Fri 2021-01-15 13:04:37, Petr Mladek wrote:
> > On Thu 2021-01-14 18:10:12, John Ogness wrote:
> > > Before commit b6cf8b3f3312 ("printk: add lockless ringbuffer"),
> > > msg_print_text() would only write up to size-1 bytes into the
> > > provided buffer. Some callers expect this behavior and append
> > > a terminator to returned string. In particular:
> > >
> > > arch/powerpc/xmon/xmon.c:dump_log_buf()
> > > arch/um/kernel/kmsg_dump.c:kmsg_dumper_stdout()
> > >
> > > msg_print_text() has been replaced by record_print_text(), which
> > > currently fills the full size of the buffer. This causes a
> > > buffer overflow for the above callers.
> > >
> > > Change record_print_text() so that it will only use size-1 bytes
> > > for text data. Also, for paranoia sakes, add a terminator after
> > > the text data.
> > >
> > > And finally, document this behavior so that it is clear that only
> > > size-1 bytes are used and a terminator is added.
> > >
> > > Fixes: b6cf8b3f3312 ("printk: add lockless ringbuffer")
> > > Signed-off-by: John Ogness
John, how did you spot these problems?
FWIW, Acked-by: Sergey Senozhatsky
> I forgot one thing. We should add stable here:
>
> Cc: sta...@vger.kernel.org # 5.10+
Good point.
-ss
Re: [PATCH] printk: fix buffer overflow potential for print_text()
On Fri 2021-01-15 15:22:03, John Ogness wrote:
> Hi Petr,
>
> I noticed some minor errors in the commit log and comments...
>
> On 2021-01-14, John Ogness wrote:
> > Before commit b6cf8b3f3312 ("printk: add lockless ringbuffer"),
> > msg_print_text()
>
> Can you fixup the patch for the commit or do you need a v2?
I could fix these when pushing ;-)
Best Regards,
Petr
Re: [PATCH] printk: fix buffer overflow potential for print_text()
Hi Petr,
I noticed some minor errors in the commit log and comments...
On 2021-01-14, John Ogness wrote:
> Before commit b6cf8b3f3312 ("printk: add lockless ringbuffer"),
> msg_print_text()
The correct commit where the change was made is: 896fbe20b4e2333fb55
("printk: use the lockless ringbuffer")
> would only write up to size-1 bytes into the
> provided buffer. Some callers expect this behavior and append
> a terminator to returned string. In particular:
>
> arch/powerpc/xmon/xmon.c:dump_log_buf()
> arch/um/kernel/kmsg_dump.c:kmsg_dumper_stdout()
>
> msg_print_text() has been replaced by record_print_text(), which
> currently fills the full size of the buffer. This causes a
> buffer overflow for the above callers.
>
> Change record_print_text() so that it will only use size-1 bytes
> for text data. Also, for paranoia sakes, add a terminator after
> the text data.
>
> And finally, document this behavior so that it is clear that only
> size-1 bytes are used and a terminator is added.
>
> Fixes: b6cf8b3f3312 ("printk: add lockless ringbuffer")
Ditto for Fixes tag:
896fbe20b4e2333fb55 ("printk: use the lockless ringbuffer")
> Signed-off-by: John Ogness
> ---
> kernel/printk/printk.c | 35 +++
> 1 file changed, 27 insertions(+), 8 deletions(-)
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index ffdd0dc7ec6d..73f9eae19f05 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1293,9 +1293,15 @@ static size_t info_print_prefix(const struct
> printk_info *info, bool syslog,
> * - Add prefix for each line.
> * - Add the trailing newline that has been removed in vprintk_store().
> * - Drop truncated lines that do not longer fit into the buffer.
> + * - Add a trailing newline.
> + * - Add a string terminator.
I didn't realize that the newline was already listed (since it was out
of order). I recommend these comments changing to:
- Add prefix for each line.
- Drop truncated lines that no longer fit into the buffer.
- Add the trailing newline that has been removed in vprintk_store().
- Add a string terminator.
Can you fixup the patch for the commit or do you need a v2?
John Ogness
Re: [PATCH] printk: fix buffer overflow potential for print_text()
On Fri 2021-01-15 13:04:37, Petr Mladek wrote:
> On Thu 2021-01-14 18:10:12, John Ogness wrote:
> > Before commit b6cf8b3f3312 ("printk: add lockless ringbuffer"),
> > msg_print_text() would only write up to size-1 bytes into the
> > provided buffer. Some callers expect this behavior and append
> > a terminator to returned string. In particular:
> >
> > arch/powerpc/xmon/xmon.c:dump_log_buf()
> > arch/um/kernel/kmsg_dump.c:kmsg_dumper_stdout()
> >
> > msg_print_text() has been replaced by record_print_text(), which
> > currently fills the full size of the buffer. This causes a
> > buffer overflow for the above callers.
> >
> > Change record_print_text() so that it will only use size-1 bytes
> > for text data. Also, for paranoia sakes, add a terminator after
> > the text data.
> >
> > And finally, document this behavior so that it is clear that only
> > size-1 bytes are used and a terminator is added.
> >
> > Fixes: b6cf8b3f3312 ("printk: add lockless ringbuffer")
> > Signed-off-by: John Ogness
I forgot one thing. We should add stable here:
Cc: sta...@vger.kernel.org # 5.10+
No need to resend the patch. I'll add it when pushing the patch.
Best Regards,
Petr
Re: [PATCH] printk: fix buffer overflow potential for print_text()
On Thu 2021-01-14 18:10:12, John Ogness wrote:
> Before commit b6cf8b3f3312 ("printk: add lockless ringbuffer"),
> msg_print_text() would only write up to size-1 bytes into the
> provided buffer. Some callers expect this behavior and append
> a terminator to returned string. In particular:
>
> arch/powerpc/xmon/xmon.c:dump_log_buf()
> arch/um/kernel/kmsg_dump.c:kmsg_dumper_stdout()
>
> msg_print_text() has been replaced by record_print_text(), which
> currently fills the full size of the buffer. This causes a
> buffer overflow for the above callers.
>
> Change record_print_text() so that it will only use size-1 bytes
> for text data. Also, for paranoia sakes, add a terminator after
> the text data.
>
> And finally, document this behavior so that it is clear that only
> size-1 bytes are used and a terminator is added.
>
> Fixes: b6cf8b3f3312 ("printk: add lockless ringbuffer")
> Signed-off-by: John Ogness
Reviewed-by: Petr Mladek
Best Regards,
Petr
[PATCH] printk: fix buffer overflow potential for print_text()
Before commit b6cf8b3f3312 ("printk: add lockless ringbuffer"),
msg_print_text() would only write up to size-1 bytes into the
provided buffer. Some callers expect this behavior and append
a terminator to returned string. In particular:
arch/powerpc/xmon/xmon.c:dump_log_buf()
arch/um/kernel/kmsg_dump.c:kmsg_dumper_stdout()
msg_print_text() has been replaced by record_print_text(), which
currently fills the full size of the buffer. This causes a
buffer overflow for the above callers.
Change record_print_text() so that it will only use size-1 bytes
for text data. Also, for paranoia sakes, add a terminator after
the text data.
And finally, document this behavior so that it is clear that only
size-1 bytes are used and a terminator is added.
Fixes: b6cf8b3f3312 ("printk: add lockless ringbuffer")
Signed-off-by: John Ogness
---
kernel/printk/printk.c | 35 +++
1 file changed, 27 insertions(+), 8 deletions(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index ffdd0dc7ec6d..73f9eae19f05 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1293,9 +1293,15 @@ static size_t info_print_prefix(const struct printk_info
*info, bool syslog,
* - Add prefix for each line.
* - Add the trailing newline that has been removed in vprintk_store().
* - Drop truncated lines that do not longer fit into the buffer.
+ * - Add a trailing newline.
+ * - Add a string terminator.
+ *
+ * Since the produced string is always terminated, the maximum possible
+ * return value is @r->text_buf_size - 1;
*
* Return: The length of the updated/prepared text, including the added
- * prefixes and the newline. The dropped line(s) are not counted.
+ * prefixes and the newline. The terminator is not counted. The dropped
+ * line(s) are not counted.
*/
static size_t record_print_text(struct printk_record *r, bool syslog,
bool time)
@@ -1338,26 +1344,31 @@ static size_t record_print_text(struct printk_record
*r, bool syslog,
/*
* Truncate the text if there is not enough space to add the
-* prefix and a trailing newline.
+* prefix and a trailing newline and a terminator.
*/
- if (len + prefix_len + text_len + 1 > buf_size) {
+ if (len + prefix_len + text_len + 1 + 1 > buf_size) {
/* Drop even the current line if no space. */
- if (len + prefix_len + line_len + 1 > buf_size)
+ if (len + prefix_len + line_len + 1 + 1 > buf_size)
break;
- text_len = buf_size - len - prefix_len - 1;
+ text_len = buf_size - len - prefix_len - 1 - 1;
truncated = true;
}
memmove(text + prefix_len, text, text_len);
memcpy(text, prefix, prefix_len);
+ /*
+* Increment the prepared length to include the text and
+* prefix that were just moved+copied. Also increment for the
+* newline at the end of this line. If this is the last line,
+* there is no newline, but it will be added immediately below.
+*/
len += prefix_len + line_len + 1;
-
if (text_len == line_len) {
/*
-* Add the trailing newline removed in
-* vprintk_store().
+* This is the last line. Add the trailing newline
+* removed in vprintk_store().
*/
text[prefix_len + line_len] = '\n';
break;
@@ -1382,6 +1393,14 @@ static size_t record_print_text(struct printk_record *r,
bool syslog,
text_len -= line_len + 1;
}
+ /*
+* If a buffer was provided, it will be terminated. Space for the
+* string terminator is guaranteed to be available. The terminator is
+* not counted in the return value.
+*/
+ if (buf_size > 0)
+ text[len] = 0;
+
return len;
}
--
2.20.1
