[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-Id: <20210120194106.26441-2-john.ogness@linutronix.de>
Date: Wed, 20 Jan 2021 20:47:06 +0106
From: John Ogness <john.ogness@...utronix.de>
To: Petr Mladek <pmladek@...e.com>
Cc: Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>,
Sergey Senozhatsky <sergey.senozhatsky@...il.com>,
Steven Rostedt <rostedt@...dmis.org>,
linux-kernel@...r.kernel.org
Subject: [PATCH 1/1] printk: fix syslog_print_all() 1024-byte edge case
If klogctl(SYSLOG_ACTION_READ_ALL) is called with a buffer size
of 1024 and the message data will exactly fill 1024 bytes and the
last message of that is multi-line, the last line of the last
message will be silently dropped.
This is because syslog_print_all() is assuming record_print_text()
will fill @size bytes and chooses the first record on this basis.
But since record_print_text() only fills @size-1 bytes, it will
truncate the last message. This behavior exists since the
introduction of msg_print_text() in commit 3ce9a7c0ac28 ("printk() -
restore prefix/timestamp printing for multi-newline strings").
SYSLOG_ACTION_READ_ALL is only supposed to print full messages, so
the expected behavior would be to drop the full multi-line message.
Fix this edge case by changing syslog_print_all() to correctly
choose the first message with the knowledge that
record_print_text() will only fill up to @size-1 bytes.
To test the syslog interface, a simple "kmsg" tool was written to
call klogctl() based on provided parameters. The tool prints the
syslog data it read and the size returned by klogctl().
A wrapper script was used to generate a single multi-line test
message and run kmsg.
----- BEGIN syslog-1024-test.sh -----
#!/bin/sh
msg=""
for i in `seq $1`; do msg="$msg."; done
msg="$msg\nhello1"
msg="$msg\nhello2"
dmesg -c > /dev/null
echo -e "$msg" > /dev/kmsg
./kmsg SYSLOG_ACTION_READ_ALL 1024
----- END syslog-1024-test.sh -----
When $1 is 928, the syslog data will be 1024 bytes and trigger the
edge case (assuming early timestamps and CALLER_ID enabled).
BEFORE this commit:
# ./syslog-1024-test.sh 927
kmsg: klogctl(SYSLOG_ACTION_READ_ALL) with buffer of 1024 bytes
<12>[ 115.933677][ T1138] ................
<12>[ 115.933677][ T1138] hello1
<12>[ 115.933677][ T1138] hello2
read 1023 bytes from klogctl
# ./syslog-1024-test.sh 928
kmsg: klogctl(SYSLOG_ACTION_READ_ALL) with buffer of 1024 bytes
<12>[ 124.834804][ T1143] ................
<12>[ 124.834804][ T1143] hello1
read 990 bytes from klogctl
# ./syslog-1024-test.sh 929
kmsg: klogctl(SYSLOG_ACTION_READ_ALL) with buffer of 1024 bytes
read 0 bytes from klogctl
AFTER this commit:
# ./syslog-1024-test.sh 927
kmsg: klogctl(SYSLOG_ACTION_READ_ALL) with buffer of 1024 bytes
<12>[ 43.079094][ T1096] ................
<12>[ 43.079094][ T1096] hello1
<12>[ 43.079094][ T1096] hello2
read 1023 bytes from klogctl
# ./syslog-1024-test.sh 928
kmsg: klogctl(SYSLOG_ACTION_READ_ALL) with buffer of 1024 bytes
read 0 bytes from klogctl
# ./syslog-1024-test.sh 929
kmsg: klogctl(SYSLOG_ACTION_READ_ALL) with buffer of 1024 bytes
read 0 bytes from klogctl
Fixes: 3ce9a7c0ac28 ("printk() - restore prefix/timestamp printing for multi-newline strings")
Signed-off-by: John Ogness <john.ogness@...utronix.de>
---
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 6639a0cfe0ac..b640d34e0351 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1513,7 +1513,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
/* move first record forward until length fits into the buffer */
prb_for_each_info(clear_seq, prb, seq, &info, &line_count) {
- if (len <= size)
+ if (len < size)
break;
len -= get_record_print_text_size(&info, line_count, true, time);
}
--
2.20.1
Powered by blists - more mailing lists