diff options
Diffstat (limited to 'kernel/trace/trace.c')
-rw-r--r-- | kernel/trace/trace.c | 149 |
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 */ |
229 | unsigned long trace_flags = TRACE_ITER_PRINT_PARENT | TRACE_ITER_PRINTK | | 229 | unsigned 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 */ |
1174 | static struct trace_entry * | 1175 | struct trace_entry *trace_find_next_entry(struct trace_iterator *iter, |
1175 | find_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 | ||
1354 | static void | ||
1355 | lat_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 | |||
1390 | unsigned long preempt_mark_thresh = 100; | ||
1391 | |||
1392 | static void | ||
1393 | lat_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 | |||
1405 | static void test_cpu_buff_start(struct trace_iterator *iter) | 1355 | static 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 | ||
1422 | static enum print_line_t | 1372 | static enum print_line_t print_lat_fmt(struct trace_iterator *iter) |
1423 | print_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 | } |