From e80c1a9d5f514ce5134c6c4263a11607341466c9 Mon Sep 17 00:00:00 2001
From: Tetsuo Handa <penguin-kernel@i-love.sakura.ne.jp>
Date: Tue, 4 Dec 2018 19:00:01 +0900
Subject: [PATCH] printk: fix printk_time race.
Git-commit: e80c1a9d5f514ce5134c6c4263a11607341466c9
Patch-mainline: v5.0-rc1
References: bsc#1152466
Since printk_time can be toggled via /sys/module/printk/parameters/time ,
it is not safe to assume that output length does not change across
multiple msg_print_text() calls. If we hit this race, we can observe
failures such as SYSLOG_ACTION_READ_ALL writes more bytes than userspace
has supplied, SYSLOG_ACTION_SIZE_UNREAD returns -EFAULT when succeeded,
SYSLOG_ACTION_READ reads garbage memory or even triggers an kernel oops
at _copy_to_user() due to integer overflow.
To close this race, get a snapshot value of printk_time and pass it to
SYSLOG_ACTION_READ, SYSLOG_ACTION_READ_ALL, SYSLOG_ACTION_SIZE_UNREAD and
kmsg_dump_get_buffer().
Link: http://lkml.kernel.org/r/555af37c-b9e0-f940-cb73-a78eba2d4944@i-love.sakura.ne.jp
To: Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>
Cc: linux-kernel@vger.kernel.org
Signed-off-by: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
Reviewed-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
Signed-off-by: Petr Mladek <pmladek@suse.com>
---
kernel/printk/printk.c | 70 ++++++++++++++++++++++++++++---------------------
1 file changed, 40 insertions(+), 30 deletions(-)
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -406,6 +406,7 @@ DECLARE_WAIT_QUEUE_HEAD(log_wait);
static u64 syslog_seq;
static u32 syslog_idx;
static size_t syslog_partial;
+static bool syslog_time;
/* index and sequence number of the first record stored in the buffer */
static u64 log_first_seq;
@@ -1212,12 +1213,7 @@ module_param_named(time, printk_time, bo
static size_t print_time(u64 ts, char *buf)
{
- unsigned long rem_nsec;
-
- if (!printk_time)
- return 0;
-
- rem_nsec = do_div(ts, 1000000000);
+ unsigned long rem_nsec = do_div(ts, 1000000000);
if (!buf)
return snprintf(NULL, 0, "[%5lu.000000] ", (unsigned long)ts);
@@ -1226,7 +1222,8 @@ static size_t print_time(u64 ts, char *b
(unsigned long)ts, rem_nsec / 1000);
}
-static size_t print_prefix(const struct printk_log *msg, bool syslog, char *buf)
+static size_t print_prefix(const struct printk_log *msg, bool syslog,
+ bool time, char *buf)
{
size_t len = 0;
unsigned int prefix = (msg->facility << 3) | msg->level;
@@ -1245,11 +1242,13 @@ static size_t print_prefix(const struct
}
}
- len += print_time(msg->ts_nsec, buf ? buf + len : NULL);
+ if (time)
+ len += print_time(msg->ts_nsec, buf ? buf + len : NULL);
return len;
}
-static size_t msg_print_text(const struct printk_log *msg, bool syslog, char *buf, size_t size)
+static size_t msg_print_text(const struct printk_log *msg, bool syslog,
+ bool time, char *buf, size_t size)
{
const char *text = log_text(msg);
size_t text_size = msg->text_len;
@@ -1268,17 +1267,17 @@ static size_t msg_print_text(const struc
}
if (buf) {
- if (print_prefix(msg, syslog, NULL) +
+ if (print_prefix(msg, syslog, time, NULL) +
text_len + 1 >= size - len)
break;
- len += print_prefix(msg, syslog, buf + len);
+ len += print_prefix(msg, syslog, time, buf + len);
memcpy(buf + len, text, text_len);
len += text_len;
buf[len++] = '\n';
} else {
/* SYSLOG_ACTION_* buffer size only calculation */
- len += print_prefix(msg, syslog, NULL);
+ len += print_prefix(msg, syslog, time, NULL);
len += text_len;
len++;
}
@@ -1315,9 +1314,17 @@ static int syslog_print(char __user *buf
break;
}
+ /*
+ * To keep reading/counting partial line consistent,
+ * use printk_time value as of the beginning of a line.
+ */
+ if (!syslog_partial)
+ syslog_time = printk_time;
+
skip = syslog_partial;
msg = log_from_idx(syslog_idx);
- n = msg_print_text(msg, true, text, LOG_LINE_MAX + PREFIX_MAX);
+ n = msg_print_text(msg, true, syslog_time, text,
+ LOG_LINE_MAX + PREFIX_MAX);
if (n - syslog_partial <= size) {
/* message fits into buffer, move forward */
syslog_idx = log_next(syslog_idx);
@@ -1353,12 +1360,14 @@ static int syslog_print(char __user *buf
static int syslog_print_all(char __user *buf, int size, bool clear)
{
char *text;
+ bool time;
int len = 0;
text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
if (!text)
return -ENOMEM;
+ time = printk_time;
logbuf_lock_irq();
if (buf) {
u64 next_seq;
@@ -1374,7 +1383,7 @@ static int syslog_print_all(char __user
while (seq < log_next_seq) {
struct printk_log *msg = log_from_idx(idx);
- len += msg_print_text(msg, true, NULL, 0);
+ len += msg_print_text(msg, true, time, NULL, 0);
idx = log_next(idx);
seq++;
}
@@ -1385,7 +1394,7 @@ static int syslog_print_all(char __user
while (len > size && seq < log_next_seq) {
struct printk_log *msg = log_from_idx(idx);
- len -= msg_print_text(msg, true, NULL, 0);
+ len -= msg_print_text(msg, true, time, NULL, 0);
idx = log_next(idx);
seq++;
}
@@ -1396,14 +1405,9 @@ static int syslog_print_all(char __user
len = 0;
while (len >= 0 && seq < next_seq) {
struct printk_log *msg = log_from_idx(idx);
- int textlen;
+ int textlen = msg_print_text(msg, true, time, text,
+ LOG_LINE_MAX + PREFIX_MAX);
- textlen = msg_print_text(msg, true, text,
- LOG_LINE_MAX + PREFIX_MAX);
- if (textlen < 0) {
- len = textlen;
- break;
- }
idx = log_next(idx);
seq++;
@@ -1530,12 +1534,15 @@ int do_syslog(int type, char __user *buf
} else {
u64 seq = syslog_seq;
u32 idx = syslog_idx;
+ bool time = syslog_partial ? syslog_time : printk_time;
error = 0;
while (seq < log_next_seq) {
struct printk_log *msg = log_from_idx(idx);
- error += msg_print_text(msg, true, NULL, 0);
+ error += msg_print_text(msg, true, time, NULL,
+ 0);
+ time = printk_time;
idx = log_next(idx);
seq++;
}
@@ -2001,6 +2008,7 @@ EXPORT_SYMBOL(printk);
#define LOG_LINE_MAX 0
#define PREFIX_MAX 0
+#define printk_time false
static u64 syslog_seq;
static u32 syslog_idx;
@@ -2023,8 +2031,8 @@ static void console_lock_spinning_enable
static int console_lock_spinning_disable_and_check(void) { return 0; }
static void call_console_drivers(const char *ext_text, size_t ext_len,
const char *text, size_t len) {}
-static size_t msg_print_text(const struct printk_log *msg,
- bool syslog, char *buf, size_t size) { return 0; }
+static size_t msg_print_text(const struct printk_log *msg, bool syslog,
+ bool time, char *buf, size_t size) { return 0; }
static bool suppress_message_printing(int level) { return false; }
#endif /* CONFIG_PRINTK */
@@ -2368,7 +2376,8 @@ skip:
goto skip;
}
- len += msg_print_text(msg, false, text + len, sizeof(text) - len);
+ len += msg_print_text(msg, false,
+ printk_time, text + len, sizeof(text) - len);
if (nr_ext_console_drivers) {
ext_len = msg_print_ext_header(ext_text,
sizeof(ext_text),
@@ -3077,7 +3086,7 @@ bool kmsg_dump_get_line_nolock(struct km
goto out;
msg = log_from_idx(dumper->cur_idx);
- l = msg_print_text(msg, syslog, line, size);
+ l = msg_print_text(msg, syslog, printk_time, line, size);
dumper->cur_idx = log_next(dumper->cur_idx);
dumper->cur_seq++;
@@ -3148,6 +3157,7 @@ bool kmsg_dump_get_buffer(struct kmsg_du
u32 next_idx;
size_t l = 0;
bool ret = false;
+ bool time = printk_time;
if (!dumper->active)
goto out;
@@ -3171,7 +3181,7 @@ bool kmsg_dump_get_buffer(struct kmsg_du
while (seq < dumper->next_seq) {
struct printk_log *msg = log_from_idx(idx);
- l += msg_print_text(msg, true, NULL, 0);
+ l += msg_print_text(msg, true, time, NULL, 0);
idx = log_next(idx);
seq++;
}
@@ -3182,7 +3192,7 @@ bool kmsg_dump_get_buffer(struct kmsg_du
while (l > size && seq < dumper->next_seq) {
struct printk_log *msg = log_from_idx(idx);
- l -= msg_print_text(msg, true, NULL, 0);
+ l -= msg_print_text(msg, true, time, NULL, 0);
idx = log_next(idx);
seq++;
}
@@ -3195,7 +3205,7 @@ bool kmsg_dump_get_buffer(struct kmsg_du
while (seq < dumper->next_seq) {
struct printk_log *msg = log_from_idx(idx);
- l += msg_print_text(msg, syslog, buf + l, size - l);
+ l += msg_print_text(msg, syslog, time, buf + l, size - l);
idx = log_next(idx);
seq++;
}