diff options
-rw-r--r-- | include/linux/ftrace.h | 2 | ||||
-rw-r--r-- | init/main.c | 20 | ||||
-rw-r--r-- | kernel/trace/trace_boot.c | 22 |
3 files changed, 26 insertions, 18 deletions
diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h index 91954eb6460f..4455490d91bd 100644 --- a/include/linux/ftrace.h +++ b/include/linux/ftrace.h | |||
@@ -216,6 +216,8 @@ struct boot_trace { | |||
216 | initcall_t func; | 216 | initcall_t func; |
217 | int result; | 217 | int result; |
218 | unsigned long long duration; | 218 | unsigned long long duration; |
219 | ktime_t calltime; | ||
220 | ktime_t rettime; | ||
219 | }; | 221 | }; |
220 | 222 | ||
221 | #ifdef CONFIG_BOOT_TRACER | 223 | #ifdef CONFIG_BOOT_TRACER |
diff --git a/init/main.c b/init/main.c index 1e39a1eab190..61eb66159391 100644 --- a/init/main.c +++ b/init/main.c | |||
@@ -706,34 +706,32 @@ __setup("initcall_debug", initcall_debug_setup); | |||
706 | int do_one_initcall(initcall_t fn) | 706 | int do_one_initcall(initcall_t fn) |
707 | { | 707 | { |
708 | int count = preempt_count(); | 708 | int count = preempt_count(); |
709 | ktime_t t0, t1, delta; | 709 | ktime_t delta; |
710 | char msgbuf[64]; | 710 | char msgbuf[64]; |
711 | int result; | ||
712 | struct boot_trace it; | 711 | struct boot_trace it; |
713 | 712 | ||
714 | if (initcall_debug) { | 713 | if (initcall_debug) { |
715 | it.caller = task_pid_nr(current); | 714 | it.caller = task_pid_nr(current); |
716 | it.func = fn; | 715 | it.func = fn; |
717 | printk("calling %pF @ %i\n", fn, it.caller); | 716 | printk("calling %pF @ %i\n", fn, it.caller); |
718 | t0 = ktime_get(); | 717 | it.calltime = ktime_get(); |
719 | } | 718 | } |
720 | 719 | ||
721 | result = fn(); | 720 | it.result = fn(); |
722 | 721 | ||
723 | if (initcall_debug) { | 722 | if (initcall_debug) { |
724 | t1 = ktime_get(); | 723 | it.rettime = ktime_get(); |
725 | delta = ktime_sub(t1, t0); | 724 | delta = ktime_sub(it.rettime, it.calltime); |
726 | it.result = result; | ||
727 | it.duration = (unsigned long long) delta.tv64 >> 20; | 725 | it.duration = (unsigned long long) delta.tv64 >> 20; |
728 | printk("initcall %pF returned %d after %Ld msecs\n", fn, | 726 | printk("initcall %pF returned %d after %Ld msecs\n", fn, |
729 | result, it.duration); | 727 | it.result, it.duration); |
730 | trace_boot(&it); | 728 | trace_boot(&it); |
731 | } | 729 | } |
732 | 730 | ||
733 | msgbuf[0] = 0; | 731 | msgbuf[0] = 0; |
734 | 732 | ||
735 | if (result && result != -ENODEV && initcall_debug) | 733 | if (it.result && it.result != -ENODEV && initcall_debug) |
736 | sprintf(msgbuf, "error code %d ", result); | 734 | sprintf(msgbuf, "error code %d ", it.result); |
737 | 735 | ||
738 | if (preempt_count() != count) { | 736 | if (preempt_count() != count) { |
739 | strlcat(msgbuf, "preemption imbalance ", sizeof(msgbuf)); | 737 | strlcat(msgbuf, "preemption imbalance ", sizeof(msgbuf)); |
@@ -747,7 +745,7 @@ int do_one_initcall(initcall_t fn) | |||
747 | printk("initcall %pF returned with %s\n", fn, msgbuf); | 745 | printk("initcall %pF returned with %s\n", fn, msgbuf); |
748 | } | 746 | } |
749 | 747 | ||
750 | return result; | 748 | return it.result; |
751 | } | 749 | } |
752 | 750 | ||
753 | 751 | ||
diff --git a/kernel/trace/trace_boot.c b/kernel/trace/trace_boot.c index f2dac6f1cf06..7c15f3e68ba3 100644 --- a/kernel/trace/trace_boot.c +++ b/kernel/trace/trace_boot.c | |||
@@ -52,16 +52,24 @@ static enum print_line_t initcall_print_line(struct trace_iterator *iter) | |||
52 | struct trace_boot *field = (struct trace_boot *)entry; | 52 | struct trace_boot *field = (struct trace_boot *)entry; |
53 | struct boot_trace *it = &field->initcall; | 53 | struct boot_trace *it = &field->initcall; |
54 | struct trace_seq *s = &iter->seq; | 54 | struct trace_seq *s = &iter->seq; |
55 | struct timespec calltime = ktime_to_timespec(it->calltime); | ||
56 | struct timespec rettime = ktime_to_timespec(it->rettime); | ||
55 | 57 | ||
56 | if (entry->type == TRACE_BOOT) { | 58 | if (entry->type == TRACE_BOOT) { |
57 | ret = trace_seq_printf(s, "%pF called from %i " | 59 | ret = trace_seq_printf(s, "[%5ld.%06ld] calling %pF @ %i\n", |
58 | "returned %d after %lld msecs\n", | 60 | calltime.tv_sec, |
59 | it->func, it->caller, it->result, | 61 | calltime.tv_nsec, |
60 | it->duration); | 62 | it->func, it->caller); |
61 | if (ret) | 63 | if (!ret) |
62 | return TRACE_TYPE_HANDLED; | ||
63 | else | ||
64 | return TRACE_TYPE_PARTIAL_LINE; | 64 | return TRACE_TYPE_PARTIAL_LINE; |
65 | ret = trace_seq_printf(s, "[%5ld.%06ld] initcall %pF " | ||
66 | "returned %d after %lld msecs\n", | ||
67 | rettime.tv_sec, | ||
68 | rettime.tv_nsec, | ||
69 | it->func, it->result, it->duration); | ||
70 | if (!ret) | ||
71 | return TRACE_TYPE_PARTIAL_LINE; | ||
72 | return TRACE_TYPE_HANDLED; | ||
65 | } | 73 | } |
66 | return TRACE_TYPE_UNHANDLED; | 74 | return TRACE_TYPE_UNHANDLED; |
67 | } | 75 | } |