2020-09-30 09:04:18

by John Ogness

[permalink] [raw]
Subject: [PATCH next v2 1/2] printk: avoid and/or handle record truncation

If a reader provides a buffer that is smaller than the message text,
the @text_len field of @info will have a value larger than the buffer
size. If readers blindly read @text_len bytes of data without
checking the size, they will read beyond their buffer.

Add this check to record_print_text() to properly recognize when such
truncation has occurred.

Add a maximum size argument to the ringbuffer function to extend
records so that records can not be created that are larger than the
buffer size of readers.

When extending records (LOG_CONT), do not extend records beyond
LOG_LINE_MAX since that is the maximum size available in the buffers
used by consoles and syslog.

Fixes: f5f022e53b87 ("printk: reimplement log_cont using record extension")
Signed-off-by: John Ogness <[email protected]>
Reported-by: Marek Szyprowski <[email protected]>
---
kernel/printk/printk.c | 9 ++++++++-
kernel/printk/printk_ringbuffer.c | 12 ++++++++++--
kernel/printk/printk_ringbuffer.h | 2 +-
3 files changed, 19 insertions(+), 4 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 78f68b4830dc..04cf1e00478f 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1357,6 +1357,13 @@ static size_t record_print_text(struct printk_record *r, bool syslog,
size_t len = 0;
char *next;

+ /*
+ * If the message was truncated because the buffer was not large
+ * enough, treat the available text as if it were the full text.
+ */
+ if (text_len > buf_size)
+ text_len = buf_size;
+
prefix_len = info_print_prefix(r->info, syslog, time, prefix);

/*
@@ -1911,7 +1918,7 @@ static size_t log_output(int facility, int level, enum log_flags lflags,
struct printk_record r;

prb_rec_init_wr(&r, text_len);
- if (prb_reserve_in_last(&e, prb, &r, caller_id)) {
+ if (prb_reserve_in_last(&e, prb, &r, caller_id, LOG_LINE_MAX)) {
memcpy(&r.text_buf[r.info->text_len], text, text_len);
r.info->text_len += text_len;
if (lflags & LOG_NEWLINE) {
diff --git a/kernel/printk/printk_ringbuffer.c b/kernel/printk/printk_ringbuffer.c
index 13b94b92342e..2493348a1631 100644
--- a/kernel/printk/printk_ringbuffer.c
+++ b/kernel/printk/printk_ringbuffer.c
@@ -202,7 +202,8 @@
* // specify additional 5 bytes text space to extend
* prb_rec_init_wr(&r, 5);
*
- * if (prb_reserve_in_last(&e, &test_rb, &r, printk_caller_id())) {
+ * // try to extend, but only if it does not exceed 32 bytes
+ * if (prb_reserve_in_last(&e, &test_rb, &r, printk_caller_id()), 32) {
* snprintf(&r.text_buf[r.info->text_len],
* r.text_buf_size - r.info->text_len, "hello");
*
@@ -1309,6 +1310,7 @@ static struct prb_desc *desc_reopen_last(struct prb_desc_ring *desc_ring,
* @rb: The ringbuffer to re-reserve and extend data in.
* @r: The record structure to allocate buffers for.
* @caller_id: The caller ID of the caller (reserving writer).
+ * @max_size: Fail if the extended size would be greater than this.
*
* This is the public function available to writers to re-reserve and extend
* data.
@@ -1343,7 +1345,7 @@ static struct prb_desc *desc_reopen_last(struct prb_desc_ring *desc_ring,
* @r->info->text_len after concatenating.
*/
bool prb_reserve_in_last(struct prb_reserved_entry *e, struct printk_ringbuffer *rb,
- struct printk_record *r, u32 caller_id)
+ struct printk_record *r, u32 caller_id, unsigned int max_size)
{
struct prb_desc_ring *desc_ring = &rb->desc_ring;
struct printk_info *info;
@@ -1389,6 +1391,9 @@ bool prb_reserve_in_last(struct prb_reserved_entry *e, struct printk_ringbuffer
if (!data_check_size(&rb->text_data_ring, r->text_buf_size))
goto fail;

+ if (r->text_buf_size > max_size)
+ goto fail;
+
r->text_buf = data_alloc(rb, &rb->text_data_ring, r->text_buf_size,
&d->text_blk_lpos, id);
} else {
@@ -1410,6 +1415,9 @@ bool prb_reserve_in_last(struct prb_reserved_entry *e, struct printk_ringbuffer
if (!data_check_size(&rb->text_data_ring, r->text_buf_size))
goto fail;

+ if (r->text_buf_size > max_size)
+ goto fail;
+
r->text_buf = data_realloc(rb, &rb->text_data_ring, r->text_buf_size,
&d->text_blk_lpos, id);
}
diff --git a/kernel/printk/printk_ringbuffer.h b/kernel/printk/printk_ringbuffer.h
index 0adaa685d1ca..5dc9d022db07 100644
--- a/kernel/printk/printk_ringbuffer.h
+++ b/kernel/printk/printk_ringbuffer.h
@@ -303,7 +303,7 @@ static inline void prb_rec_init_wr(struct printk_record *r,
bool prb_reserve(struct prb_reserved_entry *e, struct printk_ringbuffer *rb,
struct printk_record *r);
bool prb_reserve_in_last(struct prb_reserved_entry *e, struct printk_ringbuffer *rb,
- struct printk_record *r, u32 caller_id);
+ struct printk_record *r, u32 caller_id, unsigned int max_size);
void prb_commit(struct prb_reserved_entry *e);
void prb_final_commit(struct prb_reserved_entry *e);

--
2.20.1


2020-09-30 09:45:36

by Sergey Senozhatsky

[permalink] [raw]
Subject: Re: [PATCH next v2 1/2] printk: avoid and/or handle record truncation

On (20/09/30 11:07), John Ogness wrote:
[..]
> @@ -1389,6 +1391,9 @@ bool prb_reserve_in_last(struct prb_reserved_entry *e, struct printk_ringbuffer
> if (!data_check_size(&rb->text_data_ring, r->text_buf_size))
> goto fail;
>
> + if (r->text_buf_size > max_size)
> + goto fail;
> +
> r->text_buf = data_alloc(rb, &rb->text_data_ring, r->text_buf_size,
> &d->text_blk_lpos, id);
> } else {
> @@ -1410,6 +1415,9 @@ bool prb_reserve_in_last(struct prb_reserved_entry *e, struct printk_ringbuffer
> if (!data_check_size(&rb->text_data_ring, r->text_buf_size))
> goto fail;
>
> + if (r->text_buf_size > max_size)
> + goto fail;
> +
> r->text_buf = data_realloc(rb, &rb->text_data_ring, r->text_buf_size,
> &d->text_blk_lpos, id);
> }
[..]

> bool prb_reserve_in_last(struct prb_reserved_entry *e, struct printk_ringbuffer *rb,
> - struct printk_record *r, u32 caller_id);
> + struct printk_record *r, u32 caller_id, unsigned int max_size);

Isn't `max_size' always LOG_LINE_MAX?

-ss

2020-09-30 10:26:22

by John Ogness

[permalink] [raw]
Subject: Re: [PATCH next v2 1/2] printk: avoid and/or handle record truncation

On 2020-09-30, Sergey Senozhatsky <[email protected]> wrote:
> On (20/09/30 11:07), John Ogness wrote:
>> bool prb_reserve_in_last(struct prb_reserved_entry *e, struct printk_ringbuffer *rb,
>> - struct printk_record *r, u32 caller_id);
>> + struct printk_record *r, u32 caller_id, unsigned int max_size);
>
> Isn't `max_size' always LOG_LINE_MAX?

Yes. But I still think it makes sense that it is an argument of the
function. It is quite an important setting and hard-coding it within the
ringbuffer code might lead to hidden problems later.

John Ogness

2020-09-30 11:32:03

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH next v2 1/2] printk: avoid and/or handle record truncation

