aboutsummaryrefslogtreecommitdiffstats
path: root/kernel/trace/trace.c
diff options
context:
space:
mode:
Diffstat (limited to 'kernel/trace/trace.c')
-rw-r--r--kernel/trace/trace.c149
1 files changed, 35 insertions, 114 deletions
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 2f8ac1f008f5..5ec49c3c1597 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -227,7 +227,7 @@ static DECLARE_WAIT_QUEUE_HEAD(trace_wait);
227 227
228/* trace_flags holds trace_options default values */ 228/* trace_flags holds trace_options default values */
229unsigned long trace_flags = TRACE_ITER_PRINT_PARENT | TRACE_ITER_PRINTK | 229unsigned long trace_flags = TRACE_ITER_PRINT_PARENT | TRACE_ITER_PRINTK |
230 TRACE_ITER_ANNOTATE; 230 TRACE_ITER_ANNOTATE | TRACE_ITER_CONTEXT_INFO;
231 231
232/** 232/**
233 * trace_wake_up - wake up tasks waiting for trace input 233 * trace_wake_up - wake up tasks waiting for trace input
@@ -285,6 +285,7 @@ static const char *trace_options[] = {
285 "userstacktrace", 285 "userstacktrace",
286 "sym-userobj", 286 "sym-userobj",
287 "printk-msg-only", 287 "printk-msg-only",
288 "context-info",
288 NULL 289 NULL
289}; 290};
290 291
@@ -1171,8 +1172,8 @@ __find_next_entry(struct trace_iterator *iter, int *ent_cpu, u64 *ent_ts)
1171} 1172}
1172 1173
1173/* Find the next real entry, without updating the iterator itself */ 1174/* Find the next real entry, without updating the iterator itself */
1174static struct trace_entry * 1175struct trace_entry *trace_find_next_entry(struct trace_iterator *iter,
1175find_next_entry(struct trace_iterator *iter, int *ent_cpu, u64 *ent_ts) 1176 int *ent_cpu, u64 *ent_ts)
1176{ 1177{
1177 return __find_next_entry(iter, ent_cpu, ent_ts); 1178 return __find_next_entry(iter, ent_cpu, ent_ts);
1178} 1179}
@@ -1351,57 +1352,6 @@ print_trace_header(struct seq_file *m, struct trace_iterator *iter)
1351 seq_puts(m, "\n"); 1352 seq_puts(m, "\n");
1352} 1353}
1353 1354
1354static void
1355lat_print_generic(struct trace_seq *s, struct trace_entry *entry, int cpu)
1356{
1357 int hardirq, softirq;
1358 char *comm;
1359
1360 comm = trace_find_cmdline(entry->pid);
1361
1362 trace_seq_printf(s, "%8.8s-%-5d ", comm, entry->pid);
1363 trace_seq_printf(s, "%3d", cpu);
1364 trace_seq_printf(s, "%c%c",
1365 (entry->flags & TRACE_FLAG_IRQS_OFF) ? 'd' :
1366 (entry->flags & TRACE_FLAG_IRQS_NOSUPPORT) ? 'X' : '.',
1367 ((entry->flags & TRACE_FLAG_NEED_RESCHED) ? 'N' : '.'));
1368
1369 hardirq = entry->flags & TRACE_FLAG_HARDIRQ;
1370 softirq = entry->flags & TRACE_FLAG_SOFTIRQ;
1371 if (hardirq && softirq) {
1372 trace_seq_putc(s, 'H');
1373 } else {
1374 if (hardirq) {
1375 trace_seq_putc(s, 'h');
1376 } else {
1377 if (softirq)
1378 trace_seq_putc(s, 's');
1379 else
1380 trace_seq_putc(s, '.');
1381 }
1382 }
1383
1384 if (entry->preempt_count)
1385 trace_seq_printf(s, "%x", entry->preempt_count);
1386 else
1387 trace_seq_puts(s, ".");
1388}
1389
1390unsigned long preempt_mark_thresh = 100;
1391
1392static void
1393lat_print_timestamp(struct trace_seq *s, u64 abs_usecs,
1394 unsigned long rel_usecs)
1395{
1396 trace_seq_printf(s, " %4lldus", abs_usecs);
1397 if (rel_usecs > preempt_mark_thresh)
1398 trace_seq_puts(s, "!: ");
1399 else if (rel_usecs > 1)
1400 trace_seq_puts(s, "+: ");
1401 else
1402 trace_seq_puts(s, " : ");
1403}
1404
1405static void test_cpu_buff_start(struct trace_iterator *iter) 1355static void test_cpu_buff_start(struct trace_iterator *iter)
1406{ 1356{
1407 struct trace_seq *s = &iter->seq; 1357 struct trace_seq *s = &iter->seq;
@@ -1419,46 +1369,24 @@ static void test_cpu_buff_start(struct trace_iterator *iter)
1419 trace_seq_printf(s, "##### CPU %u buffer started ####\n", iter->cpu); 1369 trace_seq_printf(s, "##### CPU %u buffer started ####\n", iter->cpu);
1420} 1370}
1421 1371
1422static enum print_line_t 1372static enum print_line_t print_lat_fmt(struct trace_iterator *iter)
1423print_lat_fmt(struct trace_iterator *iter, unsigned int trace_idx, int cpu)
1424{ 1373{
1425 struct trace_seq *s = &iter->seq; 1374 struct trace_seq *s = &iter->seq;
1426 unsigned long sym_flags = (trace_flags & TRACE_ITER_SYM_MASK); 1375 unsigned long sym_flags = (trace_flags & TRACE_ITER_SYM_MASK);
1427 struct trace_entry *next_entry;
1428 struct trace_event *event; 1376 struct trace_event *event;
1429 unsigned long verbose = (trace_flags & TRACE_ITER_VERBOSE);
1430 struct trace_entry *entry = iter->ent; 1377 struct trace_entry *entry = iter->ent;
1431 unsigned long abs_usecs;
1432 unsigned long rel_usecs;
1433 u64 next_ts;
1434 char *comm;
1435 int ret; 1378 int ret;
1436 1379
1437 test_cpu_buff_start(iter); 1380 test_cpu_buff_start(iter);
1438 1381
1439 next_entry = find_next_entry(iter, NULL, &next_ts); 1382 event = ftrace_find_event(entry->type);
1440 if (!next_entry) 1383
1441 next_ts = iter->ts; 1384 if (trace_flags & TRACE_ITER_CONTEXT_INFO) {
1442 rel_usecs = ns2usecs(next_ts - iter->ts); 1385 ret = trace_print_lat_context(iter);
1443 abs_usecs = ns2usecs(iter->ts - iter->tr->time_start); 1386 if (ret)
1444 1387 return ret;
1445 if (verbose) {
1446 comm = trace_find_cmdline(entry->pid);
1447 trace_seq_printf(s, "%16s %5d %3d %d %08x %08x [%08lx]"
1448 " %ld.%03ldms (+%ld.%03ldms): ",
1449 comm,
1450 entry->pid, cpu, entry->flags,
1451 entry->preempt_count, trace_idx,
1452 ns2usecs(iter->ts),
1453 abs_usecs/1000,
1454 abs_usecs % 1000, rel_usecs/1000,
1455 rel_usecs % 1000);
1456 } else {
1457 lat_print_generic(s, entry, cpu);
1458 lat_print_timestamp(s, abs_usecs, rel_usecs);
1459 } 1388 }
1460 1389
1461 event = ftrace_find_event(entry->type);
1462 if (event && event->latency_trace) { 1390 if (event && event->latency_trace) {
1463 ret = event->latency_trace(s, entry, sym_flags); 1391 ret = event->latency_trace(s, entry, sym_flags);
1464 if (ret) 1392 if (ret)
@@ -1476,33 +1404,20 @@ static enum print_line_t print_trace_fmt(struct trace_iterator *iter)
1476 unsigned long sym_flags = (trace_flags & TRACE_ITER_SYM_MASK); 1404 unsigned long sym_flags = (trace_flags & TRACE_ITER_SYM_MASK);
1477 struct trace_entry *entry; 1405 struct trace_entry *entry;
1478 struct trace_event *event; 1406 struct trace_event *event;
1479 unsigned long usec_rem;
1480 unsigned long long t;
1481 unsigned long secs;
1482 char *comm;
1483 int ret; 1407 int ret;
1484 1408
1485 entry = iter->ent; 1409 entry = iter->ent;
1486 1410
1487 test_cpu_buff_start(iter); 1411 test_cpu_buff_start(iter);
1488 1412
1489 comm = trace_find_cmdline(iter->ent->pid); 1413 event = ftrace_find_event(entry->type);
1490
1491 t = ns2usecs(iter->ts);
1492 usec_rem = do_div(t, 1000000ULL);
1493 secs = (unsigned long)t;
1494 1414
1495 ret = trace_seq_printf(s, "%16s-%-5d ", comm, entry->pid); 1415 if (trace_flags & TRACE_ITER_CONTEXT_INFO) {
1496 if (!ret) 1416 ret = trace_print_context(iter);
1497 return TRACE_TYPE_PARTIAL_LINE; 1417 if (ret)
1498 ret = trace_seq_printf(s, "[%03d] ", iter->cpu); 1418 return ret;
1499 if (!ret) 1419 }
1500 return TRACE_TYPE_PARTIAL_LINE;
1501 ret = trace_seq_printf(s, "%5lu.%06lu: ", secs, usec_rem);
1502 if (!ret)
1503 return TRACE_TYPE_PARTIAL_LINE;
1504 1420
1505 event = ftrace_find_event(entry->type);
1506 if (event && event->trace) { 1421 if (event && event->trace) {
1507 ret = event->trace(s, entry, sym_flags); 1422 ret = event->trace(s, entry, sym_flags);
1508 if (ret) 1423 if (ret)
@@ -1525,10 +1440,12 @@ static enum print_line_t print_raw_fmt(struct trace_iterator *iter)
1525 1440
1526 entry = iter->ent; 1441 entry = iter->ent;
1527 1442
1528 ret = trace_seq_printf(s, "%d %d %llu ", 1443 if (trace_flags & TRACE_ITER_CONTEXT_INFO) {
1529 entry->pid, iter->cpu, iter->ts); 1444 ret = trace_seq_printf(s, "%d %d %llu ",
1530 if (!ret) 1445 entry->pid, iter->cpu, iter->ts);
1531 return TRACE_TYPE_PARTIAL_LINE; 1446 if (!ret)
1447 return TRACE_TYPE_PARTIAL_LINE;
1448 }
1532 1449
1533 event = ftrace_find_event(entry->type); 1450 event = ftrace_find_event(entry->type);
1534 if (event && event->raw) { 1451 if (event && event->raw) {
@@ -1553,9 +1470,11 @@ static enum print_line_t print_hex_fmt(struct trace_iterator *iter)
1553 1470
1554 entry = iter->ent; 1471 entry = iter->ent;
1555 1472
1556 SEQ_PUT_HEX_FIELD_RET(s, entry->pid); 1473 if (trace_flags & TRACE_ITER_CONTEXT_INFO) {
1557 SEQ_PUT_HEX_FIELD_RET(s, iter->cpu); 1474 SEQ_PUT_HEX_FIELD_RET(s, entry->pid);
1558 SEQ_PUT_HEX_FIELD_RET(s, iter->ts); 1475 SEQ_PUT_HEX_FIELD_RET(s, iter->cpu);
1476 SEQ_PUT_HEX_FIELD_RET(s, iter->ts);
1477 }
1559 1478
1560 event = ftrace_find_event(entry->type); 1479 event = ftrace_find_event(entry->type);
1561 if (event && event->hex) 1480 if (event && event->hex)
@@ -1575,7 +1494,7 @@ static enum print_line_t print_printk_msg_only(struct trace_iterator *iter)
1575 1494
1576 trace_assign_type(field, entry); 1495 trace_assign_type(field, entry);
1577 1496
1578 ret = trace_seq_printf(s, field->buf); 1497 ret = trace_seq_printf(s, "%s", field->buf);
1579 if (!ret) 1498 if (!ret)
1580 return TRACE_TYPE_PARTIAL_LINE; 1499 return TRACE_TYPE_PARTIAL_LINE;
1581 1500
@@ -1590,9 +1509,11 @@ static enum print_line_t print_bin_fmt(struct trace_iterator *iter)
1590 1509
1591 entry = iter->ent; 1510 entry = iter->ent;
1592 1511
1593 SEQ_PUT_FIELD_RET(s, entry->pid); 1512 if (trace_flags & TRACE_ITER_CONTEXT_INFO) {
1594 SEQ_PUT_FIELD_RET(s, entry->cpu); 1513 SEQ_PUT_FIELD_RET(s, entry->pid);
1595 SEQ_PUT_FIELD_RET(s, iter->ts); 1514 SEQ_PUT_FIELD_RET(s, entry->cpu);
1515 SEQ_PUT_FIELD_RET(s, iter->ts);
1516 }
1596 1517
1597 event = ftrace_find_event(entry->type); 1518 event = ftrace_find_event(entry->type);
1598 if (event && event->binary) 1519 if (event && event->binary)
@@ -1643,7 +1564,7 @@ static enum print_line_t print_trace_line(struct trace_iterator *iter)
1643 return print_raw_fmt(iter); 1564 return print_raw_fmt(iter);
1644 1565
1645 if (iter->iter_flags & TRACE_FILE_LAT_FMT) 1566 if (iter->iter_flags & TRACE_FILE_LAT_FMT)
1646 return print_lat_fmt(iter, iter->idx, iter->cpu); 1567 return print_lat_fmt(iter);
1647 1568
1648 return print_trace_fmt(iter); 1569 return print_trace_fmt(iter);
1649} 1570}