All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCH] printk: fix buffer overflow potential for print_text()
@ 2021-01-14 17:04 John Ogness
  2021-01-15 12:04 ` Petr Mladek
                   ` (3 more replies)
  0 siblings, 4 replies; 19+ messages in thread
From: John Ogness @ 2021-01-14 17:04 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Sergey Senozhatsky, Steven Rostedt,
	Linus Torvalds, linux-kernel

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.ogness@linutronix.de>
---
 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


^ permalink raw reply related	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-14 17:04 [PATCH] printk: fix buffer overflow potential for print_text() John Ogness
@ 2021-01-15 12:04 ` Petr Mladek
  2021-01-15 12:07   ` Petr Mladek
  2021-01-15 14:16 ` John Ogness
                   ` (2 subsequent siblings)
  3 siblings, 1 reply; 19+ messages in thread
From: Petr Mladek @ 2021-01-15 12:04 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Sergey Senozhatsky, Steven Rostedt,
	Linus Torvalds, linux-kernel

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.ogness@linutronix.de>

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-15 12:04 ` Petr Mladek
@ 2021-01-15 12:07   ` Petr Mladek
  2021-01-19  0:44     ` Sergey Senozhatsky
  0 siblings, 1 reply; 19+ messages in thread
From: Petr Mladek @ 2021-01-15 12:07 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Sergey Senozhatsky, Steven Rostedt,
	Linus Torvalds, linux-kernel

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.ogness@linutronix.de>

I forgot one thing. We should add stable here:

Cc: stable@vger.kernel.org # 5.10+

No need to resend the patch. I'll add it when pushing the patch.

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-14 17:04 [PATCH] printk: fix buffer overflow potential for print_text() John Ogness
  2021-01-15 12:04 ` Petr Mladek
@ 2021-01-15 14:16 ` John Ogness
  2021-01-15 16:04   ` Petr Mladek
  2021-01-22 21:21 ` Sven Schnelle
  2021-02-26 17:19 ` Alexander Gordeev
  3 siblings, 1 reply; 19+ messages in thread
From: John Ogness @ 2021-01-15 14:16 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Sergey Senozhatsky, Steven Rostedt,
	Linus Torvalds, linux-kernel

Hi Petr,

I noticed some minor errors in the commit log and comments...

On 2021-01-14, John Ogness <john.ogness@linutronix.de> 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 <john.ogness@linutronix.de>
> ---
>  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

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-15 14:16 ` John Ogness
@ 2021-01-15 16:04   ` Petr Mladek
  0 siblings, 0 replies; 19+ messages in thread
From: Petr Mladek @ 2021-01-15 16:04 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Sergey Senozhatsky, Steven Rostedt,
	Linus Torvalds, linux-kernel

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 <john.ogness@linutronix.de> 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

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-15 12:07   ` Petr Mladek
@ 2021-01-19  0:44     ` Sergey Senozhatsky
  2021-01-19  8:54       ` John Ogness
  2021-01-19 11:20       ` Petr Mladek
  0 siblings, 2 replies; 19+ messages in thread
From: Sergey Senozhatsky @ 2021-01-19  0:44 UTC (permalink / raw)
  To: Petr Mladek
  Cc: John Ogness, Sergey Senozhatsky, Sergey Senozhatsky,
	Steven Rostedt, Linus Torvalds, linux-kernel

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.ogness@linutronix.de>

John, how did you spot these problems?

FWIW, Acked-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>

> I forgot one thing. We should add stable here:
> 
> Cc: stable@vger.kernel.org # 5.10+

Good point.

	-ss

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-19  0:44     ` Sergey Senozhatsky
@ 2021-01-19  8:54       ` John Ogness
  2021-01-19 10:29         ` Sergey Senozhatsky
  2021-01-19 11:20       ` Petr Mladek
  1 sibling, 1 reply; 19+ messages in thread
From: John Ogness @ 2021-01-19  8:54 UTC (permalink / raw)
  To: Sergey Senozhatsky, Petr Mladek
  Cc: Sergey Senozhatsky, Sergey Senozhatsky, Steven Rostedt,
	Linus Torvalds, linux-kernel

