Printk changes for 4.21

-----BEGIN PGP SIGNATURE-----
 Version: GnuPG v2
 
 iQIcBAABAgAGBQJcG5XBAAoJEFKgDEdIgJTyoV8QAJGJtlSLXJewMaJyLom8fb2I
 YvdNo2gq+uLeNAwNoOio/pcMZypfjoISYq7T4etfElXay42c7MgZftMoo/cmtlhs
 FU9WUVYUXWLuaMgibP7nl9fsNUtRt/ySY7PfOj3nu6A/E4dqqNWnoC7V9rLp2h70
 Np7L1JEnUr0daRhY6sBm2V6VwQKxjXHY/sdC3xw88R8CVA1wMAxCxouz8qHopvn3
 4Anfhu4o6e4PGCw8YxFIwKS7K5MtDP/WESOF/80/EB+tZkJzH63B3ozqxMirlHMt
 zilw6FPwZRX1NRJ1gDJJmZjt0rwC9oCr0u93QUdUx9j179THs8TBf3DaJEIx87zZ
 fwy+PpN+8OXnS+6qAQOhSaMtms6pPE73Kr2vTukvNmhEoHc0lGIXbKQeWdVl248a
 y9nTlJiOCEiA/nssNGpUVM7uncziKOmJOoQfyaSI9OOo/u3tAwZXrAe7f3GPKeWo
 o6RaIKfTx1LJhco1vxbc93pKCK4ItXU0aQxjRbpBBRjhlFJG8C8alKRagx4LXRpe
 5bFd7L+amtN6BzpeI1uGMKEeRBwn0zjlPrc12bTe6MjiRLr3wtthspELY2ubcIxk
 ghe7ARzb05X9O206EkF6Mir/fn3oudrouuAGyJjNQyAi/OjijRB92l7dLkn/Pe1o
 hNTPMDU/po0y3ulDwaVx
 =FeVC
 -----END PGP SIGNATURE-----

Merge tag 'printk-for-4.21' of git://git.kernel.org/pub/scm/linux/kernel/git/pmladek/printk

Pull printk updates from Petr Mladek:

 - Keep spinlocks busted until the end of panic()

 - Fix races between calculating number of messages that would fit into
   user space buffers, filling the buffers, and switching printk.time
   parameter

 - Some code clean up

* tag 'printk-for-4.21' of git://git.kernel.org/pub/scm/linux/kernel/git/pmladek/printk:
  printk: Remove print_prefix() calls with NULL buffer.
  printk: fix printk_time race.
  printk: Make printk_emit() local function.
  panic: avoid deadlocks in re-entrant console drivers
This commit is contained in:
Linus Torvalds 2018-12-27 11:24:43 -08:00
commit a3b5c1065f
3 changed files with 68 additions and 74 deletions

View File

@ -166,11 +166,6 @@ int vprintk_emit(int facility, int level,
asmlinkage __printf(1, 0)
int vprintk(const char *fmt, va_list args);
asmlinkage __printf(5, 6) __cold
int printk_emit(int facility, int level,
const char *dict, size_t dictlen,
const char *fmt, ...);
asmlinkage __printf(1, 2) __cold
int printk(const char *fmt, ...);

View File

@ -14,6 +14,7 @@
#include <linux/kmsg_dump.h>
#include <linux/kallsyms.h>
#include <linux/notifier.h>
#include <linux/vt_kern.h>
#include <linux/module.h>
#include <linux/random.h>
#include <linux/ftrace.h>
@ -237,7 +238,10 @@ void panic(const char *fmt, ...)
if (_crash_kexec_post_notifiers)
__crash_kexec(NULL);
bust_spinlocks(0);
#ifdef CONFIG_VT
unblank_screen();
#endif
console_unblank();
/*
* We may have ended up stopping the CPU holding the lock (in

View File

@ -403,6 +403,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;
@ -752,6 +753,19 @@ struct devkmsg_user {
char buf[CONSOLE_EXT_LOG_MAX];
};
static __printf(3, 4) __cold
int devkmsg_emit(int facility, int level, const char *fmt, ...)
{
va_list args;
int r;
va_start(args, fmt);
r = vprintk_emit(facility, level, NULL, 0, fmt, args);
va_end(args);
return r;
}
static ssize_t devkmsg_write(struct kiocb *iocb, struct iov_iter *from)
{
char *buf, *line;
@ -810,7 +824,7 @@ static ssize_t devkmsg_write(struct kiocb *iocb, struct iov_iter *from)
}
}
printk_emit(facility, level, NULL, 0, "%s", line);
devkmsg_emit(facility, level, "%s", line);
kfree(buf);
return ret;
}
@ -1213,50 +1227,39 @@ static inline void boot_delay_msec(int level)
static bool printk_time = IS_ENABLED(CONFIG_PRINTK_TIME);
module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
static size_t print_syslog(unsigned int level, char *buf)
{
return sprintf(buf, "<%u>", level);
}
static size_t print_time(u64 ts, char *buf)
{
unsigned long rem_nsec;
if (!printk_time)
return 0;
rem_nsec = do_div(ts, 1000000000);
if (!buf)
return snprintf(NULL, 0, "[%5lu.000000] ", (unsigned long)ts);
unsigned long rem_nsec = do_div(ts, 1000000000);
return sprintf(buf, "[%5lu.%06lu] ",
(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;
if (syslog) {
if (buf) {
len += sprintf(buf, "<%u>", prefix);
} else {
len += 3;
if (prefix > 999)
len += 3;
else if (prefix > 99)
len += 2;
else if (prefix > 9)
len++;
}
}
len += print_time(msg->ts_nsec, buf ? buf + len : NULL);
if (syslog)
len = print_syslog((msg->facility << 3) | msg->level, buf);
if (time)
len += print_time(msg->ts_nsec, buf + len);
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;
size_t len = 0;
char prefix[PREFIX_MAX];
const size_t prefix_len = print_prefix(msg, syslog, time, prefix);
do {
const char *next = memchr(text, '\n', text_size);
@ -1271,19 +1274,17 @@ static size_t msg_print_text(const struct printk_log *msg, bool syslog, char *bu
}
if (buf) {
if (print_prefix(msg, syslog, NULL) +
text_len + 1 >= size - len)
if (prefix_len + text_len + 1 >= size - len)
break;
len += print_prefix(msg, syslog, buf + len);
memcpy(buf + len, prefix, prefix_len);
len += prefix_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 += text_len;
len++;
len += prefix_len + text_len + 1;
}
text = next;
@ -1318,9 +1319,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);
@ -1360,11 +1369,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,
@ -1375,7 +1386,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++;
}
@ -1386,7 +1397,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++;
}
@ -1397,14 +1408,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++;
@ -1528,11 +1534,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++;
}
@ -1935,21 +1944,6 @@ asmlinkage int vprintk(const char *fmt, va_list args)
}
EXPORT_SYMBOL(vprintk);
asmlinkage int printk_emit(int facility, int level,
const char *dict, size_t dictlen,
const char *fmt, ...)
{
va_list args;
int r;
va_start(args, fmt);
r = vprintk_emit(facility, level, dict, dictlen, fmt, args);
va_end(args);
return r;
}
EXPORT_SYMBOL(printk_emit);
int vprintk_default(const char *fmt, va_list args)
{
int r;
@ -2005,6 +1999,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;
@ -2028,8 +2023,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 */
@ -2387,8 +2382,7 @@ skip:
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),
@ -3112,7 +3106,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++;
@ -3183,6 +3177,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;
@ -3206,7 +3201,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++;
}
@ -3217,7 +3212,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++;
}
@ -3230,7 +3225,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++;
}