diff options
Diffstat (limited to 'kernel/trace/trace_output.c')
-rw-r--r-- | kernel/trace/trace_output.c | 78 |
1 files changed, 53 insertions, 25 deletions
diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c index 123b189c732c..194d79602dc7 100644 --- a/kernel/trace/trace_output.c +++ b/kernel/trace/trace_output.c | |||
@@ -610,24 +610,54 @@ lat_print_generic(struct trace_seq *s, struct trace_entry *entry, int cpu) | |||
610 | return trace_print_lat_fmt(s, entry); | 610 | return trace_print_lat_fmt(s, entry); |
611 | } | 611 | } |
612 | 612 | ||
613 | static unsigned long preempt_mark_thresh = 100; | 613 | static unsigned long preempt_mark_thresh_us = 100; |
614 | 614 | ||
615 | static int | 615 | static int |
616 | lat_print_timestamp(struct trace_seq *s, u64 abs_usecs, | 616 | lat_print_timestamp(struct trace_iterator *iter, u64 next_ts) |
617 | unsigned long rel_usecs) | ||
618 | { | 617 | { |
619 | return trace_seq_printf(s, " %4lldus%c: ", abs_usecs, | 618 | unsigned long verbose = trace_flags & TRACE_ITER_VERBOSE; |
620 | rel_usecs > preempt_mark_thresh ? '!' : | 619 | unsigned long in_ns = iter->iter_flags & TRACE_FILE_TIME_IN_NS; |
621 | rel_usecs > 1 ? '+' : ' '); | 620 | unsigned long long abs_ts = iter->ts - iter->tr->time_start; |
621 | unsigned long long rel_ts = next_ts - iter->ts; | ||
622 | struct trace_seq *s = &iter->seq; | ||
623 | |||
624 | if (in_ns) { | ||
625 | abs_ts = ns2usecs(abs_ts); | ||
626 | rel_ts = ns2usecs(rel_ts); | ||
627 | } | ||
628 | |||
629 | if (verbose && in_ns) { | ||
630 | unsigned long abs_usec = do_div(abs_ts, USEC_PER_MSEC); | ||
631 | unsigned long abs_msec = (unsigned long)abs_ts; | ||
632 | unsigned long rel_usec = do_div(rel_ts, USEC_PER_MSEC); | ||
633 | unsigned long rel_msec = (unsigned long)rel_ts; | ||
634 | |||
635 | return trace_seq_printf( | ||
636 | s, "[%08llx] %ld.%03ldms (+%ld.%03ldms): ", | ||
637 | ns2usecs(iter->ts), | ||
638 | abs_msec, abs_usec, | ||
639 | rel_msec, rel_usec); | ||
640 | } else if (verbose && !in_ns) { | ||
641 | return trace_seq_printf( | ||
642 | s, "[%016llx] %lld (+%lld): ", | ||
643 | iter->ts, abs_ts, rel_ts); | ||
644 | } else if (!verbose && in_ns) { | ||
645 | return trace_seq_printf( | ||
646 | s, " %4lldus%c: ", | ||
647 | abs_ts, | ||
648 | rel_ts > preempt_mark_thresh_us ? '!' : | ||
649 | rel_ts > 1 ? '+' : ' '); | ||
650 | } else { /* !verbose && !in_ns */ | ||
651 | return trace_seq_printf(s, " %4lld: ", abs_ts); | ||
652 | } | ||
622 | } | 653 | } |
623 | 654 | ||
624 | int trace_print_context(struct trace_iterator *iter) | 655 | int trace_print_context(struct trace_iterator *iter) |
625 | { | 656 | { |
626 | struct trace_seq *s = &iter->seq; | 657 | struct trace_seq *s = &iter->seq; |
627 | struct trace_entry *entry = iter->ent; | 658 | struct trace_entry *entry = iter->ent; |
628 | unsigned long long t = ns2usecs(iter->ts); | 659 | unsigned long long t; |
629 | unsigned long usec_rem = do_div(t, USEC_PER_SEC); | 660 | unsigned long secs, usec_rem; |
630 | unsigned long secs = (unsigned long)t; | ||
631 | char comm[TASK_COMM_LEN]; | 661 | char comm[TASK_COMM_LEN]; |
632 | int ret; | 662 | int ret; |
633 | 663 | ||
@@ -644,8 +674,13 @@ int trace_print_context(struct trace_iterator *iter) | |||
644 | return 0; | 674 | return 0; |
645 | } | 675 | } |
646 | 676 | ||
647 | return trace_seq_printf(s, " %5lu.%06lu: ", | 677 | if (iter->iter_flags & TRACE_FILE_TIME_IN_NS) { |
648 | secs, usec_rem); | 678 | t = ns2usecs(iter->ts); |
679 | usec_rem = do_div(t, USEC_PER_SEC); | ||
680 | secs = (unsigned long)t; | ||
681 | return trace_seq_printf(s, " %5lu.%06lu: ", secs, usec_rem); | ||
682 | } else | ||
683 | return trace_seq_printf(s, " %12llu: ", iter->ts); | ||
649 | } | 684 | } |
650 | 685 | ||
651 | int trace_print_lat_context(struct trace_iterator *iter) | 686 | int trace_print_lat_context(struct trace_iterator *iter) |
@@ -659,36 +694,29 @@ int trace_print_lat_context(struct trace_iterator *iter) | |||
659 | *next_entry = trace_find_next_entry(iter, NULL, | 694 | *next_entry = trace_find_next_entry(iter, NULL, |
660 | &next_ts); | 695 | &next_ts); |
661 | unsigned long verbose = (trace_flags & TRACE_ITER_VERBOSE); | 696 | unsigned long verbose = (trace_flags & TRACE_ITER_VERBOSE); |
662 | unsigned long abs_usecs = ns2usecs(iter->ts - iter->tr->time_start); | ||
663 | unsigned long rel_usecs; | ||
664 | 697 | ||
665 | /* Restore the original ent_size */ | 698 | /* Restore the original ent_size */ |
666 | iter->ent_size = ent_size; | 699 | iter->ent_size = ent_size; |
667 | 700 | ||
668 | if (!next_entry) | 701 | if (!next_entry) |
669 | next_ts = iter->ts; | 702 | next_ts = iter->ts; |
670 | rel_usecs = ns2usecs(next_ts - iter->ts); | ||
671 | 703 | ||
672 | if (verbose) { | 704 | if (verbose) { |
673 | char comm[TASK_COMM_LEN]; | 705 | char comm[TASK_COMM_LEN]; |
674 | 706 | ||
675 | trace_find_cmdline(entry->pid, comm); | 707 | trace_find_cmdline(entry->pid, comm); |
676 | 708 | ||
677 | ret = trace_seq_printf(s, "%16s %5d %3d %d %08x %08lx [%08llx]" | 709 | ret = trace_seq_printf( |
678 | " %ld.%03ldms (+%ld.%03ldms): ", comm, | 710 | s, "%16s %5d %3d %d %08x %08lx ", |
679 | entry->pid, iter->cpu, entry->flags, | 711 | comm, entry->pid, iter->cpu, entry->flags, |
680 | entry->preempt_count, iter->idx, | 712 | entry->preempt_count, iter->idx); |
681 | ns2usecs(iter->ts), | ||
682 | abs_usecs / USEC_PER_MSEC, | ||
683 | abs_usecs % USEC_PER_MSEC, | ||
684 | rel_usecs / USEC_PER_MSEC, | ||
685 | rel_usecs % USEC_PER_MSEC); | ||
686 | } else { | 713 | } else { |
687 | ret = lat_print_generic(s, entry, iter->cpu); | 714 | ret = lat_print_generic(s, entry, iter->cpu); |
688 | if (ret) | ||
689 | ret = lat_print_timestamp(s, abs_usecs, rel_usecs); | ||
690 | } | 715 | } |
691 | 716 | ||
717 | if (ret) | ||
718 | ret = lat_print_timestamp(iter, next_ts); | ||
719 | |||
692 | return ret; | 720 | return ret; |
693 | } | 721 | } |
694 | 722 | ||