Minki/linux
1
0
Fork 1
mirror of https://github.com/torvalds/linux.git synced 2024-11-17 17:41:44 +00:00
Code Issues Packages Projects Releases Wiki Activity

printk: remove games with previous record flags

Browse Source 
The record logging code looks at the previous record flags in various
ways, and they are all wrong.

You can't use the previous record flags to determine anything about the
next record, because they may simply not be related.  In particular, the
reason the previous record was a continuation record may well be exactly
_because_ the new record was printed by a different process, which is
why the previous record was flushed.

So all those games are simply wrong, and make the code hard to
understand (because the code fundamentally cdoes not make sense).

So remove it.

Signed-off-by: Linus Torvalds <torvalds@linux-foundation.org>
This commit is contained in:
Linus Torvalds 2016-10-25 11:27:31 -07:00
parent 196202be3c
commit 5aa068ea40
1 changed files with 24 additions and 85 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

101
kernel/printk/printk.c
View File

@ -356,7 +356,6 @@ DECLARE_WAIT_QUEUE_HEAD(log_wait);
/* the next printk record to read by syslog(READ) or /proc/kmsg */ /* the next printk record to read by syslog(READ) or /proc/kmsg */
static u64 syslog_seq; static u64 syslog_seq;
static u32 syslog_idx; static u32 syslog_idx;
static enum log_flags syslog_prev;
static size_t syslog_partial; static size_t syslog_partial;
/* index and sequence number of the first record stored in the buffer */ /* index and sequence number of the first record stored in the buffer */
@ -370,7 +369,6 @@ static u32 log_next_idx;
/* the next printk record to write to the console */ /* the next printk record to write to the console */
static u64 console_seq; static u64 console_seq;
static u32 console_idx; static u32 console_idx;
static enum log_flags console_prev;
/* the next printk record to read after the last 'clear' command */ /* the next printk record to read after the last 'clear' command */
static u64 clear_seq; static u64 clear_seq;
@ -639,27 +637,15 @@ static void append_char(char **pp, char *e, char c)
} }
static ssize_t msg_print_ext_header(char *buf, size_t size, static ssize_t msg_print_ext_header(char *buf, size_t size,
struct printk_log *msg, u64 seq, struct printk_log *msg, u64 seq)
enum log_flags prev_flags)
{ {
u64 ts_usec = msg->ts_nsec; u64 ts_usec = msg->ts_nsec;
char cont = '-';
do_div(ts_usec, 1000); do_div(ts_usec, 1000);
/*
* If we couldn't merge continuation line fragments during the print,
* export the stored flags to allow an optional external merge of the
* records. Merging the records isn't always neccessarily correct, like
* when we hit a race during printing. In most cases though, it produces
* better readable output. 'c' in the record flags mark the first
* fragment of a line, '+' the following.
*/
if (msg->flags & LOG_CONT)
cont = (prev_flags & LOG_CONT) ? '+' : 'c';
return scnprintf(buf, size, "%u,%llu,%llu,%c;", return scnprintf(buf, size, "%u,%llu,%llu,%c;",
(msg->facility << 3) | msg->level, seq, ts_usec, cont); (msg->facility << 3) | msg->level, seq, ts_usec,
msg->flags & LOG_CONT ? 'c' : '-');
} }
static ssize_t msg_print_ext_body(char *buf, size_t size, static ssize_t msg_print_ext_body(char *buf, size_t size,
@ -714,7 +700,6 @@ static ssize_t msg_print_ext_body(char *buf, size_t size,
struct devkmsg_user { struct devkmsg_user {
u64 seq; u64 seq;
u32 idx; u32 idx;
enum log_flags prev;
struct ratelimit_state rs; struct ratelimit_state rs;
struct mutex lock; struct mutex lock;
char buf[CONSOLE_EXT_LOG_MAX]; char buf[CONSOLE_EXT_LOG_MAX];
@ -824,12 +809,11 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
msg = log_from_idx(user->idx); msg = log_from_idx(user->idx);
len = msg_print_ext_header(user->buf, sizeof(user->buf), len = msg_print_ext_header(user->buf, sizeof(user->buf),
msg, user->seq, user->prev); msg, user->seq);
len += msg_print_ext_body(user->buf + len, sizeof(user->buf) - len, len += msg_print_ext_body(user->buf + len, sizeof(user->buf) - len,
log_dict(msg), msg->dict_len, log_dict(msg), msg->dict_len,
log_text(msg), msg->text_len); log_text(msg), msg->text_len);
user->prev = msg->flags;
user->idx = log_next(user->idx); user->idx = log_next(user->idx);
user->seq++; user->seq++;
raw_spin_unlock_irq(&logbuf_lock); raw_spin_unlock_irq(&logbuf_lock);
@ -1210,26 +1194,12 @@ static size_t print_prefix(const struct printk_log *msg, bool syslog, char *buf)
return len; return len;
} }
static size_t msg_print_text(const struct printk_log *msg, enum log_flags prev, static size_t msg_print_text(const struct printk_log *msg, bool syslog, char *buf, size_t size)
bool syslog, char *buf, size_t size)
{ {
const char *text = log_text(msg); const char *text = log_text(msg);
size_t text_size = msg->text_len; size_t text_size = msg->text_len;
bool prefix = true;
bool newline = true;
size_t len = 0; size_t len = 0;
if ((prev & LOG_CONT) && !(msg->flags & LOG_PREFIX))
prefix = false;
if (msg->flags & LOG_CONT) {
if ((prev & LOG_CONT) && !(prev & LOG_NEWLINE))
prefix = false;
if (!(msg->flags & LOG_NEWLINE))
newline = false;
}
do { do {
const char *next = memchr(text, '\n', text_size); const char *next = memchr(text, '\n', text_size);
size_t text_len; size_t text_len;
@ -1247,22 +1217,17 @@ static size_t msg_print_text(const struct printk_log *msg, enum log_flags prev,
text_len + 1 >= size - len) text_len + 1 >= size - len)
break; break;
if (prefix)
len += print_prefix(msg, syslog, buf + len); len += print_prefix(msg, syslog, buf + len);
memcpy(buf + len, text, text_len); memcpy(buf + len, text, text_len);
len += text_len; len += text_len;
if (next || newline)
buf[len++] = '\n'; buf[len++] = '\n';
} else { } else {
/* SYSLOG_ACTION_* buffer size only calculation */ /* SYSLOG_ACTION_* buffer size only calculation */
if (prefix)
len += print_prefix(msg, syslog, NULL); len += print_prefix(msg, syslog, NULL);
len += text_len; len += text_len;
if (next || newline)
len++; len++;
} }
prefix = true;
text = next; text = next;
} while (text); } while (text);
@ -1288,7 +1253,6 @@ static int syslog_print(char __user *buf, int size)
/* messages are gone, move to first one */ /* messages are gone, move to first one */
syslog_seq = log_first_seq; syslog_seq = log_first_seq;
syslog_idx = log_first_idx; syslog_idx = log_first_idx;
syslog_prev = 0;
syslog_partial = 0; syslog_partial = 0;
} }
if (syslog_seq == log_next_seq) { if (syslog_seq == log_next_seq) {
@ -1298,13 +1262,11 @@ static int syslog_print(char __user *buf, int size)
skip = syslog_partial; skip = syslog_partial;
msg = log_from_idx(syslog_idx); msg = log_from_idx(syslog_idx);
n = msg_print_text(msg, syslog_prev, true, text, n = msg_print_text(msg, true, text, LOG_LINE_MAX + PREFIX_MAX);
LOG_LINE_MAX + PREFIX_MAX);
if (n - syslog_partial <= size) { if (n - syslog_partial <= size) {
/* message fits into buffer, move forward */ /* message fits into buffer, move forward */
syslog_idx = log_next(syslog_idx); syslog_idx = log_next(syslog_idx);
syslog_seq++; syslog_seq++;
syslog_prev = msg->flags;
n -= syslog_partial; n -= syslog_partial;
syslog_partial = 0; syslog_partial = 0;
} else if (!len){ } else if (!len){
@ -1347,7 +1309,6 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
u64 next_seq; u64 next_seq;
u64 seq; u64 seq;
u32 idx; u32 idx;
enum log_flags prev;
/* /*
* Find first record that fits, including all following records, * Find first record that fits, including all following records,
@ -1355,12 +1316,10 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
*/ */
seq = clear_seq; seq = clear_seq;
idx = clear_idx; idx = clear_idx;
prev = 0;
while (seq < log_next_seq) { while (seq < log_next_seq) {
struct printk_log *msg = log_from_idx(idx); struct printk_log *msg = log_from_idx(idx);
len += msg_print_text(msg, prev, true, NULL, 0); len += msg_print_text(msg, true, NULL, 0);
prev = msg->flags;
idx = log_next(idx); idx = log_next(idx);
seq++; seq++;
} }
@ -1368,12 +1327,10 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
/* move first record forward until length fits into the buffer */ /* move first record forward until length fits into the buffer */
seq = clear_seq; seq = clear_seq;
idx = clear_idx; idx = clear_idx;
prev = 0;
while (len > size && seq < log_next_seq) { while (len > size && seq < log_next_seq) {
struct printk_log *msg = log_from_idx(idx); struct printk_log *msg = log_from_idx(idx);
len -= msg_print_text(msg, prev, true, NULL, 0); len -= msg_print_text(msg, true, NULL, 0);
prev = msg->flags;
idx = log_next(idx); idx = log_next(idx);
seq++; seq++;
} }
@ -1386,7 +1343,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
struct printk_log *msg = log_from_idx(idx); struct printk_log *msg = log_from_idx(idx);
int textlen; int textlen;
textlen = msg_print_text(msg, prev, true, text, textlen = msg_print_text(msg, true, text,
LOG_LINE_MAX + PREFIX_MAX); LOG_LINE_MAX + PREFIX_MAX);
if (textlen < 0) { if (textlen < 0) {
len = textlen; len = textlen;
@ -1394,7 +1351,6 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
} }
idx = log_next(idx); idx = log_next(idx);
seq++; seq++;
prev = msg->flags;
raw_spin_unlock_irq(&logbuf_lock); raw_spin_unlock_irq(&logbuf_lock);
if (copy_to_user(buf + len, text, textlen)) if (copy_to_user(buf + len, text, textlen))
@ -1407,7 +1363,6 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
/* messages are gone, move to next one */ /* messages are gone, move to next one */
seq = log_first_seq; seq = log_first_seq;
idx = log_first_idx; idx = log_first_idx;
prev = 0;
} }
} }
} }
@ -1508,7 +1463,6 @@ int do_syslog(int type, char __user *buf, int len, int source)
/* messages are gone, move to first one */ /* messages are gone, move to first one */
syslog_seq = log_first_seq; syslog_seq = log_first_seq;
syslog_idx = log_first_idx; syslog_idx = log_first_idx;
syslog_prev = 0;
syslog_partial = 0; syslog_partial = 0;
} }
if (source == SYSLOG_FROM_PROC) { if (source == SYSLOG_FROM_PROC) {
@ -1521,16 +1475,14 @@ int do_syslog(int type, char __user *buf, int len, int source)
} else { } else {
u64 seq = syslog_seq; u64 seq = syslog_seq;
u32 idx = syslog_idx; u32 idx = syslog_idx;
enum log_flags prev = syslog_prev;
error = 0; error = 0;
while (seq < log_next_seq) { while (seq < log_next_seq) {
struct printk_log *msg = log_from_idx(idx); struct printk_log *msg = log_from_idx(idx);
error += msg_print_text(msg, prev, true, NULL, 0); error += msg_print_text(msg, true, NULL, 0);
idx = log_next(idx); idx = log_next(idx);
seq++; seq++;
prev = msg->flags;
} }
error -= syslog_partial; error -= syslog_partial;
} }
@ -1712,7 +1664,7 @@ static size_t cont_print_text(char *text, size_t size)
size_t textlen = 0; size_t textlen = 0;
size_t len; size_t len;
if (cont.cons == 0 && (console_prev & LOG_NEWLINE)) { if (cont.cons == 0) {
textlen += print_time(cont.ts_nsec, text); textlen += print_time(cont.ts_nsec, text);
size -= textlen; size -= textlen;
} }
@ -1981,11 +1933,9 @@ static u64 syslog_seq;
static u32 syslog_idx; static u32 syslog_idx;
static u64 console_seq; static u64 console_seq;
static u32 console_idx; static u32 console_idx;
static enum log_flags syslog_prev;
static u64 log_first_seq; static u64 log_first_seq;
static u32 log_first_idx; static u32 log_first_idx;
static u64 log_next_seq; static u64 log_next_seq;
static enum log_flags console_prev;
static struct cont { static struct cont {
size_t len; size_t len;
size_t cons; size_t cons;
@ -1997,15 +1947,15 @@ static char *log_dict(const struct printk_log *msg) { return NULL; }
static struct printk_log *log_from_idx(u32 idx) { return NULL; } static struct printk_log *log_from_idx(u32 idx) { return NULL; }
static u32 log_next(u32 idx) { return 0; } static u32 log_next(u32 idx) { return 0; }
static ssize_t msg_print_ext_header(char *buf, size_t size, static ssize_t msg_print_ext_header(char *buf, size_t size,
struct printk_log *msg, u64 seq, struct printk_log *msg,
enum log_flags prev_flags) { return 0; } u64 seq) { return 0; }
static ssize_t msg_print_ext_body(char *buf, size_t size, static ssize_t msg_print_ext_body(char *buf, size_t size,
char *dict, size_t dict_len, char *dict, size_t dict_len,
char *text, size_t text_len) { return 0; } char *text, size_t text_len) { return 0; }
static void call_console_drivers(int level, static void call_console_drivers(int level,
const char *ext_text, size_t ext_len, const char *ext_text, size_t ext_len,
const char *text, size_t len) {} const char *text, size_t len) {}
static size_t msg_print_text(const struct printk_log *msg, enum log_flags prev, static size_t msg_print_text(const struct printk_log *msg,
bool syslog, char *buf, size_t size) { return 0; } bool syslog, char *buf, size_t size) { return 0; }
static size_t cont_print_text(char *text, size_t size) { return 0; } static size_t cont_print_text(char *text, size_t size) { return 0; }
static bool suppress_message_printing(int level) { return false; } static bool suppress_message_printing(int level) { return false; }
@ -2382,7 +2332,6 @@ again:
/* messages are gone, move to first one */ /* messages are gone, move to first one */
console_seq = log_first_seq; console_seq = log_first_seq;
console_idx = log_first_idx; console_idx = log_first_idx;
console_prev = 0;
} else { } else {
len = 0; len = 0;
} }
@ -2407,16 +2356,14 @@ skip:
* will properly dump everything later. * will properly dump everything later.
*/ */
msg->flags &= ~LOG_NOCONS; msg->flags &= ~LOG_NOCONS;
console_prev = msg->flags;
goto skip; goto skip;
} }
len += msg_print_text(msg, console_prev, false, len += msg_print_text(msg, false, text + len, sizeof(text) - len);
text + len, sizeof(text) - len);
if (nr_ext_console_drivers) { if (nr_ext_console_drivers) {
ext_len = msg_print_ext_header(ext_text, ext_len = msg_print_ext_header(ext_text,
sizeof(ext_text), sizeof(ext_text),
msg, console_seq, console_prev); msg, console_seq);
ext_len += msg_print_ext_body(ext_text + ext_len, ext_len += msg_print_ext_body(ext_text + ext_len,
sizeof(ext_text) - ext_len, sizeof(ext_text) - ext_len,
log_dict(msg), msg->dict_len, log_dict(msg), msg->dict_len,
@ -2424,7 +2371,6 @@ skip:
} }
console_idx = log_next(console_idx); console_idx = log_next(console_idx);
console_seq++; console_seq++;
console_prev = msg->flags;
raw_spin_unlock(&logbuf_lock); raw_spin_unlock(&logbuf_lock);
stop_critical_timings(); /* don't trace print latency */ stop_critical_timings(); /* don't trace print latency */
@ -2719,7 +2665,6 @@ void register_console(struct console *newcon)
raw_spin_lock_irqsave(&logbuf_lock, flags); raw_spin_lock_irqsave(&logbuf_lock, flags);
console_seq = syslog_seq; console_seq = syslog_seq;
console_idx = syslog_idx; console_idx = syslog_idx;
console_prev = syslog_prev;
raw_spin_unlock_irqrestore(&logbuf_lock, flags); raw_spin_unlock_irqrestore(&logbuf_lock, flags);
/* /*
* We're about to replay the log buffer. Only do this to the * We're about to replay the log buffer. Only do this to the
@ -3075,7 +3020,7 @@ bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog,
goto out; goto out;
msg = log_from_idx(dumper->cur_idx); msg = log_from_idx(dumper->cur_idx);
l = msg_print_text(msg, 0, syslog, line, size); l = msg_print_text(msg, syslog, line, size);
dumper->cur_idx = log_next(dumper->cur_idx); dumper->cur_idx = log_next(dumper->cur_idx);
dumper->cur_seq++; dumper->cur_seq++;
@ -3144,7 +3089,6 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
u32 idx; u32 idx;
u64 next_seq; u64 next_seq;
u32 next_idx; u32 next_idx;
enum log_flags prev;
size_t l = 0; size_t l = 0;
bool ret = false; bool ret = false;
@ -3167,27 +3111,23 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
/* calculate length of entire buffer */ /* calculate length of entire buffer */
seq = dumper->cur_seq; seq = dumper->cur_seq;
idx = dumper->cur_idx; idx = dumper->cur_idx;
prev = 0;
while (seq < dumper->next_seq) { while (seq < dumper->next_seq) {
struct printk_log *msg = log_from_idx(idx); struct printk_log *msg = log_from_idx(idx);
l += msg_print_text(msg, prev, true, NULL, 0); l += msg_print_text(msg, true, NULL, 0);
idx = log_next(idx); idx = log_next(idx);
seq++; seq++;
prev = msg->flags;
} }
/* move first record forward until length fits into the buffer */ /* move first record forward until length fits into the buffer */
seq = dumper->cur_seq; seq = dumper->cur_seq;
idx = dumper->cur_idx; idx = dumper->cur_idx;
prev = 0;
while (l > size && seq < dumper->next_seq) { while (l > size && seq < dumper->next_seq) {
struct printk_log *msg = log_from_idx(idx); struct printk_log *msg = log_from_idx(idx);
l -= msg_print_text(msg, prev, true, NULL, 0); l -= msg_print_text(msg, true, NULL, 0);
idx = log_next(idx); idx = log_next(idx);
seq++; seq++;
prev = msg->flags;
} }
/* last message in next interation */ /* last message in next interation */
@ -3198,10 +3138,9 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
while (seq < dumper->next_seq) { while (seq < dumper->next_seq) {
struct printk_log *msg = log_from_idx(idx); struct printk_log *msg = log_from_idx(idx);
l += msg_print_text(msg, prev, syslog, buf + l, size - l); l += msg_print_text(msg, syslog, buf + l, size - l);
idx = log_next(idx); idx = log_next(idx);
seq++; seq++;
prev = msg->flags;
} }
dumper->next_seq = next_seq; dumper->next_seq = next_seq;