diff options
Diffstat (limited to 'kernel/printk.c')
-rw-r--r-- | kernel/printk.c | 866 |
1 files changed, 670 insertions, 196 deletions
diff --git a/kernel/printk.c b/kernel/printk.c index 32462d2b364a..66a2ea37b576 100644 --- a/kernel/printk.c +++ b/kernel/printk.c | |||
@@ -193,12 +193,21 @@ static int console_may_schedule; | |||
193 | * separated by ',', and find the message after the ';' character. | 193 | * separated by ',', and find the message after the ';' character. |
194 | */ | 194 | */ |
195 | 195 | ||
196 | enum log_flags { | ||
197 | LOG_NOCONS = 1, /* already flushed, do not print to console */ | ||
198 | LOG_NEWLINE = 2, /* text ended with a newline */ | ||
199 | LOG_PREFIX = 4, /* text started with a prefix */ | ||
200 | LOG_CONT = 8, /* text is a fragment of a continuation line */ | ||
201 | }; | ||
202 | |||
196 | struct log { | 203 | struct log { |
197 | u64 ts_nsec; /* timestamp in nanoseconds */ | 204 | u64 ts_nsec; /* timestamp in nanoseconds */ |
198 | u16 len; /* length of entire record */ | 205 | u16 len; /* length of entire record */ |
199 | u16 text_len; /* length of text buffer */ | 206 | u16 text_len; /* length of text buffer */ |
200 | u16 dict_len; /* length of dictionary buffer */ | 207 | u16 dict_len; /* length of dictionary buffer */ |
201 | u16 level; /* syslog level + facility */ | 208 | u8 facility; /* syslog facility */ |
209 | u8 flags:5; /* internal record flags */ | ||
210 | u8 level:3; /* syslog level */ | ||
202 | }; | 211 | }; |
203 | 212 | ||
204 | /* | 213 | /* |
@@ -207,9 +216,12 @@ struct log { | |||
207 | */ | 216 | */ |
208 | static DEFINE_RAW_SPINLOCK(logbuf_lock); | 217 | static DEFINE_RAW_SPINLOCK(logbuf_lock); |
209 | 218 | ||
219 | #ifdef CONFIG_PRINTK | ||
210 | /* the next printk record to read by syslog(READ) or /proc/kmsg */ | 220 | /* the next printk record to read by syslog(READ) or /proc/kmsg */ |
211 | static u64 syslog_seq; | 221 | static u64 syslog_seq; |
212 | static u32 syslog_idx; | 222 | static u32 syslog_idx; |
223 | static enum log_flags syslog_prev; | ||
224 | static size_t syslog_partial; | ||
213 | 225 | ||
214 | /* index and sequence number of the first record stored in the buffer */ | 226 | /* index and sequence number of the first record stored in the buffer */ |
215 | static u64 log_first_seq; | 227 | static u64 log_first_seq; |
@@ -217,20 +229,25 @@ static u32 log_first_idx; | |||
217 | 229 | ||
218 | /* index and sequence number of the next record to store in the buffer */ | 230 | /* index and sequence number of the next record to store in the buffer */ |
219 | static u64 log_next_seq; | 231 | static u64 log_next_seq; |
220 | #ifdef CONFIG_PRINTK | ||
221 | static u32 log_next_idx; | 232 | static u32 log_next_idx; |
222 | 233 | ||
234 | /* the next printk record to write to the console */ | ||
235 | static u64 console_seq; | ||
236 | static u32 console_idx; | ||
237 | static enum log_flags console_prev; | ||
238 | |||
223 | /* the next printk record to read after the last 'clear' command */ | 239 | /* the next printk record to read after the last 'clear' command */ |
224 | static u64 clear_seq; | 240 | static u64 clear_seq; |
225 | static u32 clear_idx; | 241 | static u32 clear_idx; |
226 | 242 | ||
227 | #define LOG_LINE_MAX 1024 | 243 | #define PREFIX_MAX 32 |
244 | #define LOG_LINE_MAX 1024 - PREFIX_MAX | ||
228 | 245 | ||
229 | /* record buffer */ | 246 | /* record buffer */ |
230 | #if !defined(CONFIG_64BIT) || defined(CONFIG_HAVE_EFFICIENT_UNALIGNED_ACCESS) | 247 | #if defined(CONFIG_HAVE_EFFICIENT_UNALIGNED_ACCESS) |
231 | #define LOG_ALIGN 4 | 248 | #define LOG_ALIGN 4 |
232 | #else | 249 | #else |
233 | #define LOG_ALIGN 8 | 250 | #define LOG_ALIGN __alignof__(struct log) |
234 | #endif | 251 | #endif |
235 | #define __LOG_BUF_LEN (1 << CONFIG_LOG_BUF_SHIFT) | 252 | #define __LOG_BUF_LEN (1 << CONFIG_LOG_BUF_SHIFT) |
236 | static char __log_buf[__LOG_BUF_LEN] __aligned(LOG_ALIGN); | 253 | static char __log_buf[__LOG_BUF_LEN] __aligned(LOG_ALIGN); |
@@ -286,6 +303,7 @@ static u32 log_next(u32 idx) | |||
286 | 303 | ||
287 | /* insert record into the buffer, discard old ones, update heads */ | 304 | /* insert record into the buffer, discard old ones, update heads */ |
288 | static void log_store(int facility, int level, | 305 | static void log_store(int facility, int level, |
306 | enum log_flags flags, u64 ts_nsec, | ||
289 | const char *dict, u16 dict_len, | 307 | const char *dict, u16 dict_len, |
290 | const char *text, u16 text_len) | 308 | const char *text, u16 text_len) |
291 | { | 309 | { |
@@ -329,8 +347,13 @@ static void log_store(int facility, int level, | |||
329 | msg->text_len = text_len; | 347 | msg->text_len = text_len; |
330 | memcpy(log_dict(msg), dict, dict_len); | 348 | memcpy(log_dict(msg), dict, dict_len); |
331 | msg->dict_len = dict_len; | 349 | msg->dict_len = dict_len; |
332 | msg->level = (facility << 3) | (level & 7); | 350 | msg->facility = facility; |
333 | msg->ts_nsec = local_clock(); | 351 | msg->level = level & 7; |
352 | msg->flags = flags & 0x1f; | ||
353 | if (ts_nsec > 0) | ||
354 | msg->ts_nsec = ts_nsec; | ||
355 | else | ||
356 | msg->ts_nsec = local_clock(); | ||
334 | memset(log_dict(msg) + dict_len, 0, pad_len); | 357 | memset(log_dict(msg) + dict_len, 0, pad_len); |
335 | msg->len = sizeof(struct log) + text_len + dict_len + pad_len; | 358 | msg->len = sizeof(struct log) + text_len + dict_len + pad_len; |
336 | 359 | ||
@@ -343,6 +366,7 @@ static void log_store(int facility, int level, | |||
343 | struct devkmsg_user { | 366 | struct devkmsg_user { |
344 | u64 seq; | 367 | u64 seq; |
345 | u32 idx; | 368 | u32 idx; |
369 | enum log_flags prev; | ||
346 | struct mutex lock; | 370 | struct mutex lock; |
347 | char buf[8192]; | 371 | char buf[8192]; |
348 | }; | 372 | }; |
@@ -365,8 +389,10 @@ static ssize_t devkmsg_writev(struct kiocb *iocb, const struct iovec *iv, | |||
365 | 389 | ||
366 | line = buf; | 390 | line = buf; |
367 | for (i = 0; i < count; i++) { | 391 | for (i = 0; i < count; i++) { |
368 | if (copy_from_user(line, iv[i].iov_base, iv[i].iov_len)) | 392 | if (copy_from_user(line, iv[i].iov_base, iv[i].iov_len)) { |
393 | ret = -EFAULT; | ||
369 | goto out; | 394 | goto out; |
395 | } | ||
370 | line += iv[i].iov_len; | 396 | line += iv[i].iov_len; |
371 | } | 397 | } |
372 | 398 | ||
@@ -408,27 +434,30 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf, | |||
408 | struct log *msg; | 434 | struct log *msg; |
409 | u64 ts_usec; | 435 | u64 ts_usec; |
410 | size_t i; | 436 | size_t i; |
437 | char cont = '-'; | ||
411 | size_t len; | 438 | size_t len; |
412 | ssize_t ret; | 439 | ssize_t ret; |
413 | 440 | ||
414 | if (!user) | 441 | if (!user) |
415 | return -EBADF; | 442 | return -EBADF; |
416 | 443 | ||
417 | mutex_lock(&user->lock); | 444 | ret = mutex_lock_interruptible(&user->lock); |
418 | raw_spin_lock(&logbuf_lock); | 445 | if (ret) |
446 | return ret; | ||
447 | raw_spin_lock_irq(&logbuf_lock); | ||
419 | while (user->seq == log_next_seq) { | 448 | while (user->seq == log_next_seq) { |
420 | if (file->f_flags & O_NONBLOCK) { | 449 | if (file->f_flags & O_NONBLOCK) { |
421 | ret = -EAGAIN; | 450 | ret = -EAGAIN; |
422 | raw_spin_unlock(&logbuf_lock); | 451 | raw_spin_unlock_irq(&logbuf_lock); |
423 | goto out; | 452 | goto out; |
424 | } | 453 | } |
425 | 454 | ||
426 | raw_spin_unlock(&logbuf_lock); | 455 | raw_spin_unlock_irq(&logbuf_lock); |
427 | ret = wait_event_interruptible(log_wait, | 456 | ret = wait_event_interruptible(log_wait, |
428 | user->seq != log_next_seq); | 457 | user->seq != log_next_seq); |
429 | if (ret) | 458 | if (ret) |
430 | goto out; | 459 | goto out; |
431 | raw_spin_lock(&logbuf_lock); | 460 | raw_spin_lock_irq(&logbuf_lock); |
432 | } | 461 | } |
433 | 462 | ||
434 | if (user->seq < log_first_seq) { | 463 | if (user->seq < log_first_seq) { |
@@ -436,21 +465,38 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf, | |||
436 | user->idx = log_first_idx; | 465 | user->idx = log_first_idx; |
437 | user->seq = log_first_seq; | 466 | user->seq = log_first_seq; |
438 | ret = -EPIPE; | 467 | ret = -EPIPE; |
439 | raw_spin_unlock(&logbuf_lock); | 468 | raw_spin_unlock_irq(&logbuf_lock); |
440 | goto out; | 469 | goto out; |
441 | } | 470 | } |
442 | 471 | ||
443 | msg = log_from_idx(user->idx); | 472 | msg = log_from_idx(user->idx); |
444 | ts_usec = msg->ts_nsec; | 473 | ts_usec = msg->ts_nsec; |
445 | do_div(ts_usec, 1000); | 474 | do_div(ts_usec, 1000); |
446 | len = sprintf(user->buf, "%u,%llu,%llu;", | 475 | |
447 | msg->level, user->seq, ts_usec); | 476 | /* |
477 | * If we couldn't merge continuation line fragments during the print, | ||
478 | * export the stored flags to allow an optional external merge of the | ||
479 | * records. Merging the records isn't always neccessarily correct, like | ||
480 | * when we hit a race during printing. In most cases though, it produces | ||
481 | * better readable output. 'c' in the record flags mark the first | ||
482 | * fragment of a line, '+' the following. | ||
483 | */ | ||
484 | if (msg->flags & LOG_CONT && !(user->prev & LOG_CONT)) | ||
485 | cont = 'c'; | ||
486 | else if ((msg->flags & LOG_CONT) || | ||
487 | ((user->prev & LOG_CONT) && !(msg->flags & LOG_PREFIX))) | ||
488 | cont = '+'; | ||
489 | |||
490 | len = sprintf(user->buf, "%u,%llu,%llu,%c;", | ||
491 | (msg->facility << 3) | msg->level, | ||
492 | user->seq, ts_usec, cont); | ||
493 | user->prev = msg->flags; | ||
448 | 494 | ||
449 | /* escape non-printable characters */ | 495 | /* escape non-printable characters */ |
450 | for (i = 0; i < msg->text_len; i++) { | 496 | for (i = 0; i < msg->text_len; i++) { |
451 | unsigned char c = log_text(msg)[i]; | 497 | unsigned char c = log_text(msg)[i]; |
452 | 498 | ||
453 | if (c < ' ' || c >= 128) | 499 | if (c < ' ' || c >= 127 || c == '\\') |
454 | len += sprintf(user->buf + len, "\\x%02x", c); | 500 | len += sprintf(user->buf + len, "\\x%02x", c); |
455 | else | 501 | else |
456 | user->buf[len++] = c; | 502 | user->buf[len++] = c; |
@@ -474,7 +520,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf, | |||
474 | continue; | 520 | continue; |
475 | } | 521 | } |
476 | 522 | ||
477 | if (c < ' ' || c >= 128) { | 523 | if (c < ' ' || c >= 127 || c == '\\') { |
478 | len += sprintf(user->buf + len, "\\x%02x", c); | 524 | len += sprintf(user->buf + len, "\\x%02x", c); |
479 | continue; | 525 | continue; |
480 | } | 526 | } |
@@ -486,7 +532,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf, | |||
486 | 532 | ||
487 | user->idx = log_next(user->idx); | 533 | user->idx = log_next(user->idx); |
488 | user->seq++; | 534 | user->seq++; |
489 | raw_spin_unlock(&logbuf_lock); | 535 | raw_spin_unlock_irq(&logbuf_lock); |
490 | 536 | ||
491 | if (len > count) { | 537 | if (len > count) { |
492 | ret = -EINVAL; | 538 | ret = -EINVAL; |
@@ -513,7 +559,7 @@ static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence) | |||
513 | if (offset) | 559 | if (offset) |
514 | return -ESPIPE; | 560 | return -ESPIPE; |
515 | 561 | ||
516 | raw_spin_lock(&logbuf_lock); | 562 | raw_spin_lock_irq(&logbuf_lock); |
517 | switch (whence) { | 563 | switch (whence) { |
518 | case SEEK_SET: | 564 | case SEEK_SET: |
519 | /* the first record */ | 565 | /* the first record */ |
@@ -537,7 +583,7 @@ static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence) | |||
537 | default: | 583 | default: |
538 | ret = -EINVAL; | 584 | ret = -EINVAL; |
539 | } | 585 | } |
540 | raw_spin_unlock(&logbuf_lock); | 586 | raw_spin_unlock_irq(&logbuf_lock); |
541 | return ret; | 587 | return ret; |
542 | } | 588 | } |
543 | 589 | ||
@@ -551,14 +597,14 @@ static unsigned int devkmsg_poll(struct file *file, poll_table *wait) | |||
551 | 597 | ||
552 | poll_wait(file, &log_wait, wait); | 598 | poll_wait(file, &log_wait, wait); |
553 | 599 | ||
554 | raw_spin_lock(&logbuf_lock); | 600 | raw_spin_lock_irq(&logbuf_lock); |
555 | if (user->seq < log_next_seq) { | 601 | if (user->seq < log_next_seq) { |
556 | /* return error when data has vanished underneath us */ | 602 | /* return error when data has vanished underneath us */ |
557 | if (user->seq < log_first_seq) | 603 | if (user->seq < log_first_seq) |
558 | ret = POLLIN|POLLRDNORM|POLLERR|POLLPRI; | 604 | ret = POLLIN|POLLRDNORM|POLLERR|POLLPRI; |
559 | ret = POLLIN|POLLRDNORM; | 605 | ret = POLLIN|POLLRDNORM; |
560 | } | 606 | } |
561 | raw_spin_unlock(&logbuf_lock); | 607 | raw_spin_unlock_irq(&logbuf_lock); |
562 | 608 | ||
563 | return ret; | 609 | return ret; |
564 | } | 610 | } |
@@ -582,10 +628,10 @@ static int devkmsg_open(struct inode *inode, struct file *file) | |||
582 | 628 | ||
583 | mutex_init(&user->lock); | 629 | mutex_init(&user->lock); |
584 | 630 | ||
585 | raw_spin_lock(&logbuf_lock); | 631 | raw_spin_lock_irq(&logbuf_lock); |
586 | user->idx = log_first_idx; | 632 | user->idx = log_first_idx; |
587 | user->seq = log_first_seq; | 633 | user->seq = log_first_seq; |
588 | raw_spin_unlock(&logbuf_lock); | 634 | raw_spin_unlock_irq(&logbuf_lock); |
589 | 635 | ||
590 | file->private_data = user; | 636 | file->private_data = user; |
591 | return 0; | 637 | return 0; |
@@ -627,6 +673,15 @@ void log_buf_kexec_setup(void) | |||
627 | VMCOREINFO_SYMBOL(log_buf_len); | 673 | VMCOREINFO_SYMBOL(log_buf_len); |
628 | VMCOREINFO_SYMBOL(log_first_idx); | 674 | VMCOREINFO_SYMBOL(log_first_idx); |
629 | VMCOREINFO_SYMBOL(log_next_idx); | 675 | VMCOREINFO_SYMBOL(log_next_idx); |
676 | /* | ||
677 | * Export struct log size and field offsets. User space tools can | ||
678 | * parse it and detect any changes to structure down the line. | ||
679 | */ | ||
680 | VMCOREINFO_STRUCT_SIZE(log); | ||
681 | VMCOREINFO_OFFSET(log, ts_nsec); | ||
682 | VMCOREINFO_OFFSET(log, len); | ||
683 | VMCOREINFO_OFFSET(log, text_len); | ||
684 | VMCOREINFO_OFFSET(log, dict_len); | ||
630 | } | 685 | } |
631 | #endif | 686 | #endif |
632 | 687 | ||
@@ -785,44 +840,64 @@ static bool printk_time; | |||
785 | #endif | 840 | #endif |
786 | module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR); | 841 | module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR); |
787 | 842 | ||
843 | static size_t print_time(u64 ts, char *buf) | ||
844 | { | ||
845 | unsigned long rem_nsec; | ||
846 | |||
847 | if (!printk_time) | ||
848 | return 0; | ||
849 | |||
850 | if (!buf) | ||
851 | return 15; | ||
852 | |||
853 | rem_nsec = do_div(ts, 1000000000); | ||
854 | return sprintf(buf, "[%5lu.%06lu] ", | ||
855 | (unsigned long)ts, rem_nsec / 1000); | ||
856 | } | ||
857 | |||
788 | static size_t print_prefix(const struct log *msg, bool syslog, char *buf) | 858 | static size_t print_prefix(const struct log *msg, bool syslog, char *buf) |
789 | { | 859 | { |
790 | size_t len = 0; | 860 | size_t len = 0; |
861 | unsigned int prefix = (msg->facility << 3) | msg->level; | ||
791 | 862 | ||
792 | if (syslog) { | 863 | if (syslog) { |
793 | if (buf) { | 864 | if (buf) { |
794 | len += sprintf(buf, "<%u>", msg->level); | 865 | len += sprintf(buf, "<%u>", prefix); |
795 | } else { | 866 | } else { |
796 | len += 3; | 867 | len += 3; |
797 | if (msg->level > 9) | 868 | if (prefix > 999) |
798 | len++; | 869 | len += 3; |
799 | if (msg->level > 99) | 870 | else if (prefix > 99) |
871 | len += 2; | ||
872 | else if (prefix > 9) | ||
800 | len++; | 873 | len++; |
801 | } | 874 | } |
802 | } | 875 | } |
803 | 876 | ||
804 | if (printk_time) { | 877 | len += print_time(msg->ts_nsec, buf ? buf + len : NULL); |
805 | if (buf) { | ||
806 | unsigned long long ts = msg->ts_nsec; | ||
807 | unsigned long rem_nsec = do_div(ts, 1000000000); | ||
808 | |||
809 | len += sprintf(buf + len, "[%5lu.%06lu] ", | ||
810 | (unsigned long) ts, rem_nsec / 1000); | ||
811 | } else { | ||
812 | len += 15; | ||
813 | } | ||
814 | } | ||
815 | |||
816 | return len; | 878 | return len; |
817 | } | 879 | } |
818 | 880 | ||
819 | static size_t msg_print_text(const struct log *msg, bool syslog, | 881 | static size_t msg_print_text(const struct log *msg, enum log_flags prev, |
820 | char *buf, size_t size) | 882 | bool syslog, char *buf, size_t size) |
821 | { | 883 | { |
822 | const char *text = log_text(msg); | 884 | const char *text = log_text(msg); |
823 | size_t text_size = msg->text_len; | 885 | size_t text_size = msg->text_len; |
886 | bool prefix = true; | ||
887 | bool newline = true; | ||
824 | size_t len = 0; | 888 | size_t len = 0; |
825 | 889 | ||
890 | if ((prev & LOG_CONT) && !(msg->flags & LOG_PREFIX)) | ||
891 | prefix = false; | ||
892 | |||
893 | if (msg->flags & LOG_CONT) { | ||
894 | if ((prev & LOG_CONT) && !(prev & LOG_NEWLINE)) | ||
895 | prefix = false; | ||
896 | |||
897 | if (!(msg->flags & LOG_NEWLINE)) | ||
898 | newline = false; | ||
899 | } | ||
900 | |||
826 | do { | 901 | do { |
827 | const char *next = memchr(text, '\n', text_size); | 902 | const char *next = memchr(text, '\n', text_size); |
828 | size_t text_len; | 903 | size_t text_len; |
@@ -837,19 +912,25 @@ static size_t msg_print_text(const struct log *msg, bool syslog, | |||
837 | 912 | ||
838 | if (buf) { | 913 | if (buf) { |
839 | if (print_prefix(msg, syslog, NULL) + | 914 | if (print_prefix(msg, syslog, NULL) + |
840 | text_len + 1>= size - len) | 915 | text_len + 1 >= size - len) |
841 | break; | 916 | break; |
842 | 917 | ||
843 | len += print_prefix(msg, syslog, buf + len); | 918 | if (prefix) |
919 | len += print_prefix(msg, syslog, buf + len); | ||
844 | memcpy(buf + len, text, text_len); | 920 | memcpy(buf + len, text, text_len); |
845 | len += text_len; | 921 | len += text_len; |
846 | buf[len++] = '\n'; | 922 | if (next || newline) |
923 | buf[len++] = '\n'; | ||
847 | } else { | 924 | } else { |
848 | /* SYSLOG_ACTION_* buffer size only calculation */ | 925 | /* SYSLOG_ACTION_* buffer size only calculation */ |
849 | len += print_prefix(msg, syslog, NULL); | 926 | if (prefix) |
850 | len += text_len + 1; | 927 | len += print_prefix(msg, syslog, NULL); |
928 | len += text_len; | ||
929 | if (next || newline) | ||
930 | len++; | ||
851 | } | 931 | } |
852 | 932 | ||
933 | prefix = true; | ||
853 | text = next; | 934 | text = next; |
854 | } while (text); | 935 | } while (text); |
855 | 936 | ||
@@ -860,26 +941,61 @@ static int syslog_print(char __user *buf, int size) | |||
860 | { | 941 | { |
861 | char *text; | 942 | char *text; |
862 | struct log *msg; | 943 | struct log *msg; |
863 | int len; | 944 | int len = 0; |
864 | 945 | ||
865 | text = kmalloc(LOG_LINE_MAX, GFP_KERNEL); | 946 | text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL); |
866 | if (!text) | 947 | if (!text) |
867 | return -ENOMEM; | 948 | return -ENOMEM; |
868 | 949 | ||
869 | raw_spin_lock_irq(&logbuf_lock); | 950 | while (size > 0) { |
870 | if (syslog_seq < log_first_seq) { | 951 | size_t n; |
871 | /* messages are gone, move to first one */ | 952 | size_t skip; |
872 | syslog_seq = log_first_seq; | 953 | |
873 | syslog_idx = log_first_idx; | 954 | raw_spin_lock_irq(&logbuf_lock); |
874 | } | 955 | if (syslog_seq < log_first_seq) { |
875 | msg = log_from_idx(syslog_idx); | 956 | /* messages are gone, move to first one */ |
876 | len = msg_print_text(msg, true, text, LOG_LINE_MAX); | 957 | syslog_seq = log_first_seq; |
877 | syslog_idx = log_next(syslog_idx); | 958 | syslog_idx = log_first_idx; |
878 | syslog_seq++; | 959 | syslog_prev = 0; |
879 | raw_spin_unlock_irq(&logbuf_lock); | 960 | syslog_partial = 0; |
961 | } | ||
962 | if (syslog_seq == log_next_seq) { | ||
963 | raw_spin_unlock_irq(&logbuf_lock); | ||
964 | break; | ||
965 | } | ||
880 | 966 | ||
881 | if (len > 0 && copy_to_user(buf, text, len)) | 967 | skip = syslog_partial; |
882 | len = -EFAULT; | 968 | msg = log_from_idx(syslog_idx); |
969 | n = msg_print_text(msg, syslog_prev, true, text, | ||
970 | LOG_LINE_MAX + PREFIX_MAX); | ||
971 | if (n - syslog_partial <= size) { | ||
972 | /* message fits into buffer, move forward */ | ||
973 | syslog_idx = log_next(syslog_idx); | ||
974 | syslog_seq++; | ||
975 | syslog_prev = msg->flags; | ||
976 | n -= syslog_partial; | ||
977 | syslog_partial = 0; | ||
978 | } else if (!len){ | ||
979 | /* partial read(), remember position */ | ||
980 | n = size; | ||
981 | syslog_partial += n; | ||
982 | } else | ||
983 | n = 0; | ||
984 | raw_spin_unlock_irq(&logbuf_lock); | ||
985 | |||
986 | if (!n) | ||
987 | break; | ||
988 | |||
989 | if (copy_to_user(buf, text + skip, n)) { | ||
990 | if (!len) | ||
991 | len = -EFAULT; | ||
992 | break; | ||
993 | } | ||
994 | |||
995 | len += n; | ||
996 | size -= n; | ||
997 | buf += n; | ||
998 | } | ||
883 | 999 | ||
884 | kfree(text); | 1000 | kfree(text); |
885 | return len; | 1001 | return len; |
@@ -890,7 +1006,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear) | |||
890 | char *text; | 1006 | char *text; |
891 | int len = 0; | 1007 | int len = 0; |
892 | 1008 | ||
893 | text = kmalloc(LOG_LINE_MAX, GFP_KERNEL); | 1009 | text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL); |
894 | if (!text) | 1010 | if (!text) |
895 | return -ENOMEM; | 1011 | return -ENOMEM; |
896 | 1012 | ||
@@ -899,6 +1015,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear) | |||
899 | u64 next_seq; | 1015 | u64 next_seq; |
900 | u64 seq; | 1016 | u64 seq; |
901 | u32 idx; | 1017 | u32 idx; |
1018 | enum log_flags prev; | ||
902 | 1019 | ||
903 | if (clear_seq < log_first_seq) { | 1020 | if (clear_seq < log_first_seq) { |
904 | /* messages are gone, move to first available one */ | 1021 | /* messages are gone, move to first available one */ |
@@ -909,41 +1026,50 @@ static int syslog_print_all(char __user *buf, int size, bool clear) | |||
909 | /* | 1026 | /* |
910 | * Find first record that fits, including all following records, | 1027 | * Find first record that fits, including all following records, |
911 | * into the user-provided buffer for this dump. | 1028 | * into the user-provided buffer for this dump. |
912 | */ | 1029 | */ |
913 | seq = clear_seq; | 1030 | seq = clear_seq; |
914 | idx = clear_idx; | 1031 | idx = clear_idx; |
1032 | prev = 0; | ||
915 | while (seq < log_next_seq) { | 1033 | while (seq < log_next_seq) { |
916 | struct log *msg = log_from_idx(idx); | 1034 | struct log *msg = log_from_idx(idx); |
917 | 1035 | ||
918 | len += msg_print_text(msg, true, NULL, 0); | 1036 | len += msg_print_text(msg, prev, true, NULL, 0); |
1037 | prev = msg->flags; | ||
919 | idx = log_next(idx); | 1038 | idx = log_next(idx); |
920 | seq++; | 1039 | seq++; |
921 | } | 1040 | } |
1041 | |||
1042 | /* move first record forward until length fits into the buffer */ | ||
922 | seq = clear_seq; | 1043 | seq = clear_seq; |
923 | idx = clear_idx; | 1044 | idx = clear_idx; |
1045 | prev = 0; | ||
924 | while (len > size && seq < log_next_seq) { | 1046 | while (len > size && seq < log_next_seq) { |
925 | struct log *msg = log_from_idx(idx); | 1047 | struct log *msg = log_from_idx(idx); |
926 | 1048 | ||
927 | len -= msg_print_text(msg, true, NULL, 0); | 1049 | len -= msg_print_text(msg, prev, true, NULL, 0); |
1050 | prev = msg->flags; | ||
928 | idx = log_next(idx); | 1051 | idx = log_next(idx); |
929 | seq++; | 1052 | seq++; |
930 | } | 1053 | } |
931 | 1054 | ||
932 | /* last message in this dump */ | 1055 | /* last message fitting into this dump */ |
933 | next_seq = log_next_seq; | 1056 | next_seq = log_next_seq; |
934 | 1057 | ||
935 | len = 0; | 1058 | len = 0; |
1059 | prev = 0; | ||
936 | while (len >= 0 && seq < next_seq) { | 1060 | while (len >= 0 && seq < next_seq) { |
937 | struct log *msg = log_from_idx(idx); | 1061 | struct log *msg = log_from_idx(idx); |
938 | int textlen; | 1062 | int textlen; |
939 | 1063 | ||
940 | textlen = msg_print_text(msg, true, text, LOG_LINE_MAX); | 1064 | textlen = msg_print_text(msg, prev, true, text, |
1065 | LOG_LINE_MAX + PREFIX_MAX); | ||
941 | if (textlen < 0) { | 1066 | if (textlen < 0) { |
942 | len = textlen; | 1067 | len = textlen; |
943 | break; | 1068 | break; |
944 | } | 1069 | } |
945 | idx = log_next(idx); | 1070 | idx = log_next(idx); |
946 | seq++; | 1071 | seq++; |
1072 | prev = msg->flags; | ||
947 | 1073 | ||
948 | raw_spin_unlock_irq(&logbuf_lock); | 1074 | raw_spin_unlock_irq(&logbuf_lock); |
949 | if (copy_to_user(buf + len, text, textlen)) | 1075 | if (copy_to_user(buf + len, text, textlen)) |
@@ -956,6 +1082,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear) | |||
956 | /* messages are gone, move to next one */ | 1082 | /* messages are gone, move to next one */ |
957 | seq = log_first_seq; | 1083 | seq = log_first_seq; |
958 | idx = log_first_idx; | 1084 | idx = log_first_idx; |
1085 | prev = 0; | ||
959 | } | 1086 | } |
960 | } | 1087 | } |
961 | } | 1088 | } |
@@ -1027,6 +1154,7 @@ int do_syslog(int type, char __user *buf, int len, bool from_file) | |||
1027 | /* Clear ring buffer */ | 1154 | /* Clear ring buffer */ |
1028 | case SYSLOG_ACTION_CLEAR: | 1155 | case SYSLOG_ACTION_CLEAR: |
1029 | syslog_print_all(NULL, 0, true); | 1156 | syslog_print_all(NULL, 0, true); |
1157 | break; | ||
1030 | /* Disable logging to console */ | 1158 | /* Disable logging to console */ |
1031 | case SYSLOG_ACTION_CONSOLE_OFF: | 1159 | case SYSLOG_ACTION_CONSOLE_OFF: |
1032 | if (saved_console_loglevel == -1) | 1160 | if (saved_console_loglevel == -1) |
@@ -1059,6 +1187,8 @@ int do_syslog(int type, char __user *buf, int len, bool from_file) | |||
1059 | /* messages are gone, move to first one */ | 1187 | /* messages are gone, move to first one */ |
1060 | syslog_seq = log_first_seq; | 1188 | syslog_seq = log_first_seq; |
1061 | syslog_idx = log_first_idx; | 1189 | syslog_idx = log_first_idx; |
1190 | syslog_prev = 0; | ||
1191 | syslog_partial = 0; | ||
1062 | } | 1192 | } |
1063 | if (from_file) { | 1193 | if (from_file) { |
1064 | /* | 1194 | /* |
@@ -1068,19 +1198,20 @@ int do_syslog(int type, char __user *buf, int len, bool from_file) | |||
1068 | */ | 1198 | */ |
1069 | error = log_next_idx - syslog_idx; | 1199 | error = log_next_idx - syslog_idx; |
1070 | } else { | 1200 | } else { |
1071 | u64 seq; | 1201 | u64 seq = syslog_seq; |
1072 | u32 idx; | 1202 | u32 idx = syslog_idx; |
1203 | enum log_flags prev = syslog_prev; | ||
1073 | 1204 | ||
1074 | error = 0; | 1205 | error = 0; |
1075 | seq = syslog_seq; | ||
1076 | idx = syslog_idx; | ||
1077 | while (seq < log_next_seq) { | 1206 | while (seq < log_next_seq) { |
1078 | struct log *msg = log_from_idx(idx); | 1207 | struct log *msg = log_from_idx(idx); |
1079 | 1208 | ||
1080 | error += msg_print_text(msg, true, NULL, 0); | 1209 | error += msg_print_text(msg, prev, true, NULL, 0); |
1081 | idx = log_next(idx); | 1210 | idx = log_next(idx); |
1082 | seq++; | 1211 | seq++; |
1212 | prev = msg->flags; | ||
1083 | } | 1213 | } |
1214 | error -= syslog_partial; | ||
1084 | } | 1215 | } |
1085 | raw_spin_unlock_irq(&logbuf_lock); | 1216 | raw_spin_unlock_irq(&logbuf_lock); |
1086 | break; | 1217 | break; |
@@ -1101,21 +1232,6 @@ SYSCALL_DEFINE3(syslog, int, type, char __user *, buf, int, len) | |||
1101 | return do_syslog(type, buf, len, SYSLOG_FROM_CALL); | 1232 | return do_syslog(type, buf, len, SYSLOG_FROM_CALL); |
1102 | } | 1233 | } |
1103 | 1234 | ||
1104 | #ifdef CONFIG_KGDB_KDB | ||
1105 | /* kdb dmesg command needs access to the syslog buffer. do_syslog() | ||
1106 | * uses locks so it cannot be used during debugging. Just tell kdb | ||
1107 | * where the start and end of the physical and logical logs are. This | ||
1108 | * is equivalent to do_syslog(3). | ||
1109 | */ | ||
1110 | void kdb_syslog_data(char *syslog_data[4]) | ||
1111 | { | ||
1112 | syslog_data[0] = log_buf; | ||
1113 | syslog_data[1] = log_buf + log_buf_len; | ||
1114 | syslog_data[2] = log_buf + log_first_idx; | ||
1115 | syslog_data[3] = log_buf + log_next_idx; | ||
1116 | } | ||
1117 | #endif /* CONFIG_KGDB_KDB */ | ||
1118 | |||
1119 | static bool __read_mostly ignore_loglevel; | 1235 | static bool __read_mostly ignore_loglevel; |
1120 | 1236 | ||
1121 | static int __init ignore_loglevel_setup(char *str) | 1237 | static int __init ignore_loglevel_setup(char *str) |
@@ -1259,22 +1375,121 @@ static inline void printk_delay(void) | |||
1259 | } | 1375 | } |
1260 | } | 1376 | } |
1261 | 1377 | ||
1378 | /* | ||
1379 | * Continuation lines are buffered, and not committed to the record buffer | ||
1380 | * until the line is complete, or a race forces it. The line fragments | ||
1381 | * though, are printed immediately to the consoles to ensure everything has | ||
1382 | * reached the console in case of a kernel crash. | ||
1383 | */ | ||
1384 | static struct cont { | ||
1385 | char buf[LOG_LINE_MAX]; | ||
1386 | size_t len; /* length == 0 means unused buffer */ | ||
1387 | size_t cons; /* bytes written to console */ | ||
1388 | struct task_struct *owner; /* task of first print*/ | ||
1389 | u64 ts_nsec; /* time of first print */ | ||
1390 | u8 level; /* log level of first message */ | ||
1391 | u8 facility; /* log level of first message */ | ||
1392 | enum log_flags flags; /* prefix, newline flags */ | ||
1393 | bool flushed:1; /* buffer sealed and committed */ | ||
1394 | } cont; | ||
1395 | |||
1396 | static void cont_flush(enum log_flags flags) | ||
1397 | { | ||
1398 | if (cont.flushed) | ||
1399 | return; | ||
1400 | if (cont.len == 0) | ||
1401 | return; | ||
1402 | |||
1403 | if (cont.cons) { | ||
1404 | /* | ||
1405 | * If a fragment of this line was directly flushed to the | ||
1406 | * console; wait for the console to pick up the rest of the | ||
1407 | * line. LOG_NOCONS suppresses a duplicated output. | ||
1408 | */ | ||
1409 | log_store(cont.facility, cont.level, flags | LOG_NOCONS, | ||
1410 | cont.ts_nsec, NULL, 0, cont.buf, cont.len); | ||
1411 | cont.flags = flags; | ||
1412 | cont.flushed = true; | ||
1413 | } else { | ||
1414 | /* | ||
1415 | * If no fragment of this line ever reached the console, | ||
1416 | * just submit it to the store and free the buffer. | ||
1417 | */ | ||
1418 | log_store(cont.facility, cont.level, flags, 0, | ||
1419 | NULL, 0, cont.buf, cont.len); | ||
1420 | cont.len = 0; | ||
1421 | } | ||
1422 | } | ||
1423 | |||
1424 | static bool cont_add(int facility, int level, const char *text, size_t len) | ||
1425 | { | ||
1426 | if (cont.len && cont.flushed) | ||
1427 | return false; | ||
1428 | |||
1429 | if (cont.len + len > sizeof(cont.buf)) { | ||
1430 | /* the line gets too long, split it up in separate records */ | ||
1431 | cont_flush(LOG_CONT); | ||
1432 | return false; | ||
1433 | } | ||
1434 | |||
1435 | if (!cont.len) { | ||
1436 | cont.facility = facility; | ||
1437 | cont.level = level; | ||
1438 | cont.owner = current; | ||
1439 | cont.ts_nsec = local_clock(); | ||
1440 | cont.flags = 0; | ||
1441 | cont.cons = 0; | ||
1442 | cont.flushed = false; | ||
1443 | } | ||
1444 | |||
1445 | memcpy(cont.buf + cont.len, text, len); | ||
1446 | cont.len += len; | ||
1447 | |||
1448 | if (cont.len > (sizeof(cont.buf) * 80) / 100) | ||
1449 | cont_flush(LOG_CONT); | ||
1450 | |||
1451 | return true; | ||
1452 | } | ||
1453 | |||
1454 | static size_t cont_print_text(char *text, size_t size) | ||
1455 | { | ||
1456 | size_t textlen = 0; | ||
1457 | size_t len; | ||
1458 | |||
1459 | if (cont.cons == 0 && (console_prev & LOG_NEWLINE)) { | ||
1460 | textlen += print_time(cont.ts_nsec, text); | ||
1461 | size -= textlen; | ||
1462 | } | ||
1463 | |||
1464 | len = cont.len - cont.cons; | ||
1465 | if (len > 0) { | ||
1466 | if (len+1 > size) | ||
1467 | len = size-1; | ||
1468 | memcpy(text + textlen, cont.buf + cont.cons, len); | ||
1469 | textlen += len; | ||
1470 | cont.cons = cont.len; | ||
1471 | } | ||
1472 | |||
1473 | if (cont.flushed) { | ||
1474 | if (cont.flags & LOG_NEWLINE) | ||
1475 | text[textlen++] = '\n'; | ||
1476 | /* got everything, release buffer */ | ||
1477 | cont.len = 0; | ||
1478 | } | ||
1479 | return textlen; | ||
1480 | } | ||
1481 | |||
1262 | asmlinkage int vprintk_emit(int facility, int level, | 1482 | asmlinkage int vprintk_emit(int facility, int level, |
1263 | const char *dict, size_t dictlen, | 1483 | const char *dict, size_t dictlen, |
1264 | const char *fmt, va_list args) | 1484 | const char *fmt, va_list args) |
1265 | { | 1485 | { |
1266 | static int recursion_bug; | 1486 | static int recursion_bug; |
1267 | static char cont_buf[LOG_LINE_MAX]; | ||
1268 | static size_t cont_len; | ||
1269 | static int cont_level; | ||
1270 | static struct task_struct *cont_task; | ||
1271 | static char textbuf[LOG_LINE_MAX]; | 1487 | static char textbuf[LOG_LINE_MAX]; |
1272 | char *text = textbuf; | 1488 | char *text = textbuf; |
1273 | size_t text_len; | 1489 | size_t text_len; |
1490 | enum log_flags lflags = 0; | ||
1274 | unsigned long flags; | 1491 | unsigned long flags; |
1275 | int this_cpu; | 1492 | int this_cpu; |
1276 | bool newline = false; | ||
1277 | bool prefix = false; | ||
1278 | int printed_len = 0; | 1493 | int printed_len = 0; |
1279 | 1494 | ||
1280 | boot_delay_msec(); | 1495 | boot_delay_msec(); |
@@ -1313,7 +1528,8 @@ asmlinkage int vprintk_emit(int facility, int level, | |||
1313 | recursion_bug = 0; | 1528 | recursion_bug = 0; |
1314 | printed_len += strlen(recursion_msg); | 1529 | printed_len += strlen(recursion_msg); |
1315 | /* emit KERN_CRIT message */ | 1530 | /* emit KERN_CRIT message */ |
1316 | log_store(0, 2, NULL, 0, recursion_msg, printed_len); | 1531 | log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0, |
1532 | NULL, 0, recursion_msg, printed_len); | ||
1317 | } | 1533 | } |
1318 | 1534 | ||
1319 | /* | 1535 | /* |
@@ -1325,81 +1541,67 @@ asmlinkage int vprintk_emit(int facility, int level, | |||
1325 | /* mark and strip a trailing newline */ | 1541 | /* mark and strip a trailing newline */ |
1326 | if (text_len && text[text_len-1] == '\n') { | 1542 | if (text_len && text[text_len-1] == '\n') { |
1327 | text_len--; | 1543 | text_len--; |
1328 | newline = true; | 1544 | lflags |= LOG_NEWLINE; |
1329 | } | 1545 | } |
1330 | 1546 | ||
1331 | /* strip syslog prefix and extract log level or control flags */ | 1547 | /* strip kernel syslog prefix and extract log level or control flags */ |
1332 | if (text[0] == '<' && text[1] && text[2] == '>') { | 1548 | if (facility == 0) { |
1333 | switch (text[1]) { | 1549 | int kern_level = printk_get_level(text); |
1334 | case '0' ... '7': | 1550 | |
1335 | if (level == -1) | 1551 | if (kern_level) { |
1336 | level = text[1] - '0'; | 1552 | const char *end_of_header = printk_skip_level(text); |
1337 | case 'd': /* KERN_DEFAULT */ | 1553 | switch (kern_level) { |
1338 | prefix = true; | 1554 | case '0' ... '7': |
1339 | case 'c': /* KERN_CONT */ | 1555 | if (level == -1) |
1340 | text += 3; | 1556 | level = kern_level - '0'; |
1341 | text_len -= 3; | 1557 | case 'd': /* KERN_DEFAULT */ |
1558 | lflags |= LOG_PREFIX; | ||
1559 | case 'c': /* KERN_CONT */ | ||
1560 | break; | ||
1561 | } | ||
1562 | text_len -= end_of_header - text; | ||
1563 | text = (char *)end_of_header; | ||
1342 | } | 1564 | } |
1343 | } | 1565 | } |
1344 | 1566 | ||
1345 | if (level == -1) | 1567 | if (level == -1) |
1346 | level = default_message_loglevel; | 1568 | level = default_message_loglevel; |
1347 | 1569 | ||
1348 | if (dict) { | 1570 | if (dict) |
1349 | prefix = true; | 1571 | lflags |= LOG_PREFIX|LOG_NEWLINE; |
1350 | newline = true; | ||
1351 | } | ||
1352 | |||
1353 | if (!newline) { | ||
1354 | if (cont_len && (prefix || cont_task != current)) { | ||
1355 | /* | ||
1356 | * Flush earlier buffer, which is either from a | ||
1357 | * different thread, or when we got a new prefix. | ||
1358 | */ | ||
1359 | log_store(facility, cont_level, NULL, 0, cont_buf, cont_len); | ||
1360 | cont_len = 0; | ||
1361 | } | ||
1362 | 1572 | ||
1363 | if (!cont_len) { | 1573 | if (!(lflags & LOG_NEWLINE)) { |
1364 | cont_level = level; | 1574 | /* |
1365 | cont_task = current; | 1575 | * Flush the conflicting buffer. An earlier newline was missing, |
1366 | } | 1576 | * or another task also prints continuation lines. |
1577 | */ | ||
1578 | if (cont.len && (lflags & LOG_PREFIX || cont.owner != current)) | ||
1579 | cont_flush(LOG_NEWLINE); | ||
1367 | 1580 | ||
1368 | /* buffer or append to earlier buffer from the same thread */ | 1581 | /* buffer line if possible, otherwise store it right away */ |
1369 | if (cont_len + text_len > sizeof(cont_buf)) | 1582 | if (!cont_add(facility, level, text, text_len)) |
1370 | text_len = sizeof(cont_buf) - cont_len; | 1583 | log_store(facility, level, lflags | LOG_CONT, 0, |
1371 | memcpy(cont_buf + cont_len, text, text_len); | 1584 | dict, dictlen, text, text_len); |
1372 | cont_len += text_len; | ||
1373 | } else { | 1585 | } else { |
1374 | if (cont_len && cont_task == current) { | 1586 | bool stored = false; |
1375 | if (prefix) { | ||
1376 | /* | ||
1377 | * New prefix from the same thread; flush. We | ||
1378 | * either got no earlier newline, or we race | ||
1379 | * with an interrupt. | ||
1380 | */ | ||
1381 | log_store(facility, cont_level, | ||
1382 | NULL, 0, cont_buf, cont_len); | ||
1383 | cont_len = 0; | ||
1384 | } | ||
1385 | 1587 | ||
1386 | /* append to the earlier buffer and flush */ | 1588 | /* |
1387 | if (cont_len + text_len > sizeof(cont_buf)) | 1589 | * If an earlier newline was missing and it was the same task, |
1388 | text_len = sizeof(cont_buf) - cont_len; | 1590 | * either merge it with the current buffer and flush, or if |
1389 | memcpy(cont_buf + cont_len, text, text_len); | 1591 | * there was a race with interrupts (prefix == true) then just |
1390 | cont_len += text_len; | 1592 | * flush it out and store this line separately. |
1391 | log_store(facility, cont_level, | 1593 | */ |
1392 | NULL, 0, cont_buf, cont_len); | 1594 | if (cont.len && cont.owner == current) { |
1393 | cont_len = 0; | 1595 | if (!(lflags & LOG_PREFIX)) |
1394 | cont_task = NULL; | 1596 | stored = cont_add(facility, level, text, text_len); |
1395 | printed_len = cont_len; | 1597 | cont_flush(LOG_NEWLINE); |
1396 | } else { | ||
1397 | /* ordinary single and terminated line */ | ||
1398 | log_store(facility, level, | ||
1399 | dict, dictlen, text, text_len); | ||
1400 | printed_len = text_len; | ||
1401 | } | 1598 | } |
1599 | |||
1600 | if (!stored) | ||
1601 | log_store(facility, level, lflags, 0, | ||
1602 | dict, dictlen, text, text_len); | ||
1402 | } | 1603 | } |
1604 | printed_len += text_len; | ||
1403 | 1605 | ||
1404 | /* | 1606 | /* |
1405 | * Try to acquire and then immediately release the console semaphore. | 1607 | * Try to acquire and then immediately release the console semaphore. |
@@ -1483,14 +1685,32 @@ asmlinkage int printk(const char *fmt, ...) | |||
1483 | } | 1685 | } |
1484 | EXPORT_SYMBOL(printk); | 1686 | EXPORT_SYMBOL(printk); |
1485 | 1687 | ||
1486 | #else | 1688 | #else /* CONFIG_PRINTK */ |
1487 | 1689 | ||
1690 | #define LOG_LINE_MAX 0 | ||
1691 | #define PREFIX_MAX 0 | ||
1488 | #define LOG_LINE_MAX 0 | 1692 | #define LOG_LINE_MAX 0 |
1693 | static u64 syslog_seq; | ||
1694 | static u32 syslog_idx; | ||
1695 | static u64 console_seq; | ||
1696 | static u32 console_idx; | ||
1697 | static enum log_flags syslog_prev; | ||
1698 | static u64 log_first_seq; | ||
1699 | static u32 log_first_idx; | ||
1700 | static u64 log_next_seq; | ||
1701 | static enum log_flags console_prev; | ||
1702 | static struct cont { | ||
1703 | size_t len; | ||
1704 | size_t cons; | ||
1705 | u8 level; | ||
1706 | bool flushed:1; | ||
1707 | } cont; | ||
1489 | static struct log *log_from_idx(u32 idx) { return NULL; } | 1708 | static struct log *log_from_idx(u32 idx) { return NULL; } |
1490 | static u32 log_next(u32 idx) { return 0; } | 1709 | static u32 log_next(u32 idx) { return 0; } |
1491 | static void call_console_drivers(int level, const char *text, size_t len) {} | 1710 | static void call_console_drivers(int level, const char *text, size_t len) {} |
1492 | static size_t msg_print_text(const struct log *msg, bool syslog, | 1711 | static size_t msg_print_text(const struct log *msg, enum log_flags prev, |
1493 | char *buf, size_t size) { return 0; } | 1712 | bool syslog, char *buf, size_t size) { return 0; } |
1713 | static size_t cont_print_text(char *text, size_t size) { return 0; } | ||
1494 | 1714 | ||
1495 | #endif /* CONFIG_PRINTK */ | 1715 | #endif /* CONFIG_PRINTK */ |
1496 | 1716 | ||
@@ -1762,9 +1982,34 @@ void wake_up_klogd(void) | |||
1762 | this_cpu_or(printk_pending, PRINTK_PENDING_WAKEUP); | 1982 | this_cpu_or(printk_pending, PRINTK_PENDING_WAKEUP); |
1763 | } | 1983 | } |
1764 | 1984 | ||
1765 | /* the next printk record to write to the console */ | 1985 | static void console_cont_flush(char *text, size_t size) |
1766 | static u64 console_seq; | 1986 | { |
1767 | static u32 console_idx; | 1987 | unsigned long flags; |
1988 | size_t len; | ||
1989 | |||
1990 | raw_spin_lock_irqsave(&logbuf_lock, flags); | ||
1991 | |||
1992 | if (!cont.len) | ||
1993 | goto out; | ||
1994 | |||
1995 | /* | ||
1996 | * We still queue earlier records, likely because the console was | ||
1997 | * busy. The earlier ones need to be printed before this one, we | ||
1998 | * did not flush any fragment so far, so just let it queue up. | ||
1999 | */ | ||
2000 | if (console_seq < log_next_seq && !cont.cons) | ||
2001 | goto out; | ||
2002 | |||
2003 | len = cont_print_text(text, size); | ||
2004 | raw_spin_unlock(&logbuf_lock); | ||
2005 | stop_critical_timings(); | ||
2006 | call_console_drivers(cont.level, text, len); | ||
2007 | start_critical_timings(); | ||
2008 | local_irq_restore(flags); | ||
2009 | return; | ||
2010 | out: | ||
2011 | raw_spin_unlock_irqrestore(&logbuf_lock, flags); | ||
2012 | } | ||
1768 | 2013 | ||
1769 | /** | 2014 | /** |
1770 | * console_unlock - unlock the console system | 2015 | * console_unlock - unlock the console system |
@@ -1782,6 +2027,7 @@ static u32 console_idx; | |||
1782 | */ | 2027 | */ |
1783 | void console_unlock(void) | 2028 | void console_unlock(void) |
1784 | { | 2029 | { |
2030 | static char text[LOG_LINE_MAX + PREFIX_MAX]; | ||
1785 | static u64 seen_seq; | 2031 | static u64 seen_seq; |
1786 | unsigned long flags; | 2032 | unsigned long flags; |
1787 | bool wake_klogd = false; | 2033 | bool wake_klogd = false; |
@@ -1794,10 +2040,11 @@ void console_unlock(void) | |||
1794 | 2040 | ||
1795 | console_may_schedule = 0; | 2041 | console_may_schedule = 0; |
1796 | 2042 | ||
2043 | /* flush buffered message fragment immediately to console */ | ||
2044 | console_cont_flush(text, sizeof(text)); | ||
1797 | again: | 2045 | again: |
1798 | for (;;) { | 2046 | for (;;) { |
1799 | struct log *msg; | 2047 | struct log *msg; |
1800 | static char text[LOG_LINE_MAX]; | ||
1801 | size_t len; | 2048 | size_t len; |
1802 | int level; | 2049 | int level; |
1803 | 2050 | ||
@@ -1811,18 +2058,36 @@ again: | |||
1811 | /* messages are gone, move to first one */ | 2058 | /* messages are gone, move to first one */ |
1812 | console_seq = log_first_seq; | 2059 | console_seq = log_first_seq; |
1813 | console_idx = log_first_idx; | 2060 | console_idx = log_first_idx; |
2061 | console_prev = 0; | ||
1814 | } | 2062 | } |
1815 | 2063 | skip: | |
1816 | if (console_seq == log_next_seq) | 2064 | if (console_seq == log_next_seq) |
1817 | break; | 2065 | break; |
1818 | 2066 | ||
1819 | msg = log_from_idx(console_idx); | 2067 | msg = log_from_idx(console_idx); |
1820 | level = msg->level & 7; | 2068 | if (msg->flags & LOG_NOCONS) { |
1821 | 2069 | /* | |
1822 | len = msg_print_text(msg, false, text, sizeof(text)); | 2070 | * Skip record we have buffered and already printed |
2071 | * directly to the console when we received it. | ||
2072 | */ | ||
2073 | console_idx = log_next(console_idx); | ||
2074 | console_seq++; | ||
2075 | /* | ||
2076 | * We will get here again when we register a new | ||
2077 | * CON_PRINTBUFFER console. Clear the flag so we | ||
2078 | * will properly dump everything later. | ||
2079 | */ | ||
2080 | msg->flags &= ~LOG_NOCONS; | ||
2081 | console_prev = msg->flags; | ||
2082 | goto skip; | ||
2083 | } | ||
1823 | 2084 | ||
2085 | level = msg->level; | ||
2086 | len = msg_print_text(msg, console_prev, false, | ||
2087 | text, sizeof(text)); | ||
1824 | console_idx = log_next(console_idx); | 2088 | console_idx = log_next(console_idx); |
1825 | console_seq++; | 2089 | console_seq++; |
2090 | console_prev = msg->flags; | ||
1826 | raw_spin_unlock(&logbuf_lock); | 2091 | raw_spin_unlock(&logbuf_lock); |
1827 | 2092 | ||
1828 | stop_critical_timings(); /* don't trace print latency */ | 2093 | stop_critical_timings(); /* don't trace print latency */ |
@@ -2085,6 +2350,7 @@ void register_console(struct console *newcon) | |||
2085 | raw_spin_lock_irqsave(&logbuf_lock, flags); | 2350 | raw_spin_lock_irqsave(&logbuf_lock, flags); |
2086 | console_seq = syslog_seq; | 2351 | console_seq = syslog_seq; |
2087 | console_idx = syslog_idx; | 2352 | console_idx = syslog_idx; |
2353 | console_prev = syslog_prev; | ||
2088 | raw_spin_unlock_irqrestore(&logbuf_lock, flags); | 2354 | raw_spin_unlock_irqrestore(&logbuf_lock, flags); |
2089 | /* | 2355 | /* |
2090 | * We're about to replay the log buffer. Only do this to the | 2356 | * We're about to replay the log buffer. Only do this to the |
@@ -2300,48 +2566,256 @@ module_param_named(always_kmsg_dump, always_kmsg_dump, bool, S_IRUGO | S_IWUSR); | |||
2300 | * kmsg_dump - dump kernel log to kernel message dumpers. | 2566 | * kmsg_dump - dump kernel log to kernel message dumpers. |
2301 | * @reason: the reason (oops, panic etc) for dumping | 2567 | * @reason: the reason (oops, panic etc) for dumping |
2302 | * | 2568 | * |
2303 | * Iterate through each of the dump devices and call the oops/panic | 2569 | * Call each of the registered dumper's dump() callback, which can |
2304 | * callbacks with the log buffer. | 2570 | * retrieve the kmsg records with kmsg_dump_get_line() or |
2571 | * kmsg_dump_get_buffer(). | ||
2305 | */ | 2572 | */ |
2306 | void kmsg_dump(enum kmsg_dump_reason reason) | 2573 | void kmsg_dump(enum kmsg_dump_reason reason) |
2307 | { | 2574 | { |
2308 | u64 idx; | ||
2309 | struct kmsg_dumper *dumper; | 2575 | struct kmsg_dumper *dumper; |
2310 | const char *s1, *s2; | ||
2311 | unsigned long l1, l2; | ||
2312 | unsigned long flags; | 2576 | unsigned long flags; |
2313 | 2577 | ||
2314 | if ((reason > KMSG_DUMP_OOPS) && !always_kmsg_dump) | 2578 | if ((reason > KMSG_DUMP_OOPS) && !always_kmsg_dump) |
2315 | return; | 2579 | return; |
2316 | 2580 | ||
2317 | /* Theoretically, the log could move on after we do this, but | 2581 | rcu_read_lock(); |
2318 | there's not a lot we can do about that. The new messages | 2582 | list_for_each_entry_rcu(dumper, &dump_list, list) { |
2319 | will overwrite the start of what we dump. */ | 2583 | if (dumper->max_reason && reason > dumper->max_reason) |
2584 | continue; | ||
2585 | |||
2586 | /* initialize iterator with data about the stored records */ | ||
2587 | dumper->active = true; | ||
2588 | |||
2589 | raw_spin_lock_irqsave(&logbuf_lock, flags); | ||
2590 | dumper->cur_seq = clear_seq; | ||
2591 | dumper->cur_idx = clear_idx; | ||
2592 | dumper->next_seq = log_next_seq; | ||
2593 | dumper->next_idx = log_next_idx; | ||
2594 | raw_spin_unlock_irqrestore(&logbuf_lock, flags); | ||
2595 | |||
2596 | /* invoke dumper which will iterate over records */ | ||
2597 | dumper->dump(dumper, reason); | ||
2598 | |||
2599 | /* reset iterator */ | ||
2600 | dumper->active = false; | ||
2601 | } | ||
2602 | rcu_read_unlock(); | ||
2603 | } | ||
2604 | |||
2605 | /** | ||
2606 | * kmsg_dump_get_line_nolock - retrieve one kmsg log line (unlocked version) | ||
2607 | * @dumper: registered kmsg dumper | ||
2608 | * @syslog: include the "<4>" prefixes | ||
2609 | * @line: buffer to copy the line to | ||
2610 | * @size: maximum size of the buffer | ||
2611 | * @len: length of line placed into buffer | ||
2612 | * | ||
2613 | * Start at the beginning of the kmsg buffer, with the oldest kmsg | ||
2614 | * record, and copy one record into the provided buffer. | ||
2615 | * | ||
2616 | * Consecutive calls will return the next available record moving | ||
2617 | * towards the end of the buffer with the youngest messages. | ||
2618 | * | ||
2619 | * A return value of FALSE indicates that there are no more records to | ||
2620 | * read. | ||
2621 | * | ||
2622 | * The function is similar to kmsg_dump_get_line(), but grabs no locks. | ||
2623 | */ | ||
2624 | bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog, | ||
2625 | char *line, size_t size, size_t *len) | ||
2626 | { | ||
2627 | struct log *msg; | ||
2628 | size_t l = 0; | ||
2629 | bool ret = false; | ||
2630 | |||
2631 | if (!dumper->active) | ||
2632 | goto out; | ||
2633 | |||
2634 | if (dumper->cur_seq < log_first_seq) { | ||
2635 | /* messages are gone, move to first available one */ | ||
2636 | dumper->cur_seq = log_first_seq; | ||
2637 | dumper->cur_idx = log_first_idx; | ||
2638 | } | ||
2639 | |||
2640 | /* last entry */ | ||
2641 | if (dumper->cur_seq >= log_next_seq) | ||
2642 | goto out; | ||
2643 | |||
2644 | msg = log_from_idx(dumper->cur_idx); | ||
2645 | l = msg_print_text(msg, 0, syslog, line, size); | ||
2646 | |||
2647 | dumper->cur_idx = log_next(dumper->cur_idx); | ||
2648 | dumper->cur_seq++; | ||
2649 | ret = true; | ||
2650 | out: | ||
2651 | if (len) | ||
2652 | *len = l; | ||
2653 | return ret; | ||
2654 | } | ||
2655 | |||
2656 | /** | ||
2657 | * kmsg_dump_get_line - retrieve one kmsg log line | ||
2658 | * @dumper: registered kmsg dumper | ||
2659 | * @syslog: include the "<4>" prefixes | ||
2660 | * @line: buffer to copy the line to | ||
2661 | * @size: maximum size of the buffer | ||
2662 | * @len: length of line placed into buffer | ||
2663 | * | ||
2664 | * Start at the beginning of the kmsg buffer, with the oldest kmsg | ||
2665 | * record, and copy one record into the provided buffer. | ||
2666 | * | ||
2667 | * Consecutive calls will return the next available record moving | ||
2668 | * towards the end of the buffer with the youngest messages. | ||
2669 | * | ||
2670 | * A return value of FALSE indicates that there are no more records to | ||
2671 | * read. | ||
2672 | */ | ||
2673 | bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog, | ||
2674 | char *line, size_t size, size_t *len) | ||
2675 | { | ||
2676 | unsigned long flags; | ||
2677 | bool ret; | ||
2320 | 2678 | ||
2321 | raw_spin_lock_irqsave(&logbuf_lock, flags); | 2679 | raw_spin_lock_irqsave(&logbuf_lock, flags); |
2322 | if (syslog_seq < log_first_seq) | 2680 | ret = kmsg_dump_get_line_nolock(dumper, syslog, line, size, len); |
2323 | idx = syslog_idx; | 2681 | raw_spin_unlock_irqrestore(&logbuf_lock, flags); |
2324 | else | ||
2325 | idx = log_first_idx; | ||
2326 | 2682 | ||
2327 | if (idx > log_next_idx) { | 2683 | return ret; |
2328 | s1 = log_buf; | 2684 | } |
2329 | l1 = log_next_idx; | 2685 | EXPORT_SYMBOL_GPL(kmsg_dump_get_line); |
2330 | 2686 | ||
2331 | s2 = log_buf + idx; | 2687 | /** |
2332 | l2 = log_buf_len - idx; | 2688 | * kmsg_dump_get_buffer - copy kmsg log lines |
2333 | } else { | 2689 | * @dumper: registered kmsg dumper |
2334 | s1 = ""; | 2690 | * @syslog: include the "<4>" prefixes |
2335 | l1 = 0; | 2691 | * @buf: buffer to copy the line to |
2692 | * @size: maximum size of the buffer | ||
2693 | * @len: length of line placed into buffer | ||
2694 | * | ||
2695 | * Start at the end of the kmsg buffer and fill the provided buffer | ||
2696 | * with as many of the the *youngest* kmsg records that fit into it. | ||
2697 | * If the buffer is large enough, all available kmsg records will be | ||
2698 | * copied with a single call. | ||
2699 | * | ||
2700 | * Consecutive calls will fill the buffer with the next block of | ||
2701 | * available older records, not including the earlier retrieved ones. | ||
2702 | * | ||
2703 | * A return value of FALSE indicates that there are no more records to | ||
2704 | * read. | ||
2705 | */ | ||
2706 | bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog, | ||
2707 | char *buf, size_t size, size_t *len) | ||
2708 | { | ||
2709 | unsigned long flags; | ||
2710 | u64 seq; | ||
2711 | u32 idx; | ||
2712 | u64 next_seq; | ||
2713 | u32 next_idx; | ||
2714 | enum log_flags prev; | ||
2715 | size_t l = 0; | ||
2716 | bool ret = false; | ||
2717 | |||
2718 | if (!dumper->active) | ||
2719 | goto out; | ||
2720 | |||
2721 | raw_spin_lock_irqsave(&logbuf_lock, flags); | ||
2722 | if (dumper->cur_seq < log_first_seq) { | ||
2723 | /* messages are gone, move to first available one */ | ||
2724 | dumper->cur_seq = log_first_seq; | ||
2725 | dumper->cur_idx = log_first_idx; | ||
2726 | } | ||
2336 | 2727 | ||
2337 | s2 = log_buf + idx; | 2728 | /* last entry */ |
2338 | l2 = log_next_idx - idx; | 2729 | if (dumper->cur_seq >= dumper->next_seq) { |
2730 | raw_spin_unlock_irqrestore(&logbuf_lock, flags); | ||
2731 | goto out; | ||
2339 | } | 2732 | } |
2733 | |||
2734 | /* calculate length of entire buffer */ | ||
2735 | seq = dumper->cur_seq; | ||
2736 | idx = dumper->cur_idx; | ||
2737 | prev = 0; | ||
2738 | while (seq < dumper->next_seq) { | ||
2739 | struct log *msg = log_from_idx(idx); | ||
2740 | |||
2741 | l += msg_print_text(msg, prev, true, NULL, 0); | ||
2742 | idx = log_next(idx); | ||
2743 | seq++; | ||
2744 | prev = msg->flags; | ||
2745 | } | ||
2746 | |||
2747 | /* move first record forward until length fits into the buffer */ | ||
2748 | seq = dumper->cur_seq; | ||
2749 | idx = dumper->cur_idx; | ||
2750 | prev = 0; | ||
2751 | while (l > size && seq < dumper->next_seq) { | ||
2752 | struct log *msg = log_from_idx(idx); | ||
2753 | |||
2754 | l -= msg_print_text(msg, prev, true, NULL, 0); | ||
2755 | idx = log_next(idx); | ||
2756 | seq++; | ||
2757 | prev = msg->flags; | ||
2758 | } | ||
2759 | |||
2760 | /* last message in next interation */ | ||
2761 | next_seq = seq; | ||
2762 | next_idx = idx; | ||
2763 | |||
2764 | l = 0; | ||
2765 | prev = 0; | ||
2766 | while (seq < dumper->next_seq) { | ||
2767 | struct log *msg = log_from_idx(idx); | ||
2768 | |||
2769 | l += msg_print_text(msg, prev, syslog, buf + l, size - l); | ||
2770 | idx = log_next(idx); | ||
2771 | seq++; | ||
2772 | prev = msg->flags; | ||
2773 | } | ||
2774 | |||
2775 | dumper->next_seq = next_seq; | ||
2776 | dumper->next_idx = next_idx; | ||
2777 | ret = true; | ||
2340 | raw_spin_unlock_irqrestore(&logbuf_lock, flags); | 2778 | raw_spin_unlock_irqrestore(&logbuf_lock, flags); |
2779 | out: | ||
2780 | if (len) | ||
2781 | *len = l; | ||
2782 | return ret; | ||
2783 | } | ||
2784 | EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer); | ||
2341 | 2785 | ||
2342 | rcu_read_lock(); | 2786 | /** |
2343 | list_for_each_entry_rcu(dumper, &dump_list, list) | 2787 | * kmsg_dump_rewind_nolock - reset the interator (unlocked version) |
2344 | dumper->dump(dumper, reason, s1, l1, s2, l2); | 2788 | * @dumper: registered kmsg dumper |
2345 | rcu_read_unlock(); | 2789 | * |
2790 | * Reset the dumper's iterator so that kmsg_dump_get_line() and | ||
2791 | * kmsg_dump_get_buffer() can be called again and used multiple | ||
2792 | * times within the same dumper.dump() callback. | ||
2793 | * | ||
2794 | * The function is similar to kmsg_dump_rewind(), but grabs no locks. | ||
2795 | */ | ||
2796 | void kmsg_dump_rewind_nolock(struct kmsg_dumper *dumper) | ||
2797 | { | ||
2798 | dumper->cur_seq = clear_seq; | ||
2799 | dumper->cur_idx = clear_idx; | ||
2800 | dumper->next_seq = log_next_seq; | ||
2801 | dumper->next_idx = log_next_idx; | ||
2802 | } | ||
2803 | |||
2804 | /** | ||
2805 | * kmsg_dump_rewind - reset the interator | ||
2806 | * @dumper: registered kmsg dumper | ||
2807 | * | ||
2808 | * Reset the dumper's iterator so that kmsg_dump_get_line() and | ||
2809 | * kmsg_dump_get_buffer() can be called again and used multiple | ||
2810 | * times within the same dumper.dump() callback. | ||
2811 | */ | ||
2812 | void kmsg_dump_rewind(struct kmsg_dumper *dumper) | ||
2813 | { | ||
2814 | unsigned long flags; | ||
2815 | |||
2816 | raw_spin_lock_irqsave(&logbuf_lock, flags); | ||
2817 | kmsg_dump_rewind_nolock(dumper); | ||
2818 | raw_spin_unlock_irqrestore(&logbuf_lock, flags); | ||
2346 | } | 2819 | } |
2820 | EXPORT_SYMBOL_GPL(kmsg_dump_rewind); | ||
2347 | #endif | 2821 | #endif |