Re: [PATCH 2/4] ftrace - add function_duration tracer

[Steven Rostedt <rostedt@goodmis.org>]

On Thu, 2009-12-10 at 14:36 -0800, Tim Bird wrote:

> The ring buffer code was particularly slow.  I was using
> a simple fixed-size array in KFT (on a uniprocessor), and
> the time to save an event was under 1 microsecond.  With
> ftrace on the same hardware, it costs about 6 microseconds
> to save an event.
>  

Well, I know you work in embedded so it may be much slower.

I just ran the ring_buffer_benchmark on a Xeon Quad 2660MHz with
2.6.32-rc7 and I got 190ns per trace entry. (Note most of this time is
spent in the timestamp calculation!)

I booted the latest 2.6.32 kernel, where I've made some changes to the
time keeping code and got 117ns per entry. I sent out a RFC patch set,
and disabled all the RB_WARN_ON safety checks and got it down to 90ns
per trace entry!  This still includes the 3 levels of checking if the
buffer is enabled. Those checks are just a nit and probably (haven't
tested) cost a single ns. The variables being checked are labeled
read_mostly and are most likely in the cache.


Maybe you want to test out the overhead again?

Note, the ftrace infrastructure's first priority is stability so I won't
be removing those RB_WARN_ONs. Next priority is to have non tracing be
unaffected. Third is tracing being as fast as possible. A tracer that
does not need to worry about going away when  disabled will probably
have a performance advantage when tracing. But, if it causes a
noticeable overhead when disabled (like -finstrument-function does, and
it has a lot more lines than mcount), it will never be merged.

-- Steve