On 2021-01-19, Sergey Senozhatsky <sergey.senozhatsky@gmail.com> 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

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-19  8:54       ` John Ogness
@ 2021-01-19 10:29         ` Sergey Senozhatsky
  2021-01-19 11:44           ` John Ogness
  0 siblings, 1 reply; 19+ messages in thread
From: Sergey Senozhatsky @ 2021-01-19 10:29 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Petr Mladek, Sergey Senozhatsky,
	Steven Rostedt, Linus Torvalds, linux-kernel

On (21/01/19 10:00), John Ogness wrote:
> On 2021-01-19, Sergey Senozhatsky <sergey.senozhatsky@gmail.com> 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

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-19  0:44     ` Sergey Senozhatsky
  2021-01-19  8:54       ` John Ogness
@ 2021-01-19 11:20       ` Petr Mladek
  1 sibling, 0 replies; 19+ messages in thread
From: Petr Mladek @ 2021-01-19 11:20 UTC (permalink / raw)
  To: Sergey Senozhatsky
  Cc: John Ogness, Sergey Senozhatsky, Steven Rostedt, Linus Torvalds,
	linux-kernel

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.ogness@linutronix.de>
> 
> John, how did you spot these problems?
> 
> FWIW, Acked-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>

The patch has been committed into printk/linux.git, branch
printk-rework.

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-19 10:29         ` Sergey Senozhatsky
@ 2021-01-19 11:44           ` John Ogness
  2021-01-19 12:22             ` Petr Mladek
  0 siblings, 1 reply; 19+ messages in thread
From: John Ogness @ 2021-01-19 11:44 UTC (permalink / raw)
  To: Sergey Senozhatsky
  Cc: Sergey Senozhatsky, Petr Mladek, Sergey Senozhatsky,
	Steven Rostedt, Linus Torvalds, linux-kernel

On 2021-01-19, Sergey Senozhatsky <sergey.senozhatsky@gmail.com> 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

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-19 11:44           ` John Ogness
@ 2021-01-19 12:22             ` Petr Mladek
  0 siblings, 0 replies; 19+ messages in thread
From: Petr Mladek @ 2021-01-19 12:22 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Sergey Senozhatsky, Steven Rostedt,
	Linus Torvalds, linux-kernel

On Tue 2021-01-19 12:50:47, John Ogness wrote:
> On 2021-01-19, Sergey Senozhatsky <sergey.senozhatsky@gmail.com> 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

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-14 17:04 [PATCH] printk: fix buffer overflow potential for print_text() John Ogness
  2021-01-15 12:04 ` Petr Mladek
  2021-01-15 14:16 ` John Ogness
@ 2021-01-22 21:21 ` Sven Schnelle
  2021-01-22 23:42   ` John Ogness
  2021-02-26 17:19 ` Alexander Gordeev
  3 siblings, 1 reply; 19+ messages in thread
From: Sven Schnelle @ 2021-01-22 21:21 UTC (permalink / raw)
  To: John Ogness
  Cc: Petr Mladek, Sergey Senozhatsky, Sergey Senozhatsky,
	Steven Rostedt, Linus Torvalds, linux-kernel

John Ogness <john.ogness@linutronix.de> 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 <john.ogness@linutronix.de>
> ---
> [..]

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 = 0xe320f0a00004e320, 
  exit = 0x208e0094eb112000, 
  match = 0xcec1c006e017f, 
  flags = -4984, 
  index = 133, 
  cflag = 8143136, 
  data = 0x800458108004ec12, 
  next = 0x5007eaf000000
}

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      : 0x0002000180000000 0x0000000078c8400e
  -function : stop_run at 78c8400e
  -prefix   : 0x0041e000
  -cpu timer: 0x7ffff953a957e166
  -clock cmp: 0xd92876863ac66b00
  -general registers:
     0xf0f0f0f000000000 0x0000000078c8400e
     0x0000000079984830 0x0000000079984830
     0x0000000079ac62c0 0x0000000000000002
     0x0000000000000038 000000000000000000
     0x000000007a19157e 000000000000000000
     0x00000000fffffffa 000000000000000000
     0x00000000dad24000 000000000000000000
     0x0000000078c8416e 0x00000380033136f0
  -access registers:
     0x7d5b4da0 0xa2a795c0 0000000000 0000000000
     0000000000 0000000000 0000000000 0000000000
     0000000000 0000000000 0000000000 0000000000
     0000000000 0000000000 0000000000 0000000000
  -control registers:
     0x00a0000014966a10 0x000000007a15c007
     0x000000000001d0a0 000000000000000000
     0x000000000000ffff 0x000000000001d080
     0x000000003b000000 0x00000001f29b81c7
     0x0000000000008000 000000000000000000
     000000000000000000 000000000000000000
     000000000000000000 0x000000007a15c007
     0x00000000db000000 0x000000000001d0c0
  -floating point registers:
     0x5faaaaabeb67f92f 0x0007fffffffffff8
     0x40400000eb67f000 000000000000000000
     0x0000000000000007 0x0000006400000000
     0x000002aa2a63f028 0x000000000963cf85
     0x000000002a642c60 000000000000000000
     0x7f85516ceb67f222 0x000003ffeb67f528
     0x000003ffeb67f230 0x0000000100000000
     0x000003ffeb67f21d 0x000002aa28d2d970

 #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:  0404c00180000000 0000000078d304ba (kmsg_dump_rewind+290)
 GPRS: 0000000000000020 0000000000000000 0000000000000000 00000000ffffec88 
       000000000000000e 00000000793f4800 0000000000000224 0000000000000000 
       0000000000000000 0000000000000000 0000000000000224 0005007eaf000000 
       00000000dad24000 0000000000000000 0000038003313a68 0000038003313a18 
 #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:  0705300080000000 000000007d7983b2 (user space)
 GPRS: 0000000000000000 000000007d798360 0000000000000010 000003ff00000004 
       000000007f854dd0 000000007d7e9788 000003ff00401b30 000000007f854ff8 
       000003ff00000000 000003ff7d5b4da0 000003ff00000000 000003ff00000010 
       000003ff004022c6 000003ff004024b0 0000000080401796 000000007f854de8

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.

