[<prev] [next>] [<thread-prev] [day] [month] [year] [list]
Message-ID: <c62985530812041028u3d276f6g8e6599c44c9cc76@mail.gmail.com>
Date: Thu, 4 Dec 2008 19:28:12 +0100
From: "Frédéric Weisbecker" <fweisbec@...il.com>
To: "Steven Rostedt" <rostedt@...dmis.org>
Cc: "Ingo Molnar" <mingo@...e.hu>,
"Peter Zijlstra" <a.p.zijlstra@...llo.nl>,
"Linux Kernel" <linux-kernel@...r.kernel.org>,
"Tim Bird" <tim.bird@...sony.com>, "Pekka Paalanen" <pq@....fi>
Subject: Re: [PATCH] tracing/function-graph-tracer: handle ftrace_printk entries
2008/12/4 Steven Rostedt <rostedt@...dmis.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@...dmis.org>
>> Cc: Pekka Paalanen <pq@....fi>
>> Signed-off-by: Frederic Weisbecker <fweisbec@...il.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.
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists