aboutsummaryrefslogtreecommitdiffstats
path: root/kernel/printk.c
diff options
context:
space:
mode:
authorDavid S. Miller <davem@davemloft.net>2012-07-05 06:44:25 -0400
committerDavid S. Miller <davem@davemloft.net>2012-07-05 06:44:25 -0400
commitc90a9bb9073a4096596360f02ea711c619663494 (patch)
treedc85d9f4c0d423e6b523e81c41a5b68e267de14f /kernel/printk.c
parent23c342153ef2a4ad8bd4f2d6515126449658d2b3 (diff)
parent9e85a6f9dc231f3ed3c1dc1b12217505d970142a (diff)
Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net
Diffstat (limited to 'kernel/printk.c')
-rw-r--r--kernel/printk.c299
1 files changed, 214 insertions, 85 deletions
diff --git a/kernel/printk.c b/kernel/printk.c
index a2276b916769..dba18211685e 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -193,12 +193,19 @@ 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_DEFAULT = 0,
198 LOG_NOCONS = 1, /* already flushed, do not print to console */
199};
200
196struct log { 201struct log {
197 u64 ts_nsec; /* timestamp in nanoseconds */ 202 u64 ts_nsec; /* timestamp in nanoseconds */
198 u16 len; /* length of entire record */ 203 u16 len; /* length of entire record */
199 u16 text_len; /* length of text buffer */ 204 u16 text_len; /* length of text buffer */
200 u16 dict_len; /* length of dictionary buffer */ 205 u16 dict_len; /* length of dictionary buffer */
201 u16 level; /* syslog level + facility */ 206 u8 facility; /* syslog facility */
207 u8 flags:5; /* internal record flags */
208 u8 level:3; /* syslog level */
202}; 209};
203 210
204/* 211/*
@@ -286,6 +293,7 @@ static u32 log_next(u32 idx)
286 293
287/* insert record into the buffer, discard old ones, update heads */ 294/* insert record into the buffer, discard old ones, update heads */
288static void log_store(int facility, int level, 295static void log_store(int facility, int level,
296 enum log_flags flags, u64 ts_nsec,
289 const char *dict, u16 dict_len, 297 const char *dict, u16 dict_len,
290 const char *text, u16 text_len) 298 const char *text, u16 text_len)
291{ 299{
@@ -329,8 +337,13 @@ static void log_store(int facility, int level,
329 msg->text_len = text_len; 337 msg->text_len = text_len;
330 memcpy(log_dict(msg), dict, dict_len); 338 memcpy(log_dict(msg), dict, dict_len);
331 msg->dict_len = dict_len; 339 msg->dict_len = dict_len;
332 msg->level = (facility << 3) | (level & 7); 340 msg->facility = facility;
333 msg->ts_nsec = local_clock(); 341 msg->level = level & 7;
342 msg->flags = flags & 0x1f;
343 if (ts_nsec > 0)
344 msg->ts_nsec = ts_nsec;
345 else
346 msg->ts_nsec = local_clock();
334 memset(log_dict(msg) + dict_len, 0, pad_len); 347 memset(log_dict(msg) + dict_len, 0, pad_len);
335 msg->len = sizeof(struct log) + text_len + dict_len + pad_len; 348 msg->len = sizeof(struct log) + text_len + dict_len + pad_len;
336 349
@@ -446,7 +459,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
446 ts_usec = msg->ts_nsec; 459 ts_usec = msg->ts_nsec;
447 do_div(ts_usec, 1000); 460 do_div(ts_usec, 1000);
448 len = sprintf(user->buf, "%u,%llu,%llu;", 461 len = sprintf(user->buf, "%u,%llu,%llu;",
449 msg->level, user->seq, ts_usec); 462 (msg->facility << 3) | msg->level, user->seq, ts_usec);
450 463
451 /* escape non-printable characters */ 464 /* escape non-printable characters */
452 for (i = 0; i < msg->text_len; i++) { 465 for (i = 0; i < msg->text_len; i++) {
@@ -787,6 +800,21 @@ static bool printk_time;
787#endif 800#endif
788module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR); 801module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
789 802
803static size_t print_time(u64 ts, char *buf)
804{
805 unsigned long rem_nsec;
806
807 if (!printk_time)
808 return 0;
809
810 if (!buf)
811 return 15;
812
813 rem_nsec = do_div(ts, 1000000000);
814 return sprintf(buf, "[%5lu.%06lu] ",
815 (unsigned long)ts, rem_nsec / 1000);
816}
817
790static size_t print_prefix(const struct log *msg, bool syslog, char *buf) 818static size_t print_prefix(const struct log *msg, bool syslog, char *buf)
791{ 819{
792 size_t len = 0; 820 size_t len = 0;
@@ -803,18 +831,7 @@ static size_t print_prefix(const struct log *msg, bool syslog, char *buf)
803 } 831 }
804 } 832 }
805 833
806 if (printk_time) { 834 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; 835 return len;
819} 836}
820 837
@@ -862,28 +879,49 @@ static int syslog_print(char __user *buf, int size)
862{ 879{
863 char *text; 880 char *text;
864 struct log *msg; 881 struct log *msg;
865 int len; 882 int len = 0;
866 883
867 text = kmalloc(LOG_LINE_MAX, GFP_KERNEL); 884 text = kmalloc(LOG_LINE_MAX, GFP_KERNEL);
868 if (!text) 885 if (!text)
869 return -ENOMEM; 886 return -ENOMEM;
870 887
871 raw_spin_lock_irq(&logbuf_lock); 888 while (size > 0) {
872 if (syslog_seq < log_first_seq) { 889 size_t n;
873 /* messages are gone, move to first one */
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 890
883 if (len > size) 891 raw_spin_lock_irq(&logbuf_lock);
884 len = -EINVAL; 892 if (syslog_seq < log_first_seq) {
885 else if (len > 0 && copy_to_user(buf, text, len)) 893 /* messages are gone, move to first one */
886 len = -EFAULT; 894 syslog_seq = log_first_seq;
895 syslog_idx = log_first_idx;
896 }
897 if (syslog_seq == log_next_seq) {
898 raw_spin_unlock_irq(&logbuf_lock);
899 break;
900 }
901 msg = log_from_idx(syslog_idx);
902 n = msg_print_text(msg, true, text, LOG_LINE_MAX);
903 if (n <= size) {
904 syslog_idx = log_next(syslog_idx);
905 syslog_seq++;
906 } else
907 n = 0;
908 raw_spin_unlock_irq(&logbuf_lock);
909
910 if (!n)
911 break;
912
913 len += n;
914 size -= n;
915 buf += n;
916 n = copy_to_user(buf - n, text, n);
917
918 if (n) {
919 len -= n;
920 if (!len)
921 len = -EFAULT;
922 break;
923 }
924 }
887 925
888 kfree(text); 926 kfree(text);
889 return len; 927 return len;
@@ -1040,6 +1078,7 @@ int do_syslog(int type, char __user *buf, int len, bool from_file)
1040 /* Clear ring buffer */ 1078 /* Clear ring buffer */
1041 case SYSLOG_ACTION_CLEAR: 1079 case SYSLOG_ACTION_CLEAR:
1042 syslog_print_all(NULL, 0, true); 1080 syslog_print_all(NULL, 0, true);
1081 break;
1043 /* Disable logging to console */ 1082 /* Disable logging to console */
1044 case SYSLOG_ACTION_CONSOLE_OFF: 1083 case SYSLOG_ACTION_CONSOLE_OFF:
1045 if (saved_console_loglevel == -1) 1084 if (saved_console_loglevel == -1)
@@ -1272,15 +1311,92 @@ static inline void printk_delay(void)
1272 } 1311 }
1273} 1312}
1274 1313
1314/*
1315 * Continuation lines are buffered, and not committed to the record buffer
1316 * until the line is complete, or a race forces it. The line fragments
1317 * though, are printed immediately to the consoles to ensure everything has
1318 * reached the console in case of a kernel crash.
1319 */
1320static struct cont {
1321 char buf[LOG_LINE_MAX];
1322 size_t len; /* length == 0 means unused buffer */
1323 size_t cons; /* bytes written to console */
1324 struct task_struct *owner; /* task of first print*/
1325 u64 ts_nsec; /* time of first print */
1326 u8 level; /* log level of first message */
1327 u8 facility; /* log level of first message */
1328 bool flushed:1; /* buffer sealed and committed */
1329} cont;
1330
1331static void cont_flush(void)
1332{
1333 if (cont.flushed)
1334 return;
1335 if (cont.len == 0)
1336 return;
1337
1338 log_store(cont.facility, cont.level, LOG_NOCONS, cont.ts_nsec,
1339 NULL, 0, cont.buf, cont.len);
1340
1341 cont.flushed = true;
1342}
1343
1344static bool cont_add(int facility, int level, const char *text, size_t len)
1345{
1346 if (cont.len && cont.flushed)
1347 return false;
1348
1349 if (cont.len + len > sizeof(cont.buf)) {
1350 cont_flush();
1351 return false;
1352 }
1353
1354 if (!cont.len) {
1355 cont.facility = facility;
1356 cont.level = level;
1357 cont.owner = current;
1358 cont.ts_nsec = local_clock();
1359 cont.cons = 0;
1360 cont.flushed = false;
1361 }
1362
1363 memcpy(cont.buf + cont.len, text, len);
1364 cont.len += len;
1365 return true;
1366}
1367
1368static size_t cont_print_text(char *text, size_t size)
1369{
1370 size_t textlen = 0;
1371 size_t len;
1372
1373 if (cont.cons == 0) {
1374 textlen += print_time(cont.ts_nsec, text);
1375 size -= textlen;
1376 }
1377
1378 len = cont.len - cont.cons;
1379 if (len > 0) {
1380 if (len+1 > size)
1381 len = size-1;
1382 memcpy(text + textlen, cont.buf + cont.cons, len);
1383 textlen += len;
1384 cont.cons = cont.len;
1385 }
1386
1387 if (cont.flushed) {
1388 text[textlen++] = '\n';
1389 /* got everything, release buffer */
1390 cont.len = 0;
1391 }
1392 return textlen;
1393}
1394
1275asmlinkage int vprintk_emit(int facility, int level, 1395asmlinkage int vprintk_emit(int facility, int level,
1276 const char *dict, size_t dictlen, 1396 const char *dict, size_t dictlen,
1277 const char *fmt, va_list args) 1397 const char *fmt, va_list args)
1278{ 1398{
1279 static int recursion_bug; 1399 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]; 1400 static char textbuf[LOG_LINE_MAX];
1285 char *text = textbuf; 1401 char *text = textbuf;
1286 size_t text_len; 1402 size_t text_len;
@@ -1326,7 +1442,8 @@ asmlinkage int vprintk_emit(int facility, int level,
1326 recursion_bug = 0; 1442 recursion_bug = 0;
1327 printed_len += strlen(recursion_msg); 1443 printed_len += strlen(recursion_msg);
1328 /* emit KERN_CRIT message */ 1444 /* emit KERN_CRIT message */
1329 log_store(0, 2, NULL, 0, recursion_msg, printed_len); 1445 log_store(0, 2, LOG_DEFAULT, 0,
1446 NULL, 0, recursion_msg, printed_len);
1330 } 1447 }
1331 1448
1332 /* 1449 /*
@@ -1364,55 +1481,37 @@ asmlinkage int vprintk_emit(int facility, int level,
1364 } 1481 }
1365 1482
1366 if (!newline) { 1483 if (!newline) {
1367 if (cont_len && (prefix || cont_task != current)) { 1484 /*
1368 /* 1485 * Flush the conflicting buffer. An earlier newline was missing,
1369 * Flush earlier buffer, which is either from a 1486 * or another task also prints continuation lines.
1370 * different thread, or when we got a new prefix. 1487 */
1371 */ 1488 if (cont.len && (prefix || cont.owner != current))
1372 log_store(facility, cont_level, NULL, 0, cont_buf, cont_len); 1489 cont_flush();
1373 cont_len = 0;
1374 }
1375
1376 if (!cont_len) {
1377 cont_level = level;
1378 cont_task = current;
1379 }
1380 1490
1381 /* buffer or append to earlier buffer from the same thread */ 1491 /* buffer line if possible, otherwise store it right away */
1382 if (cont_len + text_len > sizeof(cont_buf)) 1492 if (!cont_add(facility, level, text, text_len))
1383 text_len = sizeof(cont_buf) - cont_len; 1493 log_store(facility, level, LOG_DEFAULT, 0,
1384 memcpy(cont_buf + cont_len, text, text_len); 1494 dict, dictlen, text, text_len);
1385 cont_len += text_len;
1386 } else { 1495 } else {
1387 if (cont_len && cont_task == current) { 1496 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 1497
1399 /* append to the earlier buffer and flush */ 1498 /*
1400 if (cont_len + text_len > sizeof(cont_buf)) 1499 * If an earlier newline was missing and it was the same task,
1401 text_len = sizeof(cont_buf) - cont_len; 1500 * either merge it with the current buffer and flush, or if
1402 memcpy(cont_buf + cont_len, text, text_len); 1501 * there was a race with interrupts (prefix == true) then just
1403 cont_len += text_len; 1502 * flush it out and store this line separately.
1404 log_store(facility, cont_level, 1503 */
1405 NULL, 0, cont_buf, cont_len); 1504 if (cont.len && cont.owner == current) {
1406 cont_len = 0; 1505 if (!prefix)
1407 cont_task = NULL; 1506 stored = cont_add(facility, level, text, text_len);
1408 printed_len = cont_len; 1507 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 } 1508 }
1509
1510 if (!stored)
1511 log_store(facility, level, LOG_DEFAULT, 0,
1512 dict, dictlen, text, text_len);
1415 } 1513 }
1514 printed_len += text_len;
1416 1515
1417 /* 1516 /*
1418 * Try to acquire and then immediately release the console semaphore. 1517 * Try to acquire and then immediately release the console semaphore.
@@ -1499,11 +1598,18 @@ EXPORT_SYMBOL(printk);
1499#else 1598#else
1500 1599
1501#define LOG_LINE_MAX 0 1600#define LOG_LINE_MAX 0
1601static struct cont {
1602 size_t len;
1603 size_t cons;
1604 u8 level;
1605 bool flushed:1;
1606} cont;
1502static struct log *log_from_idx(u32 idx) { return NULL; } 1607static struct log *log_from_idx(u32 idx) { return NULL; }
1503static u32 log_next(u32 idx) { return 0; } 1608static u32 log_next(u32 idx) { return 0; }
1504static void call_console_drivers(int level, const char *text, size_t len) {} 1609static void call_console_drivers(int level, const char *text, size_t len) {}
1505static size_t msg_print_text(const struct log *msg, bool syslog, 1610static size_t msg_print_text(const struct log *msg, bool syslog,
1506 char *buf, size_t size) { return 0; } 1611 char *buf, size_t size) { return 0; }
1612static size_t cont_print_text(char *text, size_t size) { return 0; }
1507 1613
1508#endif /* CONFIG_PRINTK */ 1614#endif /* CONFIG_PRINTK */
1509 1615
@@ -1795,6 +1901,7 @@ static u32 console_idx;
1795 */ 1901 */
1796void console_unlock(void) 1902void console_unlock(void)
1797{ 1903{
1904 static char text[LOG_LINE_MAX];
1798 static u64 seen_seq; 1905 static u64 seen_seq;
1799 unsigned long flags; 1906 unsigned long flags;
1800 bool wake_klogd = false; 1907 bool wake_klogd = false;
@@ -1807,10 +1914,23 @@ void console_unlock(void)
1807 1914
1808 console_may_schedule = 0; 1915 console_may_schedule = 0;
1809 1916
1917 /* flush buffered message fragment immediately to console */
1918 raw_spin_lock_irqsave(&logbuf_lock, flags);
1919 if (cont.len && (cont.cons < cont.len || cont.flushed)) {
1920 size_t len;
1921
1922 len = cont_print_text(text, sizeof(text));
1923 raw_spin_unlock(&logbuf_lock);
1924 stop_critical_timings();
1925 call_console_drivers(cont.level, text, len);
1926 start_critical_timings();
1927 local_irq_restore(flags);
1928 } else
1929 raw_spin_unlock_irqrestore(&logbuf_lock, flags);
1930
1810again: 1931again:
1811 for (;;) { 1932 for (;;) {
1812 struct log *msg; 1933 struct log *msg;
1813 static char text[LOG_LINE_MAX];
1814 size_t len; 1934 size_t len;
1815 int level; 1935 int level;
1816 1936
@@ -1825,13 +1945,22 @@ again:
1825 console_seq = log_first_seq; 1945 console_seq = log_first_seq;
1826 console_idx = log_first_idx; 1946 console_idx = log_first_idx;
1827 } 1947 }
1828 1948skip:
1829 if (console_seq == log_next_seq) 1949 if (console_seq == log_next_seq)
1830 break; 1950 break;
1831 1951
1832 msg = log_from_idx(console_idx); 1952 msg = log_from_idx(console_idx);
1833 level = msg->level & 7; 1953 if (msg->flags & LOG_NOCONS) {
1954 /*
1955 * Skip record we have buffered and already printed
1956 * directly to the console when we received it.
1957 */
1958 console_idx = log_next(console_idx);
1959 console_seq++;
1960 goto skip;
1961 }
1834 1962
1963 level = msg->level;
1835 len = msg_print_text(msg, false, text, sizeof(text)); 1964 len = msg_print_text(msg, false, text, sizeof(text));
1836 1965
1837 console_idx = log_next(console_idx); 1966 console_idx = log_next(console_idx);
@@ -2409,7 +2538,7 @@ EXPORT_SYMBOL_GPL(kmsg_dump_get_line);
2409 * kmsg_dump_get_buffer - copy kmsg log lines 2538 * kmsg_dump_get_buffer - copy kmsg log lines
2410 * @dumper: registered kmsg dumper 2539 * @dumper: registered kmsg dumper
2411 * @syslog: include the "<4>" prefixes 2540 * @syslog: include the "<4>" prefixes
2412 * @line: buffer to copy the line to 2541 * @buf: buffer to copy the line to
2413 * @size: maximum size of the buffer 2542 * @size: maximum size of the buffer
2414 * @len: length of line placed into buffer 2543 * @len: length of line placed into buffer
2415 * 2544 *