Thanks
Sven

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-22 21:21 ` Sven Schnelle
@ 2021-01-22 23:42   ` John Ogness
  2021-01-23 21:18     ` Sven Schnelle
  0 siblings, 1 reply; 19+ messages in thread
From: John Ogness @ 2021-01-22 23:42 UTC (permalink / raw)
  To: Sven Schnelle
  Cc: Petr Mladek, Sergey Senozhatsky, Sergey Senozhatsky,
	Steven Rostedt, Linus Torvalds, linux-kernel

On 2021-01-22, Sven Schnelle <svens@linux.ibm.com> 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 = 0xe320f0a00004e320, 
>   exit = 0x208e0094eb112000, 
>   match = 0xcec1c006e017f, 
>   flags = -4984, 
>   index = 133, 
>   cflag = 8143136, 
>   data = 0x800458108004ec12, 
>   next = 0x5007eaf000000
> }
>
> 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      : 0x0002000180000000 0x0000000078c8400e
>   -function : stop_run at 78c8400e
>   -prefix   : 0x0041e000
>   -cpu timer: 0x7ffff953a957e166
>   -clock cmp: 0xd92876863ac66b00
>   -general registers:
>      0xf0f0f0f000000000 0x0000000078c8400e
>      0x0000000079984830 0x0000000079984830
>      0x0000000079ac62c0 0x0000000000000002
>      0x0000000000000038 000000000000000000
>      0x000000007a19157e 000000000000000000
>      0x00000000fffffffa 000000000000000000
>      0x00000000dad24000 000000000000000000
>      0x0000000078c8416e 0x00000380033136f0
>   -access registers:
>      0x7d5b4da0 0xa2a795c0 0000000000 0000000000
>      0000000000 0000000000 0000000000 0000000000
>      0000000000 0000000000 0000000000 0000000000
>      0000000000 0000000000 0000000000 0000000000
>   -control registers:
>      0x00a0000014966a10 0x000000007a15c007
>      0x000000000001d0a0 000000000000000000
>      0x000000000000ffff 0x000000000001d080
>      0x000000003b000000 0x00000001f29b81c7
>      0x0000000000008000 000000000000000000
>      000000000000000000 000000000000000000
>      000000000000000000 0x000000007a15c007
>      0x00000000db000000 0x000000000001d0c0
>   -floating point registers:
>      0x5faaaaabeb67f92f 0x0007fffffffffff8
>      0x40400000eb67f000 000000000000000000
>      0x0000000000000007 0x0000006400000000
>      0x000002aa2a63f028 0x000000000963cf85
>      0x000000002a642c60 000000000000000000
>      0x7f85516ceb67f222 0x000003ffeb67f528
>      0x000003ffeb67f230 0x0000000100000000
>      0x000003ffeb67f21d 0x000002aa28d2d970
>
>  #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:  0404c00180000000 0000000078d304ba (kmsg_dump_rewind+290)
>  GPRS: 0000000000000020 0000000000000000 0000000000000000 00000000ffffec88 
>        000000000000000e 00000000793f4800 0000000000000224 0000000000000000 
>        0000000000000000 0000000000000000 0000000000000224 0005007eaf000000 
>        00000000dad24000 0000000000000000 0000038003313a68 0000038003313a18 
>  #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:  0705300080000000 000000007d7983b2 (user space)
>  GPRS: 0000000000000000 000000007d798360 0000000000000010 000003ff00000004 
>        000000007f854dd0 000000007d7e9788 000003ff00401b30 000000007f854ff8 
>        000003ff00000000 000003ff7d5b4da0 000003ff00000000 000003ff00000010 
>        000003ff004022c6 000003ff004024b0 0000000080401796 000000007f854de8
>
> 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?

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.

John Ogness

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-22 23:42   ` John Ogness
@ 2021-01-23 21:18     ` Sven Schnelle
  2021-01-23 21:41       ` Sven Schnelle
  0 siblings, 1 reply; 19+ messages in thread
