summaryrefslogtreecommitdiffstats
path: root/kernel/printk/printk.c
diff options
context:
space:
mode:
Diffstat (limited to 'kernel/printk/printk.c')
-rw-r--r--kernel/printk/printk.c234
1 files changed, 100 insertions, 134 deletions
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 8b2696420abb..34da86e73d00 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -213,17 +213,36 @@ static int nr_ext_console_drivers;
static int __down_trylock_console_sem(unsigned long ip)
{
- if (down_trylock(&console_sem))
+ int lock_failed;
+ unsigned long flags;
+
+ /*
+ * Here and in __up_console_sem() we need to be in safe mode,
+ * because spindump/WARN/etc from under console ->lock will
+ * deadlock in printk()->down_trylock_console_sem() otherwise.
+ */
+ printk_safe_enter_irqsave(flags);
+ lock_failed = down_trylock(&console_sem);
+ printk_safe_exit_irqrestore(flags);
+
+ if (lock_failed)
return 1;
mutex_acquire(&console_lock_dep_map, 0, 1, ip);
return 0;
}
#define down_trylock_console_sem() __down_trylock_console_sem(_RET_IP_)
-#define up_console_sem() do { \
- mutex_release(&console_lock_dep_map, 1, _RET_IP_);\
- up(&console_sem);\
-} while (0)
+static void __up_console_sem(unsigned long ip)
+{
+ unsigned long flags;
+
+ mutex_release(&console_lock_dep_map, 1, ip);
+
+ printk_safe_enter_irqsave(flags);
+ up(&console_sem);
+ printk_safe_exit_irqrestore(flags);
+}
+#define up_console_sem() __up_console_sem(_RET_IP_)
/*
* This is used for debugging the mess that is the VT code by
@@ -351,6 +370,34 @@ __packed __aligned(4)
*/
DEFINE_RAW_SPINLOCK(logbuf_lock);
+/*
+ * Helper macros to lock/unlock logbuf_lock and switch between
+ * printk-safe/unsafe modes.
+ */
+#define logbuf_lock_irq() \
+ do { \
+ printk_safe_enter_irq(); \
+ raw_spin_lock(&logbuf_lock); \
+ } while (0)
+
+#define logbuf_unlock_irq() \
+ do { \
+ raw_spin_unlock(&logbuf_lock); \
+ printk_safe_exit_irq(); \
+ } while (0)
+
+#define logbuf_lock_irqsave(flags) \
+ do { \
+ printk_safe_enter_irqsave(flags); \
+ raw_spin_lock(&logbuf_lock); \
+ } while (0)
+
+#define logbuf_unlock_irqrestore(flags) \
+ do { \
+ raw_spin_unlock(&logbuf_lock); \
+ printk_safe_exit_irqrestore(flags); \
+ } while (0)
+
#ifdef CONFIG_PRINTK
DECLARE_WAIT_QUEUE_HEAD(log_wait);
/* the next printk record to read by syslog(READ) or /proc/kmsg */
@@ -782,20 +829,21 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
ret = mutex_lock_interruptible(&user->lock);
if (ret)
return ret;
- raw_spin_lock_irq(&logbuf_lock);
+
+ logbuf_lock_irq();
while (user->seq == log_next_seq) {
if (file->f_flags & O_NONBLOCK) {
ret = -EAGAIN;
- raw_spin_unlock_irq(&logbuf_lock);
+ logbuf_unlock_irq();
goto out;
}
- raw_spin_unlock_irq(&logbuf_lock);
+ logbuf_unlock_irq();
ret = wait_event_interruptible(log_wait,
user->seq != log_next_seq);
if (ret)
goto out;
- raw_spin_lock_irq(&logbuf_lock);
+ logbuf_lock_irq();
}
if (user->seq < log_first_seq) {
@@ -803,7 +851,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
user->idx = log_first_idx;
user->seq = log_first_seq;
ret = -EPIPE;
- raw_spin_unlock_irq(&logbuf_lock);
+ logbuf_unlock_irq();
goto out;
}
@@ -816,7 +864,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
user->idx = log_next(user->idx);
user->seq++;
- raw_spin_unlock_irq(&logbuf_lock);
+ logbuf_unlock_irq();
if (len > count) {
ret = -EINVAL;
@@ -843,7 +891,7 @@ static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence)
if (offset)
return -ESPIPE;
- raw_spin_lock_irq(&logbuf_lock);
+ logbuf_lock_irq();
switch (whence) {
case SEEK_SET:
/* the first record */
@@ -867,7 +915,7 @@ static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence)
default:
ret = -EINVAL;
}
- raw_spin_unlock_irq(&logbuf_lock);
+ logbuf_unlock_irq();
return ret;
}
@@ -881,7 +929,7 @@ static unsigned int devkmsg_poll(struct file *file, poll_table *wait)
poll_wait(file, &log_wait, wait);
- raw_spin_lock_irq(&logbuf_lock);
+ logbuf_lock_irq();
if (user->seq < log_next_seq) {
/* return error when data has vanished underneath us */
if (user->seq < log_first_seq)
@@ -889,7 +937,7 @@ static unsigned int devkmsg_poll(struct file *file, poll_table *wait)
else
ret = POLLIN|POLLRDNORM;
}
- raw_spin_unlock_irq(&logbuf_lock);
+ logbuf_unlock_irq();
return ret;
}
@@ -919,10 +967,10 @@ static int devkmsg_open(struct inode *inode, struct file *file)
mutex_init(&user->lock);
- raw_spin_lock_irq(&logbuf_lock);
+ logbuf_lock_irq();
user->idx = log_first_idx;
user->seq = log_first_seq;
- raw_spin_unlock_irq(&logbuf_lock);
+ logbuf_unlock_irq();
file->private_data = user;
return 0;
@@ -1064,13 +1112,13 @@ void __init setup_log_buf(int early)
return;
}
- raw_spin_lock_irqsave(&logbuf_lock, flags);
+ logbuf_lock_irqsave(flags);
log_buf_len = new_log_buf_len;
log_buf = new_log_buf;
new_log_buf_len = 0;
free = __LOG_BUF_LEN - log_next_idx;
memcpy(log_buf, __log_buf, __LOG_BUF_LEN);
- raw_spin_unlock_irqrestore(&logbuf_lock, flags);
+ logbuf_unlock_irqrestore(flags);
pr_info("log_buf_len: %d bytes\n", log_buf_len);
pr_info("early log buf free: %d(%d%%)\n",
@@ -1248,7 +1296,7 @@ static int syslog_print(char __user *buf, int size)
size_t n;
size_t skip;
- raw_spin_lock_irq(&logbuf_lock);
+ logbuf_lock_irq();
if (syslog_seq < log_first_seq) {
/* messages are gone, move to first one */
syslog_seq = log_first_seq;
@@ -1256,7 +1304,7 @@ static int syslog_print(char __user *buf, int size)
syslog_partial = 0;
}
if (syslog_seq == log_next_seq) {
- raw_spin_unlock_irq(&logbuf_lock);
+ logbuf_unlock_irq();
break;
}
@@ -1275,7 +1323,7 @@ static int syslog_print(char __user *buf, int size)
syslog_partial += n;
} else
n = 0;
- raw_spin_unlock_irq(&logbuf_lock);
+ logbuf_unlock_irq();
if (!n)
break;
@@ -1304,7 +1352,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
if (!text)
return -ENOMEM;
- raw_spin_lock_irq(&logbuf_lock);
+ logbuf_lock_irq();
if (buf) {
u64 next_seq;
u64 seq;
@@ -1352,12 +1400,12 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
idx = log_next(idx);
seq++;
- raw_spin_unlock_irq(&logbuf_lock);
+ logbuf_unlock_irq();
if (copy_to_user(buf + len, text, textlen))
len = -EFAULT;
else
len += textlen;
- raw_spin_lock_irq(&logbuf_lock);
+ logbuf_lock_irq();
if (seq < log_first_seq) {
/* messages are gone, move to next one */
@@ -1371,7 +1419,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
clear_seq = log_next_seq;
clear_idx = log_next_idx;
}
- raw_spin_unlock_irq(&logbuf_lock);
+ logbuf_unlock_irq();
kfree(text);
return len;
@@ -1458,7 +1506,7 @@ int do_syslog(int type, char __user *buf, int len, int source)
break;
/* Number of chars in the log buffer */
case SYSLOG_ACTION_SIZE_UNREAD:
- raw_spin_lock_irq(&logbuf_lock);
+ logbuf_lock_irq();
if (syslog_seq < log_first_seq) {
/* messages are gone, move to first one */
syslog_seq = log_first_seq;
@@ -1486,7 +1534,7 @@ int do_syslog(int type, char __user *buf, int len, int source)
}
error -= syslog_partial;
}
- raw_spin_unlock_irq(&logbuf_lock);
+ logbuf_unlock_irq();
break;
/* Size of the log buffer */
case SYSLOG_ACTION_SIZE_BUFFER:
@@ -1510,13 +1558,12 @@ SYSCALL_DEFINE3(syslog, int, type, char __user *, buf, int, len)
* log_buf[start] to log_buf[end - 1].
* The console_lock must be held.
*/
-static void call_console_drivers(int level,
- const char *ext_text, size_t ext_len,
+static void call_console_drivers(const char *ext_text, size_t ext_len,
const char *text, size_t len)
{
struct console *con;
- trace_console(text, len);
+ trace_console_rcuidle(text, len);
if (!console_drivers)
return;
@@ -1538,28 +1585,6 @@ static void call_console_drivers(int level,
}
}
-/*
- * Zap console related locks when oopsing.
- * To leave time for slow consoles to print a full oops,
- * only zap at most once every 30 seconds.
- */
-static void zap_locks(void)
-{
- static unsigned long oops_timestamp;
-
- if (time_after_eq(jiffies, oops_timestamp) &&
- !time_after(jiffies, oops_timestamp + 30 * HZ))
- return;
-
- oops_timestamp = jiffies;
-
- debug_locks_off();
- /* If a crash is occurring, make sure we can't deadlock */
- raw_spin_lock_init(&logbuf_lock);
- /* And make sure that we print immediately */
- sema_init(&console_sem, 1);
-}
-
int printk_delay_msec __read_mostly;
static inline void printk_delay(void)
@@ -1669,18 +1694,13 @@ asmlinkage int vprintk_emit(int facility, int level,
const char *dict, size_t dictlen,
const char *fmt, va_list args)
{
- static bool recursion_bug;
static char textbuf[LOG_LINE_MAX];
char *text = textbuf;
size_t text_len = 0;
enum log_flags lflags = 0;
unsigned long flags;
- int this_cpu;
int printed_len = 0;
- int nmi_message_lost;
bool in_sched = false;
- /* cpu currently holding logbuf_lock in this function */
- static unsigned int logbuf_cpu = UINT_MAX;
if (level == LOGLEVEL_SCHED) {
level = LOGLEVEL_DEFAULT;
@@ -1690,53 +1710,8 @@ asmlinkage int vprintk_emit(int facility, int level,
boot_delay_msec(level);
printk_delay();
- local_irq_save(flags);
- this_cpu = smp_processor_id();
-
- /*
- * Ouch, printk recursed into itself!
- */
- if (unlikely(logbuf_cpu == this_cpu)) {
- /*
- * If a crash is occurring during printk() on this CPU,
- * then try to get the crash message out but make sure
- * we can't deadlock. Otherwise just return to avoid the
- * recursion and return - but flag the recursion so that
- * it can be printed at the next appropriate moment:
- */
- if (!oops_in_progress && !lockdep_recursing(current)) {
- recursion_bug = true;
- local_irq_restore(flags);
- return 0;
- }
- zap_locks();
- }
-
- lockdep_off();
/* This stops the holder of console_sem just where we want him */
- raw_spin_lock(&logbuf_lock);
- logbuf_cpu = this_cpu;
-
- if (unlikely(recursion_bug)) {
- static const char recursion_msg[] =
- "BUG: recent printk recursion!";
-
- recursion_bug = false;
- /* emit KERN_CRIT message */
- printed_len += log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0,
- NULL, 0, recursion_msg,
- strlen(recursion_msg));
- }
-
- nmi_message_lost = get_nmi_message_lost();
- if (unlikely(nmi_message_lost)) {
- text_len = scnprintf(textbuf, sizeof(textbuf),
- "BAD LUCK: lost %d message(s) from NMI context!",
- nmi_message_lost);
- printed_len += log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0,
- NULL, 0, textbuf, text_len);
- }
-
+ logbuf_lock_irqsave(flags);
/*
* The printf needs to come first; we need the syslog
* prefix which might be passed-in as a parameter.
@@ -1779,14 +1754,10 @@ asmlinkage int vprintk_emit(int facility, int level,
printed_len += log_output(facility, level, lflags, dict, dictlen, text, text_len);
- logbuf_cpu = UINT_MAX;
- raw_spin_unlock(&logbuf_lock);
- lockdep_on();
- local_irq_restore(flags);
+ logbuf_unlock_irqrestore(flags);
/* If called from the scheduler, we can not call up(). */
if (!in_sched) {
- lockdep_off();
/*
* Try to acquire and then immediately release the console
* semaphore. The release will print out buffers and wake up
@@ -1794,7 +1765,6 @@ asmlinkage int vprintk_emit(int facility, int level,
*/
if (console_trylock())
console_unlock();
- lockdep_on();
}
return printed_len;
@@ -1803,7 +1773,7 @@ EXPORT_SYMBOL(vprintk_emit);
asmlinkage int vprintk(const char *fmt, va_list args)
{
- return vprintk_emit(0, LOGLEVEL_DEFAULT, NULL, 0, fmt, args);
+ return vprintk_func(fmt, args);
}
EXPORT_SYMBOL(vprintk);
@@ -1895,16 +1865,12 @@ static ssize_t msg_print_ext_header(char *buf, size_t size,
static ssize_t msg_print_ext_body(char *buf, size_t size,
char *dict, size_t dict_len,
char *text, size_t text_len) { return 0; }
-static void call_console_drivers(int level,
- const char *ext_text, size_t ext_len,
+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 bool suppress_message_printing(int level) { return false; }
-/* Still needs to be defined for users */
-DEFINE_PER_CPU(printk_func_t, printk_func);
-
#endif /* CONFIG_PRINTK */
#ifdef CONFIG_EARLY_PRINTK
@@ -2220,9 +2186,9 @@ again:
struct printk_log *msg;
size_t ext_len = 0;
size_t len;
- int level;
- raw_spin_lock_irqsave(&logbuf_lock, flags);
+ printk_safe_enter_irqsave(flags);
+ raw_spin_lock(&logbuf_lock);
if (seen_seq != log_next_seq) {
wake_klogd = true;
seen_seq = log_next_seq;
@@ -2243,8 +2209,7 @@ skip:
break;
msg = log_from_idx(console_idx);
- level = msg->level;
- if (suppress_message_printing(level)) {
+ if (suppress_message_printing(msg->level)) {
/*
* Skip record we have buffered and already printed
* directly to the console when we received it, and
@@ -2270,9 +2235,9 @@ skip:
raw_spin_unlock(&logbuf_lock);
stop_critical_timings(); /* don't trace print latency */
- call_console_drivers(level, ext_text, ext_len, text, len);
+ call_console_drivers(ext_text, ext_len, text, len);
start_critical_timings();
- local_irq_restore(flags);
+ printk_safe_exit_irqrestore(flags);
if (do_cond_resched)
cond_resched();
@@ -2295,7 +2260,8 @@ skip:
*/
raw_spin_lock(&logbuf_lock);
retry = console_seq != log_next_seq;
- raw_spin_unlock_irqrestore(&logbuf_lock, flags);
+ raw_spin_unlock(&logbuf_lock);
+ printk_safe_exit_irqrestore(flags);
if (retry && console_trylock())
goto again;
@@ -2558,10 +2524,10 @@ void register_console(struct console *newcon)
* console_unlock(); will print out the buffered messages
* for us.
*/
- raw_spin_lock_irqsave(&logbuf_lock, flags);
+ logbuf_lock_irqsave(flags);
console_seq = syslog_seq;
console_idx = syslog_idx;
- raw_spin_unlock_irqrestore(&logbuf_lock, flags);
+ logbuf_unlock_irqrestore(flags);
/*
* We're about to replay the log buffer. Only do this to the
* just-registered console to avoid excessive message spam to
@@ -2860,12 +2826,12 @@ void kmsg_dump(enum kmsg_dump_reason reason)
/* initialize iterator with data about the stored records */
dumper->active = true;
- raw_spin_lock_irqsave(&logbuf_lock, flags);
+ logbuf_lock_irqsave(flags);
dumper->cur_seq = clear_seq;
dumper->cur_idx = clear_idx;
dumper->next_seq = log_next_seq;
dumper->next_idx = log_next_idx;
- raw_spin_unlock_irqrestore(&logbuf_lock, flags);
+ logbuf_unlock_irqrestore(flags);
/* invoke dumper which will iterate over records */
dumper->dump(dumper, reason);
@@ -2950,9 +2916,9 @@ bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
unsigned long flags;
bool ret;
- raw_spin_lock_irqsave(&logbuf_lock, flags);
+ logbuf_lock_irqsave(flags);
ret = kmsg_dump_get_line_nolock(dumper, syslog, line, size, len);
- raw_spin_unlock_irqrestore(&logbuf_lock, flags);
+ logbuf_unlock_irqrestore(flags);
return ret;
}
@@ -2991,7 +2957,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
if (!dumper->active)
goto out;
- raw_spin_lock_irqsave(&logbuf_lock, flags);
+ logbuf_lock_irqsave(flags);
if (dumper->cur_seq < log_first_seq) {
/* messages are gone, move to first available one */
dumper->cur_seq = log_first_seq;
@@ -3000,7 +2966,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
/* last entry */
if (dumper->cur_seq >= dumper->next_seq) {
- raw_spin_unlock_irqrestore(&logbuf_lock, flags);
+ logbuf_unlock_irqrestore(flags);
goto out;
}
@@ -3042,7 +3008,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
dumper->next_seq = next_seq;
dumper->next_idx = next_idx;
ret = true;
- raw_spin_unlock_irqrestore(&logbuf_lock, flags);
+ logbuf_unlock_irqrestore(flags);
out:
if (len)
*len = l;
@@ -3080,9 +3046,9 @@ void kmsg_dump_rewind(struct kmsg_dumper *dumper)
{
unsigned long flags;
- raw_spin_lock_irqsave(&logbuf_lock, flags);
+ logbuf_lock_irqsave(flags);
kmsg_dump_rewind_nolock(dumper);
- raw_spin_unlock_irqrestore(&logbuf_lock, flags);
+ logbuf_unlock_irqrestore(flags);
}
EXPORT_SYMBOL_GPL(kmsg_dump_rewind);