Skip to content

L
linux
Commit 5becfb1d authored by Kay Sievers's avatar Kay Sievers Committed by Greg Kroah-Hartman
Browse files
Options

kmsg: merge continuation records while printing 

In (the unlikely) case our continuation merge buffer is busy, we unfortunately
can not merge further continuation printk()s into a single record and have to
store them separately, which leads to split-up output of these lines when they
are printed.

Add some flags about newlines and prefix existence to these records and try to
reconstruct the full line again, when the separated records are printed.
Reported-By: default avatarMichael Neuling <mikey@neuling.org>
Cc: Dave Jones <davej@redhat.com>
Cc: Linus Torvalds <torvalds@linux-foundation.org>
Tested-By: default avatarMichael Neuling <mikey@neuling.org>
Signed-off-by: default avatarKay Sievers <kay@vrfy.org>
Signed-off-by: default avatarGreg Kroah-Hartman <gregkh@linuxfoundation.org>
parent eb02dac9
Hide whitespace changes
Inline Side-by-side
Showing with 78 additions and 42 deletions
kernel/printk.c
View file @ 5becfb1d
...@@ -194,8 +194,10 @@ static int console_may_schedule; ...@@ -194,8 +194,10 @@ static int console_may_schedule;
*/ */
enum log_flags { enum log_flags {
LOG_DEFAULT = 0, LOG_NOCONS = 1, /* already flushed, do not print to console */
LOG_NOCONS = 1, /* already flushed, do not print to console */ LOG_NEWLINE = 2, /* text ended with a newline */
LOG_PREFIX = 4, /* text started with a prefix */
LOG_CONT = 8, /* text is a fragment of a continuation line */
}; };
struct log { struct log {
...@@ -217,6 +219,7 @@ static DEFINE_RAW_SPINLOCK(logbuf_lock); ...@@ -217,6 +219,7 @@ static DEFINE_RAW_SPINLOCK(logbuf_lock);
/* 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 */
...@@ -839,13 +842,26 @@ static size_t print_prefix(const struct log *msg, bool syslog, char *buf) ...@@ -839,13 +842,26 @@ static size_t print_prefix(const struct log *msg, bool syslog, char *buf)
return len; return len;
} }
static size_t msg_print_text(const struct log *msg, bool syslog, static size_t msg_print_text(const struct log *msg, enum log_flags prev,
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;
...@@ -863,16 +879,22 @@ static size_t msg_print_text(const struct log *msg, bool syslog, ...@@ -863,16 +879,22 @@ static size_t msg_print_text(const struct log *msg, bool syslog,
text_len + 1>= size - len) text_len + 1>= size - len)
break; break;
len += print_prefix(msg, syslog, buf + len); if (prefix)
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;
buf[len++] = '\n'; if (next || newline)
buf[len++] = '\n';
} else { } else {
/* SYSLOG_ACTION_* buffer size only calculation */ /* SYSLOG_ACTION_* buffer size only calculation */
len += print_prefix(msg, syslog, NULL); if (prefix)
len += text_len + 1; len += print_prefix(msg, syslog, NULL);
len += text_len;
if (next || newline)
len++;
} }
prefix = true;
text = next; text = next;
} while (text); } while (text);
...@@ -898,6 +920,7 @@ static int syslog_print(char __user *buf, int size) ...@@ -898,6 +920,7 @@ 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) {
...@@ -907,11 +930,12 @@ static int syslog_print(char __user *buf, int size) ...@@ -907,11 +930,12 @@ 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, true, text, LOG_LINE_MAX); n = msg_print_text(msg, syslog_prev, true, text, LOG_LINE_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){
...@@ -954,6 +978,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear) ...@@ -954,6 +978,7 @@ 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;
if (clear_seq < log_first_seq) { if (clear_seq < log_first_seq) {
/* messages are gone, move to first available one */ /* messages are gone, move to first available one */
...@@ -967,10 +992,11 @@ static int syslog_print_all(char __user *buf, int size, bool clear) ...@@ -967,10 +992,11 @@ 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 log *msg = log_from_idx(idx); struct log *msg = log_from_idx(idx);
len += msg_print_text(msg, true, NULL, 0); len += msg_print_text(msg, prev, true, NULL, 0);
idx = log_next(idx); idx = log_next(idx);
seq++; seq++;
} }
...@@ -978,10 +1004,11 @@ static int syslog_print_all(char __user *buf, int size, bool clear) ...@@ -978,10 +1004,11 @@ 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 log *msg = log_from_idx(idx); struct log *msg = log_from_idx(idx);
len -= msg_print_text(msg, true, NULL, 0); len -= msg_print_text(msg, prev, true, NULL, 0);
idx = log_next(idx); idx = log_next(idx);
seq++; seq++;
} }
...@@ -990,17 +1017,19 @@ static int syslog_print_all(char __user *buf, int size, bool clear) ...@@ -990,17 +1017,19 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
next_seq = log_next_seq; next_seq = log_next_seq;
len = 0; len = 0;
prev = 0;
while (len >= 0 && seq < next_seq) { while (len >= 0 && seq < next_seq) {
struct log *msg = log_from_idx(idx); struct log *msg = log_from_idx(idx);
int textlen; int textlen;
textlen = msg_print_text(msg, true, text, LOG_LINE_MAX); textlen = msg_print_text(msg, prev, true, text, LOG_LINE_MAX);
if (textlen < 0) { if (textlen < 0) {
len = textlen; len = textlen;
break; break;
} }
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))
...@@ -1013,6 +1042,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear) ...@@ -1013,6 +1042,7 @@ 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;
} }
} }
} }
...@@ -1117,6 +1147,7 @@ int do_syslog(int type, char __user *buf, int len, bool from_file) ...@@ -1117,6 +1147,7 @@ int do_syslog(int type, char __user *buf, int len, bool from_file)
/* 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 (from_file) { if (from_file) {
...@@ -1127,18 +1158,18 @@ int do_syslog(int type, char __user *buf, int len, bool from_file) ...@@ -1127,18 +1158,18 @@ int do_syslog(int type, char __user *buf, int len, bool from_file)
*/ */
error = log_next_idx - syslog_idx; error = log_next_idx - syslog_idx;
} else { } else {
u64 seq; u64 seq = syslog_seq;
u32 idx; u32 idx = syslog_idx;
enum log_flags prev = syslog_prev;
error = 0; error = 0;
seq = syslog_seq;
idx = syslog_idx;
while (seq < log_next_seq) { while (seq < log_next_seq) {
struct log *msg = log_from_idx(idx); struct log *msg = log_from_idx(idx);
error += msg_print_text(msg, true, NULL, 0); error += msg_print_text(msg, prev, true, NULL, 0);
idx = log_next(idx); idx = log_next(idx);
seq++; seq++;
prev = msg->flags;
} }
error -= syslog_partial; error -= syslog_partial;
} }
...@@ -1408,10 +1439,9 @@ asmlinkage int vprintk_emit(int facility, int level, ...@@ -1408,10 +1439,9 @@ asmlinkage int vprintk_emit(int facility, int level,
static char textbuf[LOG_LINE_MAX]; static char textbuf[LOG_LINE_MAX];
char *text = textbuf; char *text = textbuf;
size_t text_len; size_t text_len;
enum log_flags lflags = 0;
unsigned long flags; unsigned long flags;
int this_cpu; int this_cpu;
bool newline = false;
bool prefix = false;
int printed_len = 0; int printed_len = 0;
boot_delay_msec(); boot_delay_msec();
...@@ -1450,7 +1480,7 @@ asmlinkage int vprintk_emit(int facility, int level, ...@@ -1450,7 +1480,7 @@ asmlinkage int vprintk_emit(int facility, int level,
recursion_bug = 0; recursion_bug = 0;
printed_len += strlen(recursion_msg); printed_len += strlen(recursion_msg);
/* emit KERN_CRIT message */ /* emit KERN_CRIT message */
log_store(0, 2, LOG_DEFAULT, 0, log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0,
NULL, 0, recursion_msg, printed_len); NULL, 0, recursion_msg, printed_len);
} }
...@@ -1463,7 +1493,7 @@ asmlinkage int vprintk_emit(int facility, int level, ...@@ -1463,7 +1493,7 @@ asmlinkage int vprintk_emit(int facility, int level,
/* mark and strip a trailing newline */ /* mark and strip a trailing newline */
if (text_len && text[text_len-1] == '\n') { if (text_len && text[text_len-1] == '\n') {
text_len--; text_len--;
newline = true; lflags |= LOG_NEWLINE;
} }
/* strip syslog prefix and extract log level or control flags */ /* strip syslog prefix and extract log level or control flags */
...@@ -1473,7 +1503,7 @@ asmlinkage int vprintk_emit(int facility, int level, ...@@ -1473,7 +1503,7 @@ asmlinkage int vprintk_emit(int facility, int level,
if (level == -1) if (level == -1)
level = text[1] - '0'; level = text[1] - '0';
case 'd': /* KERN_DEFAULT */ case 'd': /* KERN_DEFAULT */
prefix = true; lflags |= LOG_PREFIX;
case 'c': /* KERN_CONT */ case 'c': /* KERN_CONT */
text += 3; text += 3;
text_len -= 3; text_len -= 3;
...@@ -1483,22 +1513,20 @@ asmlinkage int vprintk_emit(int facility, int level, ...@@ -1483,22 +1513,20 @@ asmlinkage int vprintk_emit(int facility, int level,
if (level == -1) if (level == -1)
level = default_message_loglevel; level = default_message_loglevel;
if (dict) { if (dict)
prefix = true; lflags |= LOG_PREFIX|LOG_NEWLINE;
newline = true;
}
if (!newline) { if (!(lflags & LOG_NEWLINE)) {
/* /*
* Flush the conflicting buffer. An earlier newline was missing, * Flush the conflicting buffer. An earlier newline was missing,
* or another task also prints continuation lines. * or another task also prints continuation lines.
*/ */
if (cont.len && (prefix || cont.owner != current)) if (cont.len && (lflags & LOG_PREFIX || cont.owner != current))
cont_flush(); cont_flush();
/* buffer line if possible, otherwise store it right away */ /* buffer line if possible, otherwise store it right away */
if (!cont_add(facility, level, text, text_len)) if (!cont_add(facility, level, text, text_len))
log_store(facility, level, LOG_DEFAULT, 0, log_store(facility, level, lflags | LOG_CONT, 0,
dict, dictlen, text, text_len); dict, dictlen, text, text_len);
} else { } else {
bool stored = false; bool stored = false;
...@@ -1510,13 +1538,13 @@ asmlinkage int vprintk_emit(int facility, int level, ...@@ -1510,13 +1538,13 @@ asmlinkage int vprintk_emit(int facility, int level,
* flush it out and store this line separately. * flush it out and store this line separately.
*/ */
if (cont.len && cont.owner == current) { if (cont.len && cont.owner == current) {
if (!prefix) if (!(lflags & LOG_PREFIX))
stored = cont_add(facility, level, text, text_len); stored = cont_add(facility, level, text, text_len);
cont_flush(); cont_flush();
} }
if (!stored) if (!stored)
log_store(facility, level, LOG_DEFAULT, 0, log_store(facility, level, lflags, 0,
dict, dictlen, text, text_len); dict, dictlen, text, text_len);
} }
printed_len += text_len; printed_len += text_len;
...@@ -1615,8 +1643,8 @@ static struct cont { ...@@ -1615,8 +1643,8 @@ static struct cont {
static struct log *log_from_idx(u32 idx) { return NULL; } static struct 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 void call_console_drivers(int level, const char *text, size_t len) {} static void call_console_drivers(int level, const char *text, size_t len) {}
static size_t msg_print_text(const struct log *msg, bool syslog, static size_t msg_print_text(const struct log *msg, enum log_flags prev,
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; }
#endif /* CONFIG_PRINTK */ #endif /* CONFIG_PRINTK */
...@@ -1892,6 +1920,7 @@ void wake_up_klogd(void) ...@@ -1892,6 +1920,7 @@ void wake_up_klogd(void)
/* 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;
/** /**
* console_unlock - unlock the console system * console_unlock - unlock the console system
...@@ -1952,6 +1981,7 @@ void console_unlock(void) ...@@ -1952,6 +1981,7 @@ void console_unlock(void)
/* 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;
} }
skip: skip:
if (console_seq == log_next_seq) if (console_seq == log_next_seq)
...@@ -1975,10 +2005,11 @@ void console_unlock(void) ...@@ -1975,10 +2005,11 @@ void console_unlock(void)
} }
level = msg->level; level = msg->level;
len = msg_print_text(msg, false, text, sizeof(text)); len = msg_print_text(msg, console_prev, false,
text, sizeof(text));
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 */
...@@ -2241,6 +2272,7 @@ void register_console(struct console *newcon) ...@@ -2241,6 +2272,7 @@ 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
...@@ -2534,8 +2566,7 @@ bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog, ...@@ -2534,8 +2566,7 @@ bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
} }
msg = log_from_idx(dumper->cur_idx); msg = log_from_idx(dumper->cur_idx);
l = msg_print_text(msg, syslog, l = msg_print_text(msg, 0, syslog, line, size);
line, size);
dumper->cur_idx = log_next(dumper->cur_idx); dumper->cur_idx = log_next(dumper->cur_idx);
dumper->cur_seq++; dumper->cur_seq++;
...@@ -2575,6 +2606,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog, ...@@ -2575,6 +2606,7 @@ 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;
...@@ -2597,23 +2629,27 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog, ...@@ -2597,23 +2629,27 @@ 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 log *msg = log_from_idx(idx); struct log *msg = log_from_idx(idx);
l += msg_print_text(msg, true, NULL, 0); l += msg_print_text(msg, prev, 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 log *msg = log_from_idx(idx); struct log *msg = log_from_idx(idx);
l -= msg_print_text(msg, true, NULL, 0); l -= msg_print_text(msg, prev, 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 */
...@@ -2621,14 +2657,14 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog, ...@@ -2621,14 +2657,14 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
next_idx = idx; next_idx = idx;
l = 0; l = 0;
prev = 0;
while (seq < dumper->next_seq) { while (seq < dumper->next_seq) {
struct log *msg = log_from_idx(idx); struct log *msg = log_from_idx(idx);
l += msg_print_text(msg, syslog, l += msg_print_text(msg, prev, syslog, buf + l, size - l);
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;
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment
GitLab Nexedi Edition | About GitLab | About Nexedi | 沪ICP备2021021310号-2 | 沪ICP备2021021310号-7