Re: [PATCH, RFC] sputrace: use the generic event tracer

Re: [PATCH, RFC] sputrace: use the generic event tracer

[Ingo Molnar]

(Note: please Cc all tracing related patches to lkml.)

* Christoph Hellwig <hch@lst.de> wrote:

> I wrote sputrace before generic tracing infrastrucure was 
> available. Now that we have the generic event tracer we can 
> convert it over and remove a lot of code:
> 
>   8 files changed, 45 insertions(+), 285 deletions(-)

Nice! Needs also an Ack from PowerPC folks before we can do this. 
The cross section to other powerpc code seems to be rather low.

A few comments:

> To use it make sure CONFIG_EVENT_TRACING is enabled and then enable
> the spufs trace channel by
> 
>   echo 1 > /sys/kernel/debug/tracing/events/spufs/spufs_context
> 
> and then read the trace records using e.g.
> 
>   cat /sys/kernel/debug/tracing/trace
> 
> 
> Note that the patch is ontop of the current tracing tree
> 
>   git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip.git#tracing/ftrace
> 
> as there have been some TRACE_EVENT changes in there that aren't in
> mainline yet.
> 
> I don't have any cell hardware anymore so this is only compile tested.
> 
> 
> Signed-off-by: Christoph Hellwig <hch@lst.de>
> 
> Index: linux-2.6-tip/arch/powerpc/platforms/cell/spufs/sputrace.h
> ===================================================================
> --- /dev/null	1970-01-01 00:00:00.000000000 +0000
> +++ linux-2.6-tip/arch/powerpc/platforms/cell/spufs/sputrace.h	2009-05-06 10:17:20.000000000 +0000
> @@ -0,0 +1,39 @@
> +#if !defined(_TRACE_SPUFS_H) || defined(TRACE_HEADER_MULTI_READ)
> +#define _TRACE_SPUFS_H
> +
> +#include <linux/tracepoint.h>
> +
> +#undef TRACE_SYSTEM
> +#define TRACE_SYSTEM spufs
> +
> +TRACE_EVENT(spufs_context,
> +	TP_PROTO(struct spu_context *ctx, struct spu *spu, const char *name),
> +	TP_ARGS(ctx, spu, name),
> +
> +	TP_STRUCT__entry(
> +		__field(int, owner_tid)
> +		__field(const char *, name)
> +		__field(int, number)
> +	),
> +
> +	TP_fast_assign(
> +		__entry->owner_tid = ctx->tid;
> +		__entry->name = name;
> +		__entry->number = spu ? spu->number : -1;
> +	),
> +
> +	TP_printk("%s (ctxthread = %d, spu = %d)",
> +		__entry->name, __entry->owner_tid, __entry->number)

Please keep the natural field ordering that is visible in the output 
format:

		__field(const char *, name)
		__field(int, owner_tid)
		__field(int, number)

This also has the advantage of (potentially) compressing the trace 
entry some more, as two int's are now following each other. The 
original sputrace record format had this order:

struct sputrace {
	ktime_t tstamp;
	int owner_tid; /* owner */
	int curr_tid;
	const char *name;
	int number;
};

There 'name' and 'curr_tid' was probably flipped around because 
'curr_tid' was there too. In the event tracer the PID is at the head 
of the record.

> +);
> +
> +#define spu_context_trace(name, ctx, spu) \
> +	trace_spufs_context(ctx, spu, __stringify(name))
> +#define spu_context_nospu_trace(name, ctx) \
> +	trace_spufs_context(ctx, NULL, __stringify(name))
> +
> +#endif /* _TRACE_SPUFS_H */
> +
> +#undef TRACE_INCLUDE_PATH
> +#define TRACE_INCLUDE_PATH .
> +#define TRACE_INCLUDE_FILE sputrace
> +#include <trace/define_trace.h>
> Index: linux-2.6-tip/arch/powerpc/platforms/cell/spufs/spufs.h
> ===================================================================
> --- linux-2.6-tip.orig/arch/powerpc/platforms/cell/spufs/spufs.h	2009-05-06 10:14:40.000000000 +0000
> +++ linux-2.6-tip/arch/powerpc/platforms/cell/spufs/spufs.h	2009-05-06 10:20:14.000000000 +0000
> @@ -373,9 +373,4 @@
>  extern void spuctx_switch_state(struct spu_context *ctx,
>  		enum spu_utilization_state new_state);
>  
> -#define spu_context_trace(name, ctx, spu) \
> -	trace_mark(name, "ctx %p spu %p", ctx, spu);
> -#define spu_context_nospu_trace(name, ctx) \
> -	trace_mark(name, "ctx %p", ctx);
> -
>  #endif
> Index: linux-2.6-tip/arch/powerpc/platforms/cell/Kconfig
> ===================================================================
> --- linux-2.6-tip.orig/arch/powerpc/platforms/cell/Kconfig	2009-05-06 10:17:46.000000000 +0000
> +++ linux-2.6-tip/arch/powerpc/platforms/cell/Kconfig	2009-05-06 10:17:50.000000000 +0000
> @@ -77,13 +77,6 @@
>  	  uses 4K pages. This can improve performances of applications
>  	  using multiple SPEs by lowering the TLB pressure on them.
>  
> -config SPU_TRACE
> -	tristate "SPU event tracing support"
> -	depends on SPU_FS && MARKERS
> -	help
> -	  This option allows reading a trace of spu-related events through
> -	  the sputrace file in procfs.

