Messages in this thread | | | Date | Tue, 21 Oct 2008 14:47:19 +0200 | From | "Frédéric Weisbecker" <> | Subject | Re: [PATCH 3/5] tracing/fastboot: Make the boot tracer use the cpu_clock |
| |
2008/10/11 Frederic Weisbecker <fweisbec@gmail.com>: > Make the boot tracer use the cpu_clock() rather than the ktime > API. This way we will be able to unify the time capture with > the sched_switch tracer. > Also delete the duration attribute which is not needed and can be > retrieved at print time. > > Signed-off-by: Frederic Weisbecker <fweisbec@gmail.com> > Cc: Arjan van de Ven <arjan@linux.intel.com> > --- > include/linux/ftrace.h | 5 ++--- > init/main.c | 25 ++++++++++++++++++------- > kernel/trace/trace_boot.c | 18 ++++++++++-------- > 3 files changed, 30 insertions(+), 18 deletions(-) > > diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h > index 135a33f..36b570b 100644 > --- a/include/linux/ftrace.h > +++ b/include/linux/ftrace.h > @@ -222,9 +222,8 @@ struct boot_trace { > pid_t caller; > char func[KSYM_NAME_LEN]; > int result; > - unsigned long long duration; > - ktime_t calltime; > - ktime_t rettime; > + unsigned long long calltime; > + unsigned long long rettime; > }; > > #ifdef CONFIG_BOOT_TRACER > diff --git a/init/main.c b/init/main.c > index 98c05aa..bf13013 100644 > --- a/init/main.c > +++ b/init/main.c > @@ -721,27 +721,38 @@ __setup("initcall_debug", initcall_debug_setup); > int do_one_initcall(initcall_t fn) > { > int count = preempt_count(); > - ktime_t delta; > + ktime_t delta, t0, t1; > char msgbuf[64]; > + unsigned long long duration; > struct boot_trace it; > > if (initcall_debug) { > + long cpu; > it.caller = task_pid_nr(current); > printk("calling %pF @ %i\n", fn, it.caller); > - it.calltime = ktime_get(); > + t0 = ktime_get(); > + preempt_disable(); > + cpu = raw_smp_processor_id(); > + it.calltime = cpu_clock(cpu); > + preempt_enable(); > enable_boot_trace(); > } > > it.result = fn(); > > if (initcall_debug) { > - it.rettime = ktime_get(); > - delta = ktime_sub(it.rettime, it.calltime); > - it.duration = (unsigned long long) delta.tv64 >> 20; > + long cpu; > + disable_boot_trace(); > + t1 = ktime_get(); > + preempt_disable(); > + cpu = raw_smp_processor_id(); > + it.rettime = cpu_clock(cpu); > + preempt_enable(); > + delta = ktime_sub(t1, t0); > + duration = (unsigned long long) delta.tv64 >> 20; > printk("initcall %pF returned %d after %Ld msecs\n", fn, > - it.result, it.duration); > + it.result, duration); > trace_boot(&it, fn); > - disable_boot_trace(); > } > > msgbuf[0] = 0; > diff --git a/kernel/trace/trace_boot.c b/kernel/trace/trace_boot.c > index bd5046c..20d326b 100644 > --- a/kernel/trace/trace_boot.c > +++ b/kernel/trace/trace_boot.c > @@ -68,22 +68,24 @@ static enum print_line_t initcall_print_line(struct trace_iterator *iter) > struct trace_boot *field = (struct trace_boot *)entry; > struct boot_trace *it = &field->initcall; > struct trace_seq *s = &iter->seq; > - struct timespec calltime = ktime_to_timespec(it->calltime); > - struct timespec rettime = ktime_to_timespec(it->rettime); > + unsigned long sec, nsec_rem; > + unsigned long long duration = it->rettime - it->calltime; > > if (entry->type == TRACE_BOOT) { > + nsec_rem = do_div(it->calltime, 1000000000); > + sec = (unsigned long) it->calltime; > ret = trace_seq_printf(s, "[%5ld.%09ld] calling %s @ %i\n", > - calltime.tv_sec, > - calltime.tv_nsec, > - it->func, it->caller); > + sec, nsec_rem, it->func, it->caller); > if (!ret) > return TRACE_TYPE_PARTIAL_LINE; > > + nsec_rem = do_div(it->rettime, 1000000000); > + sec = (unsigned long) it->rettime; > + do_div(duration, 1000); > ret = trace_seq_printf(s, "[%5ld.%09ld] initcall %s " > "returned %d after %lld msecs\n", > - rettime.tv_sec, > - rettime.tv_nsec, > - it->func, it->result, it->duration); > + sec, nsec_rem, it->func, it->result, > + duration); > > if (!ret) > return TRACE_TYPE_PARTIAL_LINE; >
Please just ignore this patch. I think I will change a bit the design of the boot tracer by sending two types of entries: the call and the return. With this new approach, I will be able to use the internal timestamp of the ring buffer and stay consistent with the same used for sched switch entries.
Thanks.
| |