printk: fix printk_time race.

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>

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index a1d88212a5d213cb3faff340fa360c162d8d6ca2..c7d217764db3cbd596f13b74eeb84e009c25ce00 100644 (file)
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -404,6 +404,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;
@@ -1229,12 +1230,7 @@ module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
 
 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);
@@ -1243,7 +1239,8 @@ static size_t print_time(u64 ts, char *buf)
                       (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;
@@ -1262,11 +1259,13 @@ static size_t print_prefix(const struct printk_log *msg, bool syslog, char *buf)
                }
        }
 
-       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;
@@ -1285,17 +1284,17 @@ static size_t msg_print_text(const struct printk_log *msg, bool syslog, char *bu
                }
 
                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++;
                }
@@ -1332,9 +1331,17 @@ static int syslog_print(char __user *buf, int size)
                        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);
@@ -1374,11 +1381,13 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
        u64 next_seq;
        u64 seq;
        u32 idx;
+       bool time;
 
        text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
        if (!text)
                return -ENOMEM;
 
+       time = printk_time;
        logbuf_lock_irq();
        /*
         * Find first record that fits, including all following records,
@@ -1389,7 +1398,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
        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++;
        }
@@ -1400,7 +1409,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
        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++;
        }
@@ -1411,14 +1420,9 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
        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++;
 
@@ -1542,11 +1546,14 @@ int do_syslog(int type, char __user *buf, int len, int source)
                } else {
                        u64 seq = syslog_seq;
                        u32 idx = syslog_idx;
+                       bool time = syslog_partial ? syslog_time : printk_time;
 
                        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++;
                        }
@@ -2004,6 +2011,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;
@@ -2027,8 +2035,8 @@ static void console_lock_spinning_enable(void) { }
 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 */
@@ -2386,8 +2394,7 @@ void console_unlock(void)
 
                len += msg_print_text(msg,
                                console_msg_format & MSG_FORMAT_SYSLOG,
-                               text + len,
-                               sizeof(text) - len);
+                               printk_time, text + len, sizeof(text) - len);
                if (nr_ext_console_drivers) {
                        ext_len = msg_print_ext_header(ext_text,
                                                sizeof(ext_text),
@@ -3111,7 +3118,7 @@ bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog,
                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++;
@@ -3182,6 +3189,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
        u32 next_idx;
        size_t l = 0;
        bool ret = false;
+       bool time = printk_time;
 
        if (!dumper->active)
                goto out;
@@ -3205,7 +3213,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
        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++;
        }
@@ -3216,7 +3224,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
        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++;
        }
@@ -3229,7 +3237,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
        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++;
        }