15 May, 2010

1 commit

  • Multiple events may use the same method to print their data.
    Instead of having all events have a pointer to their print funtions,
    the trace_event structure now points to a trace_event_functions structure
    that will hold the way to print ouf the event.

    The event itself is now passed to the print function to let the print
    function know what kind of event it should print.

    This opens the door to consolidating the way several events print
    their output.

    text data bss dec hex filename
    4913961 1088356 861512 6863829 68bbd5 vmlinux.orig
    4900382 1048964 861512 6810858 67ecea vmlinux.init
    4900446 1049028 861512 6810986 67ed6a vmlinux.preprint

    This change slightly increases the size but is needed for the next change.

    v3: Fix the branch tracer events to handle this change.

    v2: Fix the new function graph tracer event calls to handle this change.

    Acked-by: Mathieu Desnoyers
    Acked-by: Masami Hiramatsu
    Acked-by: Frederic Weisbecker
    Signed-off-by: Steven Rostedt

    Steven Rostedt
     

12 Sep, 2009

1 commit


10 Jun, 2009

1 commit


26 May, 2009

1 commit

  • I found that there is nothing to protect event_hash in
    ftrace_find_event(). Rcu protects the event hashlist
    but not the event itself while we use it after its extraction
    through ftrace_find_event().

    This lack of a proper locking in this spot opens a race
    window between any event dereferencing and module removal.

    Eg:

    --Task A--

    print_trace_line(trace) {
    event = find_ftrace_event(trace)

    --Task B--

    trace_module_remove_events(mod) {
    list_trace_events_module(ev, mod) {
    unregister_ftrace_event(ev->event) {
    hlist_del(ev->event->node)
    list_del(....)
    }
    }
    }
    |--> module removed, the event has been dropped

    --Task A--

    event->print(trace); // Dereferencing freed memory

    If the event retrieved belongs to a module and this module
    is concurrently removed, we may end up dereferencing a data
    from a freed module.

    RCU could solve this, but it would add latency to the kernel and
    forbid tracers output callbacks to call any sleepable code.
    So this fix converts 'trace_event_mutex' to a read/write semaphore,
    and adds trace_event_read_lock() to protect ftrace_find_event().

    [ Impact: fix possible freed memory dereference in ftrace ]

    Signed-off-by: Lai Jiangshan
    Acked-by: Steven Rostedt
    LKML-Reference:
    Signed-off-by: Frederic Weisbecker

    Lai Jiangshan
     

15 Apr, 2009

2 commits

  • In preparation to allowing trace events to happen in modules, we need
    to move some of the local declarations in the kernel/trace directory
    into include/linux.

    This patch simply moves the declarations and performs no context changes.

    Signed-off-by: Steven Rostedt

    Steven Rostedt
     
  • In the process to make TRACE_EVENT macro work for modules, the trace_seq
    operations must be available for core kernel code.

    These operations are quite useful and can be used for other implementations.

    The main idea is that we create a trace_seq handle that acts very much
    like the seq_file handle.

    struct trace_seq *s = kmalloc(sizeof(*s, GFP_KERNEL);

    trace_seq_init(s);
    trace_seq_printf(s, "some data %d\n", variable);

    printk("%s", s->buffer);

    The main use is to allow a top level function call several other functions
    that may store printf like data into the buffer. Then at the end, the top
    level function can process all the data with any method it would like to.
    It could be passed to userspace, output via printk or even use seq_file:

    trace_seq_to_user(s, ubuf, cnt);
    seq_puts(m, s->buffer);

    Signed-off-by: Steven Rostedt

    Steven Rostedt
     

07 Apr, 2009

1 commit


31 Mar, 2009

3 commits


25 Mar, 2009

1 commit

  • If the function graph trace is enabled, the function profiler will
    use it to take the timing of the functions.

    cat /debug/tracing/trace_stat/functions

    Function Hit Time
    -------- --- ----
    mwait_idle 127 183028.4 us
    schedule 26 151997.7 us
    __schedule 31 151975.1 us
    sys_wait4 2 74080.53 us
    do_wait 2 74077.80 us
    sys_newlstat 138 39929.16 us
    do_path_lookup 179 39845.79 us
    vfs_lstat_fd 138 39761.97 us
    user_path_at 153 39469.58 us
    path_walk 179 39435.76 us
    __link_path_walk 189 39143.73 us
    [...]

    Note the times are skewed due to the function graph tracer not taking
    into account schedules.

    Signed-off-by: Steven Rostedt

    Steven Rostedt
     

20 Mar, 2009

1 commit


07 Mar, 2009

1 commit

  • Impact: faster and lighter tracing

    Now that we have trace_bprintk() which is faster and consume lesser
    memory than trace_printk() and has the same purpose, we can now drop
    the old implementation in favour of the binary one from trace_bprintk(),
    which means we move all the implementation of trace_bprintk() to
    trace_printk(), so the Api doesn't change except that we must now use
    trace_seq_bprintk() to print the TRACE_PRINT entries.

    Some changes result of this:

    - Previously, trace_bprintk depended of a single tracer and couldn't
    work without. This tracer has been dropped and the whole implementation
    of trace_printk() (like the module formats management) is now integrated
    in the tracing core (comes with CONFIG_TRACING), though we keep the file
    trace_printk (previously trace_bprintk.c) where we can find the module
    management. Thus we don't overflow trace.c

    - changes some parts to use trace_seq_bprintk() to print TRACE_PRINT entries.

    - change a bit trace_printk/trace_vprintk macros to support non-builtin formats
    constants, and fix 'const' qualifiers warnings. But this is all transparent for
    developers.

    - etc...

    V2:

    - Rebase against last changes
    - Fix mispell on the changelog

    V3:

    - Rebase against last changes (moving trace_printk() to kernel.h)

    Signed-off-by: Frederic Weisbecker
    Acked-by: Steven Rostedt
    LKML-Reference:
    Signed-off-by: Ingo Molnar

    Frederic Weisbecker
     

05 Mar, 2009

1 commit

  • Impact: clean up

    The trace and latency_trace function pointers are identical for
    every tracer but the function tracer. The differences in the function
    tracer are trivial (latency output puts paranthesis around parent).

    This patch removes the latency_trace pointer and all prints will
    now just use the trace output function pointer.

    Signed-off-by: Steven Rostedt

    Steven Rostedt
     

05 Feb, 2009

1 commit


03 Feb, 2009

2 commits

  • Impact: API change

    The trace_seq and trace_entry are in trace_iterator, where there are
    more fields that may be needed by tracers, so just pass the
    tracer_iterator as is already the case for struct tracer->print_line.

    Signed-off-by: Arnaldo Carvalho de Melo
    Signed-off-by: Ingo Molnar

    Arnaldo Carvalho de Melo
     
  • Impact: make trace_event more convenient for tracers

    All tracers (for the moment) that use the struct trace_event want to
    have the context info printed before their own output: the pid/cmdline,
    cpu, and timestamp.

    But some other tracers that want to implement their trace_event
    callbacks will not necessary need these information or they may want to
    format them as they want.

    This patch adds a new default-enabled trace option:
    TRACE_ITER_CONTEXT_INFO When disabled through:

    echo nocontext-info > /debugfs/tracing/trace_options

    The pid, cpu and timestamps headers will not be printed.

    IE with the sched_switch tracer with context-info (default):

    bash-2935 [001] 100.356561: 2935:120:S ==> [001] 0:140:R
    -0 [000] 100.412804: 0:140:R + [000] 11:115:S events/0
    -0 [000] 100.412816: 0:140:R ==> [000] 11:115:R events/0
    events/0-11 [000] 100.412829: 11:115:S ==> [000] 0:140:R

    Without context-info:

    2935:120:S ==> [001] 0:140:R
    0:140:R + [000] 11:115:S events/0
    0:140:R ==> [000] 11:115:R events/0
    11:115:S ==> [000] 0:140:R

    A tracer can disable it at runtime by clearing the bit
    TRACE_ITER_CONTEXT_INFO in trace_flags.

    The print routines were renamed to trace_print_context and
    trace_print_lat_context, so that they can be used by tracers if they
    want to use them for one of the trace_event callbacks.

    Signed-off-by: Frederic Weisbecker
    Signed-off-by: Arnaldo Carvalho de Melo
    Signed-off-by: Ingo Molnar

    Frederic Weisbecker
     

16 Jan, 2009

2 commits

  • Andrew Morton suggested adding a printf checker to trace_seq_printf
    since there are a number of users that have improper format arguments.

    Signed-off-by: Steven Rostedt
    Signed-off-by: Ingo Molnar

    Steven Rostedt
     
  • Impact: fix bug for handling partial line

    trace_seq_printf(), seq_print_userip_objs(), ... return
    0 -- partial line was written
    other(>0) -- success

    duplicate output is also removed in trace_print_raw().

    Signed-off-by: Lai Jiangshan
    Signed-off-by: Steven Rostedt
    Signed-off-by: Ingo Molnar

    Lai Jiangshan
     

29 Dec, 2008

2 commits

  • Impact: rework trace.c to use new event register API

    Almost every ftrace event has to implement its output display in
    trace.c through a different function. Some events did not handle
    all the formats (trace, latency-trace, raw, hex, binary), and
    this method does not scale well.

    This patch converts the format functions to use the event API to
    find the event and and print its format. Currently, we have
    a print function for trace, latency_trace, raw, hex and binary.
    A trace_nop_print is available if the event wants to avoid output
    on a particular format.

    Perhaps other tracers could use this in the future (like mmiotrace and
    function_graph).

    Signed-off-by: Steven Rostedt
    Signed-off-by: Ingo Molnar

    Steven Rostedt
     
  • Impact: simplify/generalize/refactor trace.c

    The trace.c file is becoming more difficult to maintain due to the
    growing number of events. There is several formats that an event may
    be printed. This patch sets up the infrastructure of an event hash to
    allow for events to register how they should be printed.

    Signed-off-by: Steven Rostedt
    Signed-off-by: Ingo Molnar

    Steven Rostedt