I think we should keep this option around.

> -
>  config SPU_BASE
>  	bool
>  	default n
> Index: linux-2.6-tip/arch/powerpc/platforms/cell/spufs/Makefile
> ===================================================================
> --- linux-2.6-tip.orig/arch/powerpc/platforms/cell/spufs/Makefile	2009-05-06 10:17:56.000000000 +0000
> +++ linux-2.6-tip/arch/powerpc/platforms/cell/spufs/Makefile	2009-05-06 10:22:23.000000000 +0000
> @@ -4,7 +4,8 @@
>  spufs-y += sched.o backing_ops.o hw_ops.o run.o gang.o
>  spufs-y += switch.o fault.o lscsa_alloc.o
>  
> -obj-$(CONFIG_SPU_TRACE)	+= sputrace.o
> +# magic for the trace events
> +CFLAGS_sched.o := -I$(src)

Steve, i'm wondering whether this type of Makefile hackery (caused 
by modular tracepoints) could be eliminated ...

Anyway, nice patch!

	Ingo

Re: [PATCH, RFC] sputrace: use the generic event tracer

[Christoph Hellwig]

On Wed, May 06, 2009 at 12:57:48PM +0200, Ingo Molnar wrote:
> Nice! Needs also an Ack from PowerPC folks before we can do this. 
> The cross section to other powerpc code seems to be rather low.

cbe-oss-dev is the Cell list.

> > -config SPU_TRACE
> > -	tristate "SPU event tracing support"
> > -	depends on SPU_FS && MARKERS
> > -	help
> > -	  This option allows reading a trace of spu-related events through
> > -	  the sputrace file in procfs.
> 
> I think we should keep this option around.

Why?  trace_events that aren't enabled are extremly low overhead.
And most in the current tree are non-optional.

> > +# magic for the trace events
> > +CFLAGS_sched.o := -I$(src)
> 
> Steve, i'm wondering whether this type of Makefile hackery (caused 
> by modular tracepoints) could be eliminated ...

We would just have to include the header file with "" instead of <>.
But I remember Steve not liking this when we talked about it.

Re: [PATCH, RFC] sputrace: use the generic event tracer

[Ingo Molnar]

* Christoph Hellwig <hch@lst.de> wrote:

