hc
2024-02-20 102a0743326a03cd1a1202ceda21e175b7d3575c
kernel/kernel/printk/printk.c
....@@ -1,3 +1,4 @@
1
+// SPDX-License-Identifier: GPL-2.0-only
12 /*
23 * linux/kernel/printk.c
34 *
....@@ -16,6 +17,8 @@
1617 * 01Mar01 Andrew Morton
1718 */
1819
20
+#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt
21
+
1922 #include <linux/kernel.h>
2023 #include <linux/mm.h>
2124 #include <linux/tty.h>
....@@ -29,11 +32,9 @@
2932 #include <linux/delay.h>
3033 #include <linux/smp.h>
3134 #include <linux/security.h>
32
-#include <linux/bootmem.h>
3335 #include <linux/memblock.h>
3436 #include <linux/syscalls.h>
3537 #include <linux/crash_core.h>
36
-#include <linux/kdb.h>
3738 #include <linux/ratelimit.h>
3839 #include <linux/kmsg_dump.h>
3940 #include <linux/syslog.h>
....@@ -53,7 +54,11 @@
5354 #include <trace/events/initcall.h>
5455 #define CREATE_TRACE_POINTS
5556 #include <trace/events/printk.h>
57
+#undef CREATE_TRACE_POINTS
58
+#include <trace/hooks/printk.h>
59
+#include <trace/hooks/logbuf.h>
5660
61
+#include "printk_ringbuffer.h"
5762 #include "console_cmdline.h"
5863 #include "braille.h"
5964 #include "internal.h"
....@@ -82,6 +87,7 @@
8287 CONSOLE_LOGLEVEL_MIN, /* minimum_console_loglevel */
8388 CONSOLE_LOGLEVEL_DEFAULT, /* default_console_loglevel */
8489 };
90
+EXPORT_SYMBOL_GPL(console_printk);
8591
8692 atomic_t ignore_console_lock_warning __read_mostly = ATOMIC_INIT(0);
8793 EXPORT_SYMBOL(ignore_console_lock_warning);
....@@ -101,6 +107,12 @@
101107 static DEFINE_SEMAPHORE(console_sem);
102108 struct console *console_drivers;
103109 EXPORT_SYMBOL_GPL(console_drivers);
110
+
111
+/*
112
+ * System may need to suppress printk message under certain
113
+ * circumstances, like after kernel panic happens.
114
+ */
115
+int __read_mostly suppress_printk;
104116
105117 #ifdef CONFIG_LOCKDEP
106118 static struct lockdep_map console_lock_dep_map = {
....@@ -127,26 +139,38 @@
127139
128140 static int __control_devkmsg(char *str)
129141 {
142
+ size_t len;
143
+
130144 if (!str)
131145 return -EINVAL;
132146
133
- if (!strncmp(str, "on", 2)) {
147
+ len = str_has_prefix(str, "on");
148
+ if (len) {
134149 devkmsg_log = DEVKMSG_LOG_MASK_ON;
135
- return 2;
136
- } else if (!strncmp(str, "off", 3)) {
137
- devkmsg_log = DEVKMSG_LOG_MASK_OFF;
138
- return 3;
139
- } else if (!strncmp(str, "ratelimit", 9)) {
140
- devkmsg_log = DEVKMSG_LOG_MASK_DEFAULT;
141
- return 9;
150
+ return len;
142151 }
152
+
153
+ len = str_has_prefix(str, "off");
154
+ if (len) {
155
+ devkmsg_log = DEVKMSG_LOG_MASK_OFF;
156
+ return len;
157
+ }
158
+
159
+ len = str_has_prefix(str, "ratelimit");
160
+ if (len) {
161
+ devkmsg_log = DEVKMSG_LOG_MASK_DEFAULT;
162
+ return len;
163
+ }
164
+
143165 return -EINVAL;
144166 }
145167
146168 static int __init control_devkmsg(char *str)
147169 {
148
- if (__control_devkmsg(str) < 0)
170
+ if (__control_devkmsg(str) < 0) {
171
+ pr_warn("printk.devkmsg: bad option string '%s'\n", str);
149172 return 1;
173
+ }
150174
151175 /*
152176 * Set sysctl string accordingly:
....@@ -165,14 +189,14 @@
165189 */
166190 devkmsg_log |= DEVKMSG_LOG_MASK_LOCK;
167191
168
- return 0;
192
+ return 1;
169193 }
170194 __setup("printk.devkmsg=", control_devkmsg);
171195
172196 char devkmsg_log_str[DEVKMSG_STR_MAX_SIZE] = "ratelimit";
173197
174198 int devkmsg_sysctl_set_loglvl(struct ctl_table *table, int write,
175
- void __user *buffer, size_t *lenp, loff_t *ppos)
199
+ void *buffer, size_t *lenp, loff_t *ppos)
176200 {
177201 char old_str[DEVKMSG_STR_MAX_SIZE];
178202 unsigned int old;
....@@ -210,16 +234,7 @@
210234 return 0;
211235 }
212236
213
-/*
214
- * Number of registered extended console drivers.
215
- *
216
- * If extended consoles are present, in-kernel cont reassembly is disabled
217
- * and each fragment is stored as a separate log entry with proper
218
- * continuation flag so that every emitted message has full metadata. This
219
- * doesn't change the result for regular consoles or /proc/kmsg. For
220
- * /dev/kmsg, as long as the reader concatenates messages according to
221
- * consecutive continuation flags, the end result should be the same too.
222
- */
237
+/* Number of registered extended console drivers. */
223238 static int nr_ext_console_drivers;
224239
225240 /*
....@@ -256,7 +271,7 @@
256271 {
257272 unsigned long flags;
258273
259
- mutex_release(&console_lock_dep_map, 1, ip);
274
+ mutex_release(&console_lock_dep_map, ip);
260275
261276 printk_safe_enter_irqsave(flags);
262277 up(&console_sem);
....@@ -288,6 +303,7 @@
288303 static struct console_cmdline console_cmdline[MAX_CMDLINECONSOLES];
289304
290305 static int preferred_console = -1;
306
+static bool has_preferred_console;
291307 int console_set_on_cmdline;
292308 EXPORT_SYMBOL(console_set_on_cmdline);
293309
....@@ -302,30 +318,22 @@
302318 static int console_msg_format = MSG_FORMAT_DEFAULT;
303319
304320 /*
305
- * The printk log buffer consists of a chain of concatenated variable
306
- * length records. Every record starts with a record header, containing
307
- * the overall length of the record.
321
+ * The printk log buffer consists of a sequenced collection of records, each
322
+ * containing variable length message text. Every record also contains its
323
+ * own meta-data (@info).
308324 *
309
- * The heads to the first and last entry in the buffer, as well as the
310
- * sequence numbers of these entries are maintained when messages are
311
- * stored.
325
+ * Every record meta-data carries the timestamp in microseconds, as well as
326
+ * the standard userspace syslog level and syslog facility. The usual kernel
327
+ * messages use LOG_KERN; userspace-injected messages always carry a matching
328
+ * syslog facility, by default LOG_USER. The origin of every message can be
329
+ * reliably determined that way.
312330 *
313
- * If the heads indicate available messages, the length in the header
314
- * tells the start next message. A length == 0 for the next message
315
- * indicates a wrap-around to the beginning of the buffer.
331
+ * The human readable log message of a record is available in @text, the
332
+ * length of the message text in @text_len. The stored message is not
333
+ * terminated.
316334 *
317
- * Every record carries the monotonic timestamp in microseconds, as well as
318
- * the standard userspace syslog level and syslog facility. The usual
319
- * kernel messages use LOG_KERN; userspace-injected messages always carry
320
- * a matching syslog facility, by default LOG_USER. The origin of every
321
- * message can be reliably determined that way.
322
- *
323
- * The human readable log message directly follows the message header. The
324
- * length of the message text is stored in the header, the stored message
325
- * is not terminated.
326
- *
327
- * Optionally, a message can carry a dictionary of properties (key/value pairs),
328
- * to provide userspace with a machine-readable message context.
335
+ * Optionally, a record can carry a dictionary of properties (key/value
336
+ * pairs), to provide userspace with a machine-readable message context.
329337 *
330338 * Examples for well-defined, commonly used property names are:
331339 * DEVICE=b12:8 device identifier
....@@ -335,25 +343,22 @@
335343 * +sound:card0 subsystem:devname
336344 * SUBSYSTEM=pci driver-core subsystem name
337345 *
338
- * Valid characters in property names are [a-zA-Z0-9.-_]. The plain text value
339
- * follows directly after a '=' character. Every property is terminated by
340
- * a '\0' character. The last property is not terminated.
346
+ * Valid characters in property names are [a-zA-Z0-9.-_]. Property names
347
+ * and values are terminated by a '\0' character.
341348 *
342
- * Example of a message structure:
343
- * 0000 ff 8f 00 00 00 00 00 00 monotonic time in nsec
344
- * 0008 34 00 record is 52 bytes long
345
- * 000a 0b 00 text is 11 bytes long
346
- * 000c 1f 00 dictionary is 23 bytes long
347
- * 000e 03 00 LOG_KERN (facility) LOG_ERR (level)
348
- * 0010 69 74 27 73 20 61 20 6c "it's a l"
349
- * 69 6e 65 "ine"
350
- * 001b 44 45 56 49 43 "DEVIC"
351
- * 45 3d 62 38 3a 32 00 44 "E=b8:2\0D"
352
- * 52 49 56 45 52 3d 62 75 "RIVER=bu"
353
- * 67 "g"
354
- * 0032 00 00 00 padding to next message header
349
+ * Example of record values:
350
+ * record.text_buf = "it's a line" (unterminated)
351
+ * record.info.seq = 56
352
+ * record.info.ts_nsec = 36863
353
+ * record.info.text_len = 11
354
+ * record.info.facility = 0 (LOG_KERN)
355
+ * record.info.flags = 0
356
+ * record.info.level = 3 (LOG_ERR)
357
+ * record.info.caller_id = 299 (task 299)
358
+ * record.info.dev_info.subsystem = "pci" (terminated)
359
+ * record.info.dev_info.device = "+pci:0000:00:01.0" (terminated)
355360 *
356
- * The 'struct printk_log' buffer header must never be directly exported to
361
+ * The 'struct printk_info' buffer must never be directly exported to
357362 * userspace, it is a kernel-private implementation detail that might
358363 * need to be changed in the future, when the requirements change.
359364 *
....@@ -370,29 +375,8 @@
370375
371376 enum log_flags {
372377 LOG_NEWLINE = 2, /* text ended with a newline */
373
- LOG_PREFIX = 4, /* text started with a prefix */
374378 LOG_CONT = 8, /* text is a fragment of a continuation line */
375379 };
376
-
377
-struct printk_log {
378
- u64 ts_nsec; /* timestamp in nanoseconds */
379
- u16 len; /* length of entire record */
380
- u16 text_len; /* length of text buffer */
381
- u16 dict_len; /* length of dictionary buffer */
382
- u8 facility; /* syslog facility */
383
- u8 flags:5; /* internal record flags */
384
- u8 level:3; /* syslog level */
385
-#ifdef CONFIG_PRINTK_PROCESS
386
- char process[16]; /* process name */
387
- pid_t pid; /* process id */
388
- u8 cpu; /* cpu id */
389
- u8 in_interrupt; /* interrupt context */
390
-#endif
391
-}
392
-#ifdef CONFIG_HAVE_EFFICIENT_UNALIGNED_ACCESS
393
-__packed __aligned(4)
394
-#endif
395
-;
396380
397381 /*
398382 * The logbuf_lock protects kmsg buffer, indices, counters. This can be taken
....@@ -429,90 +413,22 @@
429413 printk_safe_exit_irqrestore(flags); \
430414 } while (0)
431415
432
-#ifdef CONFIG_EARLY_PRINTK
433
-struct console *early_console;
434
-
435
-static void early_vprintk(const char *fmt, va_list ap)
436
-{
437
- if (early_console) {
438
- char buf[512];
439
- int n = vscnprintf(buf, sizeof(buf), fmt, ap);
440
-
441
- early_console->write(early_console, buf, n);
442
- }
443
-}
444
-
445
-asmlinkage void early_printk(const char *fmt, ...)
446
-{
447
- va_list ap;
448
-
449
- va_start(ap, fmt);
450
- early_vprintk(fmt, ap);
451
- va_end(ap);
452
-}
453
-
454
-/*
455
- * This is independent of any log levels - a global
456
- * kill switch that turns off all of printk.
457
- *
458
- * Used by the NMI watchdog if early-printk is enabled.
459
- */
460
-static bool __read_mostly printk_killswitch;
461
-
462
-static int __init force_early_printk_setup(char *str)
463
-{
464
- printk_killswitch = true;
465
- return 0;
466
-}
467
-early_param("force_early_printk", force_early_printk_setup);
468
-
469
-void printk_kill(void)
470
-{
471
- printk_killswitch = true;
472
-}
473
-
474
-#ifdef CONFIG_PRINTK
475
-static int forced_early_printk(const char *fmt, va_list ap)
476
-{
477
- if (!printk_killswitch)
478
- return 0;
479
- early_vprintk(fmt, ap);
480
- return 1;
481
-}
482
-#endif
483
-
484
-#else
485
-static inline int forced_early_printk(const char *fmt, va_list ap)
486
-{
487
- return 0;
488
-}
489
-#endif
490
-
491416 #ifdef CONFIG_PRINTK
492417 DECLARE_WAIT_QUEUE_HEAD(log_wait);
493418 /* the next printk record to read by syslog(READ) or /proc/kmsg */
494419 static u64 syslog_seq;
495
-static u32 syslog_idx;
496420 static size_t syslog_partial;
497
-
498
-/* index and sequence number of the first record stored in the buffer */
499
-static u64 log_first_seq;
500
-static u32 log_first_idx;
501
-
502
-/* index and sequence number of the next record to store in the buffer */
503
-static u64 log_next_seq;
504
-static u32 log_next_idx;
421
+static bool syslog_time;
505422
506423 /* the next printk record to write to the console */
507424 static u64 console_seq;
508
-static u32 console_idx;
509425 static u64 exclusive_console_stop_seq;
426
+static unsigned long console_dropped;
510427
511428 /* the next printk record to read after the last 'clear' command */
512429 static u64 clear_seq;
513
-static u32 clear_idx;
514430
515
-#ifdef CONFIG_PRINTK_PROCESS
431
+#ifdef CONFIG_PRINTK_CALLER
516432 #define PREFIX_MAX 48
517433 #else
518434 #define PREFIX_MAX 32
....@@ -523,12 +439,29 @@
523439 #define LOG_FACILITY(v) ((v) >> 3 & 0xff)
524440
525441 /* record buffer */
526
-#define LOG_ALIGN __alignof__(struct printk_log)
442
+#define LOG_ALIGN __alignof__(unsigned long)
527443 #define __LOG_BUF_LEN (1 << CONFIG_LOG_BUF_SHIFT)
528444 #define LOG_BUF_LEN_MAX (u32)(1 << 31)
529445 static char __log_buf[__LOG_BUF_LEN] __aligned(LOG_ALIGN);
530446 static char *log_buf = __log_buf;
531447 static u32 log_buf_len = __LOG_BUF_LEN;
448
+
449
+/*
450
+ * Define the average message size. This only affects the number of
451
+ * descriptors that will be available. Underestimating is better than
452
+ * overestimating (too many available descriptors is better than not enough).
453
+ */
454
+#define PRB_AVGBITS 5 /* 32 character average length */
455
+
456
+#if CONFIG_LOG_BUF_SHIFT <= PRB_AVGBITS
457
+#error CONFIG_LOG_BUF_SHIFT value too small.
458
+#endif
459
+_DEFINE_PRINTKRB(printk_rb_static, CONFIG_LOG_BUF_SHIFT - PRB_AVGBITS,
460
+ PRB_AVGBITS, &__log_buf[0]);
461
+
462
+static struct printk_ringbuffer printk_rb_dynamic;
463
+
464
+static struct printk_ringbuffer *prb = &printk_rb_static;
532465
533466 /*
534467 * We cannot access per-CPU data (e.g. per-CPU flush irq_work) before
....@@ -556,127 +489,6 @@
556489 }
557490 EXPORT_SYMBOL_GPL(log_buf_len_get);
558491
559
-/* human readable text of the record */
560
-static char *log_text(const struct printk_log *msg)
561
-{
562
- return (char *)msg + sizeof(struct printk_log);
563
-}
564
-
565
-/* optional key/value pair dictionary attached to the record */
566
-static char *log_dict(const struct printk_log *msg)
567
-{
568
- return (char *)msg + sizeof(struct printk_log) + msg->text_len;
569
-}
570
-
571
-/* get record by index; idx must point to valid msg */
572
-static struct printk_log *log_from_idx(u32 idx)
573
-{
574
- struct printk_log *msg = (struct printk_log *)(log_buf + idx);
575
-
576
- /*
577
- * A length == 0 record is the end of buffer marker. Wrap around and
578
- * read the message at the start of the buffer.
579
- */
580
- if (!msg->len)
581
- return (struct printk_log *)log_buf;
582
- return msg;
583
-}
584
-
585
-/* get next record; idx must point to valid msg */
586
-static u32 log_next(u32 idx)
587
-{
588
- struct printk_log *msg = (struct printk_log *)(log_buf + idx);
589
-
590
- /* length == 0 indicates the end of the buffer; wrap */
591
- /*
592
- * A length == 0 record is the end of buffer marker. Wrap around and
593
- * read the message at the start of the buffer as *this* one, and
594
- * return the one after that.
595
- */
596
- if (!msg->len) {
597
- msg = (struct printk_log *)log_buf;
598
- return msg->len;
599
- }
600
- return idx + msg->len;
601
-}
602
-
603
-#ifdef CONFIG_PRINTK_PROCESS
604
-static bool printk_process = true;
605
-static size_t print_process(const struct printk_log *msg, char *buf)
606
-{
607
- if (!printk_process)
608
- return 0;
609
-
610
- if (!buf)
611
- return snprintf(NULL, 0, "%c[%1d:%15s:%5d] ", ' ', 0, " ", 0);
612
-
613
- return sprintf(buf, "%c[%1d:%15s:%5d] ",
614
- msg->in_interrupt ? 'I' : ' ',
615
- msg->cpu,
616
- msg->process,
617
- msg->pid);
618
-}
619
-module_param_named(process, printk_process, bool, 0644);
620
-#endif
621
-
622
-/*
623
- * Check whether there is enough free space for the given message.
624
- *
625
- * The same values of first_idx and next_idx mean that the buffer
626
- * is either empty or full.
627
- *
628
- * If the buffer is empty, we must respect the position of the indexes.
629
- * They cannot be reset to the beginning of the buffer.
630
- */
631
-static int logbuf_has_space(u32 msg_size, bool empty)
632
-{
633
- u32 free;
634
-
635
- if (log_next_idx > log_first_idx || empty)
636
- free = max(log_buf_len - log_next_idx, log_first_idx);
637
- else
638
- free = log_first_idx - log_next_idx;
639
-
640
- /*
641
- * We need space also for an empty header that signalizes wrapping
642
- * of the buffer.
643
- */
644
- return free >= msg_size + sizeof(struct printk_log);
645
-}
646
-
647
-static int log_make_free_space(u32 msg_size)
648
-{
649
- while (log_first_seq < log_next_seq &&
650
- !logbuf_has_space(msg_size, false)) {
651
- /* drop old messages until we have enough contiguous space */
652
- log_first_idx = log_next(log_first_idx);
653
- log_first_seq++;
654
- }
655
-
656
- if (clear_seq < log_first_seq) {
657
- clear_seq = log_first_seq;
658
- clear_idx = log_first_idx;
659
- }
660
-
661
- /* sequence numbers are equal, so the log buffer is empty */
662
- if (logbuf_has_space(msg_size, log_first_seq == log_next_seq))
663
- return 0;
664
-
665
- return -ENOMEM;
666
-}
667
-
668
-/* compute the message size including the padding bytes */
669
-static u32 msg_used_size(u16 text_len, u16 dict_len, u32 *pad_len)
670
-{
671
- u32 size;
672
-
673
- size = sizeof(struct printk_log) + text_len + dict_len;
674
- *pad_len = (-size) & (LOG_ALIGN - 1);
675
- size += *pad_len;
676
-
677
- return size;
678
-}
679
-
680492 /*
681493 * Define how much of the log buffer we could take at maximum. The value
682494 * must be greater than two. Note that only half of the buffer is available
....@@ -685,91 +497,71 @@
685497 #define MAX_LOG_TAKE_PART 4
686498 static const char trunc_msg[] = "<truncated>";
687499
688
-static u32 truncate_msg(u16 *text_len, u16 *trunc_msg_len,
689
- u16 *dict_len, u32 *pad_len)
500
+static void truncate_msg(u16 *text_len, u16 *trunc_msg_len)
690501 {
691502 /*
692503 * The message should not take the whole buffer. Otherwise, it might
693504 * get removed too soon.
694505 */
695506 u32 max_text_len = log_buf_len / MAX_LOG_TAKE_PART;
507
+
696508 if (*text_len > max_text_len)
697509 *text_len = max_text_len;
698
- /* enable the warning message */
510
+
511
+ /* enable the warning message (if there is room) */
699512 *trunc_msg_len = strlen(trunc_msg);
700
- /* disable the "dict" completely */
701
- *dict_len = 0;
702
- /* compute the size again, count also the warning message */
703
- return msg_used_size(*text_len + *trunc_msg_len, 0, pad_len);
513
+ if (*text_len >= *trunc_msg_len)
514
+ *text_len -= *trunc_msg_len;
515
+ else
516
+ *trunc_msg_len = 0;
704517 }
705518
706519 /* insert record into the buffer, discard old ones, update heads */
707
-static int log_store(int facility, int level,
520
+static int log_store(u32 caller_id, int facility, int level,
708521 enum log_flags flags, u64 ts_nsec,
709
- const char *dict, u16 dict_len,
522
+ const struct dev_printk_info *dev_info,
710523 const char *text, u16 text_len)
711524 {
712
- struct printk_log *msg;
713
- u32 size, pad_len;
525
+ struct prb_reserved_entry e;
526
+ struct printk_record r;
714527 u16 trunc_msg_len = 0;
715528
716
- /* number of '\0' padding bytes to next message */
717
- size = msg_used_size(text_len, dict_len, &pad_len);
529
+ prb_rec_init_wr(&r, text_len);
718530
719
- if (log_make_free_space(size)) {
531
+ if (!prb_reserve(&e, prb, &r)) {
720532 /* truncate the message if it is too long for empty buffer */
721
- size = truncate_msg(&text_len, &trunc_msg_len,
722
- &dict_len, &pad_len);
533
+ truncate_msg(&text_len, &trunc_msg_len);
534
+ prb_rec_init_wr(&r, text_len + trunc_msg_len);
723535 /* survive when the log buffer is too small for trunc_msg */
724
- if (log_make_free_space(size))
536
+ if (!prb_reserve(&e, prb, &r))
725537 return 0;
726538 }
727539
728
- if (log_next_idx + size + sizeof(struct printk_log) > log_buf_len) {
729
- /*
730
- * This message + an additional empty header does not fit
731
- * at the end of the buffer. Add an empty header with len == 0
732
- * to signify a wrap around.
733
- */
734
- memset(log_buf + log_next_idx, 0, sizeof(struct printk_log));
735
- log_next_idx = 0;
736
- }
737
-
738540 /* fill message */
739
- msg = (struct printk_log *)(log_buf + log_next_idx);
740
- memcpy(log_text(msg), text, text_len);
741
- msg->text_len = text_len;
742
- if (trunc_msg_len) {
743
- memcpy(log_text(msg) + text_len, trunc_msg, trunc_msg_len);
744
- msg->text_len += trunc_msg_len;
745
- }
746
- memcpy(log_dict(msg), dict, dict_len);
747
- msg->dict_len = dict_len;
748
- msg->facility = facility;
749
- msg->level = level & 7;
750
- msg->flags = flags & 0x1f;
541
+ memcpy(&r.text_buf[0], text, text_len);
542
+ if (trunc_msg_len)
543
+ memcpy(&r.text_buf[text_len], trunc_msg, trunc_msg_len);
544
+ r.info->text_len = text_len + trunc_msg_len;
545
+ r.info->facility = facility;
546
+ r.info->level = level & 7;
547
+ r.info->flags = flags & 0x1f;
751548 if (ts_nsec > 0)
752
- msg->ts_nsec = ts_nsec;
549
+ r.info->ts_nsec = ts_nsec;
753550 else
754
- msg->ts_nsec = get_local_clock();
755
- memset(log_dict(msg) + dict_len, 0, pad_len);
756
- msg->len = size;
551
+ r.info->ts_nsec = get_local_clock();
552
+ r.info->caller_id = caller_id;
553
+ if (dev_info)
554
+ memcpy(&r.info->dev_info, dev_info, sizeof(r.info->dev_info));
757555
758
-#ifdef CONFIG_PRINTK_PROCESS
759
- if (printk_process) {
760
- strncpy(msg->process, current->comm, sizeof(msg->process) - 1);
761
- msg->process[sizeof(msg->process) - 1] = '\0';
762
- msg->pid = task_pid_nr(current);
763
- msg->cpu = raw_smp_processor_id();
764
- msg->in_interrupt = in_interrupt() ? 1 : 0;
765
- }
766
-#endif
556
+ /* A message without a trailing newline can be continued. */
557
+ if (!(flags & LOG_NEWLINE))
558
+ prb_commit(&e);
559
+ else
560
+ prb_final_commit(&e);
767561
768
- /* insert message */
769
- log_next_idx += msg->len;
770
- log_next_seq++;
562
+ trace_android_vh_logbuf(prb, &r);
771563
772
- return msg->text_len;
564
+ return (text_len + trunc_msg_len);
773565 }
774566
775567 int dmesg_restrict = IS_ENABLED(CONFIG_SECURITY_DMESG_RESTRICT);
....@@ -821,21 +613,30 @@
821613 *(*pp)++ = c;
822614 }
823615
824
-static ssize_t msg_print_ext_header(char *buf, size_t size,
825
- struct printk_log *msg, u64 seq)
616
+static ssize_t info_print_ext_header(char *buf, size_t size,
617
+ struct printk_info *info)
826618 {
827
- u64 ts_usec = msg->ts_nsec;
619
+ u64 ts_usec = info->ts_nsec;
620
+ char caller[20];
621
+#ifdef CONFIG_PRINTK_CALLER
622
+ u32 id = info->caller_id;
623
+
624
+ snprintf(caller, sizeof(caller), ",caller=%c%u",
625
+ id & 0x80000000 ? 'C' : 'T', id & ~0x80000000);
626
+#else
627
+ caller[0] = '\0';
628
+#endif
828629
829630 do_div(ts_usec, 1000);
830631
831
- return scnprintf(buf, size, "%u,%llu,%llu,%c;",
832
- (msg->facility << 3) | msg->level, seq, ts_usec,
833
- msg->flags & LOG_CONT ? 'c' : '-');
632
+ return scnprintf(buf, size, "%u,%llu,%llu,%c%s;",
633
+ (info->facility << 3) | info->level, info->seq,
634
+ ts_usec, info->flags & LOG_CONT ? 'c' : '-', caller);
834635 }
835636
836
-static ssize_t msg_print_ext_body(char *buf, size_t size,
837
- char *dict, size_t dict_len,
838
- char *text, size_t text_len)
637
+static ssize_t msg_add_ext_text(char *buf, size_t size,
638
+ const char *text, size_t text_len,
639
+ unsigned char endc)
839640 {
840641 char *p = buf, *e = buf + size;
841642 size_t i;
....@@ -849,46 +650,70 @@
849650 else
850651 append_char(&p, e, c);
851652 }
852
- append_char(&p, e, '\n');
853
-
854
- if (dict_len) {
855
- bool line = true;
856
-
857
- for (i = 0; i < dict_len; i++) {
858
- unsigned char c = dict[i];
859
-
860
- if (line) {
861
- append_char(&p, e, ' ');
862
- line = false;
863
- }
864
-
865
- if (c == '\0') {
866
- append_char(&p, e, '\n');
867
- line = true;
868
- continue;
869
- }
870
-
871
- if (c < ' ' || c >= 127 || c == '\\') {
872
- p += scnprintf(p, e - p, "\\x%02x", c);
873
- continue;
874
- }
875
-
876
- append_char(&p, e, c);
877
- }
878
- append_char(&p, e, '\n');
879
- }
653
+ append_char(&p, e, endc);
880654
881655 return p - buf;
656
+}
657
+
658
+static ssize_t msg_add_dict_text(char *buf, size_t size,
659
+ const char *key, const char *val)
660
+{
661
+ size_t val_len = strlen(val);
662
+ ssize_t len;
663
+
664
+ if (!val_len)
665
+ return 0;
666
+
667
+ len = msg_add_ext_text(buf, size, "", 0, ' '); /* dict prefix */
668
+ len += msg_add_ext_text(buf + len, size - len, key, strlen(key), '=');
669
+ len += msg_add_ext_text(buf + len, size - len, val, val_len, '\n');
670
+
671
+ return len;
672
+}
673
+
674
+static ssize_t msg_print_ext_body(char *buf, size_t size,
675
+ char *text, size_t text_len,
676
+ struct dev_printk_info *dev_info)
677
+{
678
+ ssize_t len;
679
+
680
+ len = msg_add_ext_text(buf, size, text, text_len, '\n');
681
+
682
+ if (!dev_info)
683
+ goto out;
684
+
685
+ len += msg_add_dict_text(buf + len, size - len, "SUBSYSTEM",
686
+ dev_info->subsystem);
687
+ len += msg_add_dict_text(buf + len, size - len, "DEVICE",
688
+ dev_info->device);
689
+out:
690
+ return len;
882691 }
883692
884693 /* /dev/kmsg - userspace message inject/listen interface */
885694 struct devkmsg_user {
886695 u64 seq;
887
- u32 idx;
888696 struct ratelimit_state rs;
889697 struct mutex lock;
890698 char buf[CONSOLE_EXT_LOG_MAX];
699
+
700
+ struct printk_info info;
701
+ char text_buf[CONSOLE_EXT_LOG_MAX];
702
+ struct printk_record record;
891703 };
704
+
705
+static __printf(3, 4) __cold
706
+int devkmsg_emit(int facility, int level, const char *fmt, ...)
707
+{
708
+ va_list args;
709
+ int r;
710
+
711
+ va_start(args, fmt);
712
+ r = vprintk_emit(facility, level, NULL, fmt, args);
713
+ va_end(args);
714
+
715
+ return r;
716
+}
892717
893718 static ssize_t devkmsg_write(struct kiocb *iocb, struct iov_iter *from)
894719 {
....@@ -948,7 +773,7 @@
948773 }
949774 }
950775
951
- printk_emit(facility, level, NULL, 0, "%s", line);
776
+ devkmsg_emit(facility, level, "%s", line);
952777 kfree(buf);
953778 return ret;
954779 }
....@@ -957,7 +782,7 @@
957782 size_t count, loff_t *ppos)
958783 {
959784 struct devkmsg_user *user = file->private_data;
960
- struct printk_log *msg;
785
+ struct printk_record *r = &user->record;
961786 size_t len;
962787 ssize_t ret;
963788
....@@ -969,7 +794,7 @@
969794 return ret;
970795
971796 logbuf_lock_irq();
972
- while (user->seq == log_next_seq) {
797
+ if (!prb_read_valid(prb, user->seq, r)) {
973798 if (file->f_flags & O_NONBLOCK) {
974799 ret = -EAGAIN;
975800 logbuf_unlock_irq();
....@@ -978,30 +803,26 @@
978803
979804 logbuf_unlock_irq();
980805 ret = wait_event_interruptible(log_wait,
981
- user->seq != log_next_seq);
806
+ prb_read_valid(prb, user->seq, r));
982807 if (ret)
983808 goto out;
984809 logbuf_lock_irq();
985810 }
986811
987
- if (user->seq < log_first_seq) {
812
+ if (r->info->seq != user->seq) {
988813 /* our last seen message is gone, return error and reset */
989
- user->idx = log_first_idx;
990
- user->seq = log_first_seq;
814
+ user->seq = r->info->seq;
991815 ret = -EPIPE;
992816 logbuf_unlock_irq();
993817 goto out;
994818 }
995819
996
- msg = log_from_idx(user->idx);
997
- len = msg_print_ext_header(user->buf, sizeof(user->buf),
998
- msg, user->seq);
820
+ len = info_print_ext_header(user->buf, sizeof(user->buf), r->info);
999821 len += msg_print_ext_body(user->buf + len, sizeof(user->buf) - len,
1000
- log_dict(msg), msg->dict_len,
1001
- log_text(msg), msg->text_len);
822
+ &r->text_buf[0], r->info->text_len,
823
+ &r->info->dev_info);
1002824
1003
- user->idx = log_next(user->idx);
1004
- user->seq++;
825
+ user->seq = r->info->seq + 1;
1005826 logbuf_unlock_irq();
1006827
1007828 if (len > count) {
....@@ -1019,6 +840,14 @@
1019840 return ret;
1020841 }
1021842
843
+/*
844
+ * Be careful when modifying this function!!!
845
+ *
846
+ * Only few operations are supported because the device works only with the
847
+ * entire variable length messages (records). Non-standard values are
848
+ * returned in the other cases and has been this way for quite some time.
849
+ * User space applications might depend on this behavior.
850
+ */
1022851 static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence)
1023852 {
1024853 struct devkmsg_user *user = file->private_data;
....@@ -1033,8 +862,7 @@
1033862 switch (whence) {
1034863 case SEEK_SET:
1035864 /* the first record */
1036
- user->idx = log_first_idx;
1037
- user->seq = log_first_seq;
865
+ user->seq = prb_first_valid_seq(prb);
1038866 break;
1039867 case SEEK_DATA:
1040868 /*
....@@ -1042,13 +870,11 @@
1042870 * like issued by 'dmesg -c'. Reading /dev/kmsg itself
1043871 * changes no global state, and does not clear anything.
1044872 */
1045
- user->idx = clear_idx;
1046873 user->seq = clear_seq;
1047874 break;
1048875 case SEEK_END:
1049876 /* after the last record */
1050
- user->idx = log_next_idx;
1051
- user->seq = log_next_seq;
877
+ user->seq = prb_next_seq(prb);
1052878 break;
1053879 default:
1054880 ret = -EINVAL;
....@@ -1060,6 +886,7 @@
1060886 static __poll_t devkmsg_poll(struct file *file, poll_table *wait)
1061887 {
1062888 struct devkmsg_user *user = file->private_data;
889
+ struct printk_info info;
1063890 __poll_t ret = 0;
1064891
1065892 if (!user)
....@@ -1068,9 +895,9 @@
1068895 poll_wait(file, &log_wait, wait);
1069896
1070897 logbuf_lock_irq();
1071
- if (user->seq < log_next_seq) {
898
+ if (prb_read_valid_info(prb, user->seq, &info, NULL)) {
1072899 /* return error when data has vanished underneath us */
1073
- if (user->seq < log_first_seq)
900
+ if (info.seq != user->seq)
1074901 ret = EPOLLIN|EPOLLRDNORM|EPOLLERR|EPOLLPRI;
1075902 else
1076903 ret = EPOLLIN|EPOLLRDNORM;
....@@ -1105,9 +932,11 @@
1105932
1106933 mutex_init(&user->lock);
1107934
935
+ prb_rec_init_rd(&user->record, &user->info,
936
+ &user->text_buf[0], sizeof(user->text_buf));
937
+
1108938 logbuf_lock_irq();
1109
- user->idx = log_first_idx;
1110
- user->seq = log_first_seq;
939
+ user->seq = prb_first_valid_seq(prb);
1111940 logbuf_unlock_irq();
1112941
1113942 file->private_data = user;
....@@ -1148,20 +977,58 @@
1148977 */
1149978 void log_buf_vmcoreinfo_setup(void)
1150979 {
1151
- VMCOREINFO_SYMBOL(log_buf);
1152
- VMCOREINFO_SYMBOL(log_buf_len);
1153
- VMCOREINFO_SYMBOL(log_first_idx);
1154
- VMCOREINFO_SYMBOL(clear_idx);
1155
- VMCOREINFO_SYMBOL(log_next_idx);
980
+ struct dev_printk_info *dev_info = NULL;
981
+
982
+ VMCOREINFO_SYMBOL(prb);
983
+ VMCOREINFO_SYMBOL(printk_rb_static);
984
+ VMCOREINFO_SYMBOL(clear_seq);
985
+
1156986 /*
1157
- * Export struct printk_log size and field offsets. User space tools can
987
+ * Export struct size and field offsets. User space tools can
1158988 * parse it and detect any changes to structure down the line.
1159989 */
1160
- VMCOREINFO_STRUCT_SIZE(printk_log);
1161
- VMCOREINFO_OFFSET(printk_log, ts_nsec);
1162
- VMCOREINFO_OFFSET(printk_log, len);
1163
- VMCOREINFO_OFFSET(printk_log, text_len);
1164
- VMCOREINFO_OFFSET(printk_log, dict_len);
990
+
991
+ VMCOREINFO_STRUCT_SIZE(printk_ringbuffer);
992
+ VMCOREINFO_OFFSET(printk_ringbuffer, desc_ring);
993
+ VMCOREINFO_OFFSET(printk_ringbuffer, text_data_ring);
994
+ VMCOREINFO_OFFSET(printk_ringbuffer, fail);
995
+
996
+ VMCOREINFO_STRUCT_SIZE(prb_desc_ring);
997
+ VMCOREINFO_OFFSET(prb_desc_ring, count_bits);
998
+ VMCOREINFO_OFFSET(prb_desc_ring, descs);
999
+ VMCOREINFO_OFFSET(prb_desc_ring, infos);
1000
+ VMCOREINFO_OFFSET(prb_desc_ring, head_id);
1001
+ VMCOREINFO_OFFSET(prb_desc_ring, tail_id);
1002
+
1003
+ VMCOREINFO_STRUCT_SIZE(prb_desc);
1004
+ VMCOREINFO_OFFSET(prb_desc, state_var);
1005
+ VMCOREINFO_OFFSET(prb_desc, text_blk_lpos);
1006
+
1007
+ VMCOREINFO_STRUCT_SIZE(prb_data_blk_lpos);
1008
+ VMCOREINFO_OFFSET(prb_data_blk_lpos, begin);
1009
+ VMCOREINFO_OFFSET(prb_data_blk_lpos, next);
1010
+
1011
+ VMCOREINFO_STRUCT_SIZE(printk_info);
1012
+ VMCOREINFO_OFFSET(printk_info, seq);
1013
+ VMCOREINFO_OFFSET(printk_info, ts_nsec);
1014
+ VMCOREINFO_OFFSET(printk_info, text_len);
1015
+ VMCOREINFO_OFFSET(printk_info, caller_id);
1016
+ VMCOREINFO_OFFSET(printk_info, dev_info);
1017
+
1018
+ VMCOREINFO_STRUCT_SIZE(dev_printk_info);
1019
+ VMCOREINFO_OFFSET(dev_printk_info, subsystem);
1020
+ VMCOREINFO_LENGTH(printk_info_subsystem, sizeof(dev_info->subsystem));
1021
+ VMCOREINFO_OFFSET(dev_printk_info, device);
1022
+ VMCOREINFO_LENGTH(printk_info_device, sizeof(dev_info->device));
1023
+
1024
+ VMCOREINFO_STRUCT_SIZE(prb_data_ring);
1025
+ VMCOREINFO_OFFSET(prb_data_ring, size_bits);
1026
+ VMCOREINFO_OFFSET(prb_data_ring, data);
1027
+ VMCOREINFO_OFFSET(prb_data_ring, head_lpos);
1028
+ VMCOREINFO_OFFSET(prb_data_ring, tail_lpos);
1029
+
1030
+ VMCOREINFO_SIZE(atomic_long_t);
1031
+ VMCOREINFO_TYPE_OFFSET(atomic_long_t, counter);
11651032 }
11661033 #endif
11671034
....@@ -1239,11 +1106,46 @@
12391106 __printk_percpu_data_ready = true;
12401107 }
12411108
1109
+static unsigned int __init add_to_rb(struct printk_ringbuffer *rb,
1110
+ struct printk_record *r)
1111
+{
1112
+ struct prb_reserved_entry e;
1113
+ struct printk_record dest_r;
1114
+
1115
+ prb_rec_init_wr(&dest_r, r->info->text_len);
1116
+
1117
+ if (!prb_reserve(&e, rb, &dest_r))
1118
+ return 0;
1119
+
1120
+ memcpy(&dest_r.text_buf[0], &r->text_buf[0], r->info->text_len);
1121
+ dest_r.info->text_len = r->info->text_len;
1122
+ dest_r.info->facility = r->info->facility;
1123
+ dest_r.info->level = r->info->level;
1124
+ dest_r.info->flags = r->info->flags;
1125
+ dest_r.info->ts_nsec = r->info->ts_nsec;
1126
+ dest_r.info->caller_id = r->info->caller_id;
1127
+ memcpy(&dest_r.info->dev_info, &r->info->dev_info, sizeof(dest_r.info->dev_info));
1128
+
1129
+ prb_final_commit(&e);
1130
+
1131
+ return prb_record_text_space(&e);
1132
+}
1133
+
1134
+static char setup_text_buf[LOG_LINE_MAX] __initdata;
1135
+
12421136 void __init setup_log_buf(int early)
12431137 {
1138
+ struct printk_info *new_infos;
1139
+ unsigned int new_descs_count;
1140
+ struct prb_desc *new_descs;
1141
+ struct printk_info info;
1142
+ struct printk_record r;
1143
+ size_t new_descs_size;
1144
+ size_t new_infos_size;
12441145 unsigned long flags;
12451146 char *new_log_buf;
12461147 unsigned int free;
1148
+ u64 seq;
12471149
12481150 /*
12491151 * Some archs call setup_log_buf() multiple times - first is very
....@@ -1262,38 +1164,78 @@
12621164 if (!new_log_buf_len)
12631165 return;
12641166
1265
- if (early) {
1266
- new_log_buf =
1267
- memblock_virt_alloc(new_log_buf_len, LOG_ALIGN);
1268
- } else {
1269
- new_log_buf = memblock_virt_alloc_nopanic(new_log_buf_len,
1270
- LOG_ALIGN);
1271
- }
1272
-
1273
- if (unlikely(!new_log_buf)) {
1274
- pr_err("log_buf_len: %lu bytes not available\n",
1275
- new_log_buf_len);
1167
+ new_descs_count = new_log_buf_len >> PRB_AVGBITS;
1168
+ if (new_descs_count == 0) {
1169
+ pr_err("new_log_buf_len: %lu too small\n", new_log_buf_len);
12761170 return;
12771171 }
12781172
1173
+ new_log_buf = memblock_alloc(new_log_buf_len, LOG_ALIGN);
1174
+ if (unlikely(!new_log_buf)) {
1175
+ pr_err("log_buf_len: %lu text bytes not available\n",
1176
+ new_log_buf_len);
1177
+ return;
1178
+ }
1179
+
1180
+ new_descs_size = new_descs_count * sizeof(struct prb_desc);
1181
+ new_descs = memblock_alloc(new_descs_size, LOG_ALIGN);
1182
+ if (unlikely(!new_descs)) {
1183
+ pr_err("log_buf_len: %zu desc bytes not available\n",
1184
+ new_descs_size);
1185
+ goto err_free_log_buf;
1186
+ }
1187
+
1188
+ new_infos_size = new_descs_count * sizeof(struct printk_info);
1189
+ new_infos = memblock_alloc(new_infos_size, LOG_ALIGN);
1190
+ if (unlikely(!new_infos)) {
1191
+ pr_err("log_buf_len: %zu info bytes not available\n",
1192
+ new_infos_size);
1193
+ goto err_free_descs;
1194
+ }
1195
+
1196
+ prb_rec_init_rd(&r, &info, &setup_text_buf[0], sizeof(setup_text_buf));
1197
+
1198
+ prb_init(&printk_rb_dynamic,
1199
+ new_log_buf, ilog2(new_log_buf_len),
1200
+ new_descs, ilog2(new_descs_count),
1201
+ new_infos);
1202
+
12791203 logbuf_lock_irqsave(flags);
1204
+
12801205 log_buf_len = new_log_buf_len;
12811206 log_buf = new_log_buf;
12821207 new_log_buf_len = 0;
1283
- free = __LOG_BUF_LEN - log_next_idx;
1284
- memcpy(log_buf, __log_buf, __LOG_BUF_LEN);
1208
+
1209
+ free = __LOG_BUF_LEN;
1210
+ prb_for_each_record(0, &printk_rb_static, seq, &r)
1211
+ free -= add_to_rb(&printk_rb_dynamic, &r);
1212
+
1213
+ /*
1214
+ * This is early enough that everything is still running on the
1215
+ * boot CPU and interrupts are disabled. So no new messages will
1216
+ * appear during the transition to the dynamic buffer.
1217
+ */
1218
+ prb = &printk_rb_dynamic;
1219
+
12851220 logbuf_unlock_irqrestore(flags);
1221
+
1222
+ if (seq != prb_next_seq(&printk_rb_static)) {
1223
+ pr_err("dropped %llu messages\n",
1224
+ prb_next_seq(&printk_rb_static) - seq);
1225
+ }
12861226
12871227 pr_info("log_buf_len: %u bytes\n", log_buf_len);
12881228 pr_info("early log buf free: %u(%u%%)\n",
12891229 free, (free * 100) / __LOG_BUF_LEN);
1230
+ return;
1231
+
1232
+err_free_descs:
1233
+ memblock_free(__pa(new_descs), new_descs_size);
1234
+err_free_log_buf:
1235
+ memblock_free(__pa(new_log_buf), new_log_buf_len);
12901236 }
12911237
1292
-#ifdef CONFIG_PSTORE_CONSOLE_FORCE_ON
1293
-static bool __read_mostly ignore_loglevel = true;
1294
-#else
12951238 static bool __read_mostly ignore_loglevel;
1296
-#endif
12971239
12981240 static int __init ignore_loglevel_setup(char *str)
12991241 {
....@@ -1307,61 +1249,6 @@
13071249 module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
13081250 MODULE_PARM_DESC(ignore_loglevel,
13091251 "ignore loglevel setting (prints all kernel messages to the console)");
1310
-
1311
-#ifdef CONFIG_PSTORE_CONSOLE_FORCE
1312
-static bool __read_mostly pstore_con_force = IS_ENABLED(CONFIG_PSTORE_CONSOLE_FORCE_ON);
1313
-
1314
-static int __init pstore_con_force_setup(char *str)
1315
-{
1316
- bool force;
1317
- int ret = strtobool(str, &force);
1318
-
1319
- if (ret)
1320
- return ret;
1321
-
1322
- ignore_loglevel = force;
1323
- pstore_con_force = force;
1324
- if (force)
1325
- pr_info("debug: pstore console ignoring loglevel setting.\n");
1326
-
1327
- return 0;
1328
-}
1329
-
1330
-early_param("pstore_con_force", pstore_con_force_setup);
1331
-module_param(pstore_con_force, bool, S_IRUGO | S_IWUSR);
1332
-MODULE_PARM_DESC(pstore_con_force,
1333
- "ignore loglevel setting (prints all kernel messages to the pstore console)");
1334
-
1335
-static void call_console_drivers_level(int level, const char *ext_text, size_t ext_len,
1336
- const char *text, size_t len)
1337
-{
1338
- struct console *con;
1339
-
1340
- trace_console_rcuidle(text, len);
1341
-
1342
- if (!console_drivers)
1343
- return;
1344
-
1345
- for_each_console(con) {
1346
- if (pstore_con_force &&
1347
- !(con->flags & CON_PSTORE) && level >= console_loglevel)
1348
- continue;
1349
- if (exclusive_console && con != exclusive_console)
1350
- continue;
1351
- if (!(con->flags & CON_ENABLED))
1352
- continue;
1353
- if (!con->write)
1354
- continue;
1355
- if (!cpu_online(smp_processor_id()) &&
1356
- !(con->flags & CON_ANYTIME))
1357
- continue;
1358
- if (con->flags & CON_EXTENDED)
1359
- con->write(con, ext_text, ext_len);
1360
- else
1361
- con->write(con, text, len);
1362
- }
1363
-}
1364
-#endif
13651252
13661253 static bool suppress_message_printing(int level)
13671254 {
....@@ -1426,121 +1313,228 @@
14261313 static bool printk_time = IS_ENABLED(CONFIG_PRINTK_TIME);
14271314 module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
14281315
1316
+static size_t print_syslog(unsigned int level, char *buf)
1317
+{
1318
+ return sprintf(buf, "<%u>", level);
1319
+}
1320
+
14291321 static size_t print_time(u64 ts, char *buf)
14301322 {
1431
- unsigned long rem_nsec;
1323
+ unsigned long rem_nsec = do_div(ts, 1000000000);
14321324
1433
- if (!printk_time)
1434
- return 0;
1435
-
1436
- rem_nsec = do_div(ts, 1000000000);
1437
-
1438
- if (!buf)
1439
- return snprintf(NULL, 0, "[%5lu.000000] ", (unsigned long)ts);
1440
-
1441
- return sprintf(buf, "[%5lu.%06lu] ",
1325
+ return sprintf(buf, "[%5lu.%06lu]",
14421326 (unsigned long)ts, rem_nsec / 1000);
14431327 }
14441328
1445
-static size_t print_prefix(const struct printk_log *msg, bool syslog, char *buf)
1329
+#ifdef CONFIG_PRINTK_CALLER
1330
+static size_t print_caller(u32 id, char *buf)
1331
+{
1332
+ char caller[12];
1333
+
1334
+ snprintf(caller, sizeof(caller), "%c%u",
1335
+ id & 0x80000000 ? 'C' : 'T', id & ~0x80000000);
1336
+ return sprintf(buf, "[%6s]", caller);
1337
+}
1338
+#else
1339
+#define print_caller(id, buf) 0
1340
+#endif
1341
+
1342
+static size_t info_print_prefix(const struct printk_info *info, bool syslog,
1343
+ bool time, char *buf)
14461344 {
14471345 size_t len = 0;
1448
- unsigned int prefix = (msg->facility << 3) | msg->level;
14491346
1450
- if (syslog) {
1451
- if (buf) {
1452
- len += sprintf(buf, "<%u>", prefix);
1453
- } else {
1454
- len += 3;
1455
- if (prefix > 999)
1456
- len += 3;
1457
- else if (prefix > 99)
1458
- len += 2;
1459
- else if (prefix > 9)
1460
- len++;
1461
- }
1347
+ if (syslog)
1348
+ len = print_syslog((info->facility << 3) | info->level, buf);
1349
+
1350
+ if (time)
1351
+ len += print_time(info->ts_nsec, buf + len);
1352
+
1353
+ len += print_caller(info->caller_id, buf + len);
1354
+
1355
+ if (IS_ENABLED(CONFIG_PRINTK_CALLER) || time) {
1356
+ buf[len++] = ' ';
1357
+ buf[len] = '\0';
14621358 }
14631359
1464
- len += print_time(msg->ts_nsec, buf ? buf + len : NULL);
1465
-#ifdef CONFIG_PRINTK_PROCESS
1466
- len += print_process(msg, buf ? buf + len : NULL);
1467
-#endif
14681360 return len;
14691361 }
14701362
1471
-static size_t msg_print_text(const struct printk_log *msg, bool syslog, char *buf, size_t size)
1363
+/*
1364
+ * Prepare the record for printing. The text is shifted within the given
1365
+ * buffer to avoid a need for another one. The following operations are
1366
+ * done:
1367
+ *
1368
+ * - Add prefix for each line.
1369
+ * - Drop truncated lines that no longer fit into the buffer.
1370
+ * - Add the trailing newline that has been removed in vprintk_store().
1371
+ * - Add a string terminator.
1372
+ *
1373
+ * Since the produced string is always terminated, the maximum possible
1374
+ * return value is @r->text_buf_size - 1;
1375
+ *
1376
+ * Return: The length of the updated/prepared text, including the added
1377
+ * prefixes and the newline. The terminator is not counted. The dropped
1378
+ * line(s) are not counted.
1379
+ */
1380
+static size_t record_print_text(struct printk_record *r, bool syslog,
1381
+ bool time)
14721382 {
1473
- const char *text = log_text(msg);
1474
- size_t text_size = msg->text_len;
1383
+ size_t text_len = r->info->text_len;
1384
+ size_t buf_size = r->text_buf_size;
1385
+ char *text = r->text_buf;
1386
+ char prefix[PREFIX_MAX];
1387
+ bool truncated = false;
1388
+ size_t prefix_len;
1389
+ size_t line_len;
14751390 size_t len = 0;
1391
+ char *next;
14761392
1477
- do {
1478
- const char *next = memchr(text, '\n', text_size);
1479
- size_t text_len;
1393
+ /*
1394
+ * If the message was truncated because the buffer was not large
1395
+ * enough, treat the available text as if it were the full text.
1396
+ */
1397
+ if (text_len > buf_size)
1398
+ text_len = buf_size;
14801399
1400
+ prefix_len = info_print_prefix(r->info, syslog, time, prefix);
1401
+
1402
+ /*
1403
+ * @text_len: bytes of unprocessed text
1404
+ * @line_len: bytes of current line _without_ newline
1405
+ * @text: pointer to beginning of current line
1406
+ * @len: number of bytes prepared in r->text_buf
1407
+ */
1408
+ for (;;) {
1409
+ next = memchr(text, '\n', text_len);
14811410 if (next) {
1482
- text_len = next - text;
1483
- next++;
1484
- text_size -= next - text;
1411
+ line_len = next - text;
14851412 } else {
1486
- text_len = text_size;
1413
+ /* Drop truncated line(s). */
1414
+ if (truncated)
1415
+ break;
1416
+ line_len = text_len;
14871417 }
14881418
1489
- if (buf) {
1490
- if (print_prefix(msg, syslog, NULL) +
1491
- text_len + 1 >= size - len)
1419
+ /*
1420
+ * Truncate the text if there is not enough space to add the
1421
+ * prefix and a trailing newline and a terminator.
1422
+ */
1423
+ if (len + prefix_len + text_len + 1 + 1 > buf_size) {
1424
+ /* Drop even the current line if no space. */
1425
+ if (len + prefix_len + line_len + 1 + 1 > buf_size)
14921426 break;
14931427
1494
- len += print_prefix(msg, syslog, buf + len);
1495
- memcpy(buf + len, text, text_len);
1496
- len += text_len;
1497
- buf[len++] = '\n';
1498
- } else {
1499
- /* SYSLOG_ACTION_* buffer size only calculation */
1500
- len += print_prefix(msg, syslog, NULL);
1501
- len += text_len;
1502
- len++;
1428
+ text_len = buf_size - len - prefix_len - 1 - 1;
1429
+ truncated = true;
15031430 }
15041431
1505
- text = next;
1506
- } while (text);
1432
+ memmove(text + prefix_len, text, text_len);
1433
+ memcpy(text, prefix, prefix_len);
1434
+
1435
+ /*
1436
+ * Increment the prepared length to include the text and
1437
+ * prefix that were just moved+copied. Also increment for the
1438
+ * newline at the end of this line. If this is the last line,
1439
+ * there is no newline, but it will be added immediately below.
1440
+ */
1441
+ len += prefix_len + line_len + 1;
1442
+ if (text_len == line_len) {
1443
+ /*
1444
+ * This is the last line. Add the trailing newline
1445
+ * removed in vprintk_store().
1446
+ */
1447
+ text[prefix_len + line_len] = '\n';
1448
+ break;
1449
+ }
1450
+
1451
+ /*
1452
+ * Advance beyond the added prefix and the related line with
1453
+ * its newline.
1454
+ */
1455
+ text += prefix_len + line_len + 1;
1456
+
1457
+ /*
1458
+ * The remaining text has only decreased by the line with its
1459
+ * newline.
1460
+ *
1461
+ * Note that @text_len can become zero. It happens when @text
1462
+ * ended with a newline (either due to truncation or the
1463
+ * original string ending with "\n\n"). The loop is correctly
1464
+ * repeated and (if not truncated) an empty line with a prefix
1465
+ * will be prepared.
1466
+ */
1467
+ text_len -= line_len + 1;
1468
+ }
1469
+
1470
+ /*
1471
+ * If a buffer was provided, it will be terminated. Space for the
1472
+ * string terminator is guaranteed to be available. The terminator is
1473
+ * not counted in the return value.
1474
+ */
1475
+ if (buf_size > 0)
1476
+ r->text_buf[len] = 0;
15071477
15081478 return len;
1479
+}
1480
+
1481
+static size_t get_record_print_text_size(struct printk_info *info,
1482
+ unsigned int line_count,
1483
+ bool syslog, bool time)
1484
+{
1485
+ char prefix[PREFIX_MAX];
1486
+ size_t prefix_len;
1487
+
1488
+ prefix_len = info_print_prefix(info, syslog, time, prefix);
1489
+
1490
+ /*
1491
+ * Each line will be preceded with a prefix. The intermediate
1492
+ * newlines are already within the text, but a final trailing
1493
+ * newline will be added.
1494
+ */
1495
+ return ((prefix_len * line_count) + info->text_len + 1);
15091496 }
15101497
15111498 static int syslog_print(char __user *buf, int size)
15121499 {
1500
+ struct printk_info info;
1501
+ struct printk_record r;
15131502 char *text;
1514
- struct printk_log *msg;
15151503 int len = 0;
15161504
15171505 text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
15181506 if (!text)
15191507 return -ENOMEM;
15201508
1509
+ prb_rec_init_rd(&r, &info, text, LOG_LINE_MAX + PREFIX_MAX);
1510
+
15211511 while (size > 0) {
15221512 size_t n;
15231513 size_t skip;
15241514
15251515 logbuf_lock_irq();
1526
- if (syslog_seq < log_first_seq) {
1527
- /* messages are gone, move to first one */
1528
- syslog_seq = log_first_seq;
1529
- syslog_idx = log_first_idx;
1530
- syslog_partial = 0;
1531
- }
1532
- if (syslog_seq == log_next_seq) {
1516
+ if (!prb_read_valid(prb, syslog_seq, &r)) {
15331517 logbuf_unlock_irq();
15341518 break;
15351519 }
1520
+ if (r.info->seq != syslog_seq) {
1521
+ /* message is gone, move to next valid one */
1522
+ syslog_seq = r.info->seq;
1523
+ syslog_partial = 0;
1524
+ }
1525
+
1526
+ /*
1527
+ * To keep reading/counting partial line consistent,
1528
+ * use printk_time value as of the beginning of a line.
1529
+ */
1530
+ if (!syslog_partial)
1531
+ syslog_time = printk_time;
15361532
15371533 skip = syslog_partial;
1538
- msg = log_from_idx(syslog_idx);
1539
- n = msg_print_text(msg, true, text, LOG_LINE_MAX + PREFIX_MAX);
1534
+ n = record_print_text(&r, true, syslog_time);
15401535 if (n - syslog_partial <= size) {
15411536 /* message fits into buffer, move forward */
1542
- syslog_idx = log_next(syslog_idx);
1543
- syslog_seq++;
1537
+ syslog_seq = r.info->seq + 1;
15441538 n -= syslog_partial;
15451539 syslog_partial = 0;
15461540 } else if (!len){
....@@ -1571,85 +1565,46 @@
15711565
15721566 static int syslog_print_all(char __user *buf, int size, bool clear)
15731567 {
1568
+ struct printk_info info;
1569
+ unsigned int line_count;
1570
+ struct printk_record r;
15741571 char *text;
15751572 int len = 0;
1576
- u64 next_seq;
15771573 u64 seq;
1578
- u32 idx;
1579
- int attempts = 0;
1580
- int num_msg;
1574
+ bool time;
15811575
15821576 text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
15831577 if (!text)
15841578 return -ENOMEM;
15851579
1580
+ time = printk_time;
15861581 logbuf_lock_irq();
1587
-
1588
-try_again:
1589
- attempts++;
1590
- if (attempts > 10) {
1591
- len = -EBUSY;
1592
- goto out;
1593
- }
1594
- num_msg = 0;
1595
-
15961582 /*
15971583 * Find first record that fits, including all following records,
15981584 * into the user-provided buffer for this dump.
15991585 */
1600
- seq = clear_seq;
1601
- idx = clear_idx;
1602
- while (seq < log_next_seq) {
1603
- struct printk_log *msg = log_from_idx(idx);
1604
-
1605
- len += msg_print_text(msg, true, NULL, 0);
1606
- idx = log_next(idx);
1607
- seq++;
1608
- num_msg++;
1609
- if (num_msg > 5) {
1610
- num_msg = 0;
1611
- logbuf_unlock_irq();
1612
- logbuf_lock_irq();
1613
- if (clear_seq < log_first_seq)
1614
- goto try_again;
1615
- }
1616
- }
1586
+ prb_for_each_info(clear_seq, prb, seq, &info, &line_count)
1587
+ len += get_record_print_text_size(&info, line_count, true, time);
16171588
16181589 /* move first record forward until length fits into the buffer */
1619
- seq = clear_seq;
1620
- idx = clear_idx;
1621
- while (len > size && seq < log_next_seq) {
1622
- struct printk_log *msg = log_from_idx(idx);
1623
-
1624
- len -= msg_print_text(msg, true, NULL, 0);
1625
- idx = log_next(idx);
1626
- seq++;
1627
- num_msg++;
1628
- if (num_msg > 5) {
1629
- num_msg = 0;
1630
- logbuf_unlock_irq();
1631
- logbuf_lock_irq();
1632
- if (clear_seq < log_first_seq)
1633
- goto try_again;
1634
- }
1590
+ prb_for_each_info(clear_seq, prb, seq, &info, &line_count) {
1591
+ if (len <= size)
1592
+ break;
1593
+ len -= get_record_print_text_size(&info, line_count, true, time);
16351594 }
16361595
1637
- /* last message fitting into this dump */
1638
- next_seq = log_next_seq;
1596
+ prb_rec_init_rd(&r, &info, text, LOG_LINE_MAX + PREFIX_MAX);
16391597
16401598 len = 0;
1641
- while (len >= 0 && seq < next_seq) {
1642
- struct printk_log *msg = log_from_idx(idx);
1599
+ prb_for_each_record(seq, prb, seq, &r) {
16431600 int textlen;
16441601
1645
- textlen = msg_print_text(msg, true, text,
1646
- LOG_LINE_MAX + PREFIX_MAX);
1647
- if (textlen < 0) {
1648
- len = textlen;
1602
+ textlen = record_print_text(&r, true, time);
1603
+
1604
+ if (len + textlen > size) {
1605
+ seq--;
16491606 break;
16501607 }
1651
- idx = log_next(idx);
1652
- seq++;
16531608
16541609 logbuf_unlock_irq();
16551610 if (copy_to_user(buf + len, text, textlen))
....@@ -1658,18 +1613,12 @@
16581613 len += textlen;
16591614 logbuf_lock_irq();
16601615
1661
- if (seq < log_first_seq) {
1662
- /* messages are gone, move to next one */
1663
- seq = log_first_seq;
1664
- idx = log_first_idx;
1665
- }
1616
+ if (len < 0)
1617
+ break;
16661618 }
16671619
1668
- if (clear) {
1669
- clear_seq = log_next_seq;
1670
- clear_idx = log_next_idx;
1671
- }
1672
-out:
1620
+ if (clear)
1621
+ clear_seq = seq;
16731622 logbuf_unlock_irq();
16741623
16751624 kfree(text);
....@@ -1679,13 +1628,13 @@
16791628 static void syslog_clear(void)
16801629 {
16811630 logbuf_lock_irq();
1682
- clear_seq = log_next_seq;
1683
- clear_idx = log_next_idx;
1631
+ clear_seq = prb_next_seq(prb);
16841632 logbuf_unlock_irq();
16851633 }
16861634
16871635 int do_syslog(int type, char __user *buf, int len, int source)
16881636 {
1637
+ struct printk_info info;
16891638 bool clear = false;
16901639 static int saved_console_loglevel = LOGLEVEL_DEFAULT;
16911640 int error;
....@@ -1704,10 +1653,10 @@
17041653 return -EINVAL;
17051654 if (!len)
17061655 return 0;
1707
- if (!access_ok(VERIFY_WRITE, buf, len))
1656
+ if (!access_ok(buf, len))
17081657 return -EFAULT;
17091658 error = wait_event_interruptible(log_wait,
1710
- syslog_seq != log_next_seq);
1659
+ prb_read_valid(prb, syslog_seq, NULL));
17111660 if (error)
17121661 return error;
17131662 error = syslog_print(buf, len);
....@@ -1715,14 +1664,14 @@
17151664 /* Read/clear last kernel messages */
17161665 case SYSLOG_ACTION_READ_CLEAR:
17171666 clear = true;
1718
- /* FALL THRU */
1667
+ fallthrough;
17191668 /* Read last kernel messages */
17201669 case SYSLOG_ACTION_READ_ALL:
17211670 if (!buf || len < 0)
17221671 return -EINVAL;
17231672 if (!len)
17241673 return 0;
1725
- if (!access_ok(VERIFY_WRITE, buf, len))
1674
+ if (!access_ok(buf, len))
17261675 return -EFAULT;
17271676 error = syslog_print_all(buf, len, clear);
17281677 break;
....@@ -1756,10 +1705,14 @@
17561705 /* Number of chars in the log buffer */
17571706 case SYSLOG_ACTION_SIZE_UNREAD:
17581707 logbuf_lock_irq();
1759
- if (syslog_seq < log_first_seq) {
1708
+ if (!prb_read_valid_info(prb, syslog_seq, &info, NULL)) {
1709
+ /* No unread messages. */
1710
+ logbuf_unlock_irq();
1711
+ return 0;
1712
+ }
1713
+ if (info.seq != syslog_seq) {
17601714 /* messages are gone, move to first one */
1761
- syslog_seq = log_first_seq;
1762
- syslog_idx = log_first_idx;
1715
+ syslog_seq = info.seq;
17631716 syslog_partial = 0;
17641717 }
17651718 if (source == SYSLOG_FROM_PROC) {
....@@ -1768,17 +1721,17 @@
17681721 * for pending data, not the size; return the count of
17691722 * records, not the length.
17701723 */
1771
- error = log_next_seq - syslog_seq;
1724
+ error = prb_next_seq(prb) - syslog_seq;
17721725 } else {
1773
- u64 seq = syslog_seq;
1774
- u32 idx = syslog_idx;
1726
+ bool time = syslog_partial ? syslog_time : printk_time;
1727
+ unsigned int line_count;
1728
+ u64 seq;
17751729
1776
- while (seq < log_next_seq) {
1777
- struct printk_log *msg = log_from_idx(idx);
1778
-
1779
- error += msg_print_text(msg, true, NULL, 0);
1780
- idx = log_next(idx);
1781
- seq++;
1730
+ prb_for_each_info(syslog_seq, prb, seq, &info,
1731
+ &line_count) {
1732
+ error += get_record_print_text_size(&info, line_count,
1733
+ true, time);
1734
+ time = printk_time;
17821735 }
17831736 error -= syslog_partial;
17841737 }
....@@ -1801,7 +1754,6 @@
18011754 return do_syslog(type, buf, len, SYSLOG_FROM_READER);
18021755 }
18031756
1804
-#ifndef CONFIG_PREEMPT_RT_FULL
18051757 /*
18061758 * Special console_lock variants that help to reduce the risk of soft-lockups.
18071759 * They allow to pass console_lock to another printk() call using a busy wait.
....@@ -1861,20 +1813,20 @@
18611813 raw_spin_unlock(&console_owner_lock);
18621814
18631815 if (!waiter) {
1864
- spin_release(&console_owner_dep_map, 1, _THIS_IP_);
1816
+ spin_release(&console_owner_dep_map, _THIS_IP_);
18651817 return 0;
18661818 }
18671819
18681820 /* The waiter is now free to continue */
18691821 WRITE_ONCE(console_waiter, false);
18701822
1871
- spin_release(&console_owner_dep_map, 1, _THIS_IP_);
1823
+ spin_release(&console_owner_dep_map, _THIS_IP_);
18721824
18731825 /*
18741826 * Hand off console_lock to waiter. The waiter will perform
18751827 * the up(). After this, the waiter is the console_lock owner.
18761828 */
1877
- mutex_release(&console_lock_dep_map, 1, _THIS_IP_);
1829
+ mutex_release(&console_lock_dep_map, _THIS_IP_);
18781830 return 1;
18791831 }
18801832
....@@ -1928,7 +1880,7 @@
19281880 /* Owner will clear console_waiter on hand off */
19291881 while (READ_ONCE(console_waiter))
19301882 cpu_relax();
1931
- spin_release(&console_owner_dep_map, 1, _THIS_IP_);
1883
+ spin_release(&console_owner_dep_map, _THIS_IP_);
19321884
19331885 printk_safe_exit_irqrestore(flags);
19341886 /*
....@@ -1942,26 +1894,16 @@
19421894 return 1;
19431895 }
19441896
1945
-#else
1946
-
1947
-static int console_trylock_spinning(void)
1948
-{
1949
- return console_trylock();
1950
-}
1951
-
1952
-#endif
1953
-
19541897 /*
19551898 * Call the console drivers, asking them to write out
19561899 * log_buf[start] to log_buf[end - 1].
19571900 * The console_lock must be held.
19581901 */
1959
-#ifdef CONFIG_PSTORE_CONSOLE_FORCE
1960
-__maybe_unused
1961
-#endif
19621902 static void call_console_drivers(const char *ext_text, size_t ext_len,
19631903 const char *text, size_t len)
19641904 {
1905
+ static char dropped_text[64];
1906
+ size_t dropped_len = 0;
19651907 struct console *con;
19661908
19671909 trace_console_rcuidle(text, len);
....@@ -1969,12 +1911,13 @@
19691911 if (!console_drivers)
19701912 return;
19711913
1972
- if (IS_ENABLED(CONFIG_PREEMPT_RT_BASE)) {
1973
- if (in_irq() || in_nmi())
1974
- return;
1914
+ if (console_dropped) {
1915
+ dropped_len = snprintf(dropped_text, sizeof(dropped_text),
1916
+ "** %lu printk messages dropped **\n",
1917
+ console_dropped);
1918
+ console_dropped = 0;
19751919 }
19761920
1977
- migrate_disable();
19781921 for_each_console(con) {
19791922 if (exclusive_console && con != exclusive_console)
19801923 continue;
....@@ -1987,10 +1930,12 @@
19871930 continue;
19881931 if (con->flags & CON_EXTENDED)
19891932 con->write(con, ext_text, ext_len);
1990
- else
1933
+ else {
1934
+ if (dropped_len)
1935
+ con->write(con, dropped_text, dropped_len);
19911936 con->write(con, text, len);
1937
+ }
19921938 }
1993
- migrate_enable();
19941939 }
19951940
19961941 int printk_delay_msec __read_mostly;
....@@ -2007,100 +1952,46 @@
20071952 }
20081953 }
20091954
2010
-/*
2011
- * Continuation lines are buffered, and not committed to the record buffer
2012
- * until the line is complete, or a race forces it. The line fragments
2013
- * though, are printed immediately to the consoles to ensure everything has
2014
- * reached the console in case of a kernel crash.
2015
- */
2016
-static struct cont {
2017
- char buf[LOG_LINE_MAX];
2018
- size_t len; /* length == 0 means unused buffer */
2019
- struct task_struct *owner; /* task of first print*/
2020
- u64 ts_nsec; /* time of first print */
2021
- u8 level; /* log level of first message */
2022
- u8 facility; /* log facility of first message */
2023
- enum log_flags flags; /* prefix, newline flags */
2024
-} cont;
2025
-
2026
-static void cont_flush(void)
1955
+static inline u32 printk_caller_id(void)
20271956 {
2028
- if (cont.len == 0)
2029
- return;
2030
-
2031
- log_store(cont.facility, cont.level, cont.flags, cont.ts_nsec,
2032
- NULL, 0, cont.buf, cont.len);
2033
- cont.len = 0;
1957
+ return in_task() ? task_pid_nr(current) :
1958
+ 0x80000000 + raw_smp_processor_id();
20341959 }
20351960
2036
-static bool cont_add(int facility, int level, enum log_flags flags, const char *text, size_t len)
1961
+static size_t log_output(int facility, int level, enum log_flags lflags,
1962
+ const struct dev_printk_info *dev_info,
1963
+ char *text, size_t text_len)
20371964 {
2038
- /*
2039
- * If ext consoles are present, flush and skip in-kernel
2040
- * continuation. See nr_ext_console_drivers definition. Also, if
2041
- * the line gets too long, split it up in separate records.
2042
- */
2043
- if (nr_ext_console_drivers || cont.len + len > sizeof(cont.buf)) {
2044
- cont_flush();
2045
- return false;
2046
- }
1965
+ const u32 caller_id = printk_caller_id();
20471966
2048
- if (!cont.len) {
2049
- cont.facility = facility;
2050
- cont.level = level;
2051
- cont.owner = current;
2052
- cont.ts_nsec = get_local_clock();
2053
- cont.flags = flags;
2054
- }
1967
+ if (lflags & LOG_CONT) {
1968
+ struct prb_reserved_entry e;
1969
+ struct printk_record r;
20551970
2056
- memcpy(cont.buf + cont.len, text, len);
2057
- cont.len += len;
1971
+ prb_rec_init_wr(&r, text_len);
1972
+ if (prb_reserve_in_last(&e, prb, &r, caller_id, LOG_LINE_MAX)) {
1973
+ memcpy(&r.text_buf[r.info->text_len], text, text_len);
1974
+ r.info->text_len += text_len;
1975
+ if (lflags & LOG_NEWLINE) {
1976
+ r.info->flags |= LOG_NEWLINE;
1977
+ prb_final_commit(&e);
1978
+ } else {
1979
+ prb_commit(&e);
1980
+ }
20581981
2059
- // The original flags come from the first line,
2060
- // but later continuations can add a newline.
2061
- if (flags & LOG_NEWLINE) {
2062
- cont.flags |= LOG_NEWLINE;
2063
- cont_flush();
2064
- }
2065
-
2066
- if (cont.len > (sizeof(cont.buf) * 80) / 100)
2067
- cont_flush();
2068
-
2069
- return true;
2070
-}
2071
-
2072
-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)
2073
-{
2074
- /*
2075
- * If an earlier line was buffered, and we're a continuation
2076
- * write from the same process, try to add it to the buffer.
2077
- */
2078
- if (cont.len) {
2079
- if (cont.owner == current && (lflags & LOG_CONT)) {
2080
- if (cont_add(facility, level, lflags, text, text_len))
2081
- return text_len;
2082
- }
2083
- /* Otherwise, make sure it's flushed */
2084
- cont_flush();
2085
- }
2086
-
2087
- /* Skip empty continuation lines that couldn't be added - they just flush */
2088
- if (!text_len && (lflags & LOG_CONT))
2089
- return 0;
2090
-
2091
- /* If it doesn't end in a newline, try to buffer the current line */
2092
- if (!(lflags & LOG_NEWLINE)) {
2093
- if (cont_add(facility, level, lflags, text, text_len))
1982
+ trace_android_vh_logbuf_pr_cont(&r, text_len);
20941983 return text_len;
1984
+ }
20951985 }
20961986
20971987 /* Store it in the record log */
2098
- return log_store(facility, level, lflags, 0, dict, dictlen, text, text_len);
1988
+ return log_store(caller_id, facility, level, lflags, 0,
1989
+ dev_info, text, text_len);
20991990 }
21001991
21011992 /* Must be called under logbuf_lock. */
21021993 int vprintk_store(int facility, int level,
2103
- const char *dict, size_t dictlen,
1994
+ const struct dev_printk_info *dev_info,
21041995 const char *fmt, va_list args)
21051996 {
21061997 static char textbuf[LOG_LINE_MAX];
....@@ -2129,9 +2020,6 @@
21292020 case '0' ... '7':
21302021 if (level == LOGLEVEL_DEFAULT)
21312022 level = kern_level - '0';
2132
- /* fallthrough */
2133
- case 'd': /* KERN_DEFAULT */
2134
- lflags |= LOG_PREFIX;
21352023 break;
21362024 case 'c': /* KERN_CONT */
21372025 lflags |= LOG_CONT;
....@@ -2145,28 +2033,23 @@
21452033 if (level == LOGLEVEL_DEFAULT)
21462034 level = default_message_loglevel;
21472035
2148
- if (dict)
2149
- lflags |= LOG_PREFIX|LOG_NEWLINE;
2036
+ if (dev_info)
2037
+ lflags |= LOG_NEWLINE;
21502038
2151
- return log_output(facility, level, lflags,
2152
- dict, dictlen, text, text_len);
2039
+ return log_output(facility, level, lflags, dev_info, text, text_len);
21532040 }
21542041
21552042 asmlinkage int vprintk_emit(int facility, int level,
2156
- const char *dict, size_t dictlen,
2043
+ const struct dev_printk_info *dev_info,
21572044 const char *fmt, va_list args)
21582045 {
21592046 int printed_len;
2160
- bool in_sched = false, pending_output;
2047
+ bool in_sched = false;
21612048 unsigned long flags;
2162
- u64 curr_log_seq;
21632049
2164
- /*
2165
- * Fall back to early_printk if a debugging subsystem has
2166
- * killed printk output
2167
- */
2168
- if (unlikely(forced_early_printk(fmt, args)))
2169
- return 1;
2050
+ /* Suppress unimportant messages after panic happens */
2051
+ if (unlikely(suppress_printk))
2052
+ return 0;
21702053
21712054 if (level == LOGLEVEL_SCHED) {
21722055 level = LOGLEVEL_DEFAULT;
....@@ -2178,41 +2061,28 @@
21782061
21792062 /* This stops the holder of console_sem just where we want him */
21802063 logbuf_lock_irqsave(flags);
2181
- curr_log_seq = log_next_seq;
2182
- printed_len = vprintk_store(facility, level, dict, dictlen, fmt, args);
2183
- pending_output = (curr_log_seq != log_next_seq);
2064
+ printed_len = vprintk_store(facility, level, dev_info, fmt, args);
21842065 logbuf_unlock_irqrestore(flags);
21852066
21862067 /* If called from the scheduler, we can not call up(). */
2187
- if (!in_sched && pending_output) {
2188
- int may_trylock = 1;
2189
-
2190
-#ifdef CONFIG_PREEMPT_RT_FULL
2191
- /*
2192
- * we can't take a sleeping lock with IRQs or preeption disabled
2193
- * so we can't print in these contexts
2194
- */
2195
- if (!(preempt_count() == 0 && !irqs_disabled()))
2196
- may_trylock = 0;
2197
-#endif
2068
+ if (!in_sched) {
21982069 /*
21992070 * Disable preemption to avoid being preempted while holding
22002071 * console_sem which would prevent anyone from printing to
22012072 * console
22022073 */
2203
- migrate_disable();
2074
+ preempt_disable();
22042075 /*
22052076 * Try to acquire and then immediately release the console
22062077 * semaphore. The release will print out buffers and wake up
22072078 * /dev/kmsg and syslog() users.
22082079 */
2209
- if (may_trylock && console_trylock_spinning())
2080
+ if (console_trylock_spinning())
22102081 console_unlock();
2211
- migrate_enable();
2082
+ preempt_enable();
22122083 }
22132084
2214
- if (pending_output)
2215
- wake_up_klogd();
2085
+ wake_up_klogd();
22162086 return printed_len;
22172087 }
22182088 EXPORT_SYMBOL(vprintk_emit);
....@@ -2223,35 +2093,9 @@
22232093 }
22242094 EXPORT_SYMBOL(vprintk);
22252095
2226
-asmlinkage int printk_emit(int facility, int level,
2227
- const char *dict, size_t dictlen,
2228
- const char *fmt, ...)
2229
-{
2230
- va_list args;
2231
- int r;
2232
-
2233
- va_start(args, fmt);
2234
- r = vprintk_emit(facility, level, dict, dictlen, fmt, args);
2235
- va_end(args);
2236
-
2237
- return r;
2238
-}
2239
-EXPORT_SYMBOL(printk_emit);
2240
-
22412096 int vprintk_default(const char *fmt, va_list args)
22422097 {
2243
- int r;
2244
-
2245
-#ifdef CONFIG_KGDB_KDB
2246
- /* Allow to pass printk() to kdb but avoid a recursion. */
2247
- if (unlikely(kdb_trap_printk && kdb_printf_cpu < 0)) {
2248
- r = vkdb_printf(KDB_MSGSRC_PRINTK, fmt, args);
2249
- return r;
2250
- }
2251
-#endif
2252
- r = vprintk_emit(0, LOGLEVEL_DEFAULT, NULL, 0, fmt, args);
2253
-
2254
- return r;
2098
+ return vprintk_emit(0, LOGLEVEL_DEFAULT, NULL, fmt, args);
22552099 }
22562100 EXPORT_SYMBOL_GPL(vprintk_default);
22572101
....@@ -2293,37 +2137,59 @@
22932137
22942138 #define LOG_LINE_MAX 0
22952139 #define PREFIX_MAX 0
2140
+#define printk_time false
2141
+
2142
+#define prb_read_valid(rb, seq, r) false
2143
+#define prb_first_valid_seq(rb) 0
22962144
22972145 static u64 syslog_seq;
2298
-static u32 syslog_idx;
22992146 static u64 console_seq;
2300
-static u32 console_idx;
23012147 static u64 exclusive_console_stop_seq;
2302
-static u64 log_first_seq;
2303
-static u32 log_first_idx;
2304
-static u64 log_next_seq;
2305
-static char *log_text(const struct printk_log *msg) { return NULL; }
2306
-static char *log_dict(const struct printk_log *msg) { return NULL; }
2307
-static struct printk_log *log_from_idx(u32 idx) { return NULL; }
2308
-static u32 log_next(u32 idx) { return 0; }
2309
-static ssize_t msg_print_ext_header(char *buf, size_t size,
2310
- struct printk_log *msg,
2311
- u64 seq) { return 0; }
2148
+static unsigned long console_dropped;
2149
+
2150
+static size_t record_print_text(const struct printk_record *r,
2151
+ bool syslog, bool time)
2152
+{
2153
+ return 0;
2154
+}
2155
+static ssize_t info_print_ext_header(char *buf, size_t size,
2156
+ struct printk_info *info)
2157
+{
2158
+ return 0;
2159
+}
23122160 static ssize_t msg_print_ext_body(char *buf, size_t size,
2313
- char *dict, size_t dict_len,
2314
- char *text, size_t text_len) { return 0; }
2161
+ char *text, size_t text_len,
2162
+ struct dev_printk_info *dev_info) { return 0; }
23152163 static void console_lock_spinning_enable(void) { }
23162164 static int console_lock_spinning_disable_and_check(void) { return 0; }
23172165 static void call_console_drivers(const char *ext_text, size_t ext_len,
23182166 const char *text, size_t len) {}
2319
-static size_t msg_print_text(const struct printk_log *msg,
2320
- bool syslog, char *buf, size_t size) { return 0; }
23212167 static bool suppress_message_printing(int level) { return false; }
23222168
23232169 #endif /* CONFIG_PRINTK */
23242170
2171
+#ifdef CONFIG_EARLY_PRINTK
2172
+struct console *early_console;
2173
+
2174
+asmlinkage __visible void early_printk(const char *fmt, ...)
2175
+{
2176
+ va_list ap;
2177
+ char buf[512];
2178
+ int n;
2179
+
2180
+ if (!early_console)
2181
+ return;
2182
+
2183
+ va_start(ap, fmt);
2184
+ n = vscnprintf(buf, sizeof(buf), fmt, ap);
2185
+ va_end(ap);
2186
+
2187
+ early_console->write(early_console, buf, n);
2188
+}
2189
+#endif
2190
+
23252191 static int __add_preferred_console(char *name, int idx, char *options,
2326
- char *brl_options)
2192
+ char *brl_options, bool user_specified)
23272193 {
23282194 struct console_cmdline *c;
23292195 int i;
....@@ -2338,6 +2204,8 @@
23382204 if (strcmp(c->name, name) == 0 && c->index == idx) {
23392205 if (!brl_options)
23402206 preferred_console = i;
2207
+ if (user_specified)
2208
+ c->user_specified = true;
23412209 return 0;
23422210 }
23432211 }
....@@ -2347,6 +2215,7 @@
23472215 preferred_console = i;
23482216 strlcpy(c->name, name, sizeof(c->name));
23492217 c->options = options;
2218
+ c->user_specified = user_specified;
23502219 braille_set_options(c, brl_options);
23512220
23522221 c->index = idx;
....@@ -2379,7 +2248,7 @@
23792248 * for exacly this purpose.
23802249 */
23812250 if (str[0] == 0 || strcmp(str, "null") == 0) {
2382
- __add_preferred_console("ttynull", 0, NULL, NULL);
2251
+ __add_preferred_console("ttynull", 0, NULL, NULL, true);
23832252 return 1;
23842253 }
23852254
....@@ -2411,7 +2280,7 @@
24112280 idx = simple_strtoul(s, NULL, 10);
24122281 *s = 0;
24132282
2414
- __add_preferred_console(buf, idx, options, brl_options);
2283
+ __add_preferred_console(buf, idx, options, brl_options, true);
24152284 console_set_on_cmdline = 1;
24162285 return 1;
24172286 }
....@@ -2432,7 +2301,7 @@
24322301 */
24332302 int add_preferred_console(char *name, int idx, char *options)
24342303 {
2435
- return __add_preferred_console(name, idx, options, NULL);
2304
+ return __add_preferred_console(name, idx, options, NULL, false);
24362305 }
24372306
24382307 bool console_suspend_enabled = true;
....@@ -2484,6 +2353,12 @@
24842353 */
24852354 static int console_cpu_notify(unsigned int cpu)
24862355 {
2356
+ int flag = 0;
2357
+
2358
+ trace_android_vh_printk_hotplug(&flag);
2359
+ if (flag)
2360
+ return 0;
2361
+
24872362 if (!cpuhp_tasks_frozen) {
24882363 /* If trylock fails, someone else is doing the printing */
24892364 if (console_trylock())
....@@ -2588,11 +2463,15 @@
25882463 static char text[LOG_LINE_MAX + PREFIX_MAX];
25892464 unsigned long flags;
25902465 bool do_cond_resched, retry;
2466
+ struct printk_info info;
2467
+ struct printk_record r;
25912468
25922469 if (console_suspended) {
25932470 up_console_sem();
25942471 return;
25952472 }
2473
+
2474
+ prb_rec_init_rd(&r, &info, text, sizeof(text));
25962475
25972476 /*
25982477 * Console drivers are called with interrupts disabled, so
....@@ -2606,7 +2485,7 @@
26062485 *
26072486 * console_trylock() is not able to detect the preemptive
26082487 * context reliably. Therefore the value must be stored before
2609
- * and cleared after the the "again" goto label.
2488
+ * and cleared after the "again" goto label.
26102489 */
26112490 do_cond_resched = console_may_schedule;
26122491 again:
....@@ -2624,35 +2503,26 @@
26242503 }
26252504
26262505 for (;;) {
2627
- struct printk_log *msg;
26282506 size_t ext_len = 0;
26292507 size_t len;
26302508
26312509 printk_safe_enter_irqsave(flags);
26322510 raw_spin_lock(&logbuf_lock);
2633
- if (console_seq < log_first_seq) {
2634
- len = sprintf(text,
2635
- "** %llu printk messages dropped **\n",
2636
- log_first_seq - console_seq);
2637
-
2638
- /* messages are gone, move to first one */
2639
- console_seq = log_first_seq;
2640
- console_idx = log_first_idx;
2641
- } else {
2642
- len = 0;
2643
- }
26442511 skip:
2645
- if (console_seq == log_next_seq)
2512
+ if (!prb_read_valid(prb, console_seq, &r))
26462513 break;
26472514
2648
- msg = log_from_idx(console_idx);
2649
- if (suppress_message_printing(msg->level)) {
2515
+ if (console_seq != r.info->seq) {
2516
+ console_dropped += r.info->seq - console_seq;
2517
+ console_seq = r.info->seq;
2518
+ }
2519
+
2520
+ if (suppress_message_printing(r.info->level)) {
26502521 /*
26512522 * Skip record we have buffered and already printed
26522523 * directly to the console when we received it, and
26532524 * record that has level above the console loglevel.
26542525 */
2655
- console_idx = log_next(console_idx);
26562526 console_seq++;
26572527 goto skip;
26582528 }
....@@ -2663,27 +2533,26 @@
26632533 exclusive_console = NULL;
26642534 }
26652535
2666
- len += msg_print_text(msg,
2667
- console_msg_format & MSG_FORMAT_SYSLOG,
2668
- text + len,
2669
- sizeof(text) - len);
2536
+ /*
2537
+ * Handle extended console text first because later
2538
+ * record_print_text() will modify the record buffer in-place.
2539
+ */
26702540 if (nr_ext_console_drivers) {
2671
- ext_len = msg_print_ext_header(ext_text,
2541
+ ext_len = info_print_ext_header(ext_text,
26722542 sizeof(ext_text),
2673
- msg, console_seq);
2543
+ r.info);
26742544 ext_len += msg_print_ext_body(ext_text + ext_len,
26752545 sizeof(ext_text) - ext_len,
2676
- log_dict(msg), msg->dict_len,
2677
- log_text(msg), msg->text_len);
2546
+ &r.text_buf[0],
2547
+ r.info->text_len,
2548
+ &r.info->dev_info);
26782549 }
2679
- console_idx = log_next(console_idx);
2550
+ len = record_print_text(&r,
2551
+ console_msg_format & MSG_FORMAT_SYSLOG,
2552
+ printk_time);
26802553 console_seq++;
26812554 raw_spin_unlock(&logbuf_lock);
26822555
2683
-#ifdef CONFIG_PREEMPT_RT_FULL
2684
- printk_safe_exit_irqrestore(flags);
2685
- call_console_drivers(ext_text, ext_len, text, len);
2686
-#else
26872556 /*
26882557 * While actively printing out messages, if another printk()
26892558 * were to occur on another CPU, it may wait for this one to
....@@ -2693,11 +2562,7 @@
26932562 console_lock_spinning_enable();
26942563
26952564 stop_critical_timings(); /* don't trace print latency */
2696
-#ifdef CONFIG_PSTORE_CONSOLE_FORCE
2697
- call_console_drivers_level(msg->level, ext_text, ext_len, text, len);
2698
-#else
26992565 call_console_drivers(ext_text, ext_len, text, len);
2700
-#endif
27012566 start_critical_timings();
27022567
27032568 if (console_lock_spinning_disable_and_check()) {
....@@ -2706,7 +2571,6 @@
27062571 }
27072572
27082573 printk_safe_exit_irqrestore(flags);
2709
-#endif
27102574
27112575 if (do_cond_resched)
27122576 cond_resched();
....@@ -2725,7 +2589,7 @@
27252589 * flush, no worries.
27262590 */
27272591 raw_spin_lock(&logbuf_lock);
2728
- retry = console_seq != log_next_seq;
2592
+ retry = prb_read_valid(prb, console_seq, NULL);
27292593 raw_spin_unlock(&logbuf_lock);
27302594 printk_safe_exit_irqrestore(flags);
27312595
....@@ -2754,11 +2618,6 @@
27542618 {
27552619 struct console *c;
27562620
2757
- if (IS_ENABLED(CONFIG_PREEMPT_RT_BASE)) {
2758
- if (in_irq() || in_nmi())
2759
- return;
2760
- }
2761
-
27622621 /*
27632622 * console_unblank can no longer be called in interrupt context unless
27642623 * oops_in_progress is set to 1..
....@@ -2779,10 +2638,11 @@
27792638
27802639 /**
27812640 * console_flush_on_panic - flush console content on panic
2641
+ * @mode: flush all messages in buffer or just the pending ones
27822642 *
27832643 * Immediately output all pending messages no matter what.
27842644 */
2785
-void console_flush_on_panic(void)
2645
+void console_flush_on_panic(enum con_flush_mode mode)
27862646 {
27872647 /*
27882648 * If someone else is holding the console lock, trylock will fail
....@@ -2793,6 +2653,14 @@
27932653 */
27942654 console_trylock();
27952655 console_may_schedule = 0;
2656
+
2657
+ if (mode == CONSOLE_REPLAY_ALL) {
2658
+ unsigned long flags;
2659
+
2660
+ logbuf_lock_irqsave(flags);
2661
+ console_seq = prb_first_valid_seq(prb);
2662
+ logbuf_unlock_irqrestore(flags);
2663
+ }
27962664 console_unlock();
27972665 }
27982666
....@@ -2850,6 +2718,63 @@
28502718 early_param("keep_bootcon", keep_bootcon_setup);
28512719
28522720 /*
2721
+ * This is called by register_console() to try to match
2722
+ * the newly registered console with any of the ones selected
2723
+ * by either the command line or add_preferred_console() and
2724
+ * setup/enable it.
2725
+ *
2726
+ * Care need to be taken with consoles that are statically
2727
+ * enabled such as netconsole
2728
+ */
2729
+static int try_enable_new_console(struct console *newcon, bool user_specified)
2730
+{
2731
+ struct console_cmdline *c;
2732
+ int i, err;
2733
+
2734
+ for (i = 0, c = console_cmdline;
2735
+ i < MAX_CMDLINECONSOLES && c->name[0];
2736
+ i++, c++) {
2737
+ if (c->user_specified != user_specified)
2738
+ continue;
2739
+ if (!newcon->match ||
2740
+ newcon->match(newcon, c->name, c->index, c->options) != 0) {
2741
+ /* default matching */
2742
+ BUILD_BUG_ON(sizeof(c->name) != sizeof(newcon->name));
2743
+ if (strcmp(c->name, newcon->name) != 0)
2744
+ continue;
2745
+ if (newcon->index >= 0 &&
2746
+ newcon->index != c->index)
2747
+ continue;
2748
+ if (newcon->index < 0)
2749
+ newcon->index = c->index;
2750
+
2751
+ if (_braille_register_console(newcon, c))
2752
+ return 0;
2753
+
2754
+ if (newcon->setup &&
2755
+ (err = newcon->setup(newcon, c->options)) != 0)
2756
+ return err;
2757
+ }
2758
+ newcon->flags |= CON_ENABLED;
2759
+ if (i == preferred_console) {
2760
+ newcon->flags |= CON_CONSDEV;
2761
+ has_preferred_console = true;
2762
+ }
2763
+ return 0;
2764
+ }
2765
+
2766
+ /*
2767
+ * Some consoles, such as pstore and netconsole, can be enabled even
2768
+ * without matching. Accept the pre-enabled consoles only when match()
2769
+ * and setup() had a chance to be called.
2770
+ */
2771
+ if (newcon->flags & CON_ENABLED && c->user_specified == user_specified)
2772
+ return 0;
2773
+
2774
+ return -ENOENT;
2775
+}
2776
+
2777
+/*
28532778 * The console driver calls this routine during kernel initialization
28542779 * to register the console printing procedure with printk() and to
28552780 * print any messages that were printed by the kernel before the
....@@ -2870,25 +2795,21 @@
28702795 */
28712796 void register_console(struct console *newcon)
28722797 {
2873
- int i;
28742798 unsigned long flags;
28752799 struct console *bcon = NULL;
2876
- struct console_cmdline *c;
2877
- static bool has_preferred;
2800
+ int err;
28782801
2879
- if (console_drivers)
2880
- for_each_console(bcon)
2881
- if (WARN(bcon == newcon,
2882
- "console '%s%d' already registered\n",
2883
- bcon->name, bcon->index))
2884
- return;
2802
+ for_each_console(bcon) {
2803
+ if (WARN(bcon == newcon, "console '%s%d' already registered\n",
2804
+ bcon->name, bcon->index))
2805
+ return;
2806
+ }
28852807
28862808 /*
28872809 * before we register a new CON_BOOT console, make sure we don't
28882810 * already have a valid console
28892811 */
2890
- if (console_drivers && newcon->flags & CON_BOOT) {
2891
- /* find the last or real console */
2812
+ if (newcon->flags & CON_BOOT) {
28922813 for_each_console(bcon) {
28932814 if (!(bcon->flags & CON_BOOT)) {
28942815 pr_info("Too late to register bootconsole %s%d\n",
....@@ -2901,15 +2822,15 @@
29012822 if (console_drivers && console_drivers->flags & CON_BOOT)
29022823 bcon = console_drivers;
29032824
2904
- if (!has_preferred || bcon || !console_drivers)
2905
- has_preferred = preferred_console >= 0;
2825
+ if (!has_preferred_console || bcon || !console_drivers)
2826
+ has_preferred_console = preferred_console >= 0;
29062827
29072828 /*
29082829 * See if we want to use this console driver. If we
29092830 * didn't select a console we take the first one
29102831 * that registers here.
29112832 */
2912
- if (!has_preferred) {
2833
+ if (!has_preferred_console) {
29132834 if (newcon->index < 0)
29142835 newcon->index = 0;
29152836 if (newcon->setup == NULL ||
....@@ -2917,47 +2838,20 @@
29172838 newcon->flags |= CON_ENABLED;
29182839 if (newcon->device) {
29192840 newcon->flags |= CON_CONSDEV;
2920
- has_preferred = true;
2841
+ has_preferred_console = true;
29212842 }
29222843 }
29232844 }
29242845
2925
- /*
2926
- * See if this console matches one we selected on
2927
- * the command line.
2928
- */
2929
- for (i = 0, c = console_cmdline;
2930
- i < MAX_CMDLINECONSOLES && c->name[0];
2931
- i++, c++) {
2932
- if (!newcon->match ||
2933
- newcon->match(newcon, c->name, c->index, c->options) != 0) {
2934
- /* default matching */
2935
- BUILD_BUG_ON(sizeof(c->name) != sizeof(newcon->name));
2936
- if (strcmp(c->name, newcon->name) != 0)
2937
- continue;
2938
- if (newcon->index >= 0 &&
2939
- newcon->index != c->index)
2940
- continue;
2941
- if (newcon->index < 0)
2942
- newcon->index = c->index;
2846
+ /* See if this console matches one we selected on the command line */
2847
+ err = try_enable_new_console(newcon, true);
29432848
2944
- if (_braille_register_console(newcon, c))
2945
- return;
2849
+ /* If not, try to match against the platform default(s) */
2850
+ if (err == -ENOENT)
2851
+ err = try_enable_new_console(newcon, false);
29462852
2947
- if (newcon->setup &&
2948
- newcon->setup(newcon, c->options) != 0)
2949
- break;
2950
- }
2951
-
2952
- newcon->flags |= CON_ENABLED;
2953
- if (i == preferred_console) {
2954
- newcon->flags |= CON_CONSDEV;
2955
- has_preferred = true;
2956
- }
2957
- break;
2958
- }
2959
-
2960
- if (!(newcon->flags & CON_ENABLED))
2853
+ /* printk() messages are not printed to the Braille console. */
2854
+ if (err || newcon->flags & CON_BRL)
29612855 return;
29622856
29632857 /*
....@@ -2979,14 +2873,15 @@
29792873 console_drivers = newcon;
29802874 if (newcon->next)
29812875 newcon->next->flags &= ~CON_CONSDEV;
2876
+ /* Ensure this flag is always set for the head of the list */
2877
+ newcon->flags |= CON_CONSDEV;
29822878 } else {
29832879 newcon->next = console_drivers->next;
29842880 console_drivers->next = newcon;
29852881 }
29862882
29872883 if (newcon->flags & CON_EXTENDED)
2988
- if (!nr_ext_console_drivers++)
2989
- pr_info("printk: continuation disabled due to ext consoles, expect more fragments in /dev/kmsg\n");
2884
+ nr_ext_console_drivers++;
29902885
29912886 if (newcon->flags & CON_PRINTBUFFER) {
29922887 /*
....@@ -3006,7 +2901,6 @@
30062901 exclusive_console = newcon;
30072902 exclusive_console_stop_seq = console_seq;
30082903 console_seq = syslog_seq;
3009
- console_idx = syslog_idx;
30102904 logbuf_unlock_irqrestore(flags);
30112905 }
30122906 console_unlock();
....@@ -3037,7 +2931,7 @@
30372931
30382932 int unregister_console(struct console *console)
30392933 {
3040
- struct console *a, *b;
2934
+ struct console *con;
30412935 int res;
30422936
30432937 pr_info("%sconsole [%s%d] disabled\n",
....@@ -3045,26 +2939,30 @@
30452939 console->name, console->index);
30462940
30472941 res = _braille_unregister_console(console);
3048
- if (res)
2942
+ if (res < 0)
30492943 return res;
2944
+ if (res > 0)
2945
+ return 0;
30502946
3051
- res = 1;
2947
+ res = -ENODEV;
30522948 console_lock();
30532949 if (console_drivers == console) {
30542950 console_drivers=console->next;
30552951 res = 0;
3056
- } else if (console_drivers) {
3057
- for (a=console_drivers->next, b=console_drivers ;
3058
- a; b=a, a=b->next) {
3059
- if (a == console) {
3060
- b->next = a->next;
2952
+ } else {
2953
+ for_each_console(con) {
2954
+ if (con->next == console) {
2955
+ con->next = console->next;
30612956 res = 0;
30622957 break;
30632958 }
30642959 }
30652960 }
30662961
3067
- if (!res && (console->flags & CON_EXTENDED))
2962
+ if (res)
2963
+ goto out_disable_unlock;
2964
+
2965
+ if (console->flags & CON_EXTENDED)
30682966 nr_ext_console_drivers--;
30692967
30702968 /*
....@@ -3077,6 +2975,16 @@
30772975 console->flags &= ~CON_ENABLED;
30782976 console_unlock();
30792977 console_sysfs_notify();
2978
+
2979
+ if (console->exit)
2980
+ res = console->exit(console);
2981
+
2982
+ return res;
2983
+
2984
+out_disable_unlock:
2985
+ console->flags &= ~CON_ENABLED;
2986
+ console_unlock();
2987
+
30802988 return res;
30812989 }
30822990 EXPORT_SYMBOL(unregister_console);
....@@ -3185,7 +3093,7 @@
31853093
31863094 static DEFINE_PER_CPU(struct irq_work, wake_up_klogd_work) = {
31873095 .func = wake_up_klogd_work_func,
3188
- .flags = IRQ_WORK_LAZY,
3096
+ .flags = ATOMIC_INIT(IRQ_WORK_LAZY),
31893097 };
31903098
31913099 void wake_up_klogd(void)
....@@ -3216,7 +3124,7 @@
32163124 {
32173125 int r;
32183126
3219
- r = vprintk_emit(0, LOGLEVEL_SCHED, NULL, 0, fmt, args);
3127
+ r = vprintk_emit(0, LOGLEVEL_SCHED, NULL, fmt, args);
32203128 defer_console_output();
32213129
32223130 return r;
....@@ -3233,6 +3141,7 @@
32333141
32343142 return r;
32353143 }
3144
+EXPORT_SYMBOL_GPL(printk_deferred);
32363145
32373146 /*
32383147 * printk rate limiting, lifted from the networking subsystem.
....@@ -3331,6 +3240,23 @@
33313240 static bool always_kmsg_dump;
33323241 module_param_named(always_kmsg_dump, always_kmsg_dump, bool, S_IRUGO | S_IWUSR);
33333242
3243
+const char *kmsg_dump_reason_str(enum kmsg_dump_reason reason)
3244
+{
3245
+ switch (reason) {
3246
+ case KMSG_DUMP_PANIC:
3247
+ return "Panic";
3248
+ case KMSG_DUMP_OOPS:
3249
+ return "Oops";
3250
+ case KMSG_DUMP_EMERG:
3251
+ return "Emergency";
3252
+ case KMSG_DUMP_SHUTDOWN:
3253
+ return "Shutdown";
3254
+ default:
3255
+ return "Unknown";
3256
+ }
3257
+}
3258
+EXPORT_SYMBOL_GPL(kmsg_dump_reason_str);
3259
+
33343260 /**
33353261 * kmsg_dump - dump kernel log to kernel message dumpers.
33363262 * @reason: the reason (oops, panic etc) for dumping
....@@ -3344,12 +3270,19 @@
33443270 struct kmsg_dumper *dumper;
33453271 unsigned long flags;
33463272
3347
- if ((reason > KMSG_DUMP_OOPS) && !always_kmsg_dump)
3348
- return;
3349
-
33503273 rcu_read_lock();
33513274 list_for_each_entry_rcu(dumper, &dump_list, list) {
3352
- if (dumper->max_reason && reason > dumper->max_reason)
3275
+ enum kmsg_dump_reason max_reason = dumper->max_reason;
3276
+
3277
+ /*
3278
+ * If client has not provided a specific max_reason, default
3279
+ * to KMSG_DUMP_OOPS, unless always_kmsg_dump was set.
3280
+ */
3281
+ if (max_reason == KMSG_DUMP_UNDEF) {
3282
+ max_reason = always_kmsg_dump ? KMSG_DUMP_MAX :
3283
+ KMSG_DUMP_OOPS;
3284
+ }
3285
+ if (reason > max_reason)
33533286 continue;
33543287
33553288 /* initialize iterator with data about the stored records */
....@@ -3357,9 +3290,7 @@
33573290
33583291 logbuf_lock_irqsave(flags);
33593292 dumper->cur_seq = clear_seq;
3360
- dumper->cur_idx = clear_idx;
3361
- dumper->next_seq = log_next_seq;
3362
- dumper->next_idx = log_next_idx;
3293
+ dumper->next_seq = prb_next_seq(prb);
33633294 logbuf_unlock_irqrestore(flags);
33643295
33653296 /* invoke dumper which will iterate over records */
....@@ -3393,28 +3324,33 @@
33933324 bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog,
33943325 char *line, size_t size, size_t *len)
33953326 {
3396
- struct printk_log *msg;
3327
+ struct printk_info info;
3328
+ unsigned int line_count;
3329
+ struct printk_record r;
33973330 size_t l = 0;
33983331 bool ret = false;
3332
+
3333
+ prb_rec_init_rd(&r, &info, line, size);
33993334
34003335 if (!dumper->active)
34013336 goto out;
34023337
3403
- if (dumper->cur_seq < log_first_seq) {
3404
- /* messages are gone, move to first available one */
3405
- dumper->cur_seq = log_first_seq;
3406
- dumper->cur_idx = log_first_idx;
3338
+ /* Read text or count text lines? */
3339
+ if (line) {
3340
+ if (!prb_read_valid(prb, dumper->cur_seq, &r))
3341
+ goto out;
3342
+ l = record_print_text(&r, syslog, printk_time);
3343
+ } else {
3344
+ if (!prb_read_valid_info(prb, dumper->cur_seq,
3345
+ &info, &line_count)) {
3346
+ goto out;
3347
+ }
3348
+ l = get_record_print_text_size(&info, line_count, syslog,
3349
+ printk_time);
3350
+
34073351 }
34083352
3409
- /* last entry */
3410
- if (dumper->cur_seq >= log_next_seq)
3411
- goto out;
3412
-
3413
- msg = log_from_idx(dumper->cur_idx);
3414
- l = msg_print_text(msg, syslog, line, size);
3415
-
3416
- dumper->cur_idx = log_next(dumper->cur_idx);
3417
- dumper->cur_seq++;
3353
+ dumper->cur_seq = r.info->seq + 1;
34183354 ret = true;
34193355 out:
34203356 if (len)
....@@ -3462,7 +3398,7 @@
34623398 * @len: length of line placed into buffer
34633399 *
34643400 * Start at the end of the kmsg buffer and fill the provided buffer
3465
- * with as many of the the *youngest* kmsg records that fit into it.
3401
+ * with as many of the *youngest* kmsg records that fit into it.
34663402 * If the buffer is large enough, all available kmsg records will be
34673403 * copied with a single call.
34683404 *
....@@ -3475,22 +3411,27 @@
34753411 bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
34763412 char *buf, size_t size, size_t *len)
34773413 {
3414
+ struct printk_info info;
3415
+ unsigned int line_count;
3416
+ struct printk_record r;
34783417 unsigned long flags;
34793418 u64 seq;
3480
- u32 idx;
34813419 u64 next_seq;
3482
- u32 next_idx;
34833420 size_t l = 0;
34843421 bool ret = false;
3422
+ bool time = printk_time;
34853423
3486
- if (!dumper->active)
3424
+ prb_rec_init_rd(&r, &info, buf, size);
3425
+
3426
+ if (!dumper->active || !buf || !size)
34873427 goto out;
34883428
34893429 logbuf_lock_irqsave(flags);
3490
- if (dumper->cur_seq < log_first_seq) {
3491
- /* messages are gone, move to first available one */
3492
- dumper->cur_seq = log_first_seq;
3493
- dumper->cur_idx = log_first_idx;
3430
+ if (prb_read_valid_info(prb, dumper->cur_seq, &info, NULL)) {
3431
+ if (info.seq != dumper->cur_seq) {
3432
+ /* messages are gone, move to first available one */
3433
+ dumper->cur_seq = info.seq;
3434
+ }
34943435 }
34953436
34963437 /* last entry */
....@@ -3501,41 +3442,41 @@
35013442
35023443 /* calculate length of entire buffer */
35033444 seq = dumper->cur_seq;
3504
- idx = dumper->cur_idx;
3505
- while (seq < dumper->next_seq) {
3506
- struct printk_log *msg = log_from_idx(idx);
3507
-
3508
- l += msg_print_text(msg, true, NULL, 0);
3509
- idx = log_next(idx);
3510
- seq++;
3445
+ while (prb_read_valid_info(prb, seq, &info, &line_count)) {
3446
+ if (r.info->seq >= dumper->next_seq)
3447
+ break;
3448
+ l += get_record_print_text_size(&info, line_count, syslog, time);
3449
+ seq = r.info->seq + 1;
35113450 }
35123451
35133452 /* move first record forward until length fits into the buffer */
35143453 seq = dumper->cur_seq;
3515
- idx = dumper->cur_idx;
3516
- while (l >= size && seq < dumper->next_seq) {
3517
- struct printk_log *msg = log_from_idx(idx);
3518
-
3519
- l -= msg_print_text(msg, true, NULL, 0);
3520
- idx = log_next(idx);
3521
- seq++;
3454
+ while (l >= size && prb_read_valid_info(prb, seq,
3455
+ &info, &line_count)) {
3456
+ if (r.info->seq >= dumper->next_seq)
3457
+ break;
3458
+ l -= get_record_print_text_size(&info, line_count, syslog, time);
3459
+ seq = r.info->seq + 1;
35223460 }
35233461
35243462 /* last message in next interation */
35253463 next_seq = seq;
3526
- next_idx = idx;
35273464
3465
+ /* actually read text into the buffer now */
35283466 l = 0;
3529
- while (seq < dumper->next_seq) {
3530
- struct printk_log *msg = log_from_idx(idx);
3467
+ while (prb_read_valid(prb, seq, &r)) {
3468
+ if (r.info->seq >= dumper->next_seq)
3469
+ break;
35313470
3532
- l += msg_print_text(msg, syslog, buf + l, size - l);
3533
- idx = log_next(idx);
3534
- seq++;
3471
+ l += record_print_text(&r, syslog, time);
3472
+
3473
+ /* adjust record to store to remaining buffer space */
3474
+ prb_rec_init_rd(&r, &info, buf + l, size - l);
3475
+
3476
+ seq = r.info->seq + 1;
35353477 }
35363478
35373479 dumper->next_seq = next_seq;
3538
- dumper->next_idx = next_idx;
35393480 ret = true;
35403481 logbuf_unlock_irqrestore(flags);
35413482 out:
....@@ -3546,7 +3487,7 @@
35463487 EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer);
35473488
35483489 /**
3549
- * kmsg_dump_rewind_nolock - reset the interator (unlocked version)
3490
+ * kmsg_dump_rewind_nolock - reset the iterator (unlocked version)
35503491 * @dumper: registered kmsg dumper
35513492 *
35523493 * Reset the dumper's iterator so that kmsg_dump_get_line() and
....@@ -3558,13 +3499,11 @@
35583499 void kmsg_dump_rewind_nolock(struct kmsg_dumper *dumper)
35593500 {
35603501 dumper->cur_seq = clear_seq;
3561
- dumper->cur_idx = clear_idx;
3562
- dumper->next_seq = log_next_seq;
3563
- dumper->next_idx = log_next_idx;
3502
+ dumper->next_seq = prb_next_seq(prb);
35643503 }
35653504
35663505 /**
3567
- * kmsg_dump_rewind - reset the interator
3506
+ * kmsg_dump_rewind - reset the iterator
35683507 * @dumper: registered kmsg dumper
35693508 *
35703509 * Reset the dumper's iterator so that kmsg_dump_get_line() and