On Wed 2020-09-30 12:30:50, John Ogness wrote:
> On 2020-09-30, Sergey Senozhatsky <[email protected]> wrote:
> > On (20/09/30 11:07), John Ogness wrote:
> >> bool prb_reserve_in_last(struct prb_reserved_entry *e, struct printk_ringbuffer *rb,
> >> - struct printk_record *r, u32 caller_id);
> >> + struct printk_record *r, u32 caller_id, unsigned int max_size);
> >
> > Isn't `max_size' always LOG_LINE_MAX?
>
> Yes. But I still think it makes sense that it is an argument of the
> function. It is quite an important setting and hard-coding it within the
> ringbuffer code might lead to hidden problems later.

I personally prefer the argument as well.

It is true that printk_ringbuffer is not a fully generic ringbuffer.
It has very special behavior so that it can be hardly be used
anywhere else.

Sometimes it is not clear what printk() requirements should be passed via
the API or hardcoded into the ring buffer code. IMHO, it depends on the code
complexity.

Anyway, I see hardcoded limit more like a hack. It limits something
somewhere so that some other code somewhere else is safe to use.

And printk.c is really bad from this point. It sometimes does not
check for overflow because it "knows" that the buffers are big
enough. But it is error prone code, especially when there are more
limits defined (pure text, prefix, extended prefix). And it
will be worse if we allow to add more optional information
into the prefix.

Best Regards,
Petr

2020-09-30 11:46:22

by John Ogness

[permalink] [raw]
Subject: Re: [PATCH next v2 1/2] printk: avoid and/or handle record truncation

