Re: [patch 1/3] Trace code and documentation

Previous thread: [PATCH 0/3] A kernel tracing interface by David J. Wilder on Tuesday, October 2, 2007 - 9:33 am. (1 message)

Next thread: [patch 2/3] Relay Reset Consumed by David J. Wilder on Tuesday, October 2, 2007 - 9:33 am. (1 message)
From: David J. Wilder
Date: Tuesday, October 2, 2007 - 9:33 am

Trace - Provides tracing primitives

Signed-off-by: Tom Zanussi <zanussi@us.ibm.com>
Signed-off-by: Martin Hunt <hunt@redhat.com>
Signed-off-by: David Wilder <dwilder@us.ibm.com>
---
 Documentation/trace.txt |  160 ++++++++++++++
 include/linux/trace.h   |   99 +++++++++
 lib/Kconfig             |    9 +
 lib/Makefile            |    2 +
 lib/trace.c             |  563 +++++++++++++++++++++++++++++++++++++++++++++++
 5 files changed, 833 insertions(+), 0 deletions(-)

diff --git a/Documentation/trace.txt b/Documentation/trace.txt
new file mode 100644
index 0000000..195132d
--- /dev/null
+++ b/Documentation/trace.txt
@@ -0,0 +1,160 @@
+Trace Setup and Control
+=======================
+In the kernel, the trace interface provides a simple mechanism for
+starting and managing data channels (traces) to user space.  The
+trace interface builds on the relay interface.  For a complete
+description of the relay interface, please see:
+Documentation/filesystems/relay.txt.
+
+The trace interface provides a single layer in a complete tracing
+application.  Trace provides a kernel API that can be used for the setup
+and control of tracing channels.  User of trace must provide a data layer
+responsible for formatting and writing data into the trace channels.
+
+A layered approach to tracing
+=============================
+A complete kernel tracing application consists of a data provider and
+a data consumer.  Both provider and consumer contain three layers; each
+layer works in tandem with the corresponding layer in the opposite side.
+The layers are represented in the following diagram.
+
+Provider Data layer
+	Formats raw trace data and provides data-related service.
+	For example, adding timestamps used by consumer to sort data.
+
+Provider Control layer
+	Provided by the trace interface, this layer creates trace channels
+	and informs the data layer and consumer of the current state
+	of the trace channels.
+
+Provider Buffering layer
+	Provided by relay. This layer ...
From: Randy Dunlap
Date: Tuesday, October 2, 2007 - 10:05 am

---
~Randy
-

From: Andi Kleen
Date: Thursday, October 4, 2007 - 2:24 am

Wasn't relayfs supposed to do that already? Why do you need another
wrapper around it? 

Is this also really still faster than a printk below log level
(without console driver overhead). If not then why not just
use printk? 

Especially your example is worrying. It essentially defines a new
printk. I think there is a case for a fast logging subsystem because
printk() is admittedly a little slow [somewhat slow below log level
and incredible slow above it]

But fast means binary items (not sprintf), no global locks, not
multiple layers, per CPU etc.. But your example and this patch has all
this and I bet it is not very fast.

Is the result (e.g. the trace example module) still any faster
than printk below log level? If not then why bother.

Adding another slow logger would be just a waste of time imho.
It just means that everybody who needs a fast logger just need
to reimplement their own anyways. And the people who can tolerate
slow loggers are probably already adequately served by 
printk. Also there is already direct relayfs.

-Andi
-

From: David Wilder
Date: Thursday, October 4, 2007 - 12:19 pm

The code in trace is exactly what all the current users of relay do. 

Are you arguing against relayfs or trace?  Trace just makes relayfs 

Each user of trace has its own requirements for passing data over 
relayfs channels. This is why the documentation describes separate 
control and data layers.  The trace API provides a control layer with 
this flexibility.

The example shows a way to create an ASCII data layer.  The format of 
the data (binary or ascii) is just a function of how the data layer 
formats it.

Locking is only required when using global bufferers. The option of 
selecting per-cpu vs global bufferers is available to the trace user. 
The example (and the documentation) shows how to use both methods (See: 
#define USE_GLOBAL_BUFFER in the example).

There is no impact of adding an extra layer. The primitives for trace 
adds code for trace setup and control, but trace is not doing anything 
that a relayfs user would not have to do anyway.  We mostly care about 
the impact of writing data to the trace channels and trace has no impact 

True, to make trace "fast" you need a data layer that can handle the 
requirements of per-cpu buffers.  However there are still advantages of 
trace over printk even when using global bufferers: selectable bufferer 
sizes, separate data channels (not have to share data channels with 
every other subsystem in the kernel), trace control, non-overwrite mode 
and buffer management.

The next step is to provide data layer that can fully take advantage of 
per-cpu bufferers (systemtap shows us one example). Trace give us a 
place to build it.  As Christoph's said about trace:

    "Long term we probably want more complex tracing based on lttng,
     but I'm a big fan of starting out simple and doing incremental
     changes."

One advantage of the trace approach is separating control and data 
layers, therefor trace can support multiple data layers to fit multiple 
requirements.

I have my ideas on how to develop data layer, ...
From: Andi Kleen
Date: Thursday, October 4, 2007 - 2:19 pm

If everybody does this then the code should be just put into

I'm arguing against complicated trace mechanisms that are not fast.

At some point when I looked at relayfs it seemed to be reasonably
fast (per cpu buffers; not much locking, over head per call roughtly like putchar()),
but that might have regressed. 

Your example module with its lock definitely looks very slow and I don't approve

ASCII layers don't make much sense imho -- these should just use printk.

Fast dedicated binary log channels make sense though; but you don't


It's just that relayfs + another not simple layer are definitely not simple.

For a simple logger I'm thinking more like something like SGI's old
ktrace module (which undoubtedly many other people have recreated many
times for specific debugging scenarios)

But that all only makes sense if the overhead is really kept low


I'm all for that. I believe a simple fast efficient no frills logger
would serve systemtap just fine too. But the approach here seems
to be more to add all kinds of knobs and whizzles until you end
up with something as slow with printk. And since we already have
printk another one just doesn't seem to make much sense.

-Andi
-

From: David Wilder
Date: Thursday, October 4, 2007 - 4:12 pm

I disagree, I keeping the code separate (layering if you will) makes it 

What makes trace complicated?  It is just, open ,start/stop, close.  I 

No regression has occurred.  According the relay documentation if you 
use global bufferers you must use locking.  If you don't want to use 

If you don't approve of the locking then use per-cpu bufferers.  The 

So the only way I should pass ASCII to user space is using printk?  I 

I impose no restriction on what type of data you can pass over trace's 

Is your complaint with the overhead of setting up a trace channel or the 
overhead of writing to a trace channel?   For the later, trace adds 

I am using the layer definitions described in trace.txt.  In this 

If by knobs you mean the trace controls.  The only one that has any 
effect on the "speed" of tracing is the control to start and stop 
tracing.  And that had been designed to impose the minimal impact 

-

Previous thread: [PATCH 0/3] A kernel tracing interface by David J. Wilder on Tuesday, October 2, 2007 - 9:33 am. (1 message)

Next thread: [patch 2/3] Relay Reset Consumed by David J. Wilder on Tuesday, October 2, 2007 - 9:33 am. (1 message)