From: Sven Schnelle @ 2021-01-23 21:18 UTC (permalink / raw)
  To: John Ogness
  Cc: Petr Mladek, Sergey Senozhatsky, Sergey Senozhatsky,
	Steven Rostedt, Linus Torvalds, linux-kernel

John Ogness <john.ogness@linutronix.de> writes:

> On 2021-01-22, Sven Schnelle <svens@linux.ibm.com> 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 : 0705300080000000 000000007d7983b2
[ 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: 0000000000000000 000000007d798360 0000000000000010 000003ff00000004
[ 1845.640485]            000000007f854dd0 000000007d7e9788 000003ff00401b30 000000007f854ff8
[ 1845.640487]            000003ff00000000 000003ff7d5b4da0 000003ff00000000 000003ff00000010
[ 1845.640489]            000003ff004022c6 000003ff004024b0 0000000080401796 000000007f854de8

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:  -> 00000000001B8814"  MVI     92001000 >> 000000000163F1CD     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;
1403	
1404		return len;
1405	}
1406

In s390 assembly, this is the store:

   0x00000000001b8810 <+0x130>:	la	%r1,0(%r7,%r9)
   0x00000000001b8814 <+0x134>:	mvi	0(%r1),0

The cpu registers at the time of write:

01: GRG  0 =  0000000000000020  000000000163F1CD
01: GRG  2 =  0000000000000042  000003E000623A98
01: GRG  4 =  000000000000000E  000000000087BB70
01: GRG  6 =  0000000000000400  *0000000000000224*
01: GRG  8 =  000000000000000F  *000000000163EFA9*
01: GRG 10 =  0000000000000033  0000000000000000
01: GRG 12 =  00000000809AE000  000003E000623A98
01: GRG 14 =  00000000001B884C  000003E0006239E8

So r9 is 000000000163EFA9 - seems to be the start of the current message:

0163EFA9:  *[   24.069514]            000000007d7af3c2: b30d0002..debr.%f0,%f2.debr.%f0,%f2

while r7 is the offset, and that one is way to big:

0000000000000224

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: 000000007d7af3ba: 78005000            le      %f0,0(%r5) 
[   23.960773]            000000007d7af3be: 78205004            le      %f2,4(%r5) 
[   23.960773]           #000000007d7af3c2: b30d0002            debr    %f0,%f2 
[   23.960773]           >000000007d7af3c6: a7280000            lhi     %r2,0 
[   23.960773]            000000007d7af3ca: 07fe                bcr     15,%r14 
[   23.960773]            000000007d7af3cc: 0707                bcr     0,%r7 
[   23.960773]            000000007d7af3ce: 0707                bcr     0,%r7 
[   23.960773]            000000007d7af3d0: c050000289ec        larl    %r5,000000007d8007a8 

I'm pretty sure it's related to the way how the s390 disassembler
prints the buffer, it uses several pr_cont() calls, and it's crashing in the
last pr_cont("\n") (in arch/s390/kernel/dis.c - show_code());

I'm trying to get the content of the log buffer and other state, if
there's anything else i can provide let me know.