On 2020-09-30, Petr Mladek <[email protected]> wrote:
> Anyway, I see hardcoded limit more like a hack. It limits something
> somewhere so that some other code somewhere else is safe to use.
>
> And printk.c is really bad from this point. It sometimes does not
> check for overflow because it "knows" that the buffers are big
> enough. But it is error prone code, especially when there are more
> limits defined (pure text, prefix, extended prefix). And it
> will be worse if we allow to add more optional information
> into the prefix.

So should I post a v3 where the checks are added? Or should I add
comments where checks would be, explaining why the checks are not
needed?

John Ogness

2020-09-30 11:54:56

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH next v2 1/2] printk: avoid and/or handle record truncation

On Wed 2020-09-30 13:48:56, John Ogness wrote:
> On 2020-09-30, Petr Mladek <[email protected]> wrote:
> > Anyway, I see hardcoded limit more like a hack. It limits something
> > somewhere so that some other code somewhere else is safe to use.
> >
> > And printk.c is really bad from this point. It sometimes does not
> > check for overflow because it "knows" that the buffers are big
> > enough. But it is error prone code, especially when there are more
> > limits defined (pure text, prefix, extended prefix). And it
> > will be worse if we allow to add more optional information
> > into the prefix.
>
> So should I post a v3 where the checks are added? Or should I add
> comments where checks would be, explaining why the checks are not
> needed?

If you have these locations still in head then it would be nice
to add the checks.

But it is not urgent. We should be on the safe side. Both ways
to store new messages are limited again now.

Anyway, please do so in a followup patch. I would like to push this
patchset into linux-next ASAP so that the robots could continue
finding new bugs.

Best Regards,
Petr

2020-09-30 13:32:12

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH next v2 1/2] printk: avoid and/or handle record truncation

On Wed 2020-09-30 11:07:33, John Ogness wrote:
> If a reader provides a buffer that is smaller than the message text,
> the @text_len field of @info will have a value larger than the buffer
> size. If readers blindly read @text_len bytes of data without
> checking the size, they will read beyond their buffer.
>
> Add this check to record_print_text() to properly recognize when such
> truncation has occurred.
>
> Add a maximum size argument to the ringbuffer function to extend
> records so that records can not be created that are larger than the
> buffer size of readers.
>
> When extending records (LOG_CONT), do not extend records beyond
> LOG_LINE_MAX since that is the maximum size available in the buffers
> used by consoles and syslog.
>
> Fixes: f5f022e53b87 ("printk: reimplement log_cont using record extension")
> Signed-off-by: John Ogness <[email protected]>
> Reported-by: Marek Szyprowski <[email protected]>

Reviewed-by: Petr Mladek <[email protected]>

Best Regards,
Petr

2020-09-30 15:26:51

by Joe Perches

[permalink] [raw]
Subject: Re: [PATCH next v2 1/2] printk: avoid and/or handle record truncation

On Wed, 2020-09-30 at 11:07 +0206, John Ogness wrote:
> If a reader provides a buffer that is smaller than the message text,
> the @text_len field of @info will have a value larger than the buffer
> size. If readers blindly read @text_len bytes of data without
> checking the size, they will read beyond their buffer.
>
> Add this check to record_print_text() to properly recognize when such
> truncation has occurred.
>
> Add a maximum size argument to the ringbuffer function to extend
> records so that records can not be created that are larger than the
> buffer size of readers.
>
> When extending records (LOG_CONT), do not extend records beyond
> LOG_LINE_MAX since that is the maximum size available in the buffers
> used by consoles and syslog.

I still think it better to support backspace by rewinding
the buffer rather than truncation of the output.


2020-10-01 01:09:23

by Sergey Senozhatsky

[permalink] [raw]
Subject: Re: [PATCH next v2 1/2] printk: avoid and/or handle record truncation

On (20/09/30 13:53), Petr Mladek wrote:
>
> Anyway, please do so in a followup patch. I would like to push this
> patchset into linux-next ASAP so that the robots could continue
> finding new bugs.

ACK.

-ss

2020-10-01 07:28:33

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH next v2 1/2] printk: avoid and/or handle record truncation

On Wed 2020-09-30 08:25:24, Joe Perches wrote:
> On Wed, 2020-09-30 at 11:07 +0206, John Ogness wrote:
> > If a reader provides a buffer that is smaller than the message text,
> > the @text_len field of @info will have a value larger than the buffer
> > size. If readers blindly read @text_len bytes of data without
> > checking the size, they will read beyond their buffer.
> >
> > Add this check to record_print_text() to properly recognize when such
> > truncation has occurred.
> >
> > Add a maximum size argument to the ringbuffer function to extend
> > records so that records can not be created that are larger than the
> > buffer size of readers.
> >
> > When extending records (LOG_CONT), do not extend records beyond
> > LOG_LINE_MAX since that is the maximum size available in the buffers
> > used by consoles and syslog.
>
> I still think it better to support backspace by rewinding
> the buffer rather than truncation of the output.