> On Wed, May 06, 2009 at 12:57:48PM +0200, Ingo Molnar wrote:
> > Nice! Needs also an Ack from PowerPC folks before we can do this. 
> > The cross section to other powerpc code seems to be rather low.
> 
> cbe-oss-dev is the Cell list.

( ... and linuxppc-dev. And since it's all a sub-architecture of 
  PowerPC and Cell changes go upstream via the PowerPC tree, it's 
  nice to have the attention (and acks) of generic-arch maintainers 
  as well (if they are interested). And even if it's OK, Ben and 
  Arnd obviously calls the shots when it comes to workflow details: 
  in which tree and how to queue it up. )

> > > -config SPU_TRACE
> > > -	tristate "SPU event tracing support"
> > > -	depends on SPU_FS && MARKERS
> > > -	help
> > > -	  This option allows reading a trace of spu-related events through
> > > -	  the sputrace file in procfs.
> > 
> > I think we should keep this option around.
> 
> Why?  trace_events that aren't enabled are extremly low overhead.
> And most in the current tree are non-optional.

It is general curtesy to maintain the old Kconfig structure and ease 
migration to a new facility.

Part of the "being nice" excercise ;-)

> > > +# magic for the trace events
> > > +CFLAGS_sched.o := -I$(src)
> > 
> > Steve, i'm wondering whether this type of Makefile hackery (caused 
> > by modular tracepoints) could be eliminated ...
> 
> We would just have to include the header file with "" instead of 
> <>. But I remember Steve not liking this when we talked about it.

Yeah. But changing Makefiles isnt particularly clean either ...

And adding -I$(src) can have side-effects: we often have a local 
foo.h while an include/linux/foo.h as well.

	Ingo

Re: [PATCH, RFC] sputrace: use the generic event tracer

[Steven Rostedt]

On Wed, 2009-05-06 at 13:23 +0200, Ingo Molnar wrote:

> > > > +# magic for the trace events
> > > > +CFLAGS_sched.o := -I$(src)
> > > 
> > > Steve, i'm wondering whether this type of Makefile hackery (caused 
> > > by modular tracepoints) could be eliminated ...
> > 
> > We would just have to include the header file with "" instead of 
> > <>. But I remember Steve not liking this when we talked about it.
> 
> Yeah. But changing Makefiles isnt particularly clean either ...
> 
> And adding -I$(src) can have side-effects: we often have a local 
> foo.h while an include/linux/foo.h as well.

That still would not conflict, because

#include "foo.h"

will not include "linux/foo.h" and

#include <linux/foo.h>

will not include a local foo.h, unless there's also a local "linux"
directory with a foo.h in it.


The Makefile hack has to do with being able to have the "foo.h" file
with the TRACE_EVENTs someplace other than include/trace.

If the "foo.h" is in include/trace.h we do not need to include this
hack. But because the include/trace/define_trace.h needs to include the
"foo.h" file recursively, it must be able to find it. If we do not add a
search path, include/trace/define_trace.h will not look in the other
locations.

Note, as Christoph did, we only need to add the include path to the file
that defines "CREATE_TRACE_POINTS". Which is only one file.

CFLAGS_sched.o := -I$(src)

Only touches the sched.c file in that directory (Note, for those reading
this thread out of context, this is not the same file as kernel/sched.c)

-- Steve

Re: [PATCH, RFC] sputrace: use the generic event tracer

[Ingo Molnar]

* Steven Rostedt <srostedt@redhat.com> wrote:

