lkml.org 
[lkml]   [2009]   [Aug]   [17]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    Date
    From
    SubjectRe: [RFC PATCH] Add timer-source of walltime for ftrace
    On Mon, Aug 17, 2009 at 05:22:04PM +0800, Zhaolei wrote:
    > We can add a timer-source for ftrace to support wall-time display.
    > It is based on Steven Rostedt <rostedt@goodmis.org>'s suggestion in:
    > http://lkml.org/lkml/2009/7/24/103
    >
    > It needs to be applied on my patch of:
    > [PATCH v4 1/2] Add function to convert between calendar time and broken-down time for universal use
    > and
    > [PATCH v2 2/2] ftrace: Unify effect of writing to trace_options and option/*
    >
    > We can get following output:
    > # cd /mnt/debugfs/tracing/
    > # ls options/*clock
    > options/global-clock options/local-clock options/walltime-clock
    > # echo sched_switch > current_tracer
    > # cat trace
    > # tracer: sched_switch
    > #
    > # TASK-PID CPU# TIMESTAMP FUNCTION
    > # | | | | |
    > bash-3560 [000] 694.242386: 3560:120:S + [000] 3560:120:S bash
    > bash-3560 [000] 694.242476: 3560:120:S + [000] 3560:120:S bash
    > bash-3560 [000] 694.242865: 3560:120:R + [000] 5:115:S events/0
    > bash-3560 [000] 694.242912: 3560:120:R ==> [000] 5:115:R events/0
    > events/0-5 [000] 694.243015: 5:115:R + [000] 3558:120:S sshd
    > events/0-5 [000] 694.243040: 5:115:S ==> [000] 3560:120:R bash
    > bash-3560 [000] 694.243312: 3560:120:S + [000] 3560:120:S bash
    > bash-3560 [000] 694.243374: 3560:120:S ==> [000] 3558:120:R sshd
    > ...
    > # echo 1 > options/walltime-clock
    > # echo > trace
    > # cat trace
    > # tracer: sched_switch
    > #
    > # TASK-PID CPU# TIMESTAMP FUNCTION
    > # | | | | |
    > bash-3560 [000] 2009-08-17 23:58:22 3560:120:S + [000] 3560:120:S bash
    > bash-3560 [000] 2009-08-17 23:58:22 3560:120:R + [000] 5:115:S events/0
    > bash-3560 [000] 2009-08-17 23:58:22 3560:120:R ==> [000] 5:115:R events/0
    > events/0-5 [000] 2009-08-17 23:58:22 5:115:R + [000] 3558:120:S sshd
    > events/0-5 [000] 2009-08-17 23:58:22 5:115:S ==> [000] 3558:120:R sshd
    > sshd-3558 [000] 2009-08-17 23:58:22 3558:120:S ==> [000] 3560:120:R bash
    > bash-3560 [000] 2009-08-17 23:58:22 3560:120:S + [000] 3560:120:S bash
    > bash-3560 [000] 2009-08-17 23:58:22 3560:120:S + [000] 3560:120:S bash
    > ...
    >
    > Note:
    > It is only a prototype patch to for demostrate what is result looks like.
    > There still have many works to do(bug to fix) before apply.
    > For example, we need to add a hook(tracepoint) of xtime change event,
    > so we can update walltime's clock base then.
    > And maybe we need clear all events when changing clock-source, because old
    > clock value can't displayed correctly in new clock's format.
    >
    > Signed-off-by: Zhao Lei <zhaolei@cn.fujitsu.com>
    > ---
    > include/linux/trace_clock.h | 1 +
    > kernel/trace/trace.c | 55 ++++++++++++++++++++++++++++++------------
    > kernel/trace/trace.h | 6 +++-
    > kernel/trace/trace_clock.c | 47 ++++++++++++++++++++++++++++++++++++
    > kernel/trace/trace_output.c | 20 ++++++++++++---
    > 5 files changed, 107 insertions(+), 22 deletions(-)
    >
    > diff --git a/include/linux/trace_clock.h b/include/linux/trace_clock.h
    > index 7a81303..322707e 100644
    > --- a/include/linux/trace_clock.h
    > +++ b/include/linux/trace_clock.h
    > @@ -15,5 +15,6 @@
    > extern u64 notrace trace_clock_local(void);
    > extern u64 notrace trace_clock(void);
    > extern u64 notrace trace_clock_global(void);
    > +extern u64 notrace trace_clock_walltime(void);
    >
    > #endif /* _LINUX_TRACE_CLOCK_H */
    > diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
    > index b7d873b..4474f7d 100644
    > --- a/kernel/trace/trace.c
    > +++ b/kernel/trace/trace.c
    > @@ -263,8 +263,8 @@ static DECLARE_WAIT_QUEUE_HEAD(trace_wait);
    >
    > /* trace_flags holds trace_options default values */
    > unsigned long trace_flags = TRACE_ITER_PRINT_PARENT | TRACE_ITER_PRINTK |
    > - TRACE_ITER_ANNOTATE | TRACE_ITER_CONTEXT_INFO | TRACE_ITER_SLEEP_TIME |
    > - TRACE_ITER_GRAPH_TIME;
    > + TRACE_ITER_ANNOTATE | TRACE_ITER_CONTEXT_INFO | TRACE_ITER_LOCAL_CLK |
    > + TRACE_ITER_SLEEP_TIME | TRACE_ITER_GRAPH_TIME;
    >
    > /**
    > * trace_wake_up - wake up tasks waiting for trace input
    > @@ -324,6 +324,8 @@ static const char *trace_options[] = {
    > "context-info",
    > "latency-format",
    > "global-clock",
    > + "local-clock",
    > + "walltime-clock",
    > "sleep-time",
    > "graph-time",
    > NULL
    > @@ -1423,8 +1425,17 @@ static void print_lat_help_header(struct seq_file *m)
    >
    > static void print_func_help_header(struct seq_file *m)
    > {
    > - seq_puts(m, "# TASK-PID CPU# TIMESTAMP FUNCTION\n");
    > - seq_puts(m, "# | | | | |\n");
    > + if (trace_flags & TRACE_ITER_WALLTIME_CLK) {
    > + seq_puts(m, "# TASK-PID CPU# "
    > + " TIMESTAMP FUNCTION\n");
    > + seq_puts(m, "# | | | "
    > + " | |\n");
    > + } else {
    > + seq_puts(m, "# TASK-PID CPU# "
    > + " TIMESTAMP FUNCTION\n");
    > + seq_puts(m, "# | | | "
    > + " | |\n");
    > + }
    > }
    >
    >
    > @@ -2151,30 +2162,42 @@ static int set_tracer_option(struct tracer *trace, char *cmp, int neg)
    >
    > static void set_tracer_flags(unsigned int mask, int enabled)
    > {
    > + u64 (*clkfunc)(void) = NULL;
    > +
    > /* do nothing if flag is already set */
    > if (!!(trace_flags & mask) == !!enabled)
    > return;
    >
    > - if (enabled)
    > - trace_flags |= mask;
    > - else
    > - trace_flags &= ~mask;
    > + if (mask == TRACE_ITER_GLOBAL_CLK)
    > + clkfunc = trace_clock_global;
    > + if (mask == TRACE_ITER_LOCAL_CLK)
    > + clkfunc = trace_clock_local;
    > + if (mask == TRACE_ITER_WALLTIME_CLK)
    > + clkfunc = trace_clock_walltime;
    >
    > - if (mask == TRACE_ITER_GLOBAL_CLK) {
    > - u64 (*func)(void);
    > + if (clkfunc) {
    > + if (!enabled)
    > + return;



    If the user set a clock option file to 0, then it means he
    was expecting something, probably reset the default clock
    which is clock_local.

    But what if the user set 0 to the local_clock...hmm..




    \
     
     \ /
      Last update: 2009-08-17 18:53    [W:0.042 / U:2.228 seconds]
    ©2003-2016 Jasper Spaans. hosted at Digital OceanAdvertise on this site