IMHO, backspace support is not worth the complexity. It might do
some fancy animation on console but it does not bring any advantage
in static logs (dmesg, journalctl).

It is possible that it worked in the past when the log buffer was
just an array of characters that were pushed to the console when
they appeared.

But I am pretty sure that it has stopped working many years ago when
the buffer 7ff9554bb578 ("printk: convert byte-buffer to
variable-length record buffer").

Best Regards,
Petr

2020-10-01 07:41:47

by Joe Perches

[permalink] [raw]
Subject: Re: [PATCH next v2 1/2] printk: avoid and/or handle record truncation

On Thu, 2020-10-01 at 09:26 +0200, Petr Mladek wrote:
> On Wed 2020-09-30 08:25:24, Joe Perches wrote:
> > On Wed, 2020-09-30 at 11:07 +0206, John Ogness wrote:
> > > If a reader provides a buffer that is smaller than the message text,
> > > the @text_len field of @info will have a value larger than the buffer
> > > size. If readers blindly read @text_len bytes of data without
> > > checking the size, they will read beyond their buffer.
> > >
> > > Add this check to record_print_text() to properly recognize when such
> > > truncation has occurred.
> > >
> > > Add a maximum size argument to the ringbuffer function to extend
> > > records so that records can not be created that are larger than the
> > > buffer size of readers.
> > >
> > > When extending records (LOG_CONT), do not extend records beyond
> > > LOG_LINE_MAX since that is the maximum size available in the buffers
> > > used by consoles and syslog.
> >
> > I still think it better to support backspace by rewinding
> > the buffer rather than truncation of the output.
>
> IMHO, backspace support is not worth the complexity. It might do
> some fancy animation on console but it does not bring any advantage
> in static logs (dmesg, journalctl).
>
> It is possible that it worked in the past when the log buffer was
> just an array of characters that were pushed to the console when
> they appeared.
>
> But I am pretty sure that it has stopped working many years agl
> variable-length record buffer").

It's more that spinner or timer dots could fill the
buffer and any message after the spinner/dots like
success or failure is lost via truncation.

There aren't many spinners/dots, perhaps it's better
to find and delete them.


2020-10-01 08:00:04

by Petr Mladek

[permalink] [raw]
Subject: Re: [PATCH next v2 1/2] printk: avoid and/or handle record truncation

On Thu 2020-10-01 00:39:31, Joe Perches wrote:
> On Thu, 2020-10-01 at 09:26 +0200, Petr Mladek wrote:
> > On Wed 2020-09-30 08:25:24, Joe Perches wrote:
> > > On Wed, 2020-09-30 at 11:07 +0206, John Ogness wrote:
> > > > If a reader provides a buffer that is smaller than the message text,
> > > > the @text_len field of @info will have a value larger than the buffer
> > > > size. If readers blindly read @text_len bytes of data without
> > > > checking the size, they will read beyond their buffer.
> > > >
> > > > Add this check to record_print_text() to properly recognize when such
> > > > truncation has occurred.
> > > >
> > > > Add a maximum size argument to the ringbuffer function to extend
> > > > records so that records can not be created that are larger than the
> > > > buffer size of readers.
> > > >
> > > > When extending records (LOG_CONT), do not extend records beyond
> > > > LOG_LINE_MAX since that is the maximum size available in the buffers
> > > > used by consoles and syslog.
> > >
> > > I still think it better to support backspace by rewinding
> > > the buffer rather than truncation of the output.
> >
> > IMHO, backspace support is not worth the complexity. It might do
> > some fancy animation on console but it does not bring any advantage
> > in static logs (dmesg, journalctl).
> >
> > It is possible that it worked in the past when the log buffer was
> > just an array of characters that were pushed to the console when
> > they appeared.
> >
> > But I am pretty sure that it has stopped working many years agl
> > variable-length record buffer").
>
> It's more that spinner or timer dots could fill the
> buffer and any message after the spinner/dots like
> success or failure is lost via truncation.

Yeah, pushing existing parts of continuous lines on the console
would be nice. It would help to see that the system died in
the middle of a risky operation.

But it requires an extra code in the record based log buffer.
It actually has been there and it was removed later because it
complicated the code and did not really worked.

It will be even more complicated with the lockless ringbuffer
and console handled in kthreads.

It might be added when there is a big demand for it. But it does
not make sense to support looong lines full of spinners or dots.


> There aren't many spinners/dots, perhaps it's better
> to find and delete them.

Yeah, that would be nice cleanup.

Best Regards,
Petr