> 
> On Wed, 2009-05-06 at 13:23 +0200, Ingo Molnar wrote:
> 
> > > > > +# magic for the trace events
> > > > > +CFLAGS_sched.o := -I$(src)
> > > > 
> > > > Steve, i'm wondering whether this type of Makefile hackery (caused 
> > > > by modular tracepoints) could be eliminated ...
> > > 
> > > We would just have to include the header file with "" instead of 
> > > <>. But I remember Steve not liking this when we talked about it.
> > 
> > Yeah. But changing Makefiles isnt particularly clean either ...
> > 
> > And adding -I$(src) can have side-effects: we often have a local 
> > foo.h while an include/linux/foo.h as well.
> 
> That still would not conflict, because
> 
> #include "foo.h"
> 
> will not include "linux/foo.h" and
> 
> #include <linux/foo.h>
> 
> will not include a local foo.h, unless there's also a local "linux"
> directory with a foo.h in it.
>
> The Makefile hack has to do with being able to have the "foo.h" 
> file with the TRACE_EVENTs someplace other than include/trace.
> 
> If the "foo.h" is in include/trace.h we do not need to include 
> this hack. But because the include/trace/define_trace.h needs to 
> include the "foo.h" file recursively, it must be able to find it. 
> If we do not add a search path, include/trace/define_trace.h will 
> not look in the other locations.
> 
> Note, as Christoph did, we only need to add the include path to 
> the file that defines "CREATE_TRACE_POINTS". Which is only one 
> file.
> 
> CFLAGS_sched.o := -I$(src)
> 
> Only touches the sched.c file in that directory (Note, for those 
> reading this thread out of context, this is not the same file as 
> kernel/sched.c)

Yeah, i guess we can live with it. It still feels imperfect though.

(btw., find below a small typo fix)

	Ingo

