Re: [PATCH] tracing: annotate emit_log_char() notrace

[Thomas Gleixner <tglx@linutronix.de>]

On Thu, 28 May 2009, Frederic Weisbecker wrote:
> On Wed, May 27, 2009 at 05:00:44PM +0200, Thomas Gleixner wrote:
> > printk calls emit_log_char() in a loop which is cluttering the trace
> > buffer. Make it notrace.
> > 
> > Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
> > ---
> 
> 
> Does it produce that much annoying traces?
> I mean, printk() are usually rare events.
> 
> Do you have a particular debugging workflow that makes this
> function invasive in the trace?
> 
> May be it's because you are debugging using ftrace and other
> debugging options that use a lot of printk()
> In such case, it would indeed be good to apply this patch.

I noticed when I chased a boot up problem, half of the trace was full
of

   0.540550: emit_log_char <-vprintk
   0.540550: emit_log_char <-vprintk
   ...

though there is another annoyance in the same code path:

   0.540557: vgacon_set_cursor_size <-vgacon_cursor
   0.540558: __rcu_read_lock <-__atomic_notifier_call_chain
   0.540558: __rcu_read_unlock <-__atomic_notifier_call_chain
   0.540558: __rcu_read_lock <-__atomic_notifier_call_chain
   ...

It's actually the same number of times as we have emit_log_char()
there. __atomic_notifier_call_chain() itself is marked notrace but the
rcu calls inside are not. :(

IIRC the same happens with a serial console, but that can be worse as
you busy wait during the character output.

It'd be nice if we could inherit the notrace from the caller :)

Thanks,

	tglx