aboutsummaryrefslogtreecommitdiffstats
path: root/kernel/printk.c
diff options
context:
space:
mode:
Diffstat (limited to 'kernel/printk.c')
-rw-r--r--kernel/printk.c469
1 files changed, 324 insertions, 145 deletions
diff --git a/kernel/printk.c b/kernel/printk.c
index a2276b916769..177fa49357a5 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
196enum 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
196struct log { 203struct 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/*
@@ -210,6 +219,8 @@ static DEFINE_RAW_SPINLOCK(logbuf_lock);
210/* the next printk record to read by syslog(READ) or /proc/kmsg */ 219/* the next printk record to read by syslog(READ) or /proc/kmsg */
211static u64 syslog_seq; 220static u64 syslog_seq;
212static u32 syslog_idx; 221static u32 syslog_idx;
222static enum log_flags syslog_prev;
223static size_t syslog_partial;
213 224
214/* index and sequence number of the first record stored in the buffer */ 225/* index and sequence number of the first record stored in the buffer */
215static u64 log_first_seq; 226static u64 log_first_seq;
@@ -286,6 +297,7 @@ static u32 log_next(u32 idx)
286 297
287/* insert record into the buffer, discard old ones, update heads */ 298/* insert record into the buffer, discard old ones, update heads */
288static void log_store(int facility, int level, 299static void log_store(int facility, int level,
300 enum log_flags flags, u64 ts_nsec,
289 const char *dict, u16 dict_len, 301 const char *dict, u16 dict_len,
290 const char *text, u16 text_len) 302 const char *text, u16 text_len)
291{ 303{
@@ -329,8 +341,13 @@ static void log_store(int facility, int level,
329 msg->text_len = text_len; 341 msg->text_len = text_len;
330 memcpy(log_dict(msg), dict, dict_len); 342 memcpy(log_dict(msg), dict, dict_len);
331 msg->dict_len = dict_len; 343 msg->dict_len = dict_len;
332 msg->level = (facility << 3) | (level & 7); 344 msg->facility = facility;
333 msg->ts_nsec = local_clock(); 345 msg->level = level & 7;
346 msg->flags = flags & 0x1f;
347 if (ts_nsec > 0)
348 msg->ts_nsec = ts_nsec;
349 else
350 msg->ts_nsec = local_clock();
334 memset(log_dict(msg) + dict_len, 0, pad_len); 351 memset(log_dict(msg) + dict_len, 0, pad_len);
335 msg->len = sizeof(struct log) + text_len + dict_len + pad_len; 352 msg->len = sizeof(struct log) + text_len + dict_len + pad_len;
336 353
@@ -417,20 +434,20 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
417 ret = mutex_lock_interruptible(&user->lock); 434 ret = mutex_lock_interruptible(&user->lock);
418 if (ret) 435 if (ret)
419 return ret; 436 return ret;
420 raw_spin_lock(&logbuf_lock); 437 raw_spin_lock_irq(&logbuf_lock);
421 while (user->seq == log_next_seq) { 438 while (user->seq == log_next_seq) {
422 if (file->f_flags & O_NONBLOCK) { 439 if (file->f_flags & O_NONBLOCK) {
423 ret = -EAGAIN; 440 ret = -EAGAIN;
424 raw_spin_unlock(&logbuf_lock); 441 raw_spin_unlock_irq(&logbuf_lock);
425 goto out; 442 goto out;
426 } 443 }
427 444
428 raw_spin_unlock(&logbuf_lock); 445 raw_spin_unlock_irq(&logbuf_lock);
429 ret = wait_event_interruptible(log_wait, 446 ret = wait_event_interruptible(log_wait,
430 user->seq != log_next_seq); 447 user->seq != log_next_seq);
431 if (ret) 448 if (ret)
432 goto out; 449 goto out;
433 raw_spin_lock(&logbuf_lock); 450 raw_spin_lock_irq(&logbuf_lock);
434 } 451 }
435 452
436 if (user->seq < log_first_seq) { 453 if (user->seq < log_first_seq) {
@@ -438,7 +455,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
438 user->idx = log_first_idx; 455 user->idx = log_first_idx;
439 user->seq = log_first_seq; 456 user->seq = log_first_seq;
440 ret = -EPIPE; 457 ret = -EPIPE;
441 raw_spin_unlock(&logbuf_lock); 458 raw_spin_unlock_irq(&logbuf_lock);
442 goto out; 459 goto out;
443 } 460 }
444 461
@@ -446,13 +463,13 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
446 ts_usec = msg->ts_nsec; 463 ts_usec = msg->ts_nsec;
447 do_div(ts_usec, 1000); 464 do_div(ts_usec, 1000);
448 len = sprintf(user->buf, "%u,%llu,%llu;", 465 len = sprintf(user->buf, "%u,%llu,%llu;",
449 msg->level, user->seq, ts_usec); 466 (msg->facility << 3) | msg->level, user->seq, ts_usec);
450 467
451 /* escape non-printable characters */ 468 /* escape non-printable characters */
452 for (i = 0; i < msg->text_len; i++) { 469 for (i = 0; i < msg->text_len; i++) {
453 unsigned char c = log_text(msg)[i]; 470 unsigned char c = log_text(msg)[i];
454 471
455 if (c < ' ' || c >= 128) 472 if (c < ' ' || c >= 127 || c == '\\')
456 len += sprintf(user->buf + len, "\\x%02x", c); 473 len += sprintf(user->buf + len, "\\x%02x", c);
457 else 474 else
458 user->buf[len++] = c; 475 user->buf[len++] = c;
@@ -476,7 +493,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
476 continue; 493 continue;
477 } 494 }
478 495
479 if (c < ' ' || c >= 128) { 496 if (c < ' ' || c >= 127 || c == '\\') {
480 len += sprintf(user->buf + len, "\\x%02x", c); 497 len += sprintf(user->buf + len, "\\x%02x", c);
481 continue; 498 continue;
482 } 499 }
@@ -488,7 +505,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
488 505
489 user->idx = log_next(user->idx); 506 user->idx = log_next(user->idx);
490 user->seq++; 507 user->seq++;
491 raw_spin_unlock(&logbuf_lock); 508 raw_spin_unlock_irq(&logbuf_lock);
492 509
493 if (len > count) { 510 if (len > count) {
494 ret = -EINVAL; 511 ret = -EINVAL;
@@ -515,7 +532,7 @@ static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence)
515 if (offset) 532 if (offset)
516 return -ESPIPE; 533 return -ESPIPE;
517 534
518 raw_spin_lock(&logbuf_lock); 535 raw_spin_lock_irq(&logbuf_lock);
519 switch (whence) { 536 switch (whence) {
520 case SEEK_SET: 537 case SEEK_SET:
521 /* the first record */ 538 /* the first record */
@@ -539,7 +556,7 @@ static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence)
539 default: 556 default:
540 ret = -EINVAL; 557 ret = -EINVAL;
541 } 558 }
542 raw_spin_unlock(&logbuf_lock); 559 raw_spin_unlock_irq(&logbuf_lock);
543 return ret; 560 return ret;
544} 561}
545 562
@@ -553,14 +570,14 @@ static unsigned int devkmsg_poll(struct file *file, poll_table *wait)
553 570
554 poll_wait(file, &log_wait, wait); 571 poll_wait(file, &log_wait, wait);
555 572
556 raw_spin_lock(&logbuf_lock); 573 raw_spin_lock_irq(&logbuf_lock);
557 if (user->seq < log_next_seq) { 574 if (user->seq < log_next_seq) {
558 /* return error when data has vanished underneath us */ 575 /* return error when data has vanished underneath us */
559 if (user->seq < log_first_seq) 576 if (user->seq < log_first_seq)
560 ret = POLLIN|POLLRDNORM|POLLERR|POLLPRI; 577 ret = POLLIN|POLLRDNORM|POLLERR|POLLPRI;
561 ret = POLLIN|POLLRDNORM; 578 ret = POLLIN|POLLRDNORM;
562 } 579 }
563 raw_spin_unlock(&logbuf_lock); 580 raw_spin_unlock_irq(&logbuf_lock);
564 581
565 return ret; 582 return ret;
566} 583}
@@ -584,10 +601,10 @@ static int devkmsg_open(struct inode *inode, struct file *file)
584 601
585 mutex_init(&user->lock); 602 mutex_init(&user->lock);
586 603
587 raw_spin_lock(&logbuf_lock); 604 raw_spin_lock_irq(&logbuf_lock);
588 user->idx = log_first_idx; 605 user->idx = log_first_idx;
589 user->seq = log_first_seq; 606 user->seq = log_first_seq;
590 raw_spin_unlock(&logbuf_lock); 607 raw_spin_unlock_irq(&logbuf_lock);
591 608
592 file->private_data = user; 609 file->private_data = user;
593 return 0; 610 return 0;
@@ -787,44 +804,64 @@ static bool printk_time;
787#endif 804#endif
788module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR); 805module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
789 806
807static size_t print_time(u64 ts, char *buf)
808{
809 unsigned long rem_nsec;
810
811 if (!printk_time)
812 return 0;
813
814 if (!buf)
815 return 15;
816
817 rem_nsec = do_div(ts, 1000000000);
818 return sprintf(buf, "[%5lu.%06lu] ",
819 (unsigned long)ts, rem_nsec / 1000);
820}
821
790static size_t print_prefix(const struct log *msg, bool syslog, char *buf) 822static size_t print_prefix(const struct log *msg, bool syslog, char *buf)
791{ 823{
792 size_t len = 0; 824 size_t len = 0;
825 unsigned int prefix = (msg->facility << 3) | msg->level;
793 826
794 if (syslog) { 827 if (syslog) {
795 if (buf) { 828 if (buf) {
796 len += sprintf(buf, "<%u>", msg->level); 829 len += sprintf(buf, "<%u>", prefix);
797 } else { 830 } else {
798 len += 3; 831 len += 3;
799 if (msg->level > 9) 832 if (prefix > 999)
800 len++; 833 len += 3;
801 if (msg->level > 99) 834 else if (prefix > 99)
835 len += 2;
836 else if (prefix > 9)
802 len++; 837 len++;
803 } 838 }
804 } 839 }
805 840
806 if (printk_time) { 841 len += print_time(msg->ts_nsec, buf ? buf + len : NULL);
807 if (buf) {
808 unsigned long long ts = msg->ts_nsec;
809 unsigned long rem_nsec = do_div(ts, 1000000000);
810
811 len += sprintf(buf + len, "[%5lu.%06lu] ",
812 (unsigned long) ts, rem_nsec / 1000);
813 } else {
814 len += 15;
815 }
816 }
817
818 return len; 842 return len;
819} 843}
820 844
821static size_t msg_print_text(const struct log *msg, bool syslog, 845static size_t msg_print_text(const struct log *msg, enum log_flags prev,
822 char *buf, size_t size) 846 bool syslog, char *buf, size_t size)
823{ 847{
824 const char *text = log_text(msg); 848 const char *text = log_text(msg);
825 size_t text_size = msg->text_len; 849 size_t text_size = msg->text_len;
850 bool prefix = true;
851 bool newline = true;
826 size_t len = 0; 852 size_t len = 0;
827 853
854 if ((prev & LOG_CONT) && !(msg->flags & LOG_PREFIX))
855 prefix = false;
856
857 if (msg->flags & LOG_CONT) {
858 if ((prev & LOG_CONT) && !(prev & LOG_NEWLINE))
859 prefix = false;
860
861 if (!(msg->flags & LOG_NEWLINE))
862 newline = false;
863 }
864
828 do { 865 do {
829 const char *next = memchr(text, '\n', text_size); 866 const char *next = memchr(text, '\n', text_size);
830 size_t text_len; 867 size_t text_len;
@@ -842,16 +879,22 @@ static size_t msg_print_text(const struct log *msg, bool syslog,
842 text_len + 1>= size - len) 879 text_len + 1>= size - len)
843 break; 880 break;
844 881
845 len += print_prefix(msg, syslog, buf + len); 882 if (prefix)
883 len += print_prefix(msg, syslog, buf + len);
846 memcpy(buf + len, text, text_len); 884 memcpy(buf + len, text, text_len);
847 len += text_len; 885 len += text_len;
848 buf[len++] = '\n'; 886 if (next || newline)
887 buf[len++] = '\n';
849 } else { 888 } else {
850 /* SYSLOG_ACTION_* buffer size only calculation */ 889 /* SYSLOG_ACTION_* buffer size only calculation */
851 len += print_prefix(msg, syslog, NULL); 890 if (prefix)
852 len += text_len + 1; 891 len += print_prefix(msg, syslog, NULL);
892 len += text_len;
893 if (next || newline)
894 len++;
853 } 895 }
854 896
897 prefix = true;
855 text = next; 898 text = next;
856 } while (text); 899 } while (text);
857 900
@@ -862,28 +905,60 @@ static int syslog_print(char __user *buf, int size)
862{ 905{
863 char *text; 906 char *text;
864 struct log *msg; 907 struct log *msg;
865 int len; 908 int len = 0;
866 909
867 text = kmalloc(LOG_LINE_MAX, GFP_KERNEL); 910 text = kmalloc(LOG_LINE_MAX, GFP_KERNEL);
868 if (!text) 911 if (!text)
869 return -ENOMEM; 912 return -ENOMEM;
870 913
871 raw_spin_lock_irq(&logbuf_lock); 914 while (size > 0) {
872 if (syslog_seq < log_first_seq) { 915 size_t n;
873 /* messages are gone, move to first one */ 916 size_t skip;
874 syslog_seq = log_first_seq;
875 syslog_idx = log_first_idx;
876 }
877 msg = log_from_idx(syslog_idx);
878 len = msg_print_text(msg, true, text, LOG_LINE_MAX);
879 syslog_idx = log_next(syslog_idx);
880 syslog_seq++;
881 raw_spin_unlock_irq(&logbuf_lock);
882 917
883 if (len > size) 918 raw_spin_lock_irq(&logbuf_lock);
884 len = -EINVAL; 919 if (syslog_seq < log_first_seq) {
885 else if (len > 0 && copy_to_user(buf, text, len)) 920 /* messages are gone, move to first one */
886 len = -EFAULT; 921 syslog_seq = log_first_seq;
922 syslog_idx = log_first_idx;
923 syslog_prev = 0;
924 syslog_partial = 0;
925 }
926 if (syslog_seq == log_next_seq) {
927 raw_spin_unlock_irq(&logbuf_lock);
928 break;
929 }
930
931 skip = syslog_partial;
932 msg = log_from_idx(syslog_idx);
933 n = msg_print_text(msg, syslog_prev, true, text, LOG_LINE_MAX);
934 if (n - syslog_partial <= size) {
935 /* message fits into buffer, move forward */
936 syslog_idx = log_next(syslog_idx);
937 syslog_seq++;
938 syslog_prev = msg->flags;
939 n -= syslog_partial;
940 syslog_partial = 0;
941 } else if (!len){
942 /* partial read(), remember position */
943 n = size;
944 syslog_partial += n;
945 } else
946 n = 0;
947 raw_spin_unlock_irq(&logbuf_lock);
948
949 if (!n)
950 break;
951
952 if (copy_to_user(buf, text + skip, n)) {
953 if (!len)
954 len = -EFAULT;
955 break;
956 }
957
958 len += n;
959 size -= n;
960 buf += n;
961 }
887 962
888 kfree(text); 963 kfree(text);
889 return len; 964 return len;
@@ -903,6 +978,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
903 u64 next_seq; 978 u64 next_seq;
904 u64 seq; 979 u64 seq;
905 u32 idx; 980 u32 idx;
981 enum log_flags prev;
906 982
907 if (clear_seq < log_first_seq) { 983 if (clear_seq < log_first_seq) {
908 /* messages are gone, move to first available one */ 984 /* messages are gone, move to first available one */
@@ -916,10 +992,11 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
916 */ 992 */
917 seq = clear_seq; 993 seq = clear_seq;
918 idx = clear_idx; 994 idx = clear_idx;
995 prev = 0;
919 while (seq < log_next_seq) { 996 while (seq < log_next_seq) {
920 struct log *msg = log_from_idx(idx); 997 struct log *msg = log_from_idx(idx);
921 998
922 len += msg_print_text(msg, true, NULL, 0); 999 len += msg_print_text(msg, prev, true, NULL, 0);
923 idx = log_next(idx); 1000 idx = log_next(idx);
924 seq++; 1001 seq++;
925 } 1002 }
@@ -927,10 +1004,11 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
927 /* move first record forward until length fits into the buffer */ 1004 /* move first record forward until length fits into the buffer */
928 seq = clear_seq; 1005 seq = clear_seq;
929 idx = clear_idx; 1006 idx = clear_idx;
1007 prev = 0;
930 while (len > size && seq < log_next_seq) { 1008 while (len > size && seq < log_next_seq) {
931 struct log *msg = log_from_idx(idx); 1009 struct log *msg = log_from_idx(idx);
932 1010
933 len -= msg_print_text(msg, true, NULL, 0); 1011 len -= msg_print_text(msg, prev, true, NULL, 0);
934 idx = log_next(idx); 1012 idx = log_next(idx);
935 seq++; 1013 seq++;
936 } 1014 }
@@ -939,17 +1017,19 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
939 next_seq = log_next_seq; 1017 next_seq = log_next_seq;
940 1018
941 len = 0; 1019 len = 0;
1020 prev = 0;
942 while (len >= 0 && seq < next_seq) { 1021 while (len >= 0 && seq < next_seq) {
943 struct log *msg = log_from_idx(idx); 1022 struct log *msg = log_from_idx(idx);
944 int textlen; 1023 int textlen;
945 1024
946 textlen = msg_print_text(msg, true, text, LOG_LINE_MAX); 1025 textlen = msg_print_text(msg, prev, true, text, LOG_LINE_MAX);
947 if (textlen < 0) { 1026 if (textlen < 0) {
948 len = textlen; 1027 len = textlen;
949 break; 1028 break;
950 } 1029 }
951 idx = log_next(idx); 1030 idx = log_next(idx);
952 seq++; 1031 seq++;
1032 prev = msg->flags;
953 1033
954 raw_spin_unlock_irq(&logbuf_lock); 1034 raw_spin_unlock_irq(&logbuf_lock);
955 if (copy_to_user(buf + len, text, textlen)) 1035 if (copy_to_user(buf + len, text, textlen))
@@ -962,6 +1042,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
962 /* messages are gone, move to next one */ 1042 /* messages are gone, move to next one */
963 seq = log_first_seq; 1043 seq = log_first_seq;
964 idx = log_first_idx; 1044 idx = log_first_idx;
1045 prev = 0;
965 } 1046 }
966 } 1047 }
967 } 1048 }
@@ -980,7 +1061,6 @@ int do_syslog(int type, char __user *buf, int len, bool from_file)
980{ 1061{
981 bool clear = false; 1062 bool clear = false;
982 static int saved_console_loglevel = -1; 1063 static int saved_console_loglevel = -1;
983 static DEFINE_MUTEX(syslog_mutex);
984 int error; 1064 int error;
985 1065
986 error = check_syslog_permissions(type, from_file); 1066 error = check_syslog_permissions(type, from_file);
@@ -1007,17 +1087,11 @@ int do_syslog(int type, char __user *buf, int len, bool from_file)
1007 error = -EFAULT; 1087 error = -EFAULT;
1008 goto out; 1088 goto out;
1009 } 1089 }
1010 error = mutex_lock_interruptible(&syslog_mutex);
1011 if (error)
1012 goto out;
1013 error = wait_event_interruptible(log_wait, 1090 error = wait_event_interruptible(log_wait,
1014 syslog_seq != log_next_seq); 1091 syslog_seq != log_next_seq);
1015 if (error) { 1092 if (error)
1016 mutex_unlock(&syslog_mutex);
1017 goto out; 1093 goto out;
1018 }
1019 error = syslog_print(buf, len); 1094 error = syslog_print(buf, len);
1020 mutex_unlock(&syslog_mutex);
1021 break; 1095 break;
1022 /* Read/clear last kernel messages */ 1096 /* Read/clear last kernel messages */
1023 case SYSLOG_ACTION_READ_CLEAR: 1097 case SYSLOG_ACTION_READ_CLEAR:
@@ -1040,6 +1114,7 @@ int do_syslog(int type, char __user *buf, int len, bool from_file)
1040 /* Clear ring buffer */ 1114 /* Clear ring buffer */
1041 case SYSLOG_ACTION_CLEAR: 1115 case SYSLOG_ACTION_CLEAR:
1042 syslog_print_all(NULL, 0, true); 1116 syslog_print_all(NULL, 0, true);
1117 break;
1043 /* Disable logging to console */ 1118 /* Disable logging to console */
1044 case SYSLOG_ACTION_CONSOLE_OFF: 1119 case SYSLOG_ACTION_CONSOLE_OFF:
1045 if (saved_console_loglevel == -1) 1120 if (saved_console_loglevel == -1)
@@ -1072,6 +1147,8 @@ int do_syslog(int type, char __user *buf, int len, bool from_file)
1072 /* messages are gone, move to first one */ 1147 /* messages are gone, move to first one */
1073 syslog_seq = log_first_seq; 1148 syslog_seq = log_first_seq;
1074 syslog_idx = log_first_idx; 1149 syslog_idx = log_first_idx;
1150 syslog_prev = 0;
1151 syslog_partial = 0;
1075 } 1152 }
1076 if (from_file) { 1153 if (from_file) {
1077 /* 1154 /*
@@ -1081,19 +1158,20 @@ int do_syslog(int type, char __user *buf, int len, bool from_file)
1081 */ 1158 */
1082 error = log_next_idx - syslog_idx; 1159 error = log_next_idx - syslog_idx;
1083 } else { 1160 } else {
1084 u64 seq; 1161 u64 seq = syslog_seq;
1085 u32 idx; 1162 u32 idx = syslog_idx;
1163 enum log_flags prev = syslog_prev;
1086 1164
1087 error = 0; 1165 error = 0;
1088 seq = syslog_seq;
1089 idx = syslog_idx;
1090 while (seq < log_next_seq) { 1166 while (seq < log_next_seq) {
1091 struct log *msg = log_from_idx(idx); 1167 struct log *msg = log_from_idx(idx);
1092 1168
1093 error += msg_print_text(msg, true, NULL, 0); 1169 error += msg_print_text(msg, prev, true, NULL, 0);
1094 idx = log_next(idx); 1170 idx = log_next(idx);
1095 seq++; 1171 seq++;
1172 prev = msg->flags;
1096 } 1173 }
1174 error -= syslog_partial;
1097 } 1175 }
1098 raw_spin_unlock_irq(&logbuf_lock); 1176 raw_spin_unlock_irq(&logbuf_lock);
1099 break; 1177 break;
@@ -1272,22 +1350,98 @@ static inline void printk_delay(void)
1272 } 1350 }
1273} 1351}
1274 1352
1353/*
1354 * Continuation lines are buffered, and not committed to the record buffer
1355 * until the line is complete, or a race forces it. The line fragments
1356 * though, are printed immediately to the consoles to ensure everything has
1357 * reached the console in case of a kernel crash.
1358 */
1359static struct cont {
1360 char buf[LOG_LINE_MAX];
1361 size_t len; /* length == 0 means unused buffer */
1362 size_t cons; /* bytes written to console */
1363 struct task_struct *owner; /* task of first print*/
1364 u64 ts_nsec; /* time of first print */
1365 u8 level; /* log level of first message */
1366 u8 facility; /* log level of first message */
1367 bool flushed:1; /* buffer sealed and committed */
1368} cont;
1369
1370static void cont_flush(void)
1371{
1372 if (cont.flushed)
1373 return;
1374 if (cont.len == 0)
1375 return;
1376
1377 log_store(cont.facility, cont.level, LOG_NOCONS, cont.ts_nsec,
1378 NULL, 0, cont.buf, cont.len);
1379
1380 cont.flushed = true;
1381}
1382
1383static bool cont_add(int facility, int level, const char *text, size_t len)
1384{
1385 if (cont.len && cont.flushed)
1386 return false;
1387
1388 if (cont.len + len > sizeof(cont.buf)) {
1389 cont_flush();
1390 return false;
1391 }
1392
1393 if (!cont.len) {
1394 cont.facility = facility;
1395 cont.level = level;
1396 cont.owner = current;
1397 cont.ts_nsec = local_clock();
1398 cont.cons = 0;
1399 cont.flushed = false;
1400 }
1401
1402 memcpy(cont.buf + cont.len, text, len);
1403 cont.len += len;
1404 return true;
1405}
1406
1407static size_t cont_print_text(char *text, size_t size)
1408{
1409 size_t textlen = 0;
1410 size_t len;
1411
1412 if (cont.cons == 0) {
1413 textlen += print_time(cont.ts_nsec, text);
1414 size -= textlen;
1415 }
1416
1417 len = cont.len - cont.cons;
1418 if (len > 0) {
1419 if (len+1 > size)
1420 len = size-1;
1421 memcpy(text + textlen, cont.buf + cont.cons, len);
1422 textlen += len;
1423 cont.cons = cont.len;
1424 }
1425
1426 if (cont.flushed) {
1427 text[textlen++] = '\n';
1428 /* got everything, release buffer */
1429 cont.len = 0;
1430 }
1431 return textlen;
1432}
1433
1275asmlinkage int vprintk_emit(int facility, int level, 1434asmlinkage int vprintk_emit(int facility, int level,
1276 const char *dict, size_t dictlen, 1435 const char *dict, size_t dictlen,
1277 const char *fmt, va_list args) 1436 const char *fmt, va_list args)
1278{ 1437{
1279 static int recursion_bug; 1438 static int recursion_bug;
1280 static char cont_buf[LOG_LINE_MAX];
1281 static size_t cont_len;
1282 static int cont_level;
1283 static struct task_struct *cont_task;
1284 static char textbuf[LOG_LINE_MAX]; 1439 static char textbuf[LOG_LINE_MAX];
1285 char *text = textbuf; 1440 char *text = textbuf;
1286 size_t text_len; 1441 size_t text_len;
1442 enum log_flags lflags = 0;
1287 unsigned long flags; 1443 unsigned long flags;
1288 int this_cpu; 1444 int this_cpu;
1289 bool newline = false;
1290 bool prefix = false;
1291 int printed_len = 0; 1445 int printed_len = 0;
1292 1446
1293 boot_delay_msec(); 1447 boot_delay_msec();
@@ -1326,7 +1480,8 @@ asmlinkage int vprintk_emit(int facility, int level,
1326 recursion_bug = 0; 1480 recursion_bug = 0;
1327 printed_len += strlen(recursion_msg); 1481 printed_len += strlen(recursion_msg);
1328 /* emit KERN_CRIT message */ 1482 /* emit KERN_CRIT message */
1329 log_store(0, 2, NULL, 0, recursion_msg, printed_len); 1483 log_store(0, 2, LOG_PREFIX|LOG_NEWLINE, 0,
1484 NULL, 0, recursion_msg, printed_len);
1330 } 1485 }
1331 1486
1332 /* 1487 /*
@@ -1338,7 +1493,7 @@ asmlinkage int vprintk_emit(int facility, int level,
1338 /* mark and strip a trailing newline */ 1493 /* mark and strip a trailing newline */
1339 if (text_len && text[text_len-1] == '\n') { 1494 if (text_len && text[text_len-1] == '\n') {
1340 text_len--; 1495 text_len--;
1341 newline = true; 1496 lflags |= LOG_NEWLINE;
1342 } 1497 }
1343 1498
1344 /* strip syslog prefix and extract log level or control flags */ 1499 /* strip syslog prefix and extract log level or control flags */
@@ -1348,7 +1503,7 @@ asmlinkage int vprintk_emit(int facility, int level,
1348 if (level == -1) 1503 if (level == -1)
1349 level = text[1] - '0'; 1504 level = text[1] - '0';
1350 case 'd': /* KERN_DEFAULT */ 1505 case 'd': /* KERN_DEFAULT */
1351 prefix = true; 1506 lflags |= LOG_PREFIX;
1352 case 'c': /* KERN_CONT */ 1507 case 'c': /* KERN_CONT */
1353 text += 3; 1508 text += 3;
1354 text_len -= 3; 1509 text_len -= 3;
@@ -1358,61 +1513,41 @@ asmlinkage int vprintk_emit(int facility, int level,
1358 if (level == -1) 1513 if (level == -1)
1359 level = default_message_loglevel; 1514 level = default_message_loglevel;
1360 1515
1361 if (dict) { 1516 if (dict)
1362 prefix = true; 1517 lflags |= LOG_PREFIX|LOG_NEWLINE;
1363 newline = true;
1364 }
1365 1518
1366 if (!newline) { 1519 if (!(lflags & LOG_NEWLINE)) {
1367 if (cont_len && (prefix || cont_task != current)) { 1520 /*
1368 /* 1521 * Flush the conflicting buffer. An earlier newline was missing,
1369 * Flush earlier buffer, which is either from a 1522 * or another task also prints continuation lines.
1370 * different thread, or when we got a new prefix. 1523 */
1371 */ 1524 if (cont.len && (lflags & LOG_PREFIX || cont.owner != current))
1372 log_store(facility, cont_level, NULL, 0, cont_buf, cont_len); 1525 cont_flush();
1373 cont_len = 0;
1374 }
1375
1376 if (!cont_len) {
1377 cont_level = level;
1378 cont_task = current;
1379 }
1380 1526
1381 /* buffer or append to earlier buffer from the same thread */ 1527 /* buffer line if possible, otherwise store it right away */
1382 if (cont_len + text_len > sizeof(cont_buf)) 1528 if (!cont_add(facility, level, text, text_len))
1383 text_len = sizeof(cont_buf) - cont_len; 1529 log_store(facility, level, lflags | LOG_CONT, 0,
1384 memcpy(cont_buf + cont_len, text, text_len); 1530 dict, dictlen, text, text_len);
1385 cont_len += text_len;
1386 } else { 1531 } else {
1387 if (cont_len && cont_task == current) { 1532 bool stored = false;
1388 if (prefix) {
1389 /*
1390 * New prefix from the same thread; flush. We
1391 * either got no earlier newline, or we race
1392 * with an interrupt.
1393 */
1394 log_store(facility, cont_level,
1395 NULL, 0, cont_buf, cont_len);
1396 cont_len = 0;
1397 }
1398 1533
1399 /* append to the earlier buffer and flush */ 1534 /*
1400 if (cont_len + text_len > sizeof(cont_buf)) 1535 * If an earlier newline was missing and it was the same task,
1401 text_len = sizeof(cont_buf) - cont_len; 1536 * either merge it with the current buffer and flush, or if
1402 memcpy(cont_buf + cont_len, text, text_len); 1537 * there was a race with interrupts (prefix == true) then just
1403 cont_len += text_len; 1538 * flush it out and store this line separately.
1404 log_store(facility, cont_level, 1539 */
1405 NULL, 0, cont_buf, cont_len); 1540 if (cont.len && cont.owner == current) {
1406 cont_len = 0; 1541 if (!(lflags & LOG_PREFIX))
1407 cont_task = NULL; 1542 stored = cont_add(facility, level, text, text_len);
1408 printed_len = cont_len; 1543 cont_flush();
1409 } else {
1410 /* ordinary single and terminated line */
1411 log_store(facility, level,
1412 dict, dictlen, text, text_len);
1413 printed_len = text_len;
1414 } 1544 }
1545
1546 if (!stored)
1547 log_store(facility, level, lflags, 0,
1548 dict, dictlen, text, text_len);
1415 } 1549 }
1550 printed_len += text_len;
1416 1551
1417 /* 1552 /*
1418 * Try to acquire and then immediately release the console semaphore. 1553 * Try to acquire and then immediately release the console semaphore.
@@ -1499,11 +1634,18 @@ EXPORT_SYMBOL(printk);
1499#else 1634#else
1500 1635
1501#define LOG_LINE_MAX 0 1636#define LOG_LINE_MAX 0
1637static struct cont {
1638 size_t len;
1639 size_t cons;
1640 u8 level;
1641 bool flushed:1;
1642} cont;
1502static struct log *log_from_idx(u32 idx) { return NULL; } 1643static struct log *log_from_idx(u32 idx) { return NULL; }
1503static u32 log_next(u32 idx) { return 0; } 1644static u32 log_next(u32 idx) { return 0; }
1504static void call_console_drivers(int level, const char *text, size_t len) {} 1645static void call_console_drivers(int level, const char *text, size_t len) {}
1505static size_t msg_print_text(const struct log *msg, bool syslog, 1646static size_t msg_print_text(const struct log *msg, enum log_flags prev,
1506 char *buf, size_t size) { return 0; } 1647 bool syslog, char *buf, size_t size) { return 0; }
1648static size_t cont_print_text(char *text, size_t size) { return 0; }
1507 1649
1508#endif /* CONFIG_PRINTK */ 1650#endif /* CONFIG_PRINTK */
1509 1651
@@ -1778,6 +1920,7 @@ void wake_up_klogd(void)
1778/* the next printk record to write to the console */ 1920/* the next printk record to write to the console */
1779static u64 console_seq; 1921static u64 console_seq;
1780static u32 console_idx; 1922static u32 console_idx;
1923static enum log_flags console_prev;
1781 1924
1782/** 1925/**
1783 * console_unlock - unlock the console system 1926 * console_unlock - unlock the console system
@@ -1795,6 +1938,7 @@ static u32 console_idx;
1795 */ 1938 */
1796void console_unlock(void) 1939void console_unlock(void)
1797{ 1940{
1941 static char text[LOG_LINE_MAX];
1798 static u64 seen_seq; 1942 static u64 seen_seq;
1799 unsigned long flags; 1943 unsigned long flags;
1800 bool wake_klogd = false; 1944 bool wake_klogd = false;
@@ -1807,10 +1951,23 @@ void console_unlock(void)
1807 1951
1808 console_may_schedule = 0; 1952 console_may_schedule = 0;
1809 1953
1954 /* flush buffered message fragment immediately to console */
1955 raw_spin_lock_irqsave(&logbuf_lock, flags);
1956 if (cont.len && (cont.cons < cont.len || cont.flushed)) {
1957 size_t len;
1958
1959 len = cont_print_text(text, sizeof(text));
1960 raw_spin_unlock(&logbuf_lock);
1961 stop_critical_timings();
1962 call_console_drivers(cont.level, text, len);
1963 start_critical_timings();
1964 local_irq_restore(flags);
1965 } else
1966 raw_spin_unlock_irqrestore(&logbuf_lock, flags);
1967
1810again: 1968again:
1811 for (;;) { 1969 for (;;) {
1812 struct log *msg; 1970 struct log *msg;
1813 static char text[LOG_LINE_MAX];
1814 size_t len; 1971 size_t len;
1815 int level; 1972 int level;
1816 1973
@@ -1824,18 +1981,35 @@ again:
1824 /* messages are gone, move to first one */ 1981 /* messages are gone, move to first one */
1825 console_seq = log_first_seq; 1982 console_seq = log_first_seq;
1826 console_idx = log_first_idx; 1983 console_idx = log_first_idx;
1984 console_prev = 0;
1827 } 1985 }
1828 1986skip:
1829 if (console_seq == log_next_seq) 1987 if (console_seq == log_next_seq)
1830 break; 1988 break;
1831 1989
1832 msg = log_from_idx(console_idx); 1990 msg = log_from_idx(console_idx);
1833 level = msg->level & 7; 1991 if (msg->flags & LOG_NOCONS) {
1834 1992 /*
1835 len = msg_print_text(msg, false, text, sizeof(text)); 1993 * Skip record we have buffered and already printed
1994 * directly to the console when we received it.
1995 */
1996 console_idx = log_next(console_idx);
1997 console_seq++;
1998 /*
1999 * We will get here again when we register a new
2000 * CON_PRINTBUFFER console. Clear the flag so we
2001 * will properly dump everything later.
2002 */
2003 msg->flags &= ~LOG_NOCONS;
2004 goto skip;
2005 }
1836 2006
2007 level = msg->level;
2008 len = msg_print_text(msg, console_prev, false,
2009 text, sizeof(text));
1837 console_idx = log_next(console_idx); 2010 console_idx = log_next(console_idx);
1838 console_seq++; 2011 console_seq++;
2012 console_prev = msg->flags;
1839 raw_spin_unlock(&logbuf_lock); 2013 raw_spin_unlock(&logbuf_lock);
1840 2014
1841 stop_critical_timings(); /* don't trace print latency */ 2015 stop_critical_timings(); /* don't trace print latency */
@@ -2098,6 +2272,7 @@ void register_console(struct console *newcon)
2098 raw_spin_lock_irqsave(&logbuf_lock, flags); 2272 raw_spin_lock_irqsave(&logbuf_lock, flags);
2099 console_seq = syslog_seq; 2273 console_seq = syslog_seq;
2100 console_idx = syslog_idx; 2274 console_idx = syslog_idx;
2275 console_prev = syslog_prev;
2101 raw_spin_unlock_irqrestore(&logbuf_lock, flags); 2276 raw_spin_unlock_irqrestore(&logbuf_lock, flags);
2102 /* 2277 /*
2103 * We're about to replay the log buffer. Only do this to the 2278 * We're about to replay the log buffer. Only do this to the
@@ -2391,8 +2566,7 @@ bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
2391 } 2566 }
2392 2567
2393 msg = log_from_idx(dumper->cur_idx); 2568 msg = log_from_idx(dumper->cur_idx);
2394 l = msg_print_text(msg, syslog, 2569 l = msg_print_text(msg, 0, syslog, line, size);
2395 line, size);
2396 2570
2397 dumper->cur_idx = log_next(dumper->cur_idx); 2571 dumper->cur_idx = log_next(dumper->cur_idx);
2398 dumper->cur_seq++; 2572 dumper->cur_seq++;
@@ -2409,7 +2583,7 @@ EXPORT_SYMBOL_GPL(kmsg_dump_get_line);
2409 * kmsg_dump_get_buffer - copy kmsg log lines 2583 * kmsg_dump_get_buffer - copy kmsg log lines
2410 * @dumper: registered kmsg dumper 2584 * @dumper: registered kmsg dumper
2411 * @syslog: include the "<4>" prefixes 2585 * @syslog: include the "<4>" prefixes
2412 * @line: buffer to copy the line to 2586 * @buf: buffer to copy the line to
2413 * @size: maximum size of the buffer 2587 * @size: maximum size of the buffer
2414 * @len: length of line placed into buffer 2588 * @len: length of line placed into buffer
2415 * 2589 *
@@ -2432,6 +2606,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
2432 u32 idx; 2606 u32 idx;
2433 u64 next_seq; 2607 u64 next_seq;
2434 u32 next_idx; 2608 u32 next_idx;
2609 enum log_flags prev;
2435 size_t l = 0; 2610 size_t l = 0;
2436 bool ret = false; 2611 bool ret = false;
2437 2612
@@ -2454,23 +2629,27 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
2454 /* calculate length of entire buffer */ 2629 /* calculate length of entire buffer */
2455 seq = dumper->cur_seq; 2630 seq = dumper->cur_seq;
2456 idx = dumper->cur_idx; 2631 idx = dumper->cur_idx;
2632 prev = 0;
2457 while (seq < dumper->next_seq) { 2633 while (seq < dumper->next_seq) {
2458 struct log *msg = log_from_idx(idx); 2634 struct log *msg = log_from_idx(idx);
2459 2635
2460 l += msg_print_text(msg, true, NULL, 0); 2636 l += msg_print_text(msg, prev, true, NULL, 0);
2461 idx = log_next(idx); 2637 idx = log_next(idx);
2462 seq++; 2638 seq++;
2639 prev = msg->flags;
2463 } 2640 }
2464 2641
2465 /* move first record forward until length fits into the buffer */ 2642 /* move first record forward until length fits into the buffer */
2466 seq = dumper->cur_seq; 2643 seq = dumper->cur_seq;
2467 idx = dumper->cur_idx; 2644 idx = dumper->cur_idx;
2645 prev = 0;
2468 while (l > size && seq < dumper->next_seq) { 2646 while (l > size && seq < dumper->next_seq) {
2469 struct log *msg = log_from_idx(idx); 2647 struct log *msg = log_from_idx(idx);
2470 2648
2471 l -= msg_print_text(msg, true, NULL, 0); 2649 l -= msg_print_text(msg, prev, true, NULL, 0);
2472 idx = log_next(idx); 2650 idx = log_next(idx);
2473 seq++; 2651 seq++;
2652 prev = msg->flags;
2474 } 2653 }
2475 2654
2476 /* last message in next interation */ 2655 /* last message in next interation */
@@ -2478,14 +2657,14 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
2478 next_idx = idx; 2657 next_idx = idx;
2479 2658
2480 l = 0; 2659 l = 0;
2660 prev = 0;
2481 while (seq < dumper->next_seq) { 2661 while (seq < dumper->next_seq) {
2482 struct log *msg = log_from_idx(idx); 2662 struct log *msg = log_from_idx(idx);
2483 2663
2484 l += msg_print_text(msg, syslog, 2664 l += msg_print_text(msg, prev, syslog, buf + l, size - l);
2485 buf + l, size - l);
2486
2487 idx = log_next(idx); 2665 idx = log_next(idx);
2488 seq++; 2666 seq++;
2667 prev = msg->flags;
2489 } 2668 }
2490 2669
2491 dumper->next_seq = next_seq; 2670 dumper->next_seq = next_seq;