diff --git a/include/trace/define_trace.h b/include/trace/define_trace.h
index f7a7ae1..1d6fa17 100644
--- a/include/trace/define_trace.h
+++ b/include/trace/define_trace.h
@@ -1,5 +1,5 @@
 /*
- * Trace files that want to automate creationg of all tracepoints defined
+ * Trace files that want to automate the creation of all tracepoints defined
  * in their file should include this file. The following are macros that the
  * trace file may define:
  *

Re: [PATCH, RFC] sputrace: use the generic event tracer

[Steven Rostedt]

On Wed, 2009-05-06 at 16:47 +0200, Ingo Molnar wrote:
> * Steven Rostedt <srostedt@redhat.com> wrote:
> 
> > 
> > On Wed, 2009-05-06 at 13:23 +0200, Ingo Molnar wrote:
> > 
> > > > > > +# magic for the trace events
> > > > > > +CFLAGS_sched.o := -I$(src)
> > > > > 
> > > > > Steve, i'm wondering whether this type of Makefile hackery (caused 
> > > > > by modular tracepoints) could be eliminated ...
> > > > 
> > > > We would just have to include the header file with "" instead of 
> > > > <>. But I remember Steve not liking this when we talked about it.
> > > 
> > > Yeah. But changing Makefiles isnt particularly clean either ...
> > > 
> > > And adding -I$(src) can have side-effects: we often have a local 
> > > foo.h while an include/linux/foo.h as well.
> > 
> > That still would not conflict, because
> > 
> > #include "foo.h"
> > 
> > will not include "linux/foo.h" and
> > 
> > #include <linux/foo.h>
> > 
> > will not include a local foo.h, unless there's also a local "linux"
> > directory with a foo.h in it.
> >
> > The Makefile hack has to do with being able to have the "foo.h" 
> > file with the TRACE_EVENTs someplace other than include/trace.
> > 
> > If the "foo.h" is in include/trace.h we do not need to include 
> > this hack. But because the include/trace/define_trace.h needs to 
> > include the "foo.h" file recursively, it must be able to find it. 
> > If we do not add a search path, include/trace/define_trace.h will 
> > not look in the other locations.
> > 
> > Note, as Christoph did, we only need to add the include path to 
> > the file that defines "CREATE_TRACE_POINTS". Which is only one 
> > file.
> > 
> > CFLAGS_sched.o := -I$(src)
> > 
> > Only touches the sched.c file in that directory (Note, for those 
> > reading this thread out of context, this is not the same file as 
> > kernel/sched.c)
> 
> Yeah, i guess we can live with it. It still feels imperfect though.

Yeah, I dislike it too. But this is a limitation on CPP. When we get
sparse to replace CPP then we can fix it there ;-)

> 
> (btw., find below a small typo fix)
> 
> 	Ingo
> 
> diff --git a/include/trace/define_trace.h b/include/trace/define_trace.h
> index f7a7ae1..1d6fa17 100644
> --- a/include/trace/define_trace.h
> +++ b/include/trace/define_trace.h
> @@ -1,5 +1,5 @@
>  /*
> - * Trace files that want to automate creationg of all tracepoints defined
> + * Trace files that want to automate the creation of all tracepoints defined
>   * in their file should include this file. The following are macros that the
>   * trace file may define:
>   *

Thanks,

-- Steve

Re: [PATCH, RFC] sputrace: use the generic event tracer

[Frederic Weisbecker]

On Wed, May 06, 2009 at 12:57:48PM +0200, Ingo Molnar wrote:
> 
> (Note: please Cc all tracing related patches to lkml.)
> 
> * Christoph Hellwig <hch@lst.de> wrote:
> 
> > I wrote sputrace before generic tracing infrastrucure was 
> > available. Now that we have the generic event tracer we can 
> > convert it over and remove a lot of code:
> > 
> >   8 files changed, 45 insertions(+), 285 deletions(-)
> 
> Nice! Needs also an Ack from PowerPC folks before we can do this. 
> The cross section to other powerpc code seems to be rather low.
> 
> A few comments:
> 
> > To use it make sure CONFIG_EVENT_TRACING is enabled and then enable
> > the spufs trace channel by
> > 
> >   echo 1 > /sys/kernel/debug/tracing/events/spufs/spufs_context
> > 
> > and then read the trace records using e.g.
> > 
> >   cat /sys/kernel/debug/tracing/trace
> > 
> > 
> > Note that the patch is ontop of the current tracing tree
> > 
> >   git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip.git#tracing/ftrace
> > 
> > as there have been some TRACE_EVENT changes in there that aren't in
> > mainline yet.
> > 
> > I don't have any cell hardware anymore so this is only compile tested.
> > 
> > 
> > Signed-off-by: Christoph Hellwig <hch@lst.de>
> > 
> > Index: linux-2.6-tip/arch/powerpc/platforms/cell/spufs/sputrace.h
> > ===================================================================
> > --- /dev/null	1970-01-01 00:00:00.000000000 +0000
> > +++ linux-2.6-tip/arch/powerpc/platforms/cell/spufs/sputrace.h	2009-05-06 10:17:20.000000000 +0000
> > @@ -0,0 +1,39 @@
> > +#if !defined(_TRACE_SPUFS_H) || defined(TRACE_HEADER_MULTI_READ)
> > +#define _TRACE_SPUFS_H
> > +
> > +#include <linux/tracepoint.h>
> > +
> > +#undef TRACE_SYSTEM
> > +#define TRACE_SYSTEM spufs
> > +
> > +TRACE_EVENT(spufs_context,
> > +	TP_PROTO(struct spu_context *ctx, struct spu *spu, const char *name),
> > +	TP_ARGS(ctx, spu, name),
> > +
> > +	TP_STRUCT__entry(
> > +		__field(int, owner_tid)
> > +		__field(const char *, name)


Christoph,

I don't know much the code you are tracing. But it is rare that
a const char * is safe on tracing. Still it could be, you just have to
ensure the string cannot be freed in any way because this pointer
will be stored in the ring buffer and it can be read and dereferenced later
in a random time, could be several years :-)

So if this pointer references built-in data, no problem with that.
But if it can freed (comes from a module, __initdata, ...), then
you should use the __string() field which does an strcpy on the
ring buffer.

If you think this is safe, then it's the best choice because
storing a pointer is of course less costly than an strcpy.
If so I will add the support for char * in the filters (trivial).

Thanks,

Frederic.

Re: [PATCH, RFC] sputrace: use the generic event tracer

[Christoph Hellwig]

On Wed, May 06, 2009 at 06:53:37PM +0200, Frederic Weisbecker wrote:
> I don't know much the code you are tracing. But it is rare that
> a const char * is safe on tracing. Still it could be, you just have to
> ensure the string cannot be freed in any way because this pointer
> will be stored in the ring buffer and it can be read and dereferenced later
> in a random time, could be several years :-)
> 
> So if this pointer references built-in data, no problem with that.
> But if it can freed (comes from a module, __initdata, ...), then
> you should use the __string() field which does an strcpy on the
> ring buffer.
> 
> If you think this is safe, then it's the best choice because
> storing a pointer is of course less costly than an strcpy.
> If so I will add the support for char * in the filters (trivial).

The pointer here only ever references string constants, it's always
a string literal in the callers.

Re: [PATCH, RFC] sputrace: use the generic event tracer

[Steven Rostedt]

On Wed, 2009-05-06 at 19:13 +0200, Christoph Hellwig wrote:
> On Wed, May 06, 2009 at 06:53:37PM +0200, Frederic Weisbecker wrote:
> > I don't know much the code you are tracing. But it is rare that
> > a const char * is safe on tracing. Still it could be, you just have to
> > ensure the string cannot be freed in any way because this pointer
> > will be stored in the ring buffer and it can be read and dereferenced later
> > in a random time, could be several years :-)
> > 
> > So if this pointer references built-in data, no problem with that.
> > But if it can freed (comes from a module, __initdata, ...), then
> > you should use the __string() field which does an strcpy on the
> > ring buffer.
> > 
> > If you think this is safe, then it's the best choice because
> > storing a pointer is of course less costly than an strcpy.
> > If so I will add the support for char * in the filters (trivial).
> 
> The pointer here only ever references string constants, it's always
> a string literal in the callers.

The worry is if this is used by modules. A constant string may not be
around when the buffer is read.

This should not be a problem because the formatting of the string is not
around either, and we just output 'unknown type'.  But I may be adding
code when a module is unloaded to reset the ring buffer if the module
registered any events. That's because we have other races to worry
about.

-- Steve

Re: [Cbe-oss-dev] [PATCH, RFC] sputrace: use the generic event tracer

[Christoph Hellwig]

On Wed, May 06, 2009 at 03:05:39PM -0400, Steven Rostedt wrote:
> The worry is if this is used by modules. A constant string may not be
> around when the buffer is read.
> 
> This should not be a problem because the formatting of the string is not
> around either, and we just output 'unknown type'.  But I may be adding
> code when a module is unloaded to reset the ring buffer if the module
> registered any events. That's because we have other races to worry
> about.

I think having some constant string description for trace events is
pretty common and used in just above any ad-hoc tracer I've seen,
and just storing the pointers makes this a lot more efficient.

So either we try to make sure this works, or we need some big waivers
in the documentation that people need to use the slower __string
variant.

Re: [PATCH, RFC] sputrace: use the generic event tracer

[Ingo Molnar]

* Christoph Hellwig <hch@lst.de> wrote:

> Index: linux-2.6-tip/arch/powerpc/platforms/cell/spufs/sputrace.c
> ===================================================================
> --- linux-2.6-tip.orig/arch/powerpc/platforms/cell/spufs/sputrace.c	2009-05-06 10:18:03.000000000 +0000
> +++ /dev/null	1970-01-01 00:00:00.000000000 +0000
> @@ -1,272 +0,0 @@
> -/*
> - * Copyright (C) 2007 IBM Deutschland Entwicklung GmbH
> - *	Released under GPL v2.
> - *
> - * Partially based on net/ipv4/tcp_probe.c.

btw., net/ipv4/tcp_probe.c would be another potential candidate to 
convert to tracepoints.

	Ingo