^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-23 21:18     ` Sven Schnelle
@ 2021-01-23 21:41       ` Sven Schnelle
  2021-01-24  8:13         ` John Ogness
  0 siblings, 1 reply; 19+ messages in thread
From: Sven Schnelle @ 2021-01-23 21:41 UTC (permalink / raw)
  To: John Ogness
  Cc: Petr Mladek, Sergey Senozhatsky, Sergey Senozhatsky,
	Steven Rostedt, Linus Torvalds, linux-kernel

Sven Schnelle <svens@linux.ibm.com> writes:

> John Ogness <john.ogness@linutronix.de> writes:
>
>> On 2021-01-22, Sven Schnelle <svens@linux.ibm.com> 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:  -> 00000000001B8814"  MVI     92001000 >> 000000000163F1CD     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
>


^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-23 21:41       ` Sven Schnelle
@ 2021-01-24  8:13         ` John Ogness
  2021-01-24  8:59           ` Sven Schnelle
  0 siblings, 1 reply; 19+ messages in thread
From: John Ogness @ 2021-01-24  8:13 UTC (permalink / raw)
  To: Sven Schnelle
  Cc: Petr Mladek, Sergey Senozhatsky, Sergey Senozhatsky,
	Steven Rostedt, Linus Torvalds, linux-kernel

Hi Sven,

Thanks for the outstanding analysis!

On 2021-01-23, Sven Schnelle <svens@linux.ibm.com> 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

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-24  8:13         ` John Ogness
@ 2021-01-24  8:59           ` Sven Schnelle
  0 siblings, 0 replies; 19+ messages in thread
From: Sven Schnelle @ 2021-01-24  8:59 UTC (permalink / raw)
  To: John Ogness
  Cc: Petr Mladek, Sergey Senozhatsky, Sergey Senozhatsky,
	Steven Rostedt, Linus Torvalds, linux-kernel

John Ogness <john.ogness@linutronix.de> writes:

> Hi Sven,
>
> Thanks for the outstanding analysis!
>
> On 2021-01-23, Sven Schnelle <svens@linux.ibm.com> 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).

Please go ahead, thank you!

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-01-14 17:04 [PATCH] printk: fix buffer overflow potential for print_text() John Ogness
                   ` (2 preceding siblings ...)
  2021-01-22 21:21 ` Sven Schnelle
@ 2021-02-26 17:19 ` Alexander Gordeev
  2021-02-26 17:39   ` John Ogness
  3 siblings, 1 reply; 19+ messages in thread
From: Alexander Gordeev @ 2021-02-26 17:19 UTC (permalink / raw)
  To: John Ogness
  Cc: Petr Mladek, Sergey Senozhatsky, Sergey Senozhatsky,
	Steven Rostedt, Linus Torvalds, linux-kernel, Sven Schnelle

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 <john.ogness@linutronix.de>
> ---
>  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 00000000bf9e6992 by task swapper/0/1

Reverting the patch shuts the complain.

> +
>  	return len;
>  }
>  
> -- 
> 2.20.1
> 

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH] printk: fix buffer overflow potential for print_text()
  2021-02-26 17:19 ` Alexander Gordeev
@ 2021-02-26 17:39   ` John Ogness
  0 siblings, 0 replies; 19+ messages in thread
From: John Ogness @ 2021-02-26 17:39 UTC (permalink / raw)
  To: Alexander Gordeev
  Cc: Petr Mladek, Sergey Senozhatsky, Sergey Senozhatsky,
	Steven Rostedt, Linus Torvalds, linux-kernel, Sven Schnelle

On 2021-02-26, Alexander Gordeev <agordeev@linux.ibm.com> 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

^ permalink raw reply	[flat|nested] 19+ messages in thread

end of thread, other threads:[~2021-02-26 17:40 UTC | newest]

Thread overview: 19+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-01-14 17:04 [PATCH] printk: fix buffer overflow potential for print_text() John Ogness
2021-01-15 12:04 ` Petr Mladek
2021-01-15 12:07   ` Petr Mladek
2021-01-19  0:44     ` Sergey Senozhatsky
2021-01-19  8:54       ` John Ogness
2021-01-19 10:29         ` Sergey Senozhatsky
2021-01-19 11:44           ` John Ogness
2021-01-19 12:22             ` Petr Mladek
2021-01-19 11:20       ` Petr Mladek
2021-01-15 14:16 ` John Ogness
2021-01-15 16:04   ` Petr Mladek
2021-01-22 21:21 ` Sven Schnelle
2021-01-22 23:42   ` John Ogness
2021-01-23 21:18     ` Sven Schnelle
2021-01-23 21:41       ` Sven Schnelle
2021-01-24  8:13         ` John Ogness
2021-01-24  8:59           ` Sven Schnelle
2021-02-26 17:19 ` Alexander Gordeev
2021-02-26 17:39   ` John Ogness

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.