Re: Benchmarks of kernel tracing options (ftrace and ktrace)

From: Frederic Weisbecker
Date: Thu Oct 14 2010 - 07:28:03 EST


On Wed, Oct 13, 2010 at 08:00:27PM -0400, Mathieu Desnoyers wrote:
> * Steven Rostedt (rostedt@xxxxxxxxxxx) wrote:
> > On Wed, 2010-10-13 at 16:19 -0700, David Sharp wrote:
> > > Google uses kernel tracing aggressively in the its data centers. We
> >
> > Thanks!
> >
> > > wrote our own kernel tracer, ktrace. However ftrace, perf and LTTng
> > > all have a better feature set than ktrace, so we are abandoning that
> > > code.
> >
> > Cool!
> >
> > >
> > > We see several implementations of tracing aimed at the mainline kernel
> > > and wanted a fair comparison of each of them to make sure they will
> > > not significantly impact performance. A tracing toolkit that is too
> > > expensive is not usable in our environment.
> > >
> >
> > [ snip for now (I'm traveling) ]
> >
> > > This first set of benchmark results compares ftrace to ktrace. The
> > > numbers below are the "on" result minus the "off" result for each
> > > configuration.
> > >
> > > ktrace: 200ns (tracepoint: kernel_getuid)
> > > ftrace: 224ns (tracepoint: timer:sys_getuid)
> > > ftrace: 587ns (tracepoint: syscalls:sys_enter_getuid)
> >
> >
> > > The last result shows that the syscall tracing is about twice as
> > > expensive as a normal tracepoint, which is interesting.
> >
> > Argh, the syscall tracing has a lot of overhead. There is only one
> > tracepoint that is hooked into the ptrace code, and will save all
> > registers before calling the functions. It enables tracing on all
> > syscalls and there's a table that decides whether or not to trace the
> > syscall.
> >
> > So I'm not surprised with the result that the syscall trace point is so
> > slow (note, perf uses the same infrastructure).
>
> Yes, the interesting result in this first set of benchmarks is that syscall
> tracing is quite slow. We could do better though. I think a different scheme
> for syscall tracing that would not rely of saving all registers is needed. We
> could do this automatically by adding tracepoints in the actual syscall
> functions by modifying the DEFINE_SYSCALL*() macros. I would leave the current
> syscall tracing mode as the default though, especially until gcc 4.5 and asm
> gotos are more broadly adopted.
>
> So the modified DEFINE_SYSCALL*() macros would generate code that looks like:
> (approximately)
>
> static int _syscall_name(type1, name1);
>
> int syscall_name(type1 name1)
> {
> int ret;
>
> trace_syscall_entry_name(name1);
> ret = _syscall_name(name1);
> trace_syscall_exit_name(name1);
> return ret;
> }
>
> static int _syscall_name(typê1, name1)
>
>
> So when we expand:
>
> DEFINE_SYSCALL1(name, type1, name1)
> {
> .. actual body ...
> }
>
> We have the tracepoints automatically added.
>
> Mathieu



Looks like that would be a good improvement, it would also
simplify some tricky code parts I think.

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/