Re: Tracing/ftrace: trouble with trace_entries and trace_pipe

[Steven Rostedt]

On Mon, 15 Sep 2008, Pekka Paalanen wrote:

> Hi Steven and others,
> 
> first a minor bug: it seems the units of /debug/tracing/trace_entries
> is different for read and write. This is confusing for the users, since
> I can't say "if you have problems, double it". If I read from it
> something like 16422, then write back 16422, next I read 214. I can't
> recall the exact numbers, but the difference really is two orders of
> magnitude. I have 1 GB RAM in this box, so that shouldn't be an issue.

You write to it the same number that you read from and it returned 
something different?? That is indeed a bug, since it should definitely 
detect that. Is this linux-tip? I'll have to play with it to make sure 
nothing broke it recently.

I just tried the latest mainline, and it seemed to work there.

> 
> My other problem is with trace_pipe. It is again making 'cat' quit too
> early. The condition triggered is
> 	if (!tracer_enabled && iter->pos) {
> in tracing_read_pipe(), and it is followed by triggering
>         /* stop when tracing is finished */
>         if (trace_empty(iter)) {
> and then sret=0, so read returns 0 and 'cat' exits.
> 
> Now, I am trying my mmiotrace marker patches, but as far as I can tell,
> nothing I modified is the reason for this. I didn't yet explicitly test
> for it, though. I'll send these patches after I hear from Frederic.
> 
> The cat-quit problem is not a constant state. After boot, I could play
> with my markers and testmmiotrace without cat quitting. Then something
> happens, and cat starts the quitting behaviour, and won't get to normal
> by disabling and enabling mmiotrace.
> 
> I have a couple of wild guesses of what might be related:
> - ring buffer wrap-around
> - ring buffer overflow (at first try I hit these, the second try
> after putting debug-pr_info's in place I don't hit this)
> - ring buffer resize (after playing with trace_entries, cat-quit
> problem was present, though it might have been present before)
> 
> After viewing the git history, I have some more guesses, mainly
> related to setting tracer_enabled to 0.
> - commit 2b1bce1787700768cbc87c8509851c6f49d252dc
> I don't see where tracer_enabled would be set to 1, when
> mmiotrace is enabled. It used to default to 1 and mmiotrace was happy.
> - __tracing_open() sets it to 0 (not called for the pipe)
> - tracing_release() sets it to 1
> - tracing_ctrl_write() toggles it
> - tracing_read_pipe() tests it
> - tracer_alloc_buffers() uses it
> And other tracers seem to use it a lot.
> 
> Mmiotrace does use the tracer::ctrl_update hook, and allow/disallow
> calls to __trace_mmiotrace_{rw,map}() via enabling/disabling the whole
> mmiotrace core. Is this not enough, or is it inappropriate?
> 
> It seems tracer_enabled is used by the trace framework itself to
> enable/disable... what? Hmm, maybe nothing I care about.
> 
> Should mmiotrace simply do
> 	tracer_enabled = 1;
> in mmio_trace_init()?
> 
> Should mmiotrace test tracer_enabled, and if so, when?

No, tracer_enabled is something that is internal to the tracer 
infrastructure. 

if you read from either tracing/trace or tracing/latency_trace it will 
disable the tracer while you dump. But you should not be doing that. The 
trace_pipe should not disable that either.

-- Steve

--
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/