Branch data Line data Source code
1 : : // SPDX-License-Identifier: GPL-2.0-only
2 : : /*
3 : : * linux/kernel/printk.c
4 : : *
5 : : * Copyright (C) 1991, 1992 Linus Torvalds
6 : : *
7 : : * Modified to make sys_syslog() more flexible: added commands to
8 : : * return the last 4k of kernel messages, regardless of whether
9 : : * they've been read or not. Added option to suppress kernel printk's
10 : : * to the console. Added hook for sending the console messages
11 : : * elsewhere, in preparation for a serial line console (someday).
12 : : * Ted Ts'o, 2/11/93.
13 : : * Modified for sysctl support, 1/8/97, Chris Horn.
14 : : * Fixed SMP synchronization, 08/08/99, Manfred Spraul
15 : : * manfred@colorfullife.com
16 : : * Rewrote bits to get rid of console_lock
17 : : * 01Mar01 Andrew Morton
18 : : */
19 : :
20 : : #define pr_fmt(fmt) KBUILD_MODNAME ": " fmt
21 : :
22 : : #include <linux/kernel.h>
23 : : #include <linux/mm.h>
24 : : #include <linux/tty.h>
25 : : #include <linux/tty_driver.h>
26 : : #include <linux/console.h>
27 : : #include <linux/init.h>
28 : : #include <linux/jiffies.h>
29 : : #include <linux/nmi.h>
30 : : #include <linux/module.h>
31 : : #include <linux/moduleparam.h>
32 : : #include <linux/delay.h>
33 : : #include <linux/smp.h>
34 : : #include <linux/security.h>
35 : : #include <linux/memblock.h>
36 : : #include <linux/syscalls.h>
37 : : #include <linux/crash_core.h>
38 : : #include <linux/kdb.h>
39 : : #include <linux/ratelimit.h>
40 : : #include <linux/kmsg_dump.h>
41 : : #include <linux/syslog.h>
42 : : #include <linux/cpu.h>
43 : : #include <linux/rculist.h>
44 : : #include <linux/poll.h>
45 : : #include <linux/irq_work.h>
46 : : #include <linux/ctype.h>
47 : : #include <linux/uio.h>
48 : : #include <linux/sched/clock.h>
49 : : #include <linux/sched/debug.h>
50 : : #include <linux/sched/task_stack.h>
51 : :
52 : : #include <linux/uaccess.h>
53 : : #include <asm/sections.h>
54 : :
55 : : #include <trace/events/initcall.h>
56 : : #define CREATE_TRACE_POINTS
57 : : #include <trace/events/printk.h>
58 : :
59 : : #include "console_cmdline.h"
60 : : #include "braille.h"
61 : : #include "internal.h"
62 : :
63 : : int console_printk[4] = {
64 : : CONSOLE_LOGLEVEL_DEFAULT, /* console_loglevel */
65 : : MESSAGE_LOGLEVEL_DEFAULT, /* default_message_loglevel */
66 : : CONSOLE_LOGLEVEL_MIN, /* minimum_console_loglevel */
67 : : CONSOLE_LOGLEVEL_DEFAULT, /* default_console_loglevel */
68 : : };
69 : : EXPORT_SYMBOL_GPL(console_printk);
70 : :
71 : : atomic_t ignore_console_lock_warning __read_mostly = ATOMIC_INIT(0);
72 : : EXPORT_SYMBOL(ignore_console_lock_warning);
73 : :
74 : : /*
75 : : * Low level drivers may need that to know if they can schedule in
76 : : * their unblank() callback or not. So let's export it.
77 : : */
78 : : int oops_in_progress;
79 : : EXPORT_SYMBOL(oops_in_progress);
80 : :
81 : : /*
82 : : * console_sem protects the console_drivers list, and also
83 : : * provides serialisation for access to the entire console
84 : : * driver system.
85 : : */
86 : : static DEFINE_SEMAPHORE(console_sem);
87 : : struct console *console_drivers;
88 : : EXPORT_SYMBOL_GPL(console_drivers);
89 : :
90 : : /*
91 : : * System may need to suppress printk message under certain
92 : : * circumstances, like after kernel panic happens.
93 : : */
94 : : int __read_mostly suppress_printk;
95 : :
96 : : #ifdef CONFIG_LOCKDEP
97 : : static struct lockdep_map console_lock_dep_map = {
98 : : .name = "console_lock"
99 : : };
100 : : #endif
101 : :
102 : : enum devkmsg_log_bits {
103 : : __DEVKMSG_LOG_BIT_ON = 0,
104 : : __DEVKMSG_LOG_BIT_OFF,
105 : : __DEVKMSG_LOG_BIT_LOCK,
106 : : };
107 : :
108 : : enum devkmsg_log_masks {
109 : : DEVKMSG_LOG_MASK_ON = BIT(__DEVKMSG_LOG_BIT_ON),
110 : : DEVKMSG_LOG_MASK_OFF = BIT(__DEVKMSG_LOG_BIT_OFF),
111 : : DEVKMSG_LOG_MASK_LOCK = BIT(__DEVKMSG_LOG_BIT_LOCK),
112 : : };
113 : :
114 : : /* Keep both the 'on' and 'off' bits clear, i.e. ratelimit by default: */
115 : : #define DEVKMSG_LOG_MASK_DEFAULT 0
116 : :
117 : : static unsigned int __read_mostly devkmsg_log = DEVKMSG_LOG_MASK_DEFAULT;
118 : :
119 : 0 : static int __control_devkmsg(char *str)
120 : : {
121 : : size_t len;
122 : :
123 [ # # ]: 0 : if (!str)
124 : : return -EINVAL;
125 : :
126 : : len = str_has_prefix(str, "on");
127 [ # # ]: 0 : if (len) {
128 : 0 : devkmsg_log = DEVKMSG_LOG_MASK_ON;
129 : 0 : return len;
130 : : }
131 : :
132 : : len = str_has_prefix(str, "off");
133 [ # # ]: 0 : if (len) {
134 : 0 : devkmsg_log = DEVKMSG_LOG_MASK_OFF;
135 : 0 : return len;
136 : : }
137 : :
138 : : len = str_has_prefix(str, "ratelimit");
139 [ # # ]: 0 : if (len) {
140 : 0 : devkmsg_log = DEVKMSG_LOG_MASK_DEFAULT;
141 : 0 : return len;
142 : : }
143 : :
144 : : return -EINVAL;
145 : : }
146 : :
147 : 0 : static int __init control_devkmsg(char *str)
148 : : {
149 [ # # ]: 0 : if (__control_devkmsg(str) < 0)
150 : : return 1;
151 : :
152 : : /*
153 : : * Set sysctl string accordingly:
154 : : */
155 [ # # ]: 0 : if (devkmsg_log == DEVKMSG_LOG_MASK_ON)
156 : 0 : strcpy(devkmsg_log_str, "on");
157 [ # # ]: 0 : else if (devkmsg_log == DEVKMSG_LOG_MASK_OFF)
158 : 0 : strcpy(devkmsg_log_str, "off");
159 : : /* else "ratelimit" which is set by default. */
160 : :
161 : : /*
162 : : * Sysctl cannot change it anymore. The kernel command line setting of
163 : : * this parameter is to force the setting to be permanent throughout the
164 : : * runtime of the system. This is a precation measure against userspace
165 : : * trying to be a smarta** and attempting to change it up on us.
166 : : */
167 : 0 : devkmsg_log |= DEVKMSG_LOG_MASK_LOCK;
168 : :
169 : 0 : return 0;
170 : : }
171 : : __setup("printk.devkmsg=", control_devkmsg);
172 : :
173 : : char devkmsg_log_str[DEVKMSG_STR_MAX_SIZE] = "ratelimit";
174 : :
175 : 0 : int devkmsg_sysctl_set_loglvl(struct ctl_table *table, int write,
176 : : void __user *buffer, size_t *lenp, loff_t *ppos)
177 : : {
178 : : char old_str[DEVKMSG_STR_MAX_SIZE];
179 : : unsigned int old;
180 : : int err;
181 : :
182 [ # # ]: 0 : if (write) {
183 [ # # ]: 0 : if (devkmsg_log & DEVKMSG_LOG_MASK_LOCK)
184 : : return -EINVAL;
185 : :
186 : : old = devkmsg_log;
187 : 0 : strncpy(old_str, devkmsg_log_str, DEVKMSG_STR_MAX_SIZE);
188 : : }
189 : :
190 : 0 : err = proc_dostring(table, write, buffer, lenp, ppos);
191 [ # # ]: 0 : if (err)
192 : : return err;
193 : :
194 [ # # ]: 0 : if (write) {
195 : 0 : err = __control_devkmsg(devkmsg_log_str);
196 : :
197 : : /*
198 : : * Do not accept an unknown string OR a known string with
199 : : * trailing crap...
200 : : */
201 [ # # # # ]: 0 : if (err < 0 || (err + 1 != *lenp)) {
202 : :
203 : : /* ... and restore old setting. */
204 : 0 : devkmsg_log = old;
205 : 0 : strncpy(devkmsg_log_str, old_str, DEVKMSG_STR_MAX_SIZE);
206 : :
207 : 0 : return -EINVAL;
208 : : }
209 : : }
210 : :
211 : : return 0;
212 : : }
213 : :
214 : : /* Number of registered extended console drivers. */
215 : : static int nr_ext_console_drivers;
216 : :
217 : : /*
218 : : * Helper macros to handle lockdep when locking/unlocking console_sem. We use
219 : : * macros instead of functions so that _RET_IP_ contains useful information.
220 : : */
221 : : #define down_console_sem() do { \
222 : : down(&console_sem);\
223 : : mutex_acquire(&console_lock_dep_map, 0, 0, _RET_IP_);\
224 : : } while (0)
225 : :
226 : 68039 : static int __down_trylock_console_sem(unsigned long ip)
227 : : {
228 : : int lock_failed;
229 : : unsigned long flags;
230 : :
231 : : /*
232 : : * Here and in __up_console_sem() we need to be in safe mode,
233 : : * because spindump/WARN/etc from under console ->lock will
234 : : * deadlock in printk()->down_trylock_console_sem() otherwise.
235 : : */
236 : 68039 : printk_safe_enter_irqsave(flags);
237 : 68039 : lock_failed = down_trylock(&console_sem);
238 [ + + ]: 144840 : printk_safe_exit_irqrestore(flags);
239 : :
240 [ + + ]: 68039 : if (lock_failed)
241 : : return 1;
242 : : mutex_acquire(&console_lock_dep_map, 0, 1, ip);
243 : 67475 : return 0;
244 : : }
245 : : #define down_trylock_console_sem() __down_trylock_console_sem(_RET_IP_)
246 : :
247 : 133292 : static void __up_console_sem(unsigned long ip)
248 : : {
249 : : unsigned long flags;
250 : :
251 : : mutex_release(&console_lock_dep_map, 1, ip);
252 : :
253 : 133292 : printk_safe_enter_irqsave(flags);
254 : 133292 : up(&console_sem);
255 [ + - ]: 399876 : printk_safe_exit_irqrestore(flags);
256 : 133292 : }
257 : : #define up_console_sem() __up_console_sem(_RET_IP_)
258 : :
259 : : /*
260 : : * This is used for debugging the mess that is the VT code by
261 : : * keeping track if we have the console semaphore held. It's
262 : : * definitely not the perfect debug tool (we don't know if _WE_
263 : : * hold it and are racing, but it helps tracking those weird code
264 : : * paths in the console code where we end up in places I want
265 : : * locked without the console sempahore held).
266 : : */
267 : : static int console_locked, console_suspended;
268 : :
269 : : /*
270 : : * If exclusive_console is non-NULL then only this console is to be printed to.
271 : : */
272 : : static struct console *exclusive_console;
273 : :
274 : : /*
275 : : * Array of consoles built from command line options (console=)
276 : : */
277 : :
278 : : #define MAX_CMDLINECONSOLES 8
279 : :
280 : : static struct console_cmdline console_cmdline[MAX_CMDLINECONSOLES];
281 : :
282 : : static int preferred_console = -1;
283 : : int console_set_on_cmdline;
284 : : EXPORT_SYMBOL(console_set_on_cmdline);
285 : :
286 : : /* Flag: console code may call schedule() */
287 : : static int console_may_schedule;
288 : :
289 : : enum con_msg_format_flags {
290 : : MSG_FORMAT_DEFAULT = 0,
291 : : MSG_FORMAT_SYSLOG = (1 << 0),
292 : : };
293 : :
294 : : static int console_msg_format = MSG_FORMAT_DEFAULT;
295 : :
296 : : /*
297 : : * The printk log buffer consists of a chain of concatenated variable
298 : : * length records. Every record starts with a record header, containing
299 : : * the overall length of the record.
300 : : *
301 : : * The heads to the first and last entry in the buffer, as well as the
302 : : * sequence numbers of these entries are maintained when messages are
303 : : * stored.
304 : : *
305 : : * If the heads indicate available messages, the length in the header
306 : : * tells the start next message. A length == 0 for the next message
307 : : * indicates a wrap-around to the beginning of the buffer.
308 : : *
309 : : * Every record carries the monotonic timestamp in microseconds, as well as
310 : : * the standard userspace syslog level and syslog facility. The usual
311 : : * kernel messages use LOG_KERN; userspace-injected messages always carry
312 : : * a matching syslog facility, by default LOG_USER. The origin of every
313 : : * message can be reliably determined that way.
314 : : *
315 : : * The human readable log message directly follows the message header. The
316 : : * length of the message text is stored in the header, the stored message
317 : : * is not terminated.
318 : : *
319 : : * Optionally, a message can carry a dictionary of properties (key/value pairs),
320 : : * to provide userspace with a machine-readable message context.
321 : : *
322 : : * Examples for well-defined, commonly used property names are:
323 : : * DEVICE=b12:8 device identifier
324 : : * b12:8 block dev_t
325 : : * c127:3 char dev_t
326 : : * n8 netdev ifindex
327 : : * +sound:card0 subsystem:devname
328 : : * SUBSYSTEM=pci driver-core subsystem name
329 : : *
330 : : * Valid characters in property names are [a-zA-Z0-9.-_]. The plain text value
331 : : * follows directly after a '=' character. Every property is terminated by
332 : : * a '\0' character. The last property is not terminated.
333 : : *
334 : : * Example of a message structure:
335 : : * 0000 ff 8f 00 00 00 00 00 00 monotonic time in nsec
336 : : * 0008 34 00 record is 52 bytes long
337 : : * 000a 0b 00 text is 11 bytes long
338 : : * 000c 1f 00 dictionary is 23 bytes long
339 : : * 000e 03 00 LOG_KERN (facility) LOG_ERR (level)
340 : : * 0010 69 74 27 73 20 61 20 6c "it's a l"
341 : : * 69 6e 65 "ine"
342 : : * 001b 44 45 56 49 43 "DEVIC"
343 : : * 45 3d 62 38 3a 32 00 44 "E=b8:2\0D"
344 : : * 52 49 56 45 52 3d 62 75 "RIVER=bu"
345 : : * 67 "g"
346 : : * 0032 00 00 00 padding to next message header
347 : : *
348 : : * The 'struct printk_log' buffer header must never be directly exported to
349 : : * userspace, it is a kernel-private implementation detail that might
350 : : * need to be changed in the future, when the requirements change.
351 : : *
352 : : * /dev/kmsg exports the structured data in the following line format:
353 : : * "<level>,<sequnum>,<timestamp>,<contflag>[,additional_values, ... ];<message text>\n"
354 : : *
355 : : * Users of the export format should ignore possible additional values
356 : : * separated by ',', and find the message after the ';' character.
357 : : *
358 : : * The optional key/value pairs are attached as continuation lines starting
359 : : * with a space character and terminated by a newline. All possible
360 : : * non-prinatable characters are escaped in the "\xff" notation.
361 : : */
362 : :
363 : : enum log_flags {
364 : : LOG_NEWLINE = 2, /* text ended with a newline */
365 : : LOG_CONT = 8, /* text is a fragment of a continuation line */
366 : : };
367 : :
368 : : struct printk_log {
369 : : u64 ts_nsec; /* timestamp in nanoseconds */
370 : : u16 len; /* length of entire record */
371 : : u16 text_len; /* length of text buffer */
372 : : u16 dict_len; /* length of dictionary buffer */
373 : : u8 facility; /* syslog facility */
374 : : u8 flags:5; /* internal record flags */
375 : : u8 level:3; /* syslog level */
376 : : #ifdef CONFIG_PRINTK_CALLER
377 : : u32 caller_id; /* thread id or processor id */
378 : : #endif
379 : : }
380 : : #ifdef CONFIG_HAVE_EFFICIENT_UNALIGNED_ACCESS
381 : : __packed __aligned(4)
382 : : #endif
383 : : ;
384 : :
385 : : /*
386 : : * The logbuf_lock protects kmsg buffer, indices, counters. This can be taken
387 : : * within the scheduler's rq lock. It must be released before calling
388 : : * console_unlock() or anything else that might wake up a process.
389 : : */
390 : : DEFINE_RAW_SPINLOCK(logbuf_lock);
391 : :
392 : : /*
393 : : * Helper macros to lock/unlock logbuf_lock and switch between
394 : : * printk-safe/unsafe modes.
395 : : */
396 : : #define logbuf_lock_irq() \
397 : : do { \
398 : : printk_safe_enter_irq(); \
399 : : raw_spin_lock(&logbuf_lock); \
400 : : } while (0)
401 : :
402 : : #define logbuf_unlock_irq() \
403 : : do { \
404 : : raw_spin_unlock(&logbuf_lock); \
405 : : printk_safe_exit_irq(); \
406 : : } while (0)
407 : :
408 : : #define logbuf_lock_irqsave(flags) \
409 : : do { \
410 : : printk_safe_enter_irqsave(flags); \
411 : : raw_spin_lock(&logbuf_lock); \
412 : : } while (0)
413 : :
414 : : #define logbuf_unlock_irqrestore(flags) \
415 : : do { \
416 : : raw_spin_unlock(&logbuf_lock); \
417 : : printk_safe_exit_irqrestore(flags); \
418 : : } while (0)
419 : :
420 : : #ifdef CONFIG_PRINTK
421 : : DECLARE_WAIT_QUEUE_HEAD(log_wait);
422 : : /* the next printk record to read by syslog(READ) or /proc/kmsg */
423 : : static u64 syslog_seq;
424 : : static u32 syslog_idx;
425 : : static size_t syslog_partial;
426 : : static bool syslog_time;
427 : :
428 : : /* index and sequence number of the first record stored in the buffer */
429 : : static u64 log_first_seq;
430 : : static u32 log_first_idx;
431 : :
432 : : /* index and sequence number of the next record to store in the buffer */
433 : : static u64 log_next_seq;
434 : : static u32 log_next_idx;
435 : :
436 : : /* the next printk record to write to the console */
437 : : static u64 console_seq;
438 : : static u32 console_idx;
439 : : static u64 exclusive_console_stop_seq;
440 : :
441 : : /* the next printk record to read after the last 'clear' command */
442 : : static u64 clear_seq;
443 : : static u32 clear_idx;
444 : :
445 : : #ifdef CONFIG_PRINTK_CALLER
446 : : #define PREFIX_MAX 48
447 : : #else
448 : : #define PREFIX_MAX 32
449 : : #endif
450 : : #define LOG_LINE_MAX (1024 - PREFIX_MAX)
451 : :
452 : : #define LOG_LEVEL(v) ((v) & 0x07)
453 : : #define LOG_FACILITY(v) ((v) >> 3 & 0xff)
454 : :
455 : : /* record buffer */
456 : : #define LOG_ALIGN __alignof__(struct printk_log)
457 : : #define __LOG_BUF_LEN (1 << CONFIG_LOG_BUF_SHIFT)
458 : : #define LOG_BUF_LEN_MAX (u32)(1 << 31)
459 : : static char __log_buf[__LOG_BUF_LEN] __aligned(LOG_ALIGN);
460 : : static char *log_buf = __log_buf;
461 : : static u32 log_buf_len = __LOG_BUF_LEN;
462 : :
463 : : /*
464 : : * We cannot access per-CPU data (e.g. per-CPU flush irq_work) before
465 : : * per_cpu_areas are initialised. This variable is set to true when
466 : : * it's safe to access per-CPU data.
467 : : */
468 : : static bool __printk_percpu_data_ready __read_mostly;
469 : :
470 : 0 : bool printk_percpu_data_ready(void)
471 : : {
472 : 57918 : return __printk_percpu_data_ready;
473 : : }
474 : :
475 : : /* Return log buffer address */
476 : 0 : char *log_buf_addr_get(void)
477 : : {
478 : 0 : return log_buf;
479 : : }
480 : :
481 : : /* Return log buffer size */
482 : 0 : u32 log_buf_len_get(void)
483 : : {
484 : 0 : return log_buf_len;
485 : : }
486 : :
487 : : /* human readable text of the record */
488 : : static char *log_text(const struct printk_log *msg)
489 : : {
490 : 175410 : return (char *)msg + sizeof(struct printk_log);
491 : : }
492 : :
493 : : /* optional key/value pair dictionary attached to the record */
494 : : static char *log_dict(const struct printk_log *msg)
495 : : {
496 : 173754 : return (char *)msg + sizeof(struct printk_log) + msg->text_len;
497 : : }
498 : :
499 : : /* get record by index; idx must point to valid msg */
500 : : static struct printk_log *log_from_idx(u32 idx)
501 : : {
502 : 217431 : struct printk_log *msg = (struct printk_log *)(log_buf + idx);
503 : :
504 : : /*
505 : : * A length == 0 record is the end of buffer marker. Wrap around and
506 : : * read the message at the start of the buffer.
507 : : */
508 [ # # # # : 217431 : if (!msg->len)
# # # # +
- # # # #
# # # # +
- + - ]
509 : : return (struct printk_log *)log_buf;
510 : : return msg;
511 : : }
512 : :
513 : : /* get next record; idx must point to valid msg */
514 : : static u32 log_next(u32 idx)
515 : : {
516 : 117078 : struct printk_log *msg = (struct printk_log *)(log_buf + idx);
517 : :
518 : : /* length == 0 indicates the end of the buffer; wrap */
519 : : /*
520 : : * A length == 0 record is the end of buffer marker. Wrap around and
521 : : * read the message at the start of the buffer as *this* one, and
522 : : * return the one after that.
523 : : */
524 [ # # # # : 217017 : if (!msg->len) {
# # # # -
+ - + # #
# # # # #
# - + - +
# # ]
525 : : msg = (struct printk_log *)log_buf;
526 : 0 : return msg->len;
527 : : }
528 : 217017 : return idx + msg->len;
529 : : }
530 : :
531 : : /*
532 : : * Check whether there is enough free space for the given message.
533 : : *
534 : : * The same values of first_idx and next_idx mean that the buffer
535 : : * is either empty or full.
536 : : *
537 : : * If the buffer is empty, we must respect the position of the indexes.
538 : : * They cannot be reset to the beginning of the buffer.
539 : : */
540 : : static int logbuf_has_space(u32 msg_size, bool empty)
541 : : {
542 : : u32 free;
543 : :
544 [ + - + + : 115629 : if (log_next_idx > log_first_idx || empty)
+ - ]
545 : 115629 : free = max(log_buf_len - log_next_idx, log_first_idx);
546 : : else
547 : 0 : free = log_first_idx - log_next_idx;
548 : :
549 : : /*
550 : : * We need space also for an empty header that signalizes wrapping
551 : : * of the buffer.
552 : : */
553 : 115629 : return free >= msg_size + sizeof(struct printk_log);
554 : : }
555 : :
556 : 57918 : static int log_make_free_space(u32 msg_size)
557 : : {
558 [ + + - + ]: 173547 : while (log_first_seq < log_next_seq &&
559 : : !logbuf_has_space(msg_size, false)) {
560 : : /* drop old messages until we have enough contiguous space */
561 : 0 : log_first_idx = log_next(log_first_idx);
562 : 0 : log_first_seq++;
563 : : }
564 : :
565 [ - + ]: 57918 : if (clear_seq < log_first_seq) {
566 : 0 : clear_seq = log_first_seq;
567 : 0 : clear_idx = log_first_idx;
568 : : }
569 : :
570 : : /* sequence numbers are equal, so the log buffer is empty */
571 [ - + ]: 115836 : if (logbuf_has_space(msg_size, log_first_seq == log_next_seq))
572 : : return 0;
573 : :
574 : 0 : return -ENOMEM;
575 : : }
576 : :
577 : : /* compute the message size including the padding bytes */
578 : : static u32 msg_used_size(u16 text_len, u16 dict_len, u32 *pad_len)
579 : : {
580 : : u32 size;
581 : :
582 : 57918 : size = sizeof(struct printk_log) + text_len + dict_len;
583 : 57918 : *pad_len = (-size) & (LOG_ALIGN - 1);
584 : 57918 : size += *pad_len;
585 : :
586 : : return size;
587 : : }
588 : :
589 : : /*
590 : : * Define how much of the log buffer we could take at maximum. The value
591 : : * must be greater than two. Note that only half of the buffer is available
592 : : * when the index points to the middle.
593 : : */
594 : : #define MAX_LOG_TAKE_PART 4
595 : : static const char trunc_msg[] = "<truncated>";
596 : :
597 : : static u32 truncate_msg(u16 *text_len, u16 *trunc_msg_len,
598 : : u16 *dict_len, u32 *pad_len)
599 : : {
600 : : /*
601 : : * The message should not take the whole buffer. Otherwise, it might
602 : : * get removed too soon.
603 : : */
604 : 0 : u32 max_text_len = log_buf_len / MAX_LOG_TAKE_PART;
605 [ # # ]: 0 : if (*text_len > max_text_len)
606 : 0 : *text_len = max_text_len;
607 : : /* enable the warning message */
608 : : *trunc_msg_len = strlen(trunc_msg);
609 : : /* disable the "dict" completely */
610 : : *dict_len = 0;
611 : : /* compute the size again, count also the warning message */
612 : 0 : return msg_used_size(*text_len + *trunc_msg_len, 0, pad_len);
613 : : }
614 : :
615 : : /* insert record into the buffer, discard old ones, update heads */
616 : 57918 : static int log_store(u32 caller_id, int facility, int level,
617 : : enum log_flags flags, u64 ts_nsec,
618 : : const char *dict, u16 dict_len,
619 : : const char *text, u16 text_len)
620 : : {
621 : : struct printk_log *msg;
622 : : u32 size, pad_len;
623 : : u16 trunc_msg_len = 0;
624 : :
625 : : /* number of '\0' padding bytes to next message */
626 : : size = msg_used_size(text_len, dict_len, &pad_len);
627 : :
628 [ - + ]: 57918 : if (log_make_free_space(size)) {
629 : : /* truncate the message if it is too long for empty buffer */
630 : : size = truncate_msg(&text_len, &trunc_msg_len,
631 : : &dict_len, &pad_len);
632 : : /* survive when the log buffer is too small for trunc_msg */
633 [ # # ]: 0 : if (log_make_free_space(size))
634 : : return 0;
635 : : }
636 : :
637 [ - + ]: 57918 : if (log_next_idx + size + sizeof(struct printk_log) > log_buf_len) {
638 : : /*
639 : : * This message + an additional empty header does not fit
640 : : * at the end of the buffer. Add an empty header with len == 0
641 : : * to signify a wrap around.
642 : : */
643 : 0 : memset(log_buf + log_next_idx, 0, sizeof(struct printk_log));
644 : 0 : log_next_idx = 0;
645 : : }
646 : :
647 : : /* fill message */
648 : 57918 : msg = (struct printk_log *)(log_buf + log_next_idx);
649 : 57918 : memcpy(log_text(msg), text, text_len);
650 : 57918 : msg->text_len = text_len;
651 [ - + ]: 57918 : if (trunc_msg_len) {
652 : 0 : memcpy(log_text(msg) + text_len, trunc_msg, trunc_msg_len);
653 : 0 : msg->text_len += trunc_msg_len;
654 : : }
655 : 57918 : memcpy(log_dict(msg), dict, dict_len);
656 : 57918 : msg->dict_len = dict_len;
657 : 57918 : msg->facility = facility;
658 : 57918 : msg->level = level & 7;
659 : 57918 : msg->flags = flags & 0x1f;
660 [ + + ]: 57918 : if (ts_nsec > 0)
661 : 1035 : msg->ts_nsec = ts_nsec;
662 : : else
663 : 56883 : msg->ts_nsec = local_clock();
664 : : #ifdef CONFIG_PRINTK_CALLER
665 : : msg->caller_id = caller_id;
666 : : #endif
667 : 57918 : memset(log_dict(msg) + dict_len, 0, pad_len);
668 : 57918 : msg->len = size;
669 : :
670 : : /* insert message */
671 : 57918 : log_next_idx += msg->len;
672 : 57918 : log_next_seq++;
673 : :
674 : 57918 : return msg->text_len;
675 : : }
676 : :
677 : : int dmesg_restrict = IS_ENABLED(CONFIG_SECURITY_DMESG_RESTRICT);
678 : :
679 : : static int syslog_action_restricted(int type)
680 : : {
681 [ + - ]: 414 : if (dmesg_restrict)
682 : : return 1;
683 : : /*
684 : : * Unless restricted, we allow "read all" and "get buffer size"
685 : : * for everybody.
686 : : */
687 : 828 : return type != SYSLOG_ACTION_READ_ALL &&
688 : 414 : type != SYSLOG_ACTION_SIZE_BUFFER;
689 : : }
690 : :
691 : 2923 : static int check_syslog_permissions(int type, int source)
692 : : {
693 : : /*
694 : : * If this is from /proc/kmsg and we've already opened it, then we've
695 : : * already done the capabilities checks at open time.
696 : : */
697 [ + + ]: 2923 : if (source == SYSLOG_FROM_PROC && type != SYSLOG_ACTION_OPEN)
698 : : goto ok;
699 : :
700 [ + + ]: 414 : if (syslog_action_restricted(type)) {
701 [ - + ]: 207 : if (capable(CAP_SYSLOG))
702 : : goto ok;
703 : : /*
704 : : * For historical reasons, accept CAP_SYS_ADMIN too, with
705 : : * a warning.
706 : : */
707 [ # # ]: 0 : if (capable(CAP_SYS_ADMIN)) {
708 [ # # ]: 0 : pr_warn_once("%s (%d): Attempt to access syslog with "
709 : : "CAP_SYS_ADMIN but no CAP_SYSLOG "
710 : : "(deprecated).\n",
711 : : current->comm, task_pid_nr(current));
712 : : goto ok;
713 : : }
714 : : return -EPERM;
715 : : }
716 : : ok:
717 : 2923 : return security_syslog(type);
718 : : }
719 : :
720 : : static void append_char(char **pp, char *e, char c)
721 : : {
722 [ + - + - : 3632481 : if (*pp < e)
+ - + - +
- + - ]
723 : 3632481 : *(*pp)++ = c;
724 : : }
725 : :
726 : 57918 : static ssize_t msg_print_ext_header(char *buf, size_t size,
727 : : struct printk_log *msg, u64 seq)
728 : : {
729 : 57918 : u64 ts_usec = msg->ts_nsec;
730 : : char caller[20];
731 : : #ifdef CONFIG_PRINTK_CALLER
732 : : u32 id = msg->caller_id;
733 : :
734 : : snprintf(caller, sizeof(caller), ",caller=%c%u",
735 : : id & 0x80000000 ? 'C' : 'T', id & ~0x80000000);
736 : : #else
737 : 57918 : caller[0] = '\0';
738 : : #endif
739 : :
740 : 57918 : do_div(ts_usec, 1000);
741 : :
742 [ + - ]: 115836 : return scnprintf(buf, size, "%u,%llu,%llu,%c%s;",
743 : 57918 : (msg->facility << 3) | msg->level, seq, ts_usec,
744 : 57918 : msg->flags & LOG_CONT ? 'c' : '-', caller);
745 : : }
746 : :
747 : 57918 : static ssize_t msg_print_ext_body(char *buf, size_t size,
748 : : char *dict, size_t dict_len,
749 : : char *text, size_t text_len)
750 : : {
751 : 57918 : char *p = buf, *e = buf + size;
752 : : size_t i;
753 : :
754 : : /* escape non-printable characters */
755 [ + + ]: 3229409 : for (i = 0; i < text_len; i++) {
756 : 3171491 : unsigned char c = text[i];
757 : :
758 [ + + ]: 3171491 : if (c < ' ' || c >= 127 || c == '\\')
759 : 992 : p += scnprintf(p, e - p, "\\x%02x", c);
760 : : else
761 : : append_char(&p, e, c);
762 : : }
763 : : append_char(&p, e, '\n');
764 : :
765 [ + + ]: 57918 : if (dict_len) {
766 : : bool line = true;
767 : :
768 [ + + ]: 373635 : for (i = 0; i < dict_len; i++) {
769 : 373635 : unsigned char c = dict[i];
770 : :
771 [ + + ]: 373635 : if (line) {
772 : : append_char(&p, e, ' ');
773 : : line = false;
774 : : }
775 : :
776 [ + + ]: 373635 : if (c == '\0') {
777 : : append_char(&p, e, '\n');
778 : : line = true;
779 : 10143 : continue;
780 : : }
781 : :
782 [ - + ]: 363492 : if (c < ' ' || c >= 127 || c == '\\') {
783 : 0 : p += scnprintf(p, e - p, "\\x%02x", c);
784 : 0 : continue;
785 : : }
786 : :
787 : : append_char(&p, e, c);
788 : : }
789 : : append_char(&p, e, '\n');
790 : : }
791 : :
792 : 57918 : return p - buf;
793 : : }
794 : :
795 : : /* /dev/kmsg - userspace message inject/listen interface */
796 : : struct devkmsg_user {
797 : : u64 seq;
798 : : u32 idx;
799 : : struct ratelimit_state rs;
800 : : struct mutex lock;
801 : : char buf[CONSOLE_EXT_LOG_MAX];
802 : : };
803 : :
804 : : static __printf(3, 4) __cold
805 : 2484 : int devkmsg_emit(int facility, int level, const char *fmt, ...)
806 : : {
807 : : va_list args;
808 : : int r;
809 : :
810 : 2484 : va_start(args, fmt);
811 : 2484 : r = vprintk_emit(facility, level, NULL, 0, fmt, args);
812 : 2484 : va_end(args);
813 : :
814 : 2484 : return r;
815 : : }
816 : :
817 : 9759 : static ssize_t devkmsg_write(struct kiocb *iocb, struct iov_iter *from)
818 : : {
819 : : char *buf, *line;
820 : 9759 : int level = default_message_loglevel;
821 : : int facility = 1; /* LOG_USER */
822 : 9759 : struct file *file = iocb->ki_filp;
823 : 9759 : struct devkmsg_user *user = file->private_data;
824 : : size_t len = iov_iter_count(from);
825 : 9759 : ssize_t ret = len;
826 : :
827 [ + - ]: 9759 : if (!user || len > LOG_LINE_MAX)
828 : : return -EINVAL;
829 : :
830 : : /* Ignore when user logging is disabled. */
831 [ + - ]: 9759 : if (devkmsg_log & DEVKMSG_LOG_MASK_OFF)
832 : : return len;
833 : :
834 : : /* Ratelimit when not explicitly enabled. */
835 [ + - ]: 9759 : if (!(devkmsg_log & DEVKMSG_LOG_MASK_ON)) {
836 [ + + ]: 19518 : if (!___ratelimit(&user->rs, current->comm))
837 : : return ret;
838 : : }
839 : :
840 : 2484 : buf = kmalloc(len+1, GFP_KERNEL);
841 [ + - ]: 2484 : if (buf == NULL)
842 : : return -ENOMEM;
843 : :
844 : 2484 : buf[len] = '\0';
845 [ - + ]: 2484 : if (!copy_from_iter_full(buf, len, from)) {
846 : 0 : kfree(buf);
847 : 0 : return -EFAULT;
848 : : }
849 : :
850 : : /*
851 : : * Extract and skip the syslog prefix <[0-9]*>. Coming from userspace
852 : : * the decimal value represents 32bit, the lower 3 bit are the log
853 : : * level, the rest are the log facility.
854 : : *
855 : : * If no prefix or no userspace facility is specified, we
856 : : * enforce LOG_USER, to be able to reliably distinguish
857 : : * kernel-generated messages from userspace-injected ones.
858 : : */
859 : : line = buf;
860 [ + - ]: 2484 : if (line[0] == '<') {
861 : 2484 : char *endp = NULL;
862 : : unsigned int u;
863 : :
864 : 2484 : u = simple_strtoul(line + 1, &endp, 10);
865 [ + - + - ]: 2484 : if (endp && endp[0] == '>') {
866 : 2484 : level = LOG_LEVEL(u);
867 [ + - ]: 2484 : if (LOG_FACILITY(u) != 0)
868 : 2484 : facility = LOG_FACILITY(u);
869 : 2484 : endp++;
870 : : len -= endp - line;
871 : : line = endp;
872 : : }
873 : : }
874 : :
875 : 2484 : devkmsg_emit(facility, level, "%s", line);
876 : 2484 : kfree(buf);
877 : 2484 : return ret;
878 : : }
879 : :
880 : 58125 : static ssize_t devkmsg_read(struct file *file, char __user *buf,
881 : : size_t count, loff_t *ppos)
882 : : {
883 : 58125 : struct devkmsg_user *user = file->private_data;
884 : : struct printk_log *msg;
885 : : size_t len;
886 : : ssize_t ret;
887 : :
888 [ + - ]: 58125 : if (!user)
889 : : return -EBADF;
890 : :
891 : 58125 : ret = mutex_lock_interruptible(&user->lock);
892 [ + - ]: 58125 : if (ret)
893 : : return ret;
894 : :
895 : 58125 : logbuf_lock_irq();
896 [ + + ]: 116250 : while (user->seq == log_next_seq) {
897 [ + - ]: 207 : if (file->f_flags & O_NONBLOCK) {
898 : : ret = -EAGAIN;
899 : 207 : logbuf_unlock_irq();
900 : : goto out;
901 : : }
902 : :
903 : 0 : logbuf_unlock_irq();
904 [ # # # # : 0 : ret = wait_event_interruptible(log_wait,
# # ]
905 : : user->seq != log_next_seq);
906 [ # # ]: 0 : if (ret)
907 : : goto out;
908 : 0 : logbuf_lock_irq();
909 : : }
910 : :
911 [ - + ]: 57918 : if (user->seq < log_first_seq) {
912 : : /* our last seen message is gone, return error and reset */
913 : 0 : user->idx = log_first_idx;
914 : 0 : user->seq = log_first_seq;
915 : : ret = -EPIPE;
916 : 0 : logbuf_unlock_irq();
917 : : goto out;
918 : : }
919 : :
920 : 57918 : msg = log_from_idx(user->idx);
921 : 57918 : len = msg_print_ext_header(user->buf, sizeof(user->buf),
922 : : msg, user->seq);
923 : 173754 : len += msg_print_ext_body(user->buf + len, sizeof(user->buf) - len,
924 : 57918 : log_dict(msg), msg->dict_len,
925 : : log_text(msg), msg->text_len);
926 : :
927 : 115836 : user->idx = log_next(user->idx);
928 : 57918 : user->seq++;
929 : 57918 : logbuf_unlock_irq();
930 : :
931 [ + - ]: 57918 : if (len > count) {
932 : : ret = -EINVAL;
933 : : goto out;
934 : : }
935 : :
936 [ + - ]: 57918 : if (copy_to_user(buf, user->buf, len)) {
937 : : ret = -EFAULT;
938 : : goto out;
939 : : }
940 : 57918 : ret = len;
941 : : out:
942 : 58125 : mutex_unlock(&user->lock);
943 : 58125 : return ret;
944 : : }
945 : :
946 : 0 : static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence)
947 : : {
948 : 0 : struct devkmsg_user *user = file->private_data;
949 : : loff_t ret = 0;
950 : :
951 [ # # ]: 0 : if (!user)
952 : : return -EBADF;
953 [ # # ]: 0 : if (offset)
954 : : return -ESPIPE;
955 : :
956 : 0 : logbuf_lock_irq();
957 [ # # # # ]: 0 : switch (whence) {
958 : : case SEEK_SET:
959 : : /* the first record */
960 : 0 : user->idx = log_first_idx;
961 : 0 : user->seq = log_first_seq;
962 : 0 : break;
963 : : case SEEK_DATA:
964 : : /*
965 : : * The first record after the last SYSLOG_ACTION_CLEAR,
966 : : * like issued by 'dmesg -c'. Reading /dev/kmsg itself
967 : : * changes no global state, and does not clear anything.
968 : : */
969 : 0 : user->idx = clear_idx;
970 : 0 : user->seq = clear_seq;
971 : 0 : break;
972 : : case SEEK_END:
973 : : /* after the last record */
974 : 0 : user->idx = log_next_idx;
975 : 0 : user->seq = log_next_seq;
976 : 0 : break;
977 : : default:
978 : : ret = -EINVAL;
979 : : }
980 : 0 : logbuf_unlock_irq();
981 : 0 : return ret;
982 : : }
983 : :
984 : 14694 : static __poll_t devkmsg_poll(struct file *file, poll_table *wait)
985 : : {
986 : 14694 : struct devkmsg_user *user = file->private_data;
987 : : __poll_t ret = 0;
988 : :
989 [ + - ]: 14694 : if (!user)
990 : : return EPOLLERR|EPOLLNVAL;
991 : :
992 : : poll_wait(file, &log_wait, wait);
993 : :
994 : 14694 : logbuf_lock_irq();
995 [ + + ]: 14694 : if (user->seq < log_next_seq) {
996 : : /* return error when data has vanished underneath us */
997 [ + - ]: 8652 : if (user->seq < log_first_seq)
998 : : ret = EPOLLIN|EPOLLRDNORM|EPOLLERR|EPOLLPRI;
999 : : else
1000 : : ret = EPOLLIN|EPOLLRDNORM;
1001 : : }
1002 : 14694 : logbuf_unlock_irq();
1003 : :
1004 : 14694 : return ret;
1005 : : }
1006 : :
1007 : 3503 : static int devkmsg_open(struct inode *inode, struct file *file)
1008 : : {
1009 : : struct devkmsg_user *user;
1010 : : int err;
1011 : :
1012 [ + + ]: 3503 : if (devkmsg_log & DEVKMSG_LOG_MASK_OFF)
1013 : : return -EPERM;
1014 : :
1015 : : /* write-only does not need any file context */
1016 [ + + ]: 3514 : if ((file->f_flags & O_ACCMODE) != O_WRONLY) {
1017 : 207 : err = check_syslog_permissions(SYSLOG_ACTION_READ_ALL,
1018 : : SYSLOG_FROM_READER);
1019 [ + - ]: 207 : if (err)
1020 : : return err;
1021 : : }
1022 : :
1023 : : user = kmalloc(sizeof(struct devkmsg_user), GFP_KERNEL);
1024 [ + + ]: 3519 : if (!user)
1025 : : return -ENOMEM;
1026 : :
1027 : 3500 : ratelimit_default_init(&user->rs);
1028 : : ratelimit_set_flags(&user->rs, RATELIMIT_MSG_ON_RELEASE);
1029 : :
1030 : 3500 : mutex_init(&user->lock);
1031 : :
1032 : 3511 : logbuf_lock_irq();
1033 : 3519 : user->idx = log_first_idx;
1034 : 3519 : user->seq = log_first_seq;
1035 : 3519 : logbuf_unlock_irq();
1036 : :
1037 : 3518 : file->private_data = user;
1038 : 3518 : return 0;
1039 : : }
1040 : :
1041 : 2898 : static int devkmsg_release(struct inode *inode, struct file *file)
1042 : : {
1043 : 2898 : struct devkmsg_user *user = file->private_data;
1044 : :
1045 [ + + ]: 2898 : if (!user)
1046 : : return 0;
1047 : :
1048 : 2888 : ratelimit_state_exit(&user->rs);
1049 : :
1050 : : mutex_destroy(&user->lock);
1051 : 2895 : kfree(user);
1052 : 2898 : return 0;
1053 : : }
1054 : :
1055 : : const struct file_operations kmsg_fops = {
1056 : : .open = devkmsg_open,
1057 : : .read = devkmsg_read,
1058 : : .write_iter = devkmsg_write,
1059 : : .llseek = devkmsg_llseek,
1060 : : .poll = devkmsg_poll,
1061 : : .release = devkmsg_release,
1062 : : };
1063 : :
1064 : : #ifdef CONFIG_CRASH_CORE
1065 : : /*
1066 : : * This appends the listed symbols to /proc/vmcore
1067 : : *
1068 : : * /proc/vmcore is used by various utilities, like crash and makedumpfile to
1069 : : * obtain access to symbols that are otherwise very difficult to locate. These
1070 : : * symbols are specifically used so that utilities can access and extract the
1071 : : * dmesg log from a vmcore file after a crash.
1072 : : */
1073 : : void log_buf_vmcoreinfo_setup(void)
1074 : : {
1075 : : VMCOREINFO_SYMBOL(log_buf);
1076 : : VMCOREINFO_SYMBOL(log_buf_len);
1077 : : VMCOREINFO_SYMBOL(log_first_idx);
1078 : : VMCOREINFO_SYMBOL(clear_idx);
1079 : : VMCOREINFO_SYMBOL(log_next_idx);
1080 : : /*
1081 : : * Export struct printk_log size and field offsets. User space tools can
1082 : : * parse it and detect any changes to structure down the line.
1083 : : */
1084 : : VMCOREINFO_STRUCT_SIZE(printk_log);
1085 : : VMCOREINFO_OFFSET(printk_log, ts_nsec);
1086 : : VMCOREINFO_OFFSET(printk_log, len);
1087 : : VMCOREINFO_OFFSET(printk_log, text_len);
1088 : : VMCOREINFO_OFFSET(printk_log, dict_len);
1089 : : #ifdef CONFIG_PRINTK_CALLER
1090 : : VMCOREINFO_OFFSET(printk_log, caller_id);
1091 : : #endif
1092 : : }
1093 : : #endif
1094 : :
1095 : : /* requested log_buf_len from kernel cmdline */
1096 : : static unsigned long __initdata new_log_buf_len;
1097 : :
1098 : : /* we practice scaling the ring buffer by powers of 2 */
1099 : 0 : static void __init log_buf_len_update(u64 size)
1100 : : {
1101 [ # # ]: 0 : if (size > (u64)LOG_BUF_LEN_MAX) {
1102 : : size = (u64)LOG_BUF_LEN_MAX;
1103 : 0 : pr_err("log_buf over 2G is not supported.\n");
1104 : : }
1105 : :
1106 [ # # ]: 0 : if (size)
1107 [ # # # # : 0 : size = roundup_pow_of_two(size);
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # # #
# # # #
# ]
1108 [ # # ]: 0 : if (size > log_buf_len)
1109 : 0 : new_log_buf_len = (unsigned long)size;
1110 : 0 : }
1111 : :
1112 : : /* save requested log_buf_len since it's too early to process it */
1113 : 0 : static int __init log_buf_len_setup(char *str)
1114 : : {
1115 : : u64 size;
1116 : :
1117 [ # # ]: 0 : if (!str)
1118 : : return -EINVAL;
1119 : :
1120 : 0 : size = memparse(str, &str);
1121 : :
1122 : 0 : log_buf_len_update(size);
1123 : :
1124 : 0 : return 0;
1125 : : }
1126 : : early_param("log_buf_len", log_buf_len_setup);
1127 : :
1128 : : #ifdef CONFIG_SMP
1129 : : #define __LOG_CPU_MAX_BUF_LEN (1 << CONFIG_LOG_CPU_MAX_BUF_SHIFT)
1130 : :
1131 : 207 : static void __init log_buf_add_cpu(void)
1132 : : {
1133 : : unsigned int cpu_extra;
1134 : :
1135 : : /*
1136 : : * archs should set up cpu_possible_bits properly with
1137 : : * set_cpu_possible() after setup_arch() but just in
1138 : : * case lets ensure this is valid.
1139 : : */
1140 [ + - ]: 207 : if (num_possible_cpus() == 1)
1141 : : return;
1142 : :
1143 : 207 : cpu_extra = (num_possible_cpus() - 1) * __LOG_CPU_MAX_BUF_LEN;
1144 : :
1145 : : /* by default this will only continue through for large > 64 CPUs */
1146 [ - + ]: 207 : if (cpu_extra <= __LOG_BUF_LEN / 2)
1147 : : return;
1148 : :
1149 : 0 : pr_info("log_buf_len individual max cpu contribution: %d bytes\n",
1150 : : __LOG_CPU_MAX_BUF_LEN);
1151 : 0 : pr_info("log_buf_len total cpu_extra contributions: %d bytes\n",
1152 : : cpu_extra);
1153 : 0 : pr_info("log_buf_len min size: %d bytes\n", __LOG_BUF_LEN);
1154 : :
1155 : 0 : log_buf_len_update(cpu_extra + __LOG_BUF_LEN);
1156 : : }
1157 : : #else /* !CONFIG_SMP */
1158 : : static inline void log_buf_add_cpu(void) {}
1159 : : #endif /* CONFIG_SMP */
1160 : :
1161 : 207 : static void __init set_percpu_data_ready(void)
1162 : : {
1163 : 207 : printk_safe_init();
1164 : : /* Make sure we set this flag only after printk_safe() init is done */
1165 : 207 : barrier();
1166 : 207 : __printk_percpu_data_ready = true;
1167 : 207 : }
1168 : :
1169 : 207 : void __init setup_log_buf(int early)
1170 : : {
1171 : : unsigned long flags;
1172 : : char *new_log_buf;
1173 : : unsigned int free;
1174 : :
1175 : : /*
1176 : : * Some archs call setup_log_buf() multiple times - first is very
1177 : : * early, e.g. from setup_arch(), and second - when percpu_areas
1178 : : * are initialised.
1179 : : */
1180 [ + - ]: 207 : if (!early)
1181 : 207 : set_percpu_data_ready();
1182 : :
1183 [ + - ]: 207 : if (log_buf != __log_buf)
1184 : : return;
1185 : :
1186 [ + - + - ]: 207 : if (!early && !new_log_buf_len)
1187 : 207 : log_buf_add_cpu();
1188 : :
1189 [ - + ]: 207 : if (!new_log_buf_len)
1190 : : return;
1191 : :
1192 : 0 : new_log_buf = memblock_alloc(new_log_buf_len, LOG_ALIGN);
1193 [ # # ]: 0 : if (unlikely(!new_log_buf)) {
1194 : 0 : pr_err("log_buf_len: %lu bytes not available\n",
1195 : : new_log_buf_len);
1196 : 0 : return;
1197 : : }
1198 : :
1199 : 0 : logbuf_lock_irqsave(flags);
1200 : 0 : log_buf_len = new_log_buf_len;
1201 : 0 : log_buf = new_log_buf;
1202 : 0 : new_log_buf_len = 0;
1203 : 0 : free = __LOG_BUF_LEN - log_next_idx;
1204 : 0 : memcpy(log_buf, __log_buf, __LOG_BUF_LEN);
1205 [ # # ]: 0 : logbuf_unlock_irqrestore(flags);
1206 : :
1207 : 0 : pr_info("log_buf_len: %u bytes\n", log_buf_len);
1208 : 0 : pr_info("early log buf free: %u(%u%%)\n",
1209 : : free, (free * 100) / __LOG_BUF_LEN);
1210 : : }
1211 : :
1212 : : static bool __read_mostly ignore_loglevel;
1213 : :
1214 : 0 : static int __init ignore_loglevel_setup(char *str)
1215 : : {
1216 : 0 : ignore_loglevel = true;
1217 : 0 : pr_info("debug: ignoring loglevel setting.\n");
1218 : :
1219 : 0 : return 0;
1220 : : }
1221 : :
1222 : : early_param("ignore_loglevel", ignore_loglevel_setup);
1223 : : module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
1224 : : MODULE_PARM_DESC(ignore_loglevel,
1225 : : "ignore loglevel setting (prints all kernel messages to the console)");
1226 : :
1227 : : static bool suppress_message_printing(int level)
1228 : : {
1229 [ + + - + : 101181 : return (level >= console_loglevel && !ignore_loglevel);
# # # # ]
1230 : : }
1231 : :
1232 : : #ifdef CONFIG_BOOT_PRINTK_DELAY
1233 : :
1234 : : static int boot_delay; /* msecs delay after each printk during bootup */
1235 : : static unsigned long long loops_per_msec; /* based on boot_delay */
1236 : :
1237 : 0 : static int __init boot_delay_setup(char *str)
1238 : : {
1239 : : unsigned long lpj;
1240 : :
1241 [ # # ]: 0 : lpj = preset_lpj ? preset_lpj : 1000000; /* some guess */
1242 : 0 : loops_per_msec = (unsigned long long)lpj / 1000 * HZ;
1243 : :
1244 : 0 : get_option(&str, &boot_delay);
1245 [ # # ]: 0 : if (boot_delay > 10 * 1000)
1246 : 0 : boot_delay = 0;
1247 : :
1248 : : pr_debug("boot_delay: %u, preset_lpj: %ld, lpj: %lu, "
1249 : : "HZ: %d, loops_per_msec: %llu\n",
1250 : : boot_delay, preset_lpj, lpj, HZ, loops_per_msec);
1251 : 0 : return 0;
1252 : : }
1253 : : early_param("boot_delay", boot_delay_setup);
1254 : :
1255 : 61644 : static void boot_delay_msec(int level)
1256 : : {
1257 : : unsigned long long k;
1258 : : unsigned long timeout;
1259 : :
1260 [ - + # # ]: 61644 : if ((boot_delay == 0 || system_state >= SYSTEM_RUNNING)
1261 [ # # ]: 0 : || suppress_message_printing(level)) {
1262 : 61644 : return;
1263 : : }
1264 : :
1265 : 0 : k = (unsigned long long)loops_per_msec * boot_delay;
1266 : :
1267 : 0 : timeout = jiffies + msecs_to_jiffies(boot_delay);
1268 [ # # ]: 0 : while (k) {
1269 : 0 : k--;
1270 : 0 : cpu_relax();
1271 : : /*
1272 : : * use (volatile) jiffies to prevent
1273 : : * compiler reduction; loop termination via jiffies
1274 : : * is secondary and may or may not happen.
1275 : : */
1276 [ # # ]: 0 : if (time_after(jiffies, timeout))
1277 : : break;
1278 : : touch_nmi_watchdog();
1279 : : }
1280 : : }
1281 : : #else
1282 : : static inline void boot_delay_msec(int level)
1283 : : {
1284 : : }
1285 : : #endif
1286 : :
1287 : : static bool printk_time = IS_ENABLED(CONFIG_PRINTK_TIME);
1288 : : module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
1289 : :
1290 : : static size_t print_syslog(unsigned int level, char *buf)
1291 : : {
1292 : 58332 : return sprintf(buf, "<%u>", level);
1293 : : }
1294 : :
1295 : 59574 : static size_t print_time(u64 ts, char *buf)
1296 : : {
1297 : 59574 : unsigned long rem_nsec = do_div(ts, 1000000000);
1298 : :
1299 : 59574 : return sprintf(buf, "[%5lu.%06lu]",
1300 : : (unsigned long)ts, rem_nsec / 1000);
1301 : : }
1302 : :
1303 : : #ifdef CONFIG_PRINTK_CALLER
1304 : : static size_t print_caller(u32 id, char *buf)
1305 : : {
1306 : : char caller[12];
1307 : :
1308 : : snprintf(caller, sizeof(caller), "%c%u",
1309 : : id & 0x80000000 ? 'C' : 'T', id & ~0x80000000);
1310 : : return sprintf(buf, "[%6s]", caller);
1311 : : }
1312 : : #else
1313 : : #define print_caller(id, buf) 0
1314 : : #endif
1315 : :
1316 : 59574 : static size_t print_prefix(const struct printk_log *msg, bool syslog,
1317 : : bool time, char *buf)
1318 : : {
1319 : : size_t len = 0;
1320 : :
1321 [ + + ]: 59574 : if (syslog)
1322 : 58332 : len = print_syslog((msg->facility << 3) | msg->level, buf);
1323 : :
1324 [ + - ]: 59574 : if (time)
1325 : 59574 : len += print_time(msg->ts_nsec, buf + len);
1326 : :
1327 : : len += print_caller(msg->caller_id, buf + len);
1328 : :
1329 [ + - ]: 59574 : if (IS_ENABLED(CONFIG_PRINTK_CALLER) || time) {
1330 : 59574 : buf[len++] = ' ';
1331 : 59574 : buf[len] = '\0';
1332 : : }
1333 : :
1334 : 59574 : return len;
1335 : : }
1336 : :
1337 : 59574 : static size_t msg_print_text(const struct printk_log *msg, bool syslog,
1338 : : bool time, char *buf, size_t size)
1339 : : {
1340 : : const char *text = log_text(msg);
1341 : 59574 : size_t text_size = msg->text_len;
1342 : : size_t len = 0;
1343 : : char prefix[PREFIX_MAX];
1344 : 59574 : const size_t prefix_len = print_prefix(msg, syslog, time, prefix);
1345 : :
1346 : : do {
1347 : 60402 : const char *next = memchr(text, '\n', text_size);
1348 : : size_t text_len;
1349 : :
1350 [ + + ]: 60402 : if (next) {
1351 : 828 : text_len = next - text;
1352 : 828 : next++;
1353 : 828 : text_size -= next - text;
1354 : : } else {
1355 : : text_len = text_size;
1356 : : }
1357 : :
1358 [ + - ]: 60402 : if (buf) {
1359 [ + - ]: 60402 : if (prefix_len + text_len + 1 >= size - len)
1360 : : break;
1361 : :
1362 : 60402 : memcpy(buf + len, prefix, prefix_len);
1363 : 60402 : len += prefix_len;
1364 : 60402 : memcpy(buf + len, text, text_len);
1365 : 60402 : len += text_len;
1366 : 60402 : buf[len++] = '\n';
1367 : : } else {
1368 : : /* SYSLOG_ACTION_* buffer size only calculation */
1369 : 0 : len += prefix_len + text_len + 1;
1370 : : }
1371 : :
1372 : : text = next;
1373 [ + + ]: 60402 : } while (text);
1374 : :
1375 : 59574 : return len;
1376 : : }
1377 : :
1378 : 2095 : static int syslog_print(char __user *buf, int size)
1379 : : {
1380 : : char *text;
1381 : : struct printk_log *msg;
1382 : : int len = 0;
1383 : :
1384 : : text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
1385 [ + - ]: 2095 : if (!text)
1386 : : return -ENOMEM;
1387 : :
1388 [ + - ]: 60013 : while (size > 0) {
1389 : : size_t n;
1390 : : size_t skip;
1391 : :
1392 : 60013 : logbuf_lock_irq();
1393 [ - + ]: 60013 : if (syslog_seq < log_first_seq) {
1394 : : /* messages are gone, move to first one */
1395 : 0 : syslog_seq = log_first_seq;
1396 : 0 : syslog_idx = log_first_idx;
1397 : 0 : syslog_partial = 0;
1398 : : }
1399 [ + + ]: 60013 : if (syslog_seq == log_next_seq) {
1400 : 1681 : logbuf_unlock_irq();
1401 : : break;
1402 : : }
1403 : :
1404 : : /*
1405 : : * To keep reading/counting partial line consistent,
1406 : : * use printk_time value as of the beginning of a line.
1407 : : */
1408 [ + - ]: 58332 : if (!syslog_partial)
1409 : 58332 : syslog_time = printk_time;
1410 : :
1411 : : skip = syslog_partial;
1412 : 58332 : msg = log_from_idx(syslog_idx);
1413 : 58332 : n = msg_print_text(msg, true, syslog_time, text,
1414 : : LOG_LINE_MAX + PREFIX_MAX);
1415 [ + + ]: 58332 : if (n - syslog_partial <= size) {
1416 : : /* message fits into buffer, move forward */
1417 : 115836 : syslog_idx = log_next(syslog_idx);
1418 : 57918 : syslog_seq++;
1419 : : n -= syslog_partial;
1420 : 57918 : syslog_partial = 0;
1421 [ - + ]: 414 : } else if (!len){
1422 : : /* partial read(), remember position */
1423 : : n = size;
1424 : 0 : syslog_partial += n;
1425 : : } else
1426 : : n = 0;
1427 : 58332 : logbuf_unlock_irq();
1428 : :
1429 [ + + ]: 58332 : if (!n)
1430 : : break;
1431 : :
1432 [ - + ]: 115836 : if (copy_to_user(buf, text + skip, n)) {
1433 [ # # ]: 0 : if (!len)
1434 : : len = -EFAULT;
1435 : : break;
1436 : : }
1437 : :
1438 : 57918 : len += n;
1439 : 57918 : size -= n;
1440 : 57918 : buf += n;
1441 : : }
1442 : :
1443 : 2095 : kfree(text);
1444 : 2095 : return len;
1445 : : }
1446 : :
1447 : 0 : static int syslog_print_all(char __user *buf, int size, bool clear)
1448 : : {
1449 : : char *text;
1450 : : int len = 0;
1451 : : u64 next_seq;
1452 : : u64 seq;
1453 : : u32 idx;
1454 : : bool time;
1455 : :
1456 : : text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
1457 [ # # ]: 0 : if (!text)
1458 : : return -ENOMEM;
1459 : :
1460 : 0 : time = printk_time;
1461 : 0 : logbuf_lock_irq();
1462 : : /*
1463 : : * Find first record that fits, including all following records,
1464 : : * into the user-provided buffer for this dump.
1465 : : */
1466 : 0 : seq = clear_seq;
1467 : 0 : idx = clear_idx;
1468 [ # # ]: 0 : while (seq < log_next_seq) {
1469 : : struct printk_log *msg = log_from_idx(idx);
1470 : :
1471 : 0 : len += msg_print_text(msg, true, time, NULL, 0);
1472 : : idx = log_next(idx);
1473 : 0 : seq++;
1474 : : }
1475 : :
1476 : : /* move first record forward until length fits into the buffer */
1477 : 0 : seq = clear_seq;
1478 : 0 : idx = clear_idx;
1479 [ # # # # ]: 0 : while (len > size && seq < log_next_seq) {
1480 : : struct printk_log *msg = log_from_idx(idx);
1481 : :
1482 : 0 : len -= msg_print_text(msg, true, time, NULL, 0);
1483 : : idx = log_next(idx);
1484 : 0 : seq++;
1485 : : }
1486 : :
1487 : : /* last message fitting into this dump */
1488 : 0 : next_seq = log_next_seq;
1489 : :
1490 : : len = 0;
1491 [ # # ]: 0 : while (len >= 0 && seq < next_seq) {
1492 : : struct printk_log *msg = log_from_idx(idx);
1493 : 0 : int textlen = msg_print_text(msg, true, time, text,
1494 : : LOG_LINE_MAX + PREFIX_MAX);
1495 : :
1496 : : idx = log_next(idx);
1497 : 0 : seq++;
1498 : :
1499 : 0 : logbuf_unlock_irq();
1500 [ # # ]: 0 : if (copy_to_user(buf + len, text, textlen))
1501 : : len = -EFAULT;
1502 : : else
1503 : 0 : len += textlen;
1504 : 0 : logbuf_lock_irq();
1505 : :
1506 [ # # ]: 0 : if (seq < log_first_seq) {
1507 : : /* messages are gone, move to next one */
1508 : : seq = log_first_seq;
1509 : 0 : idx = log_first_idx;
1510 : : }
1511 : : }
1512 : :
1513 [ # # ]: 0 : if (clear) {
1514 : 0 : clear_seq = log_next_seq;
1515 : 0 : clear_idx = log_next_idx;
1516 : : }
1517 : 0 : logbuf_unlock_irq();
1518 : :
1519 : 0 : kfree(text);
1520 : 0 : return len;
1521 : : }
1522 : :
1523 : 0 : static void syslog_clear(void)
1524 : : {
1525 : 0 : logbuf_lock_irq();
1526 : 0 : clear_seq = log_next_seq;
1527 : 0 : clear_idx = log_next_idx;
1528 : 0 : logbuf_unlock_irq();
1529 : 0 : }
1530 : :
1531 : 2716 : int do_syslog(int type, char __user *buf, int len, int source)
1532 : : {
1533 : : bool clear = false;
1534 : : static int saved_console_loglevel = LOGLEVEL_DEFAULT;
1535 : : int error;
1536 : :
1537 : 2716 : error = check_syslog_permissions(type, source);
1538 [ + - ]: 2716 : if (error)
1539 : : return error;
1540 : :
1541 [ + - - - : 2716 : switch (type) {
- - - - -
- + ]
1542 : : case SYSLOG_ACTION_CLOSE: /* Close log */
1543 : : break;
1544 : : case SYSLOG_ACTION_OPEN: /* Open log */
1545 : : break;
1546 : : case SYSLOG_ACTION_READ: /* Read from log */
1547 [ + + ]: 2509 : if (!buf || len < 0)
1548 : : return -EINVAL;
1549 [ + - ]: 2302 : if (!len)
1550 : : return 0;
1551 [ + - ]: 2302 : if (!access_ok(buf, len))
1552 : : return -EFAULT;
1553 [ + + + + : 2302 : error = wait_event_interruptible(log_wait,
- + ]
1554 : : syslog_seq != log_next_seq);
1555 [ + - ]: 2095 : if (error)
1556 : : return error;
1557 : 2095 : error = syslog_print(buf, len);
1558 : 2095 : break;
1559 : : /* Read/clear last kernel messages */
1560 : : case SYSLOG_ACTION_READ_CLEAR:
1561 : : clear = true;
1562 : : /* FALL THRU */
1563 : : /* Read last kernel messages */
1564 : : case SYSLOG_ACTION_READ_ALL:
1565 [ # # ]: 0 : if (!buf || len < 0)
1566 : : return -EINVAL;
1567 [ # # ]: 0 : if (!len)
1568 : : return 0;
1569 [ # # ]: 0 : if (!access_ok(buf, len))
1570 : : return -EFAULT;
1571 : 0 : error = syslog_print_all(buf, len, clear);
1572 : 0 : break;
1573 : : /* Clear ring buffer */
1574 : : case SYSLOG_ACTION_CLEAR:
1575 : 0 : syslog_clear();
1576 : 0 : break;
1577 : : /* Disable logging to console */
1578 : : case SYSLOG_ACTION_CONSOLE_OFF:
1579 [ # # ]: 0 : if (saved_console_loglevel == LOGLEVEL_DEFAULT)
1580 : 0 : saved_console_loglevel = console_loglevel;
1581 : 0 : console_loglevel = minimum_console_loglevel;
1582 : 0 : break;
1583 : : /* Enable logging to console */
1584 : : case SYSLOG_ACTION_CONSOLE_ON:
1585 [ # # ]: 0 : if (saved_console_loglevel != LOGLEVEL_DEFAULT) {
1586 : 0 : console_loglevel = saved_console_loglevel;
1587 : 0 : saved_console_loglevel = LOGLEVEL_DEFAULT;
1588 : : }
1589 : : break;
1590 : : /* Set level of messages printed to console */
1591 : : case SYSLOG_ACTION_CONSOLE_LEVEL:
1592 [ # # ]: 0 : if (len < 1 || len > 8)
1593 : : return -EINVAL;
1594 [ # # ]: 0 : if (len < minimum_console_loglevel)
1595 : : len = minimum_console_loglevel;
1596 : 0 : console_loglevel = len;
1597 : : /* Implicitly re-enable logging to console */
1598 : 0 : saved_console_loglevel = LOGLEVEL_DEFAULT;
1599 : 0 : break;
1600 : : /* Number of chars in the log buffer */
1601 : : case SYSLOG_ACTION_SIZE_UNREAD:
1602 : 0 : logbuf_lock_irq();
1603 [ # # ]: 0 : if (syslog_seq < log_first_seq) {
1604 : : /* messages are gone, move to first one */
1605 : 0 : syslog_seq = log_first_seq;
1606 : 0 : syslog_idx = log_first_idx;
1607 : 0 : syslog_partial = 0;
1608 : : }
1609 [ # # ]: 0 : if (source == SYSLOG_FROM_PROC) {
1610 : : /*
1611 : : * Short-cut for poll(/"proc/kmsg") which simply checks
1612 : : * for pending data, not the size; return the count of
1613 : : * records, not the length.
1614 : : */
1615 : 0 : error = log_next_seq - syslog_seq;
1616 : : } else {
1617 : 0 : u64 seq = syslog_seq;
1618 : 0 : u32 idx = syslog_idx;
1619 [ # # ]: 0 : bool time = syslog_partial ? syslog_time : printk_time;
1620 : :
1621 [ # # ]: 0 : while (seq < log_next_seq) {
1622 : : struct printk_log *msg = log_from_idx(idx);
1623 : :
1624 : 0 : error += msg_print_text(msg, true, time, NULL,
1625 : : 0);
1626 : 0 : time = printk_time;
1627 : : idx = log_next(idx);
1628 : 0 : seq++;
1629 : : }
1630 : 0 : error -= syslog_partial;
1631 : : }
1632 : 0 : logbuf_unlock_irq();
1633 : : break;
1634 : : /* Size of the log buffer */
1635 : : case SYSLOG_ACTION_SIZE_BUFFER:
1636 : 0 : error = log_buf_len;
1637 : 0 : break;
1638 : : default:
1639 : : error = -EINVAL;
1640 : 0 : break;
1641 : : }
1642 : :
1643 : 2302 : return error;
1644 : : }
1645 : :
1646 : 0 : SYSCALL_DEFINE3(syslog, int, type, char __user *, buf, int, len)
1647 : : {
1648 : 0 : return do_syslog(type, buf, len, SYSLOG_FROM_READER);
1649 : : }
1650 : :
1651 : : /*
1652 : : * Special console_lock variants that help to reduce the risk of soft-lockups.
1653 : : * They allow to pass console_lock to another printk() call using a busy wait.
1654 : : */
1655 : :
1656 : : #ifdef CONFIG_LOCKDEP
1657 : : static struct lockdep_map console_owner_dep_map = {
1658 : : .name = "console_owner"
1659 : : };
1660 : : #endif
1661 : :
1662 : : static DEFINE_RAW_SPINLOCK(console_owner_lock);
1663 : : static struct task_struct *console_owner;
1664 : : static bool console_waiter;
1665 : :
1666 : : /**
1667 : : * console_lock_spinning_enable - mark beginning of code where another
1668 : : * thread might safely busy wait
1669 : : *
1670 : : * This basically converts console_lock into a spinlock. This marks
1671 : : * the section where the console_lock owner can not sleep, because
1672 : : * there may be a waiter spinning (like a spinlock). Also it must be
1673 : : * ready to hand over the lock at the end of the section.
1674 : : */
1675 : 1242 : static void console_lock_spinning_enable(void)
1676 : : {
1677 : 1242 : raw_spin_lock(&console_owner_lock);
1678 : 1242 : console_owner = current;
1679 : : raw_spin_unlock(&console_owner_lock);
1680 : :
1681 : : /* The waiter may spin on us after setting console_owner */
1682 : : spin_acquire(&console_owner_dep_map, 0, 0, _THIS_IP_);
1683 : 1242 : }
1684 : :
1685 : : /**
1686 : : * console_lock_spinning_disable_and_check - mark end of code where another
1687 : : * thread was able to busy wait and check if there is a waiter
1688 : : *
1689 : : * This is called at the end of the section where spinning is allowed.
1690 : : * It has two functions. First, it is a signal that it is no longer
1691 : : * safe to start busy waiting for the lock. Second, it checks if
1692 : : * there is a busy waiter and passes the lock rights to her.
1693 : : *
1694 : : * Important: Callers lose the lock if there was a busy waiter.
1695 : : * They must not touch items synchronized by console_lock
1696 : : * in this case.
1697 : : *
1698 : : * Return: 1 if the lock rights were passed, 0 otherwise.
1699 : : */
1700 : 1242 : static int console_lock_spinning_disable_and_check(void)
1701 : : {
1702 : : int waiter;
1703 : :
1704 : 1242 : raw_spin_lock(&console_owner_lock);
1705 : 1242 : waiter = READ_ONCE(console_waiter);
1706 : 1242 : console_owner = NULL;
1707 : : raw_spin_unlock(&console_owner_lock);
1708 : :
1709 [ - + ]: 1242 : if (!waiter) {
1710 : : spin_release(&console_owner_dep_map, 1, _THIS_IP_);
1711 : : return 0;
1712 : : }
1713 : :
1714 : : /* The waiter is now free to continue */
1715 : : WRITE_ONCE(console_waiter, false);
1716 : :
1717 : : spin_release(&console_owner_dep_map, 1, _THIS_IP_);
1718 : :
1719 : : /*
1720 : : * Hand off console_lock to waiter. The waiter will perform
1721 : : * the up(). After this, the waiter is the console_lock owner.
1722 : : */
1723 : : mutex_release(&console_lock_dep_map, 1, _THIS_IP_);
1724 : 0 : return 1;
1725 : : }
1726 : :
1727 : : /**
1728 : : * console_trylock_spinning - try to get console_lock by busy waiting
1729 : : *
1730 : : * This allows to busy wait for the console_lock when the current
1731 : : * owner is running in specially marked sections. It means that
1732 : : * the current owner is running and cannot reschedule until it
1733 : : * is ready to lose the lock.
1734 : : *
1735 : : * Return: 1 if we got the lock, 0 othrewise
1736 : : */
1737 : 57504 : static int console_trylock_spinning(void)
1738 : : {
1739 : : struct task_struct *owner = NULL;
1740 : : bool waiter;
1741 : : bool spin = false;
1742 : : unsigned long flags;
1743 : :
1744 [ + + ]: 57504 : if (console_trylock())
1745 : : return 1;
1746 : :
1747 : 463 : printk_safe_enter_irqsave(flags);
1748 : :
1749 : 463 : raw_spin_lock(&console_owner_lock);
1750 : 463 : owner = READ_ONCE(console_owner);
1751 : 463 : waiter = READ_ONCE(console_waiter);
1752 [ - + # # ]: 463 : if (!waiter && owner && owner != current) {
1753 : : WRITE_ONCE(console_waiter, true);
1754 : : spin = true;
1755 : : }
1756 : : raw_spin_unlock(&console_owner_lock);
1757 : :
1758 : : /*
1759 : : * If there is an active printk() writing to the
1760 : : * consoles, instead of having it write our data too,
1761 : : * see if we can offload that load from the active
1762 : : * printer, and do some printing ourselves.
1763 : : * Go into a spin only if there isn't already a waiter
1764 : : * spinning, and there is an active printer, and
1765 : : * that active printer isn't us (recursive printk?).
1766 : : */
1767 [ - + ]: 463 : if (!spin) {
1768 [ - + ]: 926 : printk_safe_exit_irqrestore(flags);
1769 : : return 0;
1770 : : }
1771 : :
1772 : : /* We spin waiting for the owner to release us */
1773 : : spin_acquire(&console_owner_dep_map, 0, 0, _THIS_IP_);
1774 : : /* Owner will clear console_waiter on hand off */
1775 [ # # ]: 0 : while (READ_ONCE(console_waiter))
1776 : 0 : cpu_relax();
1777 : : spin_release(&console_owner_dep_map, 1, _THIS_IP_);
1778 : :
1779 [ # # ]: 0 : printk_safe_exit_irqrestore(flags);
1780 : : /*
1781 : : * The owner passed the console lock to us.
1782 : : * Since we did not spin on console lock, annotate
1783 : : * this as a trylock. Otherwise lockdep will
1784 : : * complain.
1785 : : */
1786 : : mutex_acquire(&console_lock_dep_map, 0, 1, _THIS_IP_);
1787 : :
1788 : : return 1;
1789 : : }
1790 : :
1791 : : /*
1792 : : * Call the console drivers, asking them to write out
1793 : : * log_buf[start] to log_buf[end - 1].
1794 : : * The console_lock must be held.
1795 : : */
1796 : 1242 : static void call_console_drivers(const char *ext_text, size_t ext_len,
1797 : : const char *text, size_t len)
1798 : : {
1799 : : struct console *con;
1800 : :
1801 : 1242 : trace_console_rcuidle(text, len);
1802 : :
1803 [ - + ]: 1242 : if (!console_drivers)
1804 : 1242 : return;
1805 : :
1806 [ # # ]: 0 : for_each_console(con) {
1807 [ # # # # ]: 0 : if (exclusive_console && con != exclusive_console)
1808 : 0 : continue;
1809 [ # # ]: 0 : if (!(con->flags & CON_ENABLED))
1810 : 0 : continue;
1811 [ # # ]: 0 : if (!con->write)
1812 : 0 : continue;
1813 [ # # # # ]: 0 : if (!cpu_online(smp_processor_id()) &&
1814 : 0 : !(con->flags & CON_ANYTIME))
1815 : 0 : continue;
1816 [ # # ]: 0 : if (con->flags & CON_EXTENDED)
1817 : 0 : con->write(con, ext_text, ext_len);
1818 : : else
1819 : 0 : con->write(con, text, len);
1820 : : }
1821 : : }
1822 : :
1823 : : int printk_delay_msec __read_mostly;
1824 : :
1825 : : static inline void printk_delay(void)
1826 : : {
1827 [ - + ]: 61629 : if (unlikely(printk_delay_msec)) {
1828 : : int m = printk_delay_msec;
1829 : :
1830 [ # # ]: 0 : while (m--) {
1831 : 0 : mdelay(1);
1832 : : touch_nmi_watchdog();
1833 : : }
1834 : : }
1835 : : }
1836 : :
1837 : 61644 : static inline u32 printk_caller_id(void)
1838 : : {
1839 [ + + ]: 184057 : return in_task() ? task_pid_nr(current) :
1840 : 875 : 0x80000000 + raw_smp_processor_id();
1841 : : }
1842 : :
1843 : : /*
1844 : : * Continuation lines are buffered, and not committed to the record buffer
1845 : : * until the line is complete, or a race forces it. The line fragments
1846 : : * though, are printed immediately to the consoles to ensure everything has
1847 : : * reached the console in case of a kernel crash.
1848 : : */
1849 : : static struct cont {
1850 : : char buf[LOG_LINE_MAX];
1851 : : size_t len; /* length == 0 means unused buffer */
1852 : : u32 caller_id; /* printk_caller_id() of first print */
1853 : : u64 ts_nsec; /* time of first print */
1854 : : u8 level; /* log level of first message */
1855 : : u8 facility; /* log facility of first message */
1856 : : enum log_flags flags; /* prefix, newline flags */
1857 : : } cont;
1858 : :
1859 : 1449 : static void cont_flush(void)
1860 : : {
1861 [ + - ]: 1449 : if (cont.len == 0)
1862 : 1449 : return;
1863 : :
1864 : 1449 : log_store(cont.caller_id, cont.facility, cont.level, cont.flags,
1865 : : cont.ts_nsec, NULL, 0, cont.buf, cont.len);
1866 : 1449 : cont.len = 0;
1867 : : }
1868 : :
1869 : 5175 : static bool cont_add(u32 caller_id, int facility, int level,
1870 : : enum log_flags flags, const char *text, size_t len)
1871 : : {
1872 : : /* If the line gets too long, split it up in separate records. */
1873 [ - + ]: 5175 : if (cont.len + len > sizeof(cont.buf)) {
1874 : 0 : cont_flush();
1875 : 0 : return false;
1876 : : }
1877 : :
1878 [ + + ]: 5175 : if (!cont.len) {
1879 : 2277 : cont.facility = facility;
1880 : 2277 : cont.level = level;
1881 : 2277 : cont.caller_id = caller_id;
1882 : 2277 : cont.ts_nsec = local_clock();
1883 : 2277 : cont.flags = flags;
1884 : : }
1885 : :
1886 : 5175 : memcpy(cont.buf + cont.len, text, len);
1887 : 5175 : cont.len += len;
1888 : :
1889 : : // The original flags come from the first line,
1890 : : // but later continuations can add a newline.
1891 [ + + ]: 5175 : if (flags & LOG_NEWLINE) {
1892 : 1242 : cont.flags |= LOG_NEWLINE;
1893 : 1242 : cont_flush();
1894 : : }
1895 : :
1896 : : return true;
1897 : : }
1898 : :
1899 : 61644 : static size_t log_output(int facility, int level, enum log_flags lflags, const char *dict, size_t dictlen, char *text, size_t text_len)
1900 : : {
1901 : 61644 : const u32 caller_id = printk_caller_id();
1902 : :
1903 : : /*
1904 : : * If an earlier line was buffered, and we're a continuation
1905 : : * write from the same context, try to add it to the buffer.
1906 : : */
1907 [ + + ]: 61644 : if (cont.len) {
1908 [ + - + + ]: 3105 : if (cont.caller_id == caller_id && (lflags & LOG_CONT)) {
1909 [ - + ]: 2898 : if (cont_add(caller_id, facility, level, lflags, text, text_len))
1910 : : return text_len;
1911 : : }
1912 : : /* Otherwise, make sure it's flushed */
1913 : 207 : cont_flush();
1914 : : }
1915 : :
1916 : : /* Skip empty continuation lines that couldn't be added - they just flush */
1917 [ + + + - ]: 58746 : if (!text_len && (lflags & LOG_CONT))
1918 : : return 0;
1919 : :
1920 : : /* If it doesn't end in a newline, try to buffer the current line */
1921 [ + + ]: 58746 : if (!(lflags & LOG_NEWLINE)) {
1922 [ - + ]: 2277 : if (cont_add(caller_id, facility, level, lflags, text, text_len))
1923 : : return text_len;
1924 : : }
1925 : :
1926 : : /* Store it in the record log */
1927 : 56469 : return log_store(caller_id, facility, level, lflags, 0,
1928 : : dict, dictlen, text, text_len);
1929 : : }
1930 : :
1931 : : /* Must be called under logbuf_lock. */
1932 : 61644 : int vprintk_store(int facility, int level,
1933 : : const char *dict, size_t dictlen,
1934 : : const char *fmt, va_list args)
1935 : : {
1936 : : static char textbuf[LOG_LINE_MAX];
1937 : : char *text = textbuf;
1938 : : size_t text_len;
1939 : : enum log_flags lflags = 0;
1940 : :
1941 : : /*
1942 : : * The printf needs to come first; we need the syslog
1943 : : * prefix which might be passed-in as a parameter.
1944 : : */
1945 : 61644 : text_len = vscnprintf(text, sizeof(textbuf), fmt, args);
1946 : :
1947 : : /* mark and strip a trailing newline */
1948 [ + - + + ]: 61644 : if (text_len && text[text_len-1] == '\n') {
1949 : : text_len--;
1950 : : lflags |= LOG_NEWLINE;
1951 : : }
1952 : :
1953 : : /* strip kernel syslog prefix and extract log level or control flags */
1954 [ + + ]: 61644 : if (facility == 0) {
1955 : : int kern_level;
1956 : :
1957 [ + + ]: 104658 : while ((kern_level = printk_get_level(text)) != 0) {
1958 [ + + - ]: 45498 : switch (kern_level) {
1959 : : case '0' ... '7':
1960 [ + - ]: 42600 : if (level == LOGLEVEL_DEFAULT)
1961 : 42600 : level = kern_level - '0';
1962 : : break;
1963 : : case 'c': /* KERN_CONT */
1964 : 2898 : lflags |= LOG_CONT;
1965 : : }
1966 : :
1967 : 45498 : text_len -= 2;
1968 : 45498 : text += 2;
1969 : : }
1970 : : }
1971 : :
1972 [ + + ]: 61644 : if (level == LOGLEVEL_DEFAULT)
1973 : 6417 : level = default_message_loglevel;
1974 : :
1975 [ + + ]: 61644 : if (dict)
1976 : 10143 : lflags |= LOG_NEWLINE;
1977 : :
1978 : 61644 : return log_output(facility, level, lflags,
1979 : : dict, dictlen, text, text_len);
1980 : : }
1981 : :
1982 : 61640 : asmlinkage int vprintk_emit(int facility, int level,
1983 : : const char *dict, size_t dictlen,
1984 : : const char *fmt, va_list args)
1985 : : {
1986 : : int printed_len;
1987 : : bool in_sched = false, pending_output;
1988 : : unsigned long flags;
1989 : : u64 curr_log_seq;
1990 : :
1991 : : /* Suppress unimportant messages after panic happens */
1992 [ + - ]: 61640 : if (unlikely(suppress_printk))
1993 : : return 0;
1994 : :
1995 [ + + ]: 61644 : if (level == LOGLEVEL_SCHED) {
1996 : : level = LOGLEVEL_DEFAULT;
1997 : : in_sched = true;
1998 : : }
1999 : :
2000 : 61644 : boot_delay_msec(level);
2001 : : printk_delay();
2002 : :
2003 : : /* This stops the holder of console_sem just where we want him */
2004 : 61644 : logbuf_lock_irqsave(flags);
2005 : 61644 : curr_log_seq = log_next_seq;
2006 : 61644 : printed_len = vprintk_store(facility, level, dict, dictlen, fmt, args);
2007 : 61644 : pending_output = (curr_log_seq != log_next_seq);
2008 [ + + ]: 134741 : logbuf_unlock_irqrestore(flags);
2009 : :
2010 : : /* If called from the scheduler, we can not call up(). */
2011 [ + + ]: 61644 : if (!in_sched && pending_output) {
2012 : : /*
2013 : : * Disable preemption to avoid being preempted while holding
2014 : : * console_sem which would prevent anyone from printing to
2015 : : * console
2016 : : */
2017 : 57504 : preempt_disable();
2018 : : /*
2019 : : * Try to acquire and then immediately release the console
2020 : : * semaphore. The release will print out buffers and wake up
2021 : : * /dev/kmsg and syslog() users.
2022 : : */
2023 [ + + ]: 57504 : if (console_trylock_spinning())
2024 : 57041 : console_unlock();
2025 : 57504 : preempt_enable();
2026 : : }
2027 : :
2028 [ + + ]: 61644 : if (pending_output)
2029 : 57711 : wake_up_klogd();
2030 : 61643 : return printed_len;
2031 : : }
2032 : : EXPORT_SYMBOL(vprintk_emit);
2033 : :
2034 : 4347 : asmlinkage int vprintk(const char *fmt, va_list args)
2035 : : {
2036 : 4347 : return vprintk_func(fmt, args);
2037 : : }
2038 : : EXPORT_SYMBOL(vprintk);
2039 : :
2040 : 48810 : int vprintk_default(const char *fmt, va_list args)
2041 : : {
2042 : : int r;
2043 : :
2044 : : #ifdef CONFIG_KGDB_KDB
2045 : : /* Allow to pass printk() to kdb but avoid a recursion. */
2046 [ - + # # ]: 48810 : if (unlikely(kdb_trap_printk && kdb_printf_cpu < 0)) {
2047 : 0 : r = vkdb_printf(KDB_MSGSRC_PRINTK, fmt, args);
2048 : 0 : return r;
2049 : : }
2050 : : #endif
2051 : 48810 : r = vprintk_emit(0, LOGLEVEL_DEFAULT, NULL, 0, fmt, args);
2052 : :
2053 : 48810 : return r;
2054 : : }
2055 : : EXPORT_SYMBOL_GPL(vprintk_default);
2056 : :
2057 : : /**
2058 : : * printk - print a kernel message
2059 : : * @fmt: format string
2060 : : *
2061 : : * This is printk(). It can be called from any context. We want it to work.
2062 : : *
2063 : : * We try to grab the console_lock. If we succeed, it's easy - we log the
2064 : : * output and call the console drivers. If we fail to get the semaphore, we
2065 : : * place the output into the log buffer and return. The current holder of
2066 : : * the console_sem will notice the new output in console_unlock(); and will
2067 : : * send it to the consoles before releasing the lock.
2068 : : *
2069 : : * One effect of this deferred printing is that code which calls printk() and
2070 : : * then changes console_loglevel may break. This is because console_loglevel
2071 : : * is inspected when the actual printing occurs.
2072 : : *
2073 : : * See also:
2074 : : * printf(3)
2075 : : *
2076 : : * See the vsnprintf() documentation for format string extensions over C99.
2077 : : */
2078 : 44463 : asmlinkage __visible int printk(const char *fmt, ...)
2079 : : {
2080 : : va_list args;
2081 : : int r;
2082 : :
2083 : 44463 : va_start(args, fmt);
2084 : 44463 : r = vprintk_func(fmt, args);
2085 : 44463 : va_end(args);
2086 : :
2087 : 44463 : return r;
2088 : : }
2089 : : EXPORT_SYMBOL(printk);
2090 : :
2091 : : #else /* CONFIG_PRINTK */
2092 : :
2093 : : #define LOG_LINE_MAX 0
2094 : : #define PREFIX_MAX 0
2095 : : #define printk_time false
2096 : :
2097 : : static u64 syslog_seq;
2098 : : static u32 syslog_idx;
2099 : : static u64 console_seq;
2100 : : static u32 console_idx;
2101 : : static u64 exclusive_console_stop_seq;
2102 : : static u64 log_first_seq;
2103 : : static u32 log_first_idx;
2104 : : static u64 log_next_seq;
2105 : : static char *log_text(const struct printk_log *msg) { return NULL; }
2106 : : static char *log_dict(const struct printk_log *msg) { return NULL; }
2107 : : static struct printk_log *log_from_idx(u32 idx) { return NULL; }
2108 : : static u32 log_next(u32 idx) { return 0; }
2109 : : static ssize_t msg_print_ext_header(char *buf, size_t size,
2110 : : struct printk_log *msg,
2111 : : u64 seq) { return 0; }
2112 : : static ssize_t msg_print_ext_body(char *buf, size_t size,
2113 : : char *dict, size_t dict_len,
2114 : : char *text, size_t text_len) { return 0; }
2115 : : static void console_lock_spinning_enable(void) { }
2116 : : static int console_lock_spinning_disable_and_check(void) { return 0; }
2117 : : static void call_console_drivers(const char *ext_text, size_t ext_len,
2118 : : const char *text, size_t len) {}
2119 : : static size_t msg_print_text(const struct printk_log *msg, bool syslog,
2120 : : bool time, char *buf, size_t size) { return 0; }
2121 : : static bool suppress_message_printing(int level) { return false; }
2122 : :
2123 : : #endif /* CONFIG_PRINTK */
2124 : :
2125 : : #ifdef CONFIG_EARLY_PRINTK
2126 : : struct console *early_console;
2127 : :
2128 : : asmlinkage __visible void early_printk(const char *fmt, ...)
2129 : : {
2130 : : va_list ap;
2131 : : char buf[512];
2132 : : int n;
2133 : :
2134 : : if (!early_console)
2135 : : return;
2136 : :
2137 : : va_start(ap, fmt);
2138 : : n = vscnprintf(buf, sizeof(buf), fmt, ap);
2139 : : va_end(ap);
2140 : :
2141 : : early_console->write(early_console, buf, n);
2142 : : }
2143 : : #endif
2144 : :
2145 : 414 : static int __add_preferred_console(char *name, int idx, char *options,
2146 : : char *brl_options)
2147 : : {
2148 : : struct console_cmdline *c;
2149 : : int i;
2150 : :
2151 : : /*
2152 : : * See if this tty is not yet registered, and
2153 : : * if we have a slot free.
2154 : : */
2155 [ + - ]: 1035 : for (i = 0, c = console_cmdline;
2156 [ + + ]: 621 : i < MAX_CMDLINECONSOLES && c->name[0];
2157 : 207 : i++, c++) {
2158 [ - + # # ]: 207 : if (strcmp(c->name, name) == 0 && c->index == idx) {
2159 [ # # ]: 0 : if (!brl_options)
2160 : 0 : preferred_console = i;
2161 : : return 0;
2162 : : }
2163 : : }
2164 [ + - ]: 414 : if (i == MAX_CMDLINECONSOLES)
2165 : : return -E2BIG;
2166 [ + - ]: 414 : if (!brl_options)
2167 : 414 : preferred_console = i;
2168 : 414 : strlcpy(c->name, name, sizeof(c->name));
2169 : 414 : c->options = options;
2170 : : braille_set_options(c, brl_options);
2171 : :
2172 : 414 : c->index = idx;
2173 : 414 : return 0;
2174 : : }
2175 : :
2176 : 0 : static int __init console_msg_format_setup(char *str)
2177 : : {
2178 [ # # ]: 0 : if (!strcmp(str, "syslog"))
2179 : 0 : console_msg_format = MSG_FORMAT_SYSLOG;
2180 [ # # ]: 0 : if (!strcmp(str, "default"))
2181 : 0 : console_msg_format = MSG_FORMAT_DEFAULT;
2182 : 0 : return 1;
2183 : : }
2184 : : __setup("console_msg_format=", console_msg_format_setup);
2185 : :
2186 : : /*
2187 : : * Set up a console. Called via do_early_param() in init/main.c
2188 : : * for each "console=" parameter in the boot command line.
2189 : : */
2190 : 414 : static int __init console_setup(char *str)
2191 : : {
2192 : : char buf[sizeof(console_cmdline[0].name) + 4]; /* 4 for "ttyS" */
2193 : : char *s, *options, *brl_options = NULL;
2194 : : int idx;
2195 : :
2196 : : if (_braille_console_setup(&str, &brl_options))
2197 : : return 1;
2198 : :
2199 : : /*
2200 : : * Decode str into name, index, options.
2201 : : */
2202 [ - + ]: 414 : if (str[0] >= '0' && str[0] <= '9') {
2203 : 0 : strcpy(buf, "ttyS");
2204 : 0 : strncpy(buf + 4, str, sizeof(buf) - 5);
2205 : : } else {
2206 : 414 : strncpy(buf, str, sizeof(buf) - 1);
2207 : : }
2208 : 414 : buf[sizeof(buf) - 1] = 0;
2209 : 414 : options = strchr(str, ',');
2210 [ + + ]: 414 : if (options)
2211 : 207 : *(options++) = 0;
2212 : : #ifdef __sparc__
2213 : : if (!strcmp(str, "ttya"))
2214 : : strcpy(buf, "ttyS0");
2215 : : if (!strcmp(str, "ttyb"))
2216 : : strcpy(buf, "ttyS1");
2217 : : #endif
2218 [ + - ]: 2277 : for (s = buf; *s; s++)
2219 [ + + + - ]: 2277 : if (isdigit(*s) || *s == ',')
2220 : : break;
2221 : 414 : idx = simple_strtoul(s, NULL, 10);
2222 : 414 : *s = 0;
2223 : :
2224 : 414 : __add_preferred_console(buf, idx, options, brl_options);
2225 : 414 : console_set_on_cmdline = 1;
2226 : : return 1;
2227 : : }
2228 : : __setup("console=", console_setup);
2229 : :
2230 : : /**
2231 : : * add_preferred_console - add a device to the list of preferred consoles.
2232 : : * @name: device name
2233 : : * @idx: device index
2234 : : * @options: options for this console
2235 : : *
2236 : : * The last preferred console added will be used for kernel messages
2237 : : * and stdin/out/err for init. Normally this is used by console_setup
2238 : : * above to handle user-supplied console arguments; however it can also
2239 : : * be used by arch-specific code either to override the user or more
2240 : : * commonly to provide a default console (ie from PROM variables) when
2241 : : * the user has not supplied one.
2242 : : */
2243 : 0 : int add_preferred_console(char *name, int idx, char *options)
2244 : : {
2245 : 0 : return __add_preferred_console(name, idx, options, NULL);
2246 : : }
2247 : :
2248 : : bool console_suspend_enabled = true;
2249 : : EXPORT_SYMBOL(console_suspend_enabled);
2250 : :
2251 : 0 : static int __init console_suspend_disable(char *str)
2252 : : {
2253 : 0 : console_suspend_enabled = false;
2254 : 0 : return 1;
2255 : : }
2256 : : __setup("no_console_suspend", console_suspend_disable);
2257 : : module_param_named(console_suspend, console_suspend_enabled,
2258 : : bool, S_IRUGO | S_IWUSR);
2259 : : MODULE_PARM_DESC(console_suspend, "suspend console during suspend"
2260 : : " and hibernate operations");
2261 : :
2262 : : /**
2263 : : * suspend_console - suspend the console subsystem
2264 : : *
2265 : : * This disables printk() while we go into suspend states
2266 : : */
2267 : 0 : void suspend_console(void)
2268 : : {
2269 [ # # ]: 0 : if (!console_suspend_enabled)
2270 : 0 : return;
2271 : 0 : pr_info("Suspending console(s) (use no_console_suspend to debug)\n");
2272 : 0 : console_lock();
2273 : 0 : console_suspended = 1;
2274 : 0 : up_console_sem();
2275 : : }
2276 : :
2277 : 0 : void resume_console(void)
2278 : : {
2279 [ # # ]: 0 : if (!console_suspend_enabled)
2280 : 0 : return;
2281 : 0 : down_console_sem();
2282 : 0 : console_suspended = 0;
2283 : 0 : console_unlock();
2284 : : }
2285 : :
2286 : : /**
2287 : : * console_cpu_notify - print deferred console messages after CPU hotplug
2288 : : * @cpu: unused
2289 : : *
2290 : : * If printk() is called from a CPU that is not online yet, the messages
2291 : : * will be printed on the console only if there are CON_ANYTIME consoles.
2292 : : * This function is called when a new CPU comes online (or fails to come
2293 : : * up) or goes offline.
2294 : : */
2295 : 0 : static int console_cpu_notify(unsigned int cpu)
2296 : : {
2297 [ # # ]: 0 : if (!cpuhp_tasks_frozen) {
2298 : : /* If trylock fails, someone else is doing the printing */
2299 [ # # ]: 0 : if (console_trylock())
2300 : 0 : console_unlock();
2301 : : }
2302 : 0 : return 0;
2303 : : }
2304 : :
2305 : : /**
2306 : : * console_lock - lock the console system for exclusive use.
2307 : : *
2308 : : * Acquires a lock which guarantees that the caller has
2309 : : * exclusive access to the console system and the console_drivers list.
2310 : : *
2311 : : * Can sleep, returns nothing.
2312 : : */
2313 : 65817 : void console_lock(void)
2314 : : {
2315 : 65817 : might_sleep();
2316 : :
2317 : 65816 : down_console_sem();
2318 [ + - ]: 65817 : if (console_suspended)
2319 : 65817 : return;
2320 : 65817 : console_locked = 1;
2321 : 65817 : console_may_schedule = 1;
2322 : : }
2323 : : EXPORT_SYMBOL(console_lock);
2324 : :
2325 : : /**
2326 : : * console_trylock - try to lock the console system for exclusive use.
2327 : : *
2328 : : * Try to acquire a lock which guarantees that the caller has exclusive
2329 : : * access to the console system and the console_drivers list.
2330 : : *
2331 : : * returns 1 on success, and 0 on failure to acquire the lock.
2332 : : */
2333 : 68039 : int console_trylock(void)
2334 : : {
2335 [ + + ]: 68039 : if (down_trylock_console_sem())
2336 : : return 0;
2337 [ - + ]: 67475 : if (console_suspended) {
2338 : 0 : up_console_sem();
2339 : 0 : return 0;
2340 : : }
2341 : 67475 : console_locked = 1;
2342 : 67475 : console_may_schedule = 0;
2343 : 67475 : return 1;
2344 : : }
2345 : : EXPORT_SYMBOL(console_trylock);
2346 : :
2347 : 158212 : int is_console_locked(void)
2348 : : {
2349 : 158212 : return console_locked;
2350 : : }
2351 : : EXPORT_SYMBOL(is_console_locked);
2352 : :
2353 : : /*
2354 : : * Check if we have any console that is capable of printing while cpu is
2355 : : * booting or shutting down. Requires console_sem.
2356 : : */
2357 : : static int have_callable_console(void)
2358 : : {
2359 : : struct console *con;
2360 : :
2361 [ + + ]: 2691 : for_each_console(con)
2362 [ + - ]: 1242 : if ((con->flags & CON_ENABLED) &&
2363 : : (con->flags & CON_ANYTIME))
2364 : : return 1;
2365 : :
2366 : : return 0;
2367 : : }
2368 : :
2369 : : /*
2370 : : * Can we actually use the console at this time on this cpu?
2371 : : *
2372 : : * Console drivers may assume that per-cpu resources have been allocated. So
2373 : : * unless they're explicitly marked as being able to cope (CON_ANYTIME) don't
2374 : : * call them until this CPU is officially up.
2375 : : */
2376 : 133292 : static inline int can_use_console(void)
2377 : : {
2378 [ + + + - ]: 268033 : return cpu_online(raw_smp_processor_id()) || have_callable_console();
2379 : : }
2380 : :
2381 : : /**
2382 : : * console_unlock - unlock the console system
2383 : : *
2384 : : * Releases the console_lock which the caller holds on the console system
2385 : : * and the console driver list.
2386 : : *
2387 : : * While the console_lock was held, console output may have been buffered
2388 : : * by printk(). If this is the case, console_unlock(); emits
2389 : : * the output prior to releasing the lock.
2390 : : *
2391 : : * If there is output waiting, we wake /dev/kmsg and syslog() users.
2392 : : *
2393 : : * console_unlock(); may be called from any context.
2394 : : */
2395 : 133292 : void console_unlock(void)
2396 : : {
2397 : : static char ext_text[CONSOLE_EXT_LOG_MAX];
2398 : : static char text[LOG_LINE_MAX + PREFIX_MAX];
2399 : : unsigned long flags;
2400 : : bool do_cond_resched, retry;
2401 : :
2402 [ - + ]: 133292 : if (console_suspended) {
2403 : 0 : up_console_sem();
2404 : 0 : return;
2405 : : }
2406 : :
2407 : : /*
2408 : : * Console drivers are called with interrupts disabled, so
2409 : : * @console_may_schedule should be cleared before; however, we may
2410 : : * end up dumping a lot of lines, for example, if called from
2411 : : * console registration path, and should invoke cond_resched()
2412 : : * between lines if allowable. Not doing so can cause a very long
2413 : : * scheduling stall on a slow console leading to RCU stall and
2414 : : * softlockup warnings which exacerbate the issue with more
2415 : : * messages practically incapacitating the system.
2416 : : *
2417 : : * console_trylock() is not able to detect the preemptive
2418 : : * context reliably. Therefore the value must be stored before
2419 : : * and cleared after the the "again" goto label.
2420 : : */
2421 : 133292 : do_cond_resched = console_may_schedule;
2422 : : again:
2423 : 133292 : console_may_schedule = 0;
2424 : :
2425 : : /*
2426 : : * We released the console_sem lock, so we need to recheck if
2427 : : * cpu is online and (if not) is there at least one CON_ANYTIME
2428 : : * console.
2429 : : */
2430 [ + + ]: 133292 : if (!can_use_console()) {
2431 : 1449 : console_locked = 0;
2432 : 1449 : up_console_sem();
2433 : 1449 : return;
2434 : : }
2435 : :
2436 : : for (;;) {
2437 : : struct printk_log *msg;
2438 : : size_t ext_len = 0;
2439 : : size_t len;
2440 : :
2441 : 133085 : printk_safe_enter_irqsave(flags);
2442 : 133085 : raw_spin_lock(&logbuf_lock);
2443 [ - + ]: 133085 : if (console_seq < log_first_seq) {
2444 : 0 : len = sprintf(text,
2445 : : "** %llu printk messages dropped **\n",
2446 : : log_first_seq - console_seq);
2447 : :
2448 : : /* messages are gone, move to first one */
2449 : 0 : console_seq = log_first_seq;
2450 : 0 : console_idx = log_first_idx;
2451 : : } else {
2452 : : len = 0;
2453 : : }
2454 : : skip:
2455 [ + + ]: 233024 : if (console_seq == log_next_seq)
2456 : : break;
2457 : :
2458 : 101181 : msg = log_from_idx(console_idx);
2459 [ + + ]: 202362 : if (suppress_message_printing(msg->level)) {
2460 : : /*
2461 : : * Skip record we have buffered and already printed
2462 : : * directly to the console when we received it, and
2463 : : * record that has level above the console loglevel.
2464 : : */
2465 : 99939 : console_idx = log_next(console_idx);
2466 : 99939 : console_seq++;
2467 : 99939 : goto skip;
2468 : : }
2469 : :
2470 : : /* Output to all consoles once old messages replayed. */
2471 [ - + # # ]: 1242 : if (unlikely(exclusive_console &&
2472 : : console_seq >= exclusive_console_stop_seq)) {
2473 : 0 : exclusive_console = NULL;
2474 : : }
2475 : :
2476 : 1242 : len += msg_print_text(msg,
2477 : 1242 : console_msg_format & MSG_FORMAT_SYSLOG,
2478 : : printk_time, text + len, sizeof(text) - len);
2479 [ - + ]: 1242 : if (nr_ext_console_drivers) {
2480 : 0 : ext_len = msg_print_ext_header(ext_text,
2481 : : sizeof(ext_text),
2482 : : msg, console_seq);
2483 : 0 : ext_len += msg_print_ext_body(ext_text + ext_len,
2484 : : sizeof(ext_text) - ext_len,
2485 : 0 : log_dict(msg), msg->dict_len,
2486 : : log_text(msg), msg->text_len);
2487 : : }
2488 : 2484 : console_idx = log_next(console_idx);
2489 : 1242 : console_seq++;
2490 : : raw_spin_unlock(&logbuf_lock);
2491 : :
2492 : : /*
2493 : : * While actively printing out messages, if another printk()
2494 : : * were to occur on another CPU, it may wait for this one to
2495 : : * finish. This task can not be preempted if there is a
2496 : : * waiter waiting to take over.
2497 : : */
2498 : 1242 : console_lock_spinning_enable();
2499 : :
2500 : 1242 : stop_critical_timings(); /* don't trace print latency */
2501 : 1242 : call_console_drivers(ext_text, ext_len, text, len);
2502 : 1242 : start_critical_timings();
2503 : :
2504 [ - + ]: 1242 : if (console_lock_spinning_disable_and_check()) {
2505 [ # # ]: 0 : printk_safe_exit_irqrestore(flags);
2506 : : return;
2507 : : }
2508 : :
2509 [ + - ]: 3726 : printk_safe_exit_irqrestore(flags);
2510 : :
2511 [ + - ]: 1242 : if (do_cond_resched)
2512 : 0 : cond_resched();
2513 : : }
2514 : :
2515 : 131843 : console_locked = 0;
2516 : :
2517 : : raw_spin_unlock(&logbuf_lock);
2518 : :
2519 : 131843 : up_console_sem();
2520 : :
2521 : : /*
2522 : : * Someone could have filled up the buffer again, so re-check if there's
2523 : : * something to flush. In case we cannot trylock the console_sem again,
2524 : : * there's a new owner and the console_unlock() from them will do the
2525 : : * flush, no worries.
2526 : : */
2527 : 131843 : raw_spin_lock(&logbuf_lock);
2528 : 131843 : retry = console_seq != log_next_seq;
2529 : : raw_spin_unlock(&logbuf_lock);
2530 [ + + ]: 270999 : printk_safe_exit_irqrestore(flags);
2531 : :
2532 [ + + - + ]: 131843 : if (retry && console_trylock())
2533 : : goto again;
2534 : : }
2535 : : EXPORT_SYMBOL(console_unlock);
2536 : :
2537 : : /**
2538 : : * console_conditional_schedule - yield the CPU if required
2539 : : *
2540 : : * If the console code is currently allowed to sleep, and
2541 : : * if this CPU should yield the CPU to another task, do
2542 : : * so here.
2543 : : *
2544 : : * Must be called within console_lock();.
2545 : : */
2546 : 9108 : void __sched console_conditional_schedule(void)
2547 : : {
2548 [ + - ]: 9108 : if (console_may_schedule)
2549 : 9108 : cond_resched();
2550 : 9108 : }
2551 : : EXPORT_SYMBOL(console_conditional_schedule);
2552 : :
2553 : 0 : void console_unblank(void)
2554 : : {
2555 : : struct console *c;
2556 : :
2557 : : /*
2558 : : * console_unblank can no longer be called in interrupt context unless
2559 : : * oops_in_progress is set to 1..
2560 : : */
2561 [ # # ]: 0 : if (oops_in_progress) {
2562 [ # # ]: 0 : if (down_trylock_console_sem() != 0)
2563 : 0 : return;
2564 : : } else
2565 : 0 : console_lock();
2566 : :
2567 : 0 : console_locked = 1;
2568 : 0 : console_may_schedule = 0;
2569 [ # # ]: 0 : for_each_console(c)
2570 [ # # # # ]: 0 : if ((c->flags & CON_ENABLED) && c->unblank)
2571 : 0 : c->unblank();
2572 : 0 : console_unlock();
2573 : : }
2574 : :
2575 : : /**
2576 : : * console_flush_on_panic - flush console content on panic
2577 : : * @mode: flush all messages in buffer or just the pending ones
2578 : : *
2579 : : * Immediately output all pending messages no matter what.
2580 : : */
2581 : 0 : void console_flush_on_panic(enum con_flush_mode mode)
2582 : : {
2583 : : /*
2584 : : * If someone else is holding the console lock, trylock will fail
2585 : : * and may_schedule may be set. Ignore and proceed to unlock so
2586 : : * that messages are flushed out. As this can be called from any
2587 : : * context and we don't want to get preempted while flushing,
2588 : : * ensure may_schedule is cleared.
2589 : : */
2590 : 0 : console_trylock();
2591 : 0 : console_may_schedule = 0;
2592 : :
2593 [ # # ]: 0 : if (mode == CONSOLE_REPLAY_ALL) {
2594 : : unsigned long flags;
2595 : :
2596 : 0 : logbuf_lock_irqsave(flags);
2597 : 0 : console_seq = log_first_seq;
2598 : 0 : console_idx = log_first_idx;
2599 [ # # ]: 0 : logbuf_unlock_irqrestore(flags);
2600 : : }
2601 : 0 : console_unlock();
2602 : 0 : }
2603 : :
2604 : : /*
2605 : : * Return the console tty driver structure and its associated index
2606 : : */
2607 : 17483 : struct tty_driver *console_device(int *index)
2608 : : {
2609 : : struct console *c;
2610 : : struct tty_driver *driver = NULL;
2611 : :
2612 : 17483 : console_lock();
2613 [ + - ]: 17483 : for_each_console(c) {
2614 [ - + ]: 17483 : if (!c->device)
2615 : 0 : continue;
2616 : 17483 : driver = c->device(c, index);
2617 [ - + ]: 17483 : if (driver)
2618 : : break;
2619 : : }
2620 : 17483 : console_unlock();
2621 : 17483 : return driver;
2622 : : }
2623 : :
2624 : : /*
2625 : : * Prevent further output on the passed console device so that (for example)
2626 : : * serial drivers can disable console output before suspending a port, and can
2627 : : * re-enable output afterwards.
2628 : : */
2629 : 0 : void console_stop(struct console *console)
2630 : : {
2631 : 0 : console_lock();
2632 : 0 : console->flags &= ~CON_ENABLED;
2633 : 0 : console_unlock();
2634 : 0 : }
2635 : : EXPORT_SYMBOL(console_stop);
2636 : :
2637 : 0 : void console_start(struct console *console)
2638 : : {
2639 : 0 : console_lock();
2640 : 0 : console->flags |= CON_ENABLED;
2641 : 0 : console_unlock();
2642 : 0 : }
2643 : : EXPORT_SYMBOL(console_start);
2644 : :
2645 : : static int __read_mostly keep_bootcon;
2646 : :
2647 : 0 : static int __init keep_bootcon_setup(char *str)
2648 : : {
2649 : 0 : keep_bootcon = 1;
2650 : 0 : pr_info("debug: skip boot console de-registration.\n");
2651 : :
2652 : 0 : return 0;
2653 : : }
2654 : :
2655 : : early_param("keep_bootcon", keep_bootcon_setup);
2656 : :
2657 : : /*
2658 : : * The console driver calls this routine during kernel initialization
2659 : : * to register the console printing procedure with printk() and to
2660 : : * print any messages that were printed by the kernel before the
2661 : : * console driver was initialized.
2662 : : *
2663 : : * This can happen pretty early during the boot process (because of
2664 : : * early_printk) - sometimes before setup_arch() completes - be careful
2665 : : * of what kernel features are used - they may not be initialised yet.
2666 : : *
2667 : : * There are two types of consoles - bootconsoles (early_printk) and
2668 : : * "real" consoles (everything which is not a bootconsole) which are
2669 : : * handled differently.
2670 : : * - Any number of bootconsoles can be registered at any time.
2671 : : * - As soon as a "real" console is registered, all bootconsoles
2672 : : * will be unregistered automatically.
2673 : : * - Once a "real" console is registered, any attempt to register a
2674 : : * bootconsoles will be rejected
2675 : : */
2676 : 414 : void register_console(struct console *newcon)
2677 : : {
2678 : : int i;
2679 : : unsigned long flags;
2680 : : struct console *bcon = NULL;
2681 : : struct console_cmdline *c;
2682 : : static bool has_preferred;
2683 : :
2684 [ + + ]: 414 : if (console_drivers)
2685 [ + + ]: 207 : for_each_console(bcon)
2686 [ - + + - ]: 207 : if (WARN(bcon == newcon,
2687 : : "console '%s%d' already registered\n",
2688 : : bcon->name, bcon->index))
2689 : : return;
2690 : :
2691 : : /*
2692 : : * before we register a new CON_BOOT console, make sure we don't
2693 : : * already have a valid console
2694 : : */
2695 [ + + - + ]: 414 : if (console_drivers && newcon->flags & CON_BOOT) {
2696 : : /* find the last or real console */
2697 [ # # ]: 0 : for_each_console(bcon) {
2698 [ # # ]: 0 : if (!(bcon->flags & CON_BOOT)) {
2699 : 0 : pr_info("Too late to register bootconsole %s%d\n",
2700 : : newcon->name, newcon->index);
2701 : 0 : return;
2702 : : }
2703 : : }
2704 : : }
2705 : :
2706 [ + + - + ]: 414 : if (console_drivers && console_drivers->flags & CON_BOOT)
2707 : : bcon = console_drivers;
2708 : :
2709 [ + + + - : 414 : if (!has_preferred || bcon || !console_drivers)
- + ]
2710 : 207 : has_preferred = preferred_console >= 0;
2711 : :
2712 : : /*
2713 : : * See if we want to use this console driver. If we
2714 : : * didn't select a console we take the first one
2715 : : * that registers here.
2716 : : */
2717 [ - + ]: 414 : if (!has_preferred) {
2718 [ # # ]: 0 : if (newcon->index < 0)
2719 : 0 : newcon->index = 0;
2720 [ # # # # ]: 0 : if (newcon->setup == NULL ||
2721 : 0 : newcon->setup(newcon, NULL) == 0) {
2722 : 0 : newcon->flags |= CON_ENABLED;
2723 [ # # ]: 0 : if (newcon->device) {
2724 : 0 : newcon->flags |= CON_CONSDEV;
2725 : 0 : has_preferred = true;
2726 : : }
2727 : : }
2728 : : }
2729 : :
2730 : : /*
2731 : : * See if this console matches one we selected on
2732 : : * the command line.
2733 : : */
2734 [ + - ]: 621 : for (i = 0, c = console_cmdline;
2735 [ + - ]: 621 : i < MAX_CMDLINECONSOLES && c->name[0];
2736 : 207 : i++, c++) {
2737 [ + + + - ]: 828 : if (!newcon->match ||
2738 : 207 : newcon->match(newcon, c->name, c->index, c->options) != 0) {
2739 : : /* default matching */
2740 : : BUILD_BUG_ON(sizeof(c->name) != sizeof(newcon->name));
2741 [ + + ]: 621 : if (strcmp(c->name, newcon->name) != 0)
2742 : 207 : continue;
2743 [ - + # # ]: 414 : if (newcon->index >= 0 &&
2744 : 0 : newcon->index != c->index)
2745 : 0 : continue;
2746 [ + - ]: 414 : if (newcon->index < 0)
2747 : 414 : newcon->index = c->index;
2748 : :
2749 : : if (_braille_register_console(newcon, c))
2750 : : return;
2751 : :
2752 [ + + + - ]: 621 : if (newcon->setup &&
2753 : 207 : newcon->setup(newcon, c->options) != 0)
2754 : : break;
2755 : : }
2756 : :
2757 : 414 : newcon->flags |= CON_ENABLED;
2758 [ + + ]: 414 : if (i == preferred_console) {
2759 : 207 : newcon->flags |= CON_CONSDEV;
2760 : 207 : has_preferred = true;
2761 : : }
2762 : : break;
2763 : : }
2764 : :
2765 [ + - ]: 414 : if (!(newcon->flags & CON_ENABLED))
2766 : : return;
2767 : :
2768 : : /*
2769 : : * If we have a bootconsole, and are switching to a real console,
2770 : : * don't print everything out again, since when the boot console, and
2771 : : * the real console are the same physical device, it's annoying to
2772 : : * see the beginning boot messages twice
2773 : : */
2774 [ - + # # ]: 414 : if (bcon && ((newcon->flags & (CON_CONSDEV | CON_BOOT)) == CON_CONSDEV))
2775 : 0 : newcon->flags &= ~CON_PRINTBUFFER;
2776 : :
2777 : : /*
2778 : : * Put this console in the list - keep the
2779 : : * preferred driver at the head of the list.
2780 : : */
2781 : 414 : console_lock();
2782 [ + + - + ]: 414 : if ((newcon->flags & CON_CONSDEV) || console_drivers == NULL) {
2783 : 207 : newcon->next = console_drivers;
2784 : 207 : console_drivers = newcon;
2785 [ - + ]: 207 : if (newcon->next)
2786 : 0 : newcon->next->flags &= ~CON_CONSDEV;
2787 : : } else {
2788 : 207 : newcon->next = console_drivers->next;
2789 : 207 : console_drivers->next = newcon;
2790 : : }
2791 : :
2792 [ - + ]: 414 : if (newcon->flags & CON_EXTENDED)
2793 : 0 : nr_ext_console_drivers++;
2794 : :
2795 [ + - ]: 414 : if (newcon->flags & CON_PRINTBUFFER) {
2796 : : /*
2797 : : * console_unlock(); will print out the buffered messages
2798 : : * for us.
2799 : : */
2800 : 414 : logbuf_lock_irqsave(flags);
2801 : : /*
2802 : : * We're about to replay the log buffer. Only do this to the
2803 : : * just-registered console to avoid excessive message spam to
2804 : : * the already-registered consoles.
2805 : : *
2806 : : * Set exclusive_console with disabled interrupts to reduce
2807 : : * race window with eventual console_flush_on_panic() that
2808 : : * ignores console_lock.
2809 : : */
2810 : 414 : exclusive_console = newcon;
2811 : 414 : exclusive_console_stop_seq = console_seq;
2812 : 414 : console_seq = syslog_seq;
2813 : 414 : console_idx = syslog_idx;
2814 [ - + ]: 828 : logbuf_unlock_irqrestore(flags);
2815 : : }
2816 : 414 : console_unlock();
2817 : 414 : console_sysfs_notify();
2818 : :
2819 : : /*
2820 : : * By unregistering the bootconsoles after we enable the real console
2821 : : * we get the "console xxx enabled" message on all the consoles -
2822 : : * boot consoles, real consoles, etc - this is to ensure that end
2823 : : * users know there might be something in the kernel's log buffer that
2824 : : * went to the bootconsole (that they do not see on the real console)
2825 : : */
2826 [ + - ]: 414 : pr_info("%sconsole [%s%d] enabled\n",
2827 : : (newcon->flags & CON_BOOT) ? "boot" : "" ,
2828 : : newcon->name, newcon->index);
2829 [ - + # # ]: 414 : if (bcon &&
2830 [ # # ]: 0 : ((newcon->flags & (CON_CONSDEV | CON_BOOT)) == CON_CONSDEV) &&
2831 : 0 : !keep_bootcon) {
2832 : : /* We need to iterate through all boot consoles, to make
2833 : : * sure we print everything out, before we unregister them.
2834 : : */
2835 [ # # ]: 0 : for_each_console(bcon)
2836 [ # # ]: 0 : if (bcon->flags & CON_BOOT)
2837 : 0 : unregister_console(bcon);
2838 : : }
2839 : : }
2840 : : EXPORT_SYMBOL(register_console);
2841 : :
2842 : 0 : int unregister_console(struct console *console)
2843 : : {
2844 : : struct console *a, *b;
2845 : : int res;
2846 : :
2847 [ # # ]: 0 : pr_info("%sconsole [%s%d] disabled\n",
2848 : : (console->flags & CON_BOOT) ? "boot" : "" ,
2849 : : console->name, console->index);
2850 : :
2851 : : res = _braille_unregister_console(console);
2852 : : if (res)
2853 : : return res;
2854 : :
2855 : : res = 1;
2856 : 0 : console_lock();
2857 [ # # ]: 0 : if (console_drivers == console) {
2858 : 0 : console_drivers=console->next;
2859 : : res = 0;
2860 [ # # ]: 0 : } else if (console_drivers) {
2861 [ # # ]: 0 : for (a=console_drivers->next, b=console_drivers ;
2862 : 0 : a; b=a, a=b->next) {
2863 [ # # ]: 0 : if (a == console) {
2864 : 0 : b->next = a->next;
2865 : : res = 0;
2866 : 0 : break;
2867 : : }
2868 : : }
2869 : : }
2870 : :
2871 [ # # # # ]: 0 : if (!res && (console->flags & CON_EXTENDED))
2872 : 0 : nr_ext_console_drivers--;
2873 : :
2874 : : /*
2875 : : * If this isn't the last console and it has CON_CONSDEV set, we
2876 : : * need to set it on the next preferred console.
2877 : : */
2878 [ # # # # ]: 0 : if (console_drivers != NULL && console->flags & CON_CONSDEV)
2879 : 0 : console_drivers->flags |= CON_CONSDEV;
2880 : :
2881 : 0 : console->flags &= ~CON_ENABLED;
2882 : 0 : console_unlock();
2883 : 0 : console_sysfs_notify();
2884 : : return res;
2885 : : }
2886 : : EXPORT_SYMBOL(unregister_console);
2887 : :
2888 : : /*
2889 : : * Initialize the console device. This is called *early*, so
2890 : : * we can't necessarily depend on lots of kernel help here.
2891 : : * Just do some early initializations, and do the complex setup
2892 : : * later.
2893 : : */
2894 : 207 : void __init console_init(void)
2895 : : {
2896 : : int ret;
2897 : : initcall_t call;
2898 : : initcall_entry_t *ce;
2899 : :
2900 : : /* Setup the default TTY line discipline. */
2901 : 207 : n_tty_init();
2902 : :
2903 : : /*
2904 : : * set up the console device so that later boot sequences can
2905 : : * inform about problems etc..
2906 : : */
2907 : : ce = __con_initcall_start;
2908 : 207 : trace_initcall_level("console");
2909 [ + + ]: 828 : while (ce < __con_initcall_end) {
2910 : : call = initcall_from_entry(ce);
2911 : 414 : trace_initcall_start(call);
2912 : 414 : ret = call();
2913 : 414 : trace_initcall_finish(call, ret);
2914 : 414 : ce++;
2915 : : }
2916 : 207 : }
2917 : :
2918 : : /*
2919 : : * Some boot consoles access data that is in the init section and which will
2920 : : * be discarded after the initcalls have been run. To make sure that no code
2921 : : * will access this data, unregister the boot consoles in a late initcall.
2922 : : *
2923 : : * If for some reason, such as deferred probe or the driver being a loadable
2924 : : * module, the real console hasn't registered yet at this point, there will
2925 : : * be a brief interval in which no messages are logged to the console, which
2926 : : * makes it difficult to diagnose problems that occur during this time.
2927 : : *
2928 : : * To mitigate this problem somewhat, only unregister consoles whose memory
2929 : : * intersects with the init section. Note that all other boot consoles will
2930 : : * get unregistred when the real preferred console is registered.
2931 : : */
2932 : 207 : static int __init printk_late_init(void)
2933 : : {
2934 : : struct console *con;
2935 : : int ret;
2936 : :
2937 [ + + ]: 414 : for_each_console(con) {
2938 [ + - ]: 207 : if (!(con->flags & CON_BOOT))
2939 : 207 : continue;
2940 : :
2941 : : /* Check addresses that might be used for enabled consoles. */
2942 [ # # # # ]: 0 : if (init_section_intersects(con, sizeof(*con)) ||
2943 [ # # ]: 0 : init_section_contains(con->write, 0) ||
2944 [ # # ]: 0 : init_section_contains(con->read, 0) ||
2945 [ # # ]: 0 : init_section_contains(con->device, 0) ||
2946 [ # # ]: 0 : init_section_contains(con->unblank, 0) ||
2947 : 0 : init_section_contains(con->data, 0)) {
2948 : : /*
2949 : : * Please, consider moving the reported consoles out
2950 : : * of the init section.
2951 : : */
2952 : 0 : pr_warn("bootconsole [%s%d] uses init memory and must be disabled even before the real one is ready\n",
2953 : : con->name, con->index);
2954 : 0 : unregister_console(con);
2955 : : }
2956 : : }
2957 : : ret = cpuhp_setup_state_nocalls(CPUHP_PRINTK_DEAD, "printk:dead", NULL,
2958 : : console_cpu_notify);
2959 [ - + ]: 207 : WARN_ON(ret < 0);
2960 : : ret = cpuhp_setup_state_nocalls(CPUHP_AP_ONLINE_DYN, "printk:online",
2961 : : console_cpu_notify, NULL);
2962 [ - + ]: 207 : WARN_ON(ret < 0);
2963 : 207 : return 0;
2964 : : }
2965 : : late_initcall(printk_late_init);
2966 : :
2967 : : #if defined CONFIG_PRINTK
2968 : : /*
2969 : : * Delayed printk version, for scheduler-internal messages:
2970 : : */
2971 : : #define PRINTK_PENDING_WAKEUP 0x01
2972 : : #define PRINTK_PENDING_OUTPUT 0x02
2973 : :
2974 : : static DEFINE_PER_CPU(int, printk_pending);
2975 : :
2976 : 6412 : static void wake_up_klogd_work_func(struct irq_work *irq_work)
2977 : : {
2978 : 12824 : int pending = __this_cpu_xchg(printk_pending, 0);
2979 : :
2980 [ + + ]: 6412 : if (pending & PRINTK_PENDING_OUTPUT) {
2981 : : /* If trylock fails, someone else is doing the printing */
2982 [ + - ]: 207 : if (console_trylock())
2983 : 207 : console_unlock();
2984 : : }
2985 : :
2986 [ + + ]: 6370 : if (pending & PRINTK_PENDING_WAKEUP)
2987 : 6163 : wake_up_interruptible(&log_wait);
2988 : 6414 : }
2989 : :
2990 : : static DEFINE_PER_CPU(struct irq_work, wake_up_klogd_work) = {
2991 : : .func = wake_up_klogd_work_func,
2992 : : .flags = IRQ_WORK_LAZY,
2993 : : };
2994 : :
2995 : 57711 : void wake_up_klogd(void)
2996 : : {
2997 [ + + ]: 57711 : if (!printk_percpu_data_ready())
2998 : 57711 : return;
2999 : :
3000 : 53985 : preempt_disable();
3001 [ + + ]: 53985 : if (waitqueue_active(&log_wait)) {
3002 : 17000 : this_cpu_or(printk_pending, PRINTK_PENDING_WAKEUP);
3003 : 17002 : irq_work_queue(this_cpu_ptr(&wake_up_klogd_work));
3004 : : }
3005 : 53985 : preempt_enable();
3006 : : }
3007 : :
3008 : 207 : void defer_console_output(void)
3009 : : {
3010 [ + - ]: 207 : if (!printk_percpu_data_ready())
3011 : 207 : return;
3012 : :
3013 : 207 : preempt_disable();
3014 : 414 : __this_cpu_or(printk_pending, PRINTK_PENDING_OUTPUT);
3015 : 414 : irq_work_queue(this_cpu_ptr(&wake_up_klogd_work));
3016 : 207 : preempt_enable();
3017 : : }
3018 : :
3019 : 207 : int vprintk_deferred(const char *fmt, va_list args)
3020 : : {
3021 : : int r;
3022 : :
3023 : 207 : r = vprintk_emit(0, LOGLEVEL_SCHED, NULL, 0, fmt, args);
3024 : 207 : defer_console_output();
3025 : :
3026 : 207 : return r;
3027 : : }
3028 : :
3029 : 207 : int printk_deferred(const char *fmt, ...)
3030 : : {
3031 : : va_list args;
3032 : : int r;
3033 : :
3034 : 207 : va_start(args, fmt);
3035 : 207 : r = vprintk_deferred(fmt, args);
3036 : 207 : va_end(args);
3037 : :
3038 : 207 : return r;
3039 : : }
3040 : :
3041 : : /*
3042 : : * printk rate limiting, lifted from the networking subsystem.
3043 : : *
3044 : : * This enforces a rate limit: not more than 10 kernel messages
3045 : : * every 5s to make a denial-of-service attack impossible.
3046 : : */
3047 : : DEFINE_RATELIMIT_STATE(printk_ratelimit_state, 5 * HZ, 10);
3048 : :
3049 : 207 : int __printk_ratelimit(const char *func)
3050 : : {
3051 : 207 : return ___ratelimit(&printk_ratelimit_state, func);
3052 : : }
3053 : : EXPORT_SYMBOL(__printk_ratelimit);
3054 : :
3055 : : /**
3056 : : * printk_timed_ratelimit - caller-controlled printk ratelimiting
3057 : : * @caller_jiffies: pointer to caller's state
3058 : : * @interval_msecs: minimum interval between prints
3059 : : *
3060 : : * printk_timed_ratelimit() returns true if more than @interval_msecs
3061 : : * milliseconds have elapsed since the last time printk_timed_ratelimit()
3062 : : * returned true.
3063 : : */
3064 : 0 : bool printk_timed_ratelimit(unsigned long *caller_jiffies,
3065 : : unsigned int interval_msecs)
3066 : : {
3067 : 0 : unsigned long elapsed = jiffies - *caller_jiffies;
3068 : :
3069 [ # # # # ]: 0 : if (*caller_jiffies && elapsed <= msecs_to_jiffies(interval_msecs))
3070 : : return false;
3071 : :
3072 : 0 : *caller_jiffies = jiffies;
3073 : 0 : return true;
3074 : : }
3075 : : EXPORT_SYMBOL(printk_timed_ratelimit);
3076 : :
3077 : : static DEFINE_SPINLOCK(dump_list_lock);
3078 : : static LIST_HEAD(dump_list);
3079 : :
3080 : : /**
3081 : : * kmsg_dump_register - register a kernel log dumper.
3082 : : * @dumper: pointer to the kmsg_dumper structure
3083 : : *
3084 : : * Adds a kernel log dumper to the system. The dump callback in the
3085 : : * structure will be called when the kernel oopses or panics and must be
3086 : : * set. Returns zero on success and %-EINVAL or %-EBUSY otherwise.
3087 : : */
3088 : 0 : int kmsg_dump_register(struct kmsg_dumper *dumper)
3089 : : {
3090 : : unsigned long flags;
3091 : : int err = -EBUSY;
3092 : :
3093 : : /* The dump callback needs to be set */
3094 [ # # ]: 0 : if (!dumper->dump)
3095 : : return -EINVAL;
3096 : :
3097 : 0 : spin_lock_irqsave(&dump_list_lock, flags);
3098 : : /* Don't allow registering multiple times */
3099 [ # # ]: 0 : if (!dumper->registered) {
3100 : 0 : dumper->registered = 1;
3101 : 0 : list_add_tail_rcu(&dumper->list, &dump_list);
3102 : : err = 0;
3103 : : }
3104 : : spin_unlock_irqrestore(&dump_list_lock, flags);
3105 : :
3106 : 0 : return err;
3107 : : }
3108 : : EXPORT_SYMBOL_GPL(kmsg_dump_register);
3109 : :
3110 : : /**
3111 : : * kmsg_dump_unregister - unregister a kmsg dumper.
3112 : : * @dumper: pointer to the kmsg_dumper structure
3113 : : *
3114 : : * Removes a dump device from the system. Returns zero on success and
3115 : : * %-EINVAL otherwise.
3116 : : */
3117 : 0 : int kmsg_dump_unregister(struct kmsg_dumper *dumper)
3118 : : {
3119 : : unsigned long flags;
3120 : : int err = -EINVAL;
3121 : :
3122 : 0 : spin_lock_irqsave(&dump_list_lock, flags);
3123 [ # # ]: 0 : if (dumper->registered) {
3124 : 0 : dumper->registered = 0;
3125 : : list_del_rcu(&dumper->list);
3126 : : err = 0;
3127 : : }
3128 : : spin_unlock_irqrestore(&dump_list_lock, flags);
3129 : 0 : synchronize_rcu();
3130 : :
3131 : 0 : return err;
3132 : : }
3133 : : EXPORT_SYMBOL_GPL(kmsg_dump_unregister);
3134 : :
3135 : : static bool always_kmsg_dump;
3136 : : module_param_named(always_kmsg_dump, always_kmsg_dump, bool, S_IRUGO | S_IWUSR);
3137 : :
3138 : : /**
3139 : : * kmsg_dump - dump kernel log to kernel message dumpers.
3140 : : * @reason: the reason (oops, panic etc) for dumping
3141 : : *
3142 : : * Call each of the registered dumper's dump() callback, which can
3143 : : * retrieve the kmsg records with kmsg_dump_get_line() or
3144 : : * kmsg_dump_get_buffer().
3145 : : */
3146 : 0 : void kmsg_dump(enum kmsg_dump_reason reason)
3147 : : {
3148 : : struct kmsg_dumper *dumper;
3149 : : unsigned long flags;
3150 : :
3151 [ # # # # ]: 0 : if ((reason > KMSG_DUMP_OOPS) && !always_kmsg_dump)
3152 : 0 : return;
3153 : :
3154 : : rcu_read_lock();
3155 [ # # ]: 0 : list_for_each_entry_rcu(dumper, &dump_list, list) {
3156 [ # # # # ]: 0 : if (dumper->max_reason && reason > dumper->max_reason)
3157 : 0 : continue;
3158 : :
3159 : : /* initialize iterator with data about the stored records */
3160 : 0 : dumper->active = true;
3161 : :
3162 : 0 : logbuf_lock_irqsave(flags);
3163 : 0 : dumper->cur_seq = clear_seq;
3164 : 0 : dumper->cur_idx = clear_idx;
3165 : 0 : dumper->next_seq = log_next_seq;
3166 : 0 : dumper->next_idx = log_next_idx;
3167 [ # # ]: 0 : logbuf_unlock_irqrestore(flags);
3168 : :
3169 : : /* invoke dumper which will iterate over records */
3170 : 0 : dumper->dump(dumper, reason);
3171 : :
3172 : : /* reset iterator */
3173 : 0 : dumper->active = false;
3174 : : }
3175 : : rcu_read_unlock();
3176 : : }
3177 : :
3178 : : /**
3179 : : * kmsg_dump_get_line_nolock - retrieve one kmsg log line (unlocked version)
3180 : : * @dumper: registered kmsg dumper
3181 : : * @syslog: include the "<4>" prefixes
3182 : : * @line: buffer to copy the line to
3183 : : * @size: maximum size of the buffer
3184 : : * @len: length of line placed into buffer
3185 : : *
3186 : : * Start at the beginning of the kmsg buffer, with the oldest kmsg
3187 : : * record, and copy one record into the provided buffer.
3188 : : *
3189 : : * Consecutive calls will return the next available record moving
3190 : : * towards the end of the buffer with the youngest messages.
3191 : : *
3192 : : * A return value of FALSE indicates that there are no more records to
3193 : : * read.
3194 : : *
3195 : : * The function is similar to kmsg_dump_get_line(), but grabs no locks.
3196 : : */
3197 : 0 : bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog,
3198 : : char *line, size_t size, size_t *len)
3199 : : {
3200 : : struct printk_log *msg;
3201 : : size_t l = 0;
3202 : : bool ret = false;
3203 : :
3204 [ # # ]: 0 : if (!dumper->active)
3205 : : goto out;
3206 : :
3207 [ # # ]: 0 : if (dumper->cur_seq < log_first_seq) {
3208 : : /* messages are gone, move to first available one */
3209 : 0 : dumper->cur_seq = log_first_seq;
3210 : 0 : dumper->cur_idx = log_first_idx;
3211 : : }
3212 : :
3213 : : /* last entry */
3214 [ # # ]: 0 : if (dumper->cur_seq >= log_next_seq)
3215 : : goto out;
3216 : :
3217 : 0 : msg = log_from_idx(dumper->cur_idx);
3218 : 0 : l = msg_print_text(msg, syslog, printk_time, line, size);
3219 : :
3220 : 0 : dumper->cur_idx = log_next(dumper->cur_idx);
3221 : 0 : dumper->cur_seq++;
3222 : : ret = true;
3223 : : out:
3224 [ # # ]: 0 : if (len)
3225 : 0 : *len = l;
3226 : 0 : return ret;
3227 : : }
3228 : :
3229 : : /**
3230 : : * kmsg_dump_get_line - retrieve one kmsg log line
3231 : : * @dumper: registered kmsg dumper
3232 : : * @syslog: include the "<4>" prefixes
3233 : : * @line: buffer to copy the line to
3234 : : * @size: maximum size of the buffer
3235 : : * @len: length of line placed into buffer
3236 : : *
3237 : : * Start at the beginning of the kmsg buffer, with the oldest kmsg
3238 : : * record, and copy one record into the provided buffer.
3239 : : *
3240 : : * Consecutive calls will return the next available record moving
3241 : : * towards the end of the buffer with the youngest messages.
3242 : : *
3243 : : * A return value of FALSE indicates that there are no more records to
3244 : : * read.
3245 : : */
3246 : 0 : bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
3247 : : char *line, size_t size, size_t *len)
3248 : : {
3249 : : unsigned long flags;
3250 : : bool ret;
3251 : :
3252 : 0 : logbuf_lock_irqsave(flags);
3253 : 0 : ret = kmsg_dump_get_line_nolock(dumper, syslog, line, size, len);
3254 [ # # ]: 0 : logbuf_unlock_irqrestore(flags);
3255 : :
3256 : 0 : return ret;
3257 : : }
3258 : : EXPORT_SYMBOL_GPL(kmsg_dump_get_line);
3259 : :
3260 : : /**
3261 : : * kmsg_dump_get_buffer - copy kmsg log lines
3262 : : * @dumper: registered kmsg dumper
3263 : : * @syslog: include the "<4>" prefixes
3264 : : * @buf: buffer to copy the line to
3265 : : * @size: maximum size of the buffer
3266 : : * @len: length of line placed into buffer
3267 : : *
3268 : : * Start at the end of the kmsg buffer and fill the provided buffer
3269 : : * with as many of the the *youngest* kmsg records that fit into it.
3270 : : * If the buffer is large enough, all available kmsg records will be
3271 : : * copied with a single call.
3272 : : *
3273 : : * Consecutive calls will fill the buffer with the next block of
3274 : : * available older records, not including the earlier retrieved ones.
3275 : : *
3276 : : * A return value of FALSE indicates that there are no more records to
3277 : : * read.
3278 : : */
3279 : 0 : bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
3280 : : char *buf, size_t size, size_t *len)
3281 : : {
3282 : : unsigned long flags;
3283 : : u64 seq;
3284 : : u32 idx;
3285 : : u64 next_seq;
3286 : : u32 next_idx;
3287 : : size_t l = 0;
3288 : : bool ret = false;
3289 : 0 : bool time = printk_time;
3290 : :
3291 [ # # ]: 0 : if (!dumper->active)
3292 : : goto out;
3293 : :
3294 : 0 : logbuf_lock_irqsave(flags);
3295 [ # # ]: 0 : if (dumper->cur_seq < log_first_seq) {
3296 : : /* messages are gone, move to first available one */
3297 : 0 : dumper->cur_seq = log_first_seq;
3298 : 0 : dumper->cur_idx = log_first_idx;
3299 : : }
3300 : :
3301 : : /* last entry */
3302 [ # # ]: 0 : if (dumper->cur_seq >= dumper->next_seq) {
3303 [ # # ]: 0 : logbuf_unlock_irqrestore(flags);
3304 : : goto out;
3305 : : }
3306 : :
3307 : : /* calculate length of entire buffer */
3308 : : seq = dumper->cur_seq;
3309 : 0 : idx = dumper->cur_idx;
3310 [ # # ]: 0 : while (seq < dumper->next_seq) {
3311 : : struct printk_log *msg = log_from_idx(idx);
3312 : :
3313 : 0 : l += msg_print_text(msg, true, time, NULL, 0);
3314 : : idx = log_next(idx);
3315 : 0 : seq++;
3316 : : }
3317 : :
3318 : : /* move first record forward until length fits into the buffer */
3319 : 0 : seq = dumper->cur_seq;
3320 : 0 : idx = dumper->cur_idx;
3321 [ # # # # ]: 0 : while (l >= size && seq < dumper->next_seq) {
3322 : : struct printk_log *msg = log_from_idx(idx);
3323 : :
3324 : 0 : l -= msg_print_text(msg, true, time, NULL, 0);
3325 : : idx = log_next(idx);
3326 : 0 : seq++;
3327 : : }
3328 : :
3329 : : /* last message in next interation */
3330 : 0 : next_seq = seq;
3331 : 0 : next_idx = idx;
3332 : :
3333 : : l = 0;
3334 [ # # ]: 0 : while (seq < dumper->next_seq) {
3335 : : struct printk_log *msg = log_from_idx(idx);
3336 : :
3337 : 0 : l += msg_print_text(msg, syslog, time, buf + l, size - l);
3338 : : idx = log_next(idx);
3339 : 0 : seq++;
3340 : : }
3341 : :
3342 : 0 : dumper->next_seq = next_seq;
3343 : 0 : dumper->next_idx = next_idx;
3344 : : ret = true;
3345 [ # # ]: 0 : logbuf_unlock_irqrestore(flags);
3346 : : out:
3347 [ # # ]: 0 : if (len)
3348 : 0 : *len = l;
3349 : 0 : return ret;
3350 : : }
3351 : : EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer);
3352 : :
3353 : : /**
3354 : : * kmsg_dump_rewind_nolock - reset the interator (unlocked version)
3355 : : * @dumper: registered kmsg dumper
3356 : : *
3357 : : * Reset the dumper's iterator so that kmsg_dump_get_line() and
3358 : : * kmsg_dump_get_buffer() can be called again and used multiple
3359 : : * times within the same dumper.dump() callback.
3360 : : *
3361 : : * The function is similar to kmsg_dump_rewind(), but grabs no locks.
3362 : : */
3363 : 0 : void kmsg_dump_rewind_nolock(struct kmsg_dumper *dumper)
3364 : : {
3365 : 0 : dumper->cur_seq = clear_seq;
3366 : 0 : dumper->cur_idx = clear_idx;
3367 : 0 : dumper->next_seq = log_next_seq;
3368 : 0 : dumper->next_idx = log_next_idx;
3369 : 0 : }
3370 : :
3371 : : /**
3372 : : * kmsg_dump_rewind - reset the interator
3373 : : * @dumper: registered kmsg dumper
3374 : : *
3375 : : * Reset the dumper's iterator so that kmsg_dump_get_line() and
3376 : : * kmsg_dump_get_buffer() can be called again and used multiple
3377 : : * times within the same dumper.dump() callback.
3378 : : */
3379 : 0 : void kmsg_dump_rewind(struct kmsg_dumper *dumper)
3380 : : {
3381 : : unsigned long flags;
3382 : :
3383 : 0 : logbuf_lock_irqsave(flags);
3384 : : kmsg_dump_rewind_nolock(dumper);
3385 [ # # ]: 0 : logbuf_unlock_irqrestore(flags);
3386 : 0 : }
3387 : : EXPORT_SYMBOL_GPL(kmsg_dump_rewind);
3388 : :
3389 : : #endif
|