* [PATCH v2] printk: Do not lose last line in kmsg buffer dump
@ 2019-07-11 14:29 Vincent Whitchurch
2019-07-12 8:09 ` Petr Mladek
2019-07-12 9:12 ` Petr Mladek
0 siblings, 2 replies; 8+ messages in thread
From: Vincent Whitchurch @ 2019-07-11 14:29 UTC (permalink / raw)
To: pmladek, sergey.senozhatsky, rostedt; +Cc: linux-kernel, Vincent Whitchurch
kmsg_dump_get_buffer() is supposed to select all the youngest log
messages which fit into the provided buffer. It determines the correct
start index by using msg_print_text() with a NULL buffer to calculate
the size of each entry. However, when performing the actual writes,
msg_print_text() only writes the entry to the buffer if the written len
is lesser than the size of the buffer. So if the lengths of the
selected youngest log messages happen to precisely fill up the provided
buffer, the last log message is not included.
We don't want to modify msg_print_text() to fill up the buffer and start
returning a length which is equal to the size of the buffer, since
callers of its other users, such as kmsg_dump_get_line(), depend upon
the current behaviour.
Instead, fix kmsg_dump_get_buffer() to compensate for this.
For example, with the following two final prints:
[ 6.427502] AAAAAAAAAAAAA
[ 6.427769] BBBBBBBB12345
A dump of a 64-byte buffer filled by kmsg_dump_get_buffer(), before this
patch:
00000000: 3c 30 3e 5b 20 20 20 20 36 2e 35 32 32 31 39 37 <0>[ 6.522197
00000010: 5d 20 41 41 41 41 41 41 41 41 41 41 41 41 41 0a ] AAAAAAAAAAAAA.
00000020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00000030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
After this patch:
00000000: 3c 30 3e 5b 20 20 20 20 36 2e 34 35 36 36 37 38 <0>[ 6.456678
00000010: 5d 20 42 42 42 42 42 42 42 42 31 32 33 34 35 0a ] BBBBBBBB12345.
00000020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00000030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
Signed-off-by: Vincent Whitchurch <vincent.whitchurch@axis.com>
---
v2: Move fix to kmsg_dump_get_buffer()
kernel/printk/printk.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1888f6a3b694..424abf802f02 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3274,7 +3274,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
/* move first record forward until length fits into the buffer */
seq = dumper->cur_seq;
idx = dumper->cur_idx;
- while (l > size && seq < dumper->next_seq) {
+ while (l >= size && seq < dumper->next_seq) {
struct printk_log *msg = log_from_idx(idx);
l -= msg_print_text(msg, true, time, NULL, 0);
--
2.20.0
^ permalink raw reply related [flat|nested] 8+ messages in thread
* Re: [PATCH v2] printk: Do not lose last line in kmsg buffer dump
2019-07-11 14:29 [PATCH v2] printk: Do not lose last line in kmsg buffer dump Vincent Whitchurch
@ 2019-07-12 8:09 ` Petr Mladek
2019-07-12 8:44 ` Vincent Whitchurch
2019-07-12 9:12 ` Petr Mladek
1 sibling, 1 reply; 8+ messages in thread
From: Petr Mladek @ 2019-07-12 8:09 UTC (permalink / raw)
To: Vincent Whitchurch
Cc: sergey.senozhatsky, rostedt, Vincent Whitchurch, linux-kernel
On Thu 2019-07-11 16:29:37, Vincent Whitchurch wrote:
> kmsg_dump_get_buffer() is supposed to select all the youngest log
> messages which fit into the provided buffer. It determines the correct
> start index by using msg_print_text() with a NULL buffer to calculate
> the size of each entry. However, when performing the actual writes,
> msg_print_text() only writes the entry to the buffer if the written len
> is lesser than the size of the buffer. So if the lengths of the
> selected youngest log messages happen to precisely fill up the provided
> buffer, the last log message is not included.
>
> We don't want to modify msg_print_text() to fill up the buffer and start
> returning a length which is equal to the size of the buffer, since
> callers of its other users, such as kmsg_dump_get_line(), depend upon
> the current behaviour.
>
> Instead, fix kmsg_dump_get_buffer() to compensate for this.
>
> For example, with the following two final prints:
>
> [ 6.427502] AAAAAAAAAAAAA
> [ 6.427769] BBBBBBBB12345
>
> A dump of a 64-byte buffer filled by kmsg_dump_get_buffer(), before this
> patch:
>
> 00000000: 3c 30 3e 5b 20 20 20 20 36 2e 35 32 32 31 39 37 <0>[ 6.522197
> 00000010: 5d 20 41 41 41 41 41 41 41 41 41 41 41 41 41 0a ] AAAAAAAAAAAAA.
> 00000020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
> 00000030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
>
> After this patch:
>
> 00000000: 3c 30 3e 5b 20 20 20 20 36 2e 34 35 36 36 37 38 <0>[ 6.456678
> 00000010: 5d 20 42 42 42 42 42 42 42 42 31 32 33 34 35 0a ] BBBBBBBB12345.
> 00000020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
> 00000030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
>
> Signed-off-by: Vincent Whitchurch <vincent.whitchurch@axis.com>
> ---
> v2: Move fix to kmsg_dump_get_buffer()
>
> kernel/printk/printk.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 1888f6a3b694..424abf802f02 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -3274,7 +3274,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
> /* move first record forward until length fits into the buffer */
> seq = dumper->cur_seq;
> idx = dumper->cur_idx;
> - while (l > size && seq < dumper->next_seq) {
> + while (l >= size && seq < dumper->next_seq) {
This cycle searches how many messages would fit into the buffer.
The patch looks like a hack using a hole that the next cycle
does not longer check the number of really stored characters.
What would happen when msg_print_text() starts adding
the trailing '\0' as suggested by
https://lkml.kernel.org/r/20190710121049.rwhk7fknfzn3cfkz@pathway.suse.cz
I would much more appreciate if we make the code more secure instead
of stretching its weakness to the limits.
BTW: What is the motivation for this fix? Is a bug report
or just some research of possible buffer overflows?
The commit message pretends that the problem is bigger than
it really is. It is about one byte and not one line.
Best Regards,
Petr
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [PATCH v2] printk: Do not lose last line in kmsg buffer dump
2019-07-12 8:09 ` Petr Mladek
@ 2019-07-12 8:44 ` Vincent Whitchurch
0 siblings, 0 replies; 8+ messages in thread
From: Vincent Whitchurch @ 2019-07-12 8:44 UTC (permalink / raw)
To: Petr Mladek; +Cc: sergey.senozhatsky, rostedt, linux-kernel
On Fri, Jul 12, 2019 at 10:09:04AM +0200, Petr Mladek wrote:
> The patch looks like a hack using a hole that the next cycle
> does not longer check the number of really stored characters.
>
> What would happen when msg_print_text() starts adding
> the trailing '\0' as suggested by
> https://lkml.kernel.org/r/20190710121049.rwhk7fknfzn3cfkz@pathway.suse.cz
I did have a look at that possibility, but I didn't see how that could
work without potentially affecting userspace users of the syslog ABI.
AFAICS the suggested change in msg_print_text() can be done in one of
three ways:
(1) msg_print_text() adds the '\0' and includes this length both when
it estimates the size (NULL buffer) and when it actually prints:
If we do this:
- kmsg_dump_get_line_nolock() would have to subtract 1 from the len
since its callers expected that len is always smaller than the
size of the buffer.
- The buffers given to use via the syslog interface will now include
a '\0', potentially affecting userspace applications which use
this ABI.
(2) msg_print_text() adds the '\0', and includes this in the length
only when estimating the size, and not when it actually prints.
If we do this:
- SYSLOG_ACTION_SIZE_UNREAD tries uses the size estimate to give
userspace a count of how many characters are present in the
buffer, and now this count will start differing from the actual
count that can be read, potentially affecting userspace
applications.
(3) msg_print_text() adds the '\0', and does not include this length
in the result at all.
If we do this:
- The original kmsg dump issue is not solved, since the last line
is still lost.
> BTW: What is the motivation for this fix? Is a bug report
> or just some research of possible buffer overflows?
The fix is not attempting to fix a buffer overflow, theoretical or
otherwise.
It's a fix for a bug in functionality which has been observed on our
systems: We use pstore to save the kernel log when the kernel crashes,
and sometimes the log in the pstore misses the last line, and since the
last line usual says why we're panicing so it's rather important not to
miss.
> The commit message pretends that the problem is bigger than
> it really is. It is about one byte and not one line.
I'm not quite sure I follow. The current code does fail to include the
*entire* last line.
The memcpy on line #1294 is never executed for the last line because we
stop the loop because of the check on line #1289:
1270 static size_t msg_print_text(const struct printk_log *msg, bool syslog, char *buf, size_t size)
1271 {
1272 const char *text = log_text(msg);
1273 size_t text_size = msg->text_len;
1274 size_t len = 0;
1275
1276 do {
1277 const char *next = memchr(text, '\n', text_size);
1278 size_t text_len;
1279
1280 if (next) {
1281 text_len = next - text;
1282 next++;
1283 text_size -= next - text;
1284 } else {
1285 text_len = text_size;
1286 }
1287
1288 if (buf) {
1289 if (print_prefix(msg, syslog, NULL) +
1290 text_len + 1 > size - len)
1291 break;
1292
1293 len += print_prefix(msg, syslog, buf + len);
1294 memcpy(buf + len, text, text_len);
1295 len += text_len;
1296 buf[len++] = '\n';
1297 } else {
1298 /* SYSLOG_ACTION_* buffer size only calculation */
1299 len += print_prefix(msg, syslog, NULL);
1300 len += text_len;
1301 len++;
1302 }
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [PATCH v2] printk: Do not lose last line in kmsg buffer dump
2019-07-11 14:29 [PATCH v2] printk: Do not lose last line in kmsg buffer dump Vincent Whitchurch
2019-07-12 8:09 ` Petr Mladek
@ 2019-07-12 9:12 ` Petr Mladek
2019-07-12 9:22 ` Sergey Senozhatsky
1 sibling, 1 reply; 8+ messages in thread
From: Petr Mladek @ 2019-07-12 9:12 UTC (permalink / raw)
To: Vincent Whitchurch
Cc: sergey.senozhatsky, rostedt, Vincent Whitchurch, linux-kernel
On Thu 2019-07-11 16:29:37, Vincent Whitchurch wrote:
> kmsg_dump_get_buffer() is supposed to select all the youngest log
> messages which fit into the provided buffer. It determines the correct
> start index by using msg_print_text() with a NULL buffer to calculate
> the size of each entry. However, when performing the actual writes,
> msg_print_text() only writes the entry to the buffer if the written len
> is lesser than the size of the buffer. So if the lengths of the
> selected youngest log messages happen to precisely fill up the provided
> buffer, the last log message is not included.
>
> We don't want to modify msg_print_text() to fill up the buffer and start
> returning a length which is equal to the size of the buffer, since
> callers of its other users, such as kmsg_dump_get_line(), depend upon
> the current behaviour.
>
> Instead, fix kmsg_dump_get_buffer() to compensate for this.
>
> For example, with the following two final prints:
>
> [ 6.427502] AAAAAAAAAAAAA
> [ 6.427769] BBBBBBBB12345
>
> A dump of a 64-byte buffer filled by kmsg_dump_get_buffer(), before this
> patch:
>
> 00000000: 3c 30 3e 5b 20 20 20 20 36 2e 35 32 32 31 39 37 <0>[ 6.522197
> 00000010: 5d 20 41 41 41 41 41 41 41 41 41 41 41 41 41 0a ] AAAAAAAAAAAAA.
> 00000020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
> 00000030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
>
> After this patch:
>
> 00000000: 3c 30 3e 5b 20 20 20 20 36 2e 34 35 36 36 37 38 <0>[ 6.456678
> 00000010: 5d 20 42 42 42 42 42 42 42 42 31 32 33 34 35 0a ] BBBBBBBB12345.
> 00000020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
> 00000030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
>
> Signed-off-by: Vincent Whitchurch <vincent.whitchurch@axis.com>
I think that I need vacation. I have got lost in all the checks
and got it wrongly in the morning.
This patch fixes the calculation of messages that might fit
into the buffer. It makes sure that the function that writes
the messages will really allow to write them.
It seems to be the correct fix.
Reviewed-by: Petr Mladek <pmladek@suse.com>
Best Regards,
Petr
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [PATCH v2] printk: Do not lose last line in kmsg buffer dump
2019-07-12 9:12 ` Petr Mladek
@ 2019-07-12 9:22 ` Sergey Senozhatsky
2019-07-12 13:11 ` Petr Mladek
0 siblings, 1 reply; 8+ messages in thread
From: Sergey Senozhatsky @ 2019-07-12 9:22 UTC (permalink / raw)
To: Petr Mladek
Cc: Vincent Whitchurch, sergey.senozhatsky, rostedt,
Vincent Whitchurch, linux-kernel
On (07/12/19 11:12), Petr Mladek wrote:
> > For example, with the following two final prints:
> >
> > [ 6.427502] AAAAAAAAAAAAA
> > [ 6.427769] BBBBBBBB12345
> >
> > A dump of a 64-byte buffer filled by kmsg_dump_get_buffer(), before this
> > patch:
> >
> > 00000000: 3c 30 3e 5b 20 20 20 20 36 2e 35 32 32 31 39 37 <0>[ 6.522197
> > 00000010: 5d 20 41 41 41 41 41 41 41 41 41 41 41 41 41 0a ] AAAAAAAAAAAAA.
> > 00000020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
> > 00000030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
> >
> > After this patch:
> >
> > 00000000: 3c 30 3e 5b 20 20 20 20 36 2e 34 35 36 36 37 38 <0>[ 6.456678
> > 00000010: 5d 20 42 42 42 42 42 42 42 42 31 32 33 34 35 0a ] BBBBBBBB12345.
> > 00000020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
> > 00000030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
> >
> > Signed-off-by: Vincent Whitchurch <vincent.whitchurch@axis.com>
>
> I think that I need vacation. I have got lost in all the checks
> and got it wrongly in the morning.
>
> This patch fixes the calculation of messages that might fit
> into the buffer. It makes sure that the function that writes
> the messages will really allow to write them.
>
> It seems to be the correct fix.
>
> Reviewed-by: Petr Mladek <pmladek@suse.com>
Looks correct to me as well.
Reviewed-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
-ss
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [PATCH v2] printk: Do not lose last line in kmsg buffer dump
2019-07-12 9:22 ` Sergey Senozhatsky
@ 2019-07-12 13:11 ` Petr Mladek
2019-07-13 6:03 ` Sergey Senozhatsky
0 siblings, 1 reply; 8+ messages in thread
From: Petr Mladek @ 2019-07-12 13:11 UTC (permalink / raw)
To: Sergey Senozhatsky
Cc: Vincent Whitchurch, Vincent Whitchurch, sergey.senozhatsky,
rostedt, linux-kernel
On Fri 2019-07-12 18:22:53, Sergey Senozhatsky wrote:
> On (07/12/19 11:12), Petr Mladek wrote:
> > > For example, with the following two final prints:
> > >
> > > [ 6.427502] AAAAAAAAAAAAA
> > > [ 6.427769] BBBBBBBB12345
> > >
> > > A dump of a 64-byte buffer filled by kmsg_dump_get_buffer(), before this
> > > patch:
> > >
> > > 00000000: 3c 30 3e 5b 20 20 20 20 36 2e 35 32 32 31 39 37 <0>[ 6.522197
> > > 00000010: 5d 20 41 41 41 41 41 41 41 41 41 41 41 41 41 0a ] AAAAAAAAAAAAA.
> > > 00000020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
> > > 00000030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
> > >
> > > After this patch:
> > >
> > > 00000000: 3c 30 3e 5b 20 20 20 20 36 2e 34 35 36 36 37 38 <0>[ 6.456678
> > > 00000010: 5d 20 42 42 42 42 42 42 42 42 31 32 33 34 35 0a ] BBBBBBBB12345.
> > > 00000020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
> > > 00000030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
> > >
> > > Signed-off-by: Vincent Whitchurch <vincent.whitchurch@axis.com>
> >
> > I think that I need vacation. I have got lost in all the checks
> > and got it wrongly in the morning.
> >
> > This patch fixes the calculation of messages that might fit
> > into the buffer. It makes sure that the function that writes
> > the messages will really allow to write them.
> >
> > It seems to be the correct fix.
> >
> > Reviewed-by: Petr Mladek <pmladek@suse.com>
>
> Looks correct to me as well.
>
> Reviewed-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
The patch has been committed into printk.git, branch for-5.3-fixes.
I am still a bit undecided whether to send pull request the following
week or wait for 5.4. On one hand, it is very old bug (since 3.5).
On the other hand, I think that it was not reported/fixed earlier
only because it was hard to notice. And loosing the very last message
is quite pity.
Anyway, I added stable tag.
Best Regards,
Petr
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [PATCH v2] printk: Do not lose last line in kmsg buffer dump
2019-07-12 13:11 ` Petr Mladek
@ 2019-07-13 6:03 ` Sergey Senozhatsky
2019-07-16 13:35 ` Petr Mladek
0 siblings, 1 reply; 8+ messages in thread
From: Sergey Senozhatsky @ 2019-07-13 6:03 UTC (permalink / raw)
To: Petr Mladek
Cc: Sergey Senozhatsky, Vincent Whitchurch, Vincent Whitchurch,
sergey.senozhatsky, rostedt, linux-kernel
On (07/12/19 15:11), Petr Mladek wrote:
> > Looks correct to me as well.
> >
> > Reviewed-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
>
> The patch has been committed into printk.git, branch for-5.3-fixes.
>
> I am still a bit undecided whether to send pull request the following
> week or wait for 5.4. On one hand, it is very old bug (since 3.5).
> On the other hand, I think that it was not reported/fixed earlier
> only because it was hard to notice. And loosing the very last message
> is quite pity.
My call would be - let's wait till next merge window.
-ss
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [PATCH v2] printk: Do not lose last line in kmsg buffer dump
2019-07-13 6:03 ` Sergey Senozhatsky
@ 2019-07-16 13:35 ` Petr Mladek
0 siblings, 0 replies; 8+ messages in thread
From: Petr Mladek @ 2019-07-16 13:35 UTC (permalink / raw)
To: Sergey Senozhatsky
Cc: Vincent Whitchurch, Vincent Whitchurch, Sergey Senozhatsky,
rostedt, linux-kernel
On Sat 2019-07-13 15:03:00, Sergey Senozhatsky wrote:
> On (07/12/19 15:11), Petr Mladek wrote:
> > > Looks correct to me as well.
> > >
> > > Reviewed-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
> >
> > The patch has been committed into printk.git, branch for-5.3-fixes.
> >
> > I am still a bit undecided whether to send pull request the following
> > week or wait for 5.4. On one hand, it is very old bug (since 3.5).
> > On the other hand, I think that it was not reported/fixed earlier
> > only because it was hard to notice. And loosing the very last message
> > is quite pity.
>
> My call would be - let's wait till next merge window.
Thanks for your opinion.
I'll leave it for 5.4 unless there is another urgent fix that would
trigger earlier pull request.
Best Regards,
Petr
^ permalink raw reply [flat|nested] 8+ messages in thread
end of thread, other threads:[~2019-07-16 13:35 UTC | newest]
Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2019-07-11 14:29 [PATCH v2] printk: Do not lose last line in kmsg buffer dump Vincent Whitchurch
2019-07-12 8:09 ` Petr Mladek
2019-07-12 8:44 ` Vincent Whitchurch
2019-07-12 9:12 ` Petr Mladek
2019-07-12 9:22 ` Sergey Senozhatsky
2019-07-12 13:11 ` Petr Mladek
2019-07-13 6:03 ` Sergey Senozhatsky
2019-07-16 13:35 ` Petr Mladek
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).