lkml.org 
[lkml]   [2008]   [Dec]   [4]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    Date
    From
    SubjectRe: [PATCH] tracing/function-graph-tracer: handle ftrace_printk entries
    2008/12/4 Steven Rostedt <rostedt@goodmis.org>:
    >
    > On Wed, 3 Dec 2008, Frederic Weisbecker wrote:
    >
    >> Handle the TRACE_PRINT entries from the function grapg tracer
    >> and output them as a C comment just below the function that called
    >> it, as if it was a comment inside this function.
    >
    > Cool, thanks!
    >
    >>
    >> Example with an ftrace_printk inside might_sleep() function:
    >>
    >> void __might_sleep(char *file, int line)
    >> {
    >> static unsigned long prev_jiffy; /* ratelimiting */
    >>
    >> ftrace_printk("Hi I'm a comment in might_sleep() :-)");
    >>
    >> A chunk of a resulting trace:
    >>
    >> 0) | _reiserfs_free_block() {
    >> 0) | reiserfs_read_bitmap_block() {
    >> 0) | __bread() {
    >> 0) | __getblk() {
    >> 0) | __find_get_block() {
    >> 0) 0.698 us | mark_page_accessed();
    >> 0) 2.267 us | }
    >> 0) | __might_sleep() {
    >> 0) | /* Hi I'm a comment in might_sleep() :-) */
    >> 0) 1.321 us | }
    >> 0) 5.872 us | }
    >> 0) 7.313 us | }
    >> 0) 8.718 us | }
    >>
    >> And this patch bring two minor fixes:
    >>
    >> _ The newline after a switch-out task has disappeared
    >> _ The "|" sign just before the cpu number on task-switch has been deleted.
    >>
    >> 0) 0.616 us | pick_next_task_rt();
    >> 0) 1.457 us | _spin_trylock();
    >> 0) 0.653 us | _spin_unlock();
    >> 0) 0.728 us | _spin_trylock();
    >> 0) 0.631 us | _spin_unlock();
    >> 0) 0.729 us | native_load_sp0();
    >> 0) 0.593 us | native_load_tls();
    >> ------------------------------------------
    >> 0) cat-2834 => migrati-3
    >> ------------------------------------------
    >>
    >> 0) | finish_task_switch() {
    >> 0) 0.841 us | _spin_unlock_irq();
    >> 0) 0.616 us | post_schedule_rt();
    >> 0) 3.882 us | }
    >>
    >>
    >> Cc: Steven Rostedt <rostedt@goodmis.org>
    >> Cc: Pekka Paalanen <pq@iki.fi>
    >> Signed-off-by: Frederic Weisbecker <fweisbec@gmail.com>
    >> ---
    >> kernel/trace/trace.c | 28 ++++++++++---
    >> kernel/trace/trace.h | 4 +-
    >> kernel/trace/trace_functions_graph.c | 72 +++++++++++++++++++++++++++++++++-
    >> kernel/trace/trace_mmiotrace.c | 2 +-
    >> 4 files changed, 97 insertions(+), 9 deletions(-)
    >>
    >> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
    >> index 8b6409a..1ca74c0 100644
    >> --- a/kernel/trace/trace.c
    >> +++ b/kernel/trace/trace.c
    >> @@ -3335,7 +3335,7 @@ static int mark_printk(const char *fmt, ...)
    >> int ret;
    >> va_list args;
    >> va_start(args, fmt);
    >> - ret = trace_vprintk(0, fmt, args);
    >> + ret = trace_vprintk(0, -1, fmt, args);
    >> va_end(args);
    >> return ret;
    >> }
    >> @@ -3564,9 +3564,16 @@ static __init int tracer_init_debugfs(void)
    >> return 0;
    >> }
    >>
    >> -int trace_vprintk(unsigned long ip, const char *fmt, va_list args)
    >> +int trace_vprintk(unsigned long ip, int depth, const char *fmt, va_list args)
    >> {
    >> - static DEFINE_SPINLOCK(trace_buf_lock);
    >> + /*
    >> + * Raw Spinlock because a normal spinlock would be traced here
    >> + * and append an irrelevant couple spin_lock_irqsave/
    >> + * spin_unlock_irqrestore traced by ftrace around this
    >> + * TRACE_PRINTK trace.
    >> + */
    >> + static raw_spinlock_t trace_buf_lock =
    >> + (raw_spinlock_t)__RAW_SPIN_LOCK_UNLOCKED;
    >> static char trace_buf[TRACE_BUF_SIZE];
    >>
    >> struct ring_buffer_event *event;
    >> @@ -3587,7 +3594,8 @@ int trace_vprintk(unsigned long ip, const char *fmt, va_list args)
    >> if (unlikely(atomic_read(&data->disabled)))
    >> goto out;
    >>
    >> - spin_lock_irqsave(&trace_buf_lock, flags);
    >> + local_irq_save(flags);
    >> + __raw_spin_lock(&trace_buf_lock);
    >> len = vsnprintf(trace_buf, TRACE_BUF_SIZE, fmt, args);
    >
    > I wonder if we should add a new flag called "NOTRACE" to the new
    > current->trace flags. When set, tracing is stopped for the task. Then we
    > can still use spinlock here. We only want to use raw if the tracing will
    > cause lockdep to fail, not just to prevent traces.
    >
    > We could do something like:
    >
    > pause_trace(current); /* sets the "notrace" flag */
    >
    > unpause_trace(current); /* clears the "notrace" flag */
    >


    pause_trace seems to me too much generic. Would you want to use it for
    normal ftrace too?
    I guess I could name it (un)pause_ftrace.


    \
     
     \ /
      Last update: 2008-12-04 19:31    [W:0.031 / U:30.140 seconds]
    ©2003-2016 Jasper Spaans. hosted at Digital OceanAdvertise on this site