request to add trace off and trace on with events

request to add trace off and trace on with events

[Steven Rostedt]

Hi Tom,

Could you add a way to do a call to tracing_on() or tracing_off() via
the filters. I would like to do something like:


echo 'if (pid == 1234) traceoff' > events/sched/sched_wakeup/filter

Where, if the sched_wakeup event is hit with pid == 1234 it will turn
tracing off.

I would also like to do just:

echo 'traceoff' > events/sched/sched_wakeup/filter

to disable tracing every time the event is hit.

Perhaps you can just add a call back where the kernel could register
something to be called if a command is used in the filter.

register_event_command("traceoff", trace_off_cb);

where the trace_off_cb is a function that is called by the event if the
traceoff command is hit. This would allow other commands to be added
later.

Would something like this be doable, I was looking at the code, and it
certain looks feasible, but it would take me longer to implement it than
it would you :-)

Thanks,

-- Steve

Re: request to add trace off and trace on with events

[Tim Bird]

On 04/19/2010 01:04 PM, Steven Rostedt wrote:
> Hi Tom,
> 
> Could you add a way to do a call to tracing_on() or tracing_off() via
> the filters. I would like to do something like:
> 
> 
> echo 'if (pid == 1234) traceoff' > events/sched/sched_wakeup/filter
> 
> Where, if the sched_wakeup event is hit with pid == 1234 it will turn
> tracing off.

Just a comment on the nomenclature.  In KFT I called
things like this "triggers".  I'm not sure what other
tracing systems call them.  I'm a little worried about
overloading the filtering abstraction with trigger
semantics.  (I like the idea of triggers, but it might
be better to control them with another pseudo-file for
clarity.)

I suppose both are a form of conditional execution.
Filtering has an implicit action of either 'trace this'
or 'don't trace this', while triggering usually has
an action, often explicit, to start or stop tracing.
However, since they both use the conditional testing,
it might be a pain to reproduce this code for a different
pseudo-file.

Just my 2 cents.
 -- Tim

=============================
Tim Bird
Architecture Group Chair, CE Linux Forum
Senior Staff Engineer, Sony Network Entertainment
=============================

Re: request to add trace off and trace on with events

[Steven Rostedt]

On Mon, 2010-04-19 at 13:39 -0700, Tim Bird wrote:
> On 04/19/2010 01:04 PM, Steven Rostedt wrote:
> > Hi Tom,
> > 
> > Could you add a way to do a call to tracing_on() or tracing_off() via
> > the filters. I would like to do something like:
> > 
> > 
> > echo 'if (pid == 1234) traceoff' > events/sched/sched_wakeup/filter
> > 
> > Where, if the sched_wakeup event is hit with pid == 1234 it will turn
> > tracing off.
> 
> Just a comment on the nomenclature.  In KFT I called
> things like this "triggers".  I'm not sure what other

Yeah, Mathieu calls them triggers too. But if you do, I'm fine with
calling them that as well.

> tracing systems call them.  I'm a little worried about
> overloading the filtering abstraction with trigger
> semantics.  (I like the idea of triggers, but it might
> be better to control them with another pseudo-file for
> clarity.)
> 
> I suppose both are a form of conditional execution.
> Filtering has an implicit action of either 'trace this'
> or 'don't trace this', while triggering usually has
> an action, often explicit, to start or stop tracing.
> However, since they both use the conditional testing,
> it might be a pain to reproduce this code for a different
> pseudo-file.

I thought about a separate file, but I like the idea of having control
over them. We could add a "trigger" file too, but I'm not sure if that
would be any clearer.

If we add a trigger file, then the filter can be separate, and we just
trigger the trigger if the filter passes.

This may be better, because then the triggers do not mess with the
filtering code, and I can add it without modification to Tom's code.

-- Steve

Re: request to add trace off and trace on with events

[Tim Bird]

On 04/19/2010 01:44 PM, Steven Rostedt wrote:
> On Mon, 2010-04-19 at 13:39 -0700, Tim Bird wrote:
>> On 04/19/2010 01:04 PM, Steven Rostedt wrote:
>>> Hi Tom,
>>>
>>> Could you add a way to do a call to tracing_on() or tracing_off() via
>>> the filters. I would like to do something like:
>>>
>>>
>>> echo 'if (pid == 1234) traceoff' > events/sched/sched_wakeup/filter
>>>
>>> Where, if the sched_wakeup event is hit with pid == 1234 it will turn
>>> tracing off.
>>
>> Just a comment on the nomenclature.  In KFT I called
>> things like this "triggers".  I'm not sure what other
> 
> Yeah, Mathieu calls them triggers too. But if you do, I'm fine with
> calling them that as well.
> 
>> tracing systems call them.  I'm a little worried about
>> overloading the filtering abstraction with trigger
>> semantics.  (I like the idea of triggers, but it might
>> be better to control them with another pseudo-file for
>> clarity.)
>>
>> I suppose both are a form of conditional execution.
>> Filtering has an implicit action of either 'trace this'
>> or 'don't trace this', while triggering usually has
>> an action, often explicit, to start or stop tracing.
>> However, since they both use the conditional testing,
>> it might be a pain to reproduce this code for a different
>> pseudo-file.
> 
> I thought about a separate file, but I like the idea of having control
> over them. We could add a "trigger" file too, but I'm not sure if that
> would be any clearer.

I'm not sure either.  In general I dislike proliferating
pseudo-files.  But if the tracing filter conditional is
different from the trigger conditional, it might be needed
to have something separate.

In KFT there were some non-event related trigger conditionals,
like - start tracing after 20 milliseconds and stop after
80 milliseconds.

Another thing I considered for KFT triggers, but didn't get
around to implementing, was countdown triggers - such as
"start tracing on the 5th execution of do_fork".

With the function or function_graph tracer, since the buffer
overflows quickly, these kinds of triggered trace starts and stops
can help pinpoint the data you need.

Okay - that's probably 4 cents now. :-)
 -- Tim

=============================
Tim Bird
Architecture Group Chair, CE Linux Forum
Senior Staff Engineer, Sony Network Entertainment
=============================

Re: request to add trace off and trace on with events

[Steven Rostedt]

On Mon, 2010-04-19 at 13:56 -0700, Tim Bird wrote:

> I'm not sure either.  In general I dislike proliferating
> pseudo-files.  But if the tracing filter conditional is
> different from the trigger conditional, it might be needed
> to have something separate.

I was thinking of keeping the filter trigger the trigger too.

I think we talked about this in the past. Where the "trigger" file would
default be print, but could also add other triggers to it. Thus, you do
not need to print when the event is hit (with filters). I think I
originally called this a "command", but multiple commands could perform
this.

> 
> In KFT there were some non-event related trigger conditionals,
> like - start tracing after 20 milliseconds and stop after
> 80 milliseconds.
> 
> Another thing I considered for KFT triggers, but didn't get
> around to implementing, was countdown triggers - such as
> "start tracing on the 5th execution of do_fork".
> 
> With the function or function_graph tracer, since the buffer
> overflows quickly, these kinds of triggered trace starts and stops
> can help pinpoint the data you need.

Try:

echo 'try_to_wake_up:traceon:5' 'schedule:traceoff:5' > set_ftrace_filter

;-)

-- Steve

Re: request to add trace off and trace on with events

[Tim Bird]

On 04/19/2010 02:10 PM, Steven Rostedt wrote:
> On Mon, 2010-04-19 at 13:56 -0700, Tim Bird wrote:
> Try:
> 
> echo 'try_to_wake_up:traceon:5' 'schedule:traceoff:5' > set_ftrace_filter
> 
> ;-)

Awesome!  I need to keep up better with the state of the art.
 -- Tim

=============================
Tim Bird
Architecture Group Chair, CE Linux Forum
Senior Staff Engineer, Sony Network Entertainment
=============================

Re: request to add trace off and trace on with events

[Frederic Weisbecker]

On Mon, Apr 19, 2010 at 04:44:06PM -0400, Steven Rostedt wrote:
> I thought about a separate file, but I like the idea of having control
> over them. We could add a "trigger" file too, but I'm not sure if that
> would be any clearer.
> 
> If we add a trigger file, then the filter can be separate, and we just
> trigger the trigger if the filter passes.
> 
> This may be better, because then the triggers do not mess with the
> filtering code, and I can add it without modification to Tom's code.
> 
> -- Steve
> 
> 


The problem with having triggers defined in the filter file is that
you couldn't set a normal filter plus a trigger.

That said a filter itself could be a trigger.

if (cond) filter

This is going to break some ABI though.

In fact having one file per trigger type is going to make the
things much easier if you don't want to encumber with syntax parsing,
and just reuse the filtering code as is with very few modification.
This is going to be also easier for the users as they don't have to
remember the syntax or the available triggers.

Say you are in an event directory:

$ ls triggers/

filter
tracing_off
tracing_on
dump_trace

$ echo "(a == 1 && b == 2)" > tracing_off

So in the above example, you just reuse the filtering code,
no need to parse an if or a command.
The filter becomes a command. I've listed it in the triggers
directory but this just to express the fact it can be treated
like whatever trigger command, this is just an implementation
POV. In fact we can just keep it in the event directory.

Re: request to add trace off and trace on with events

[Steven Rostedt]

On Mon, 2010-04-19 at 23:29 +0200, Frederic Weisbecker wrote:

> The problem with having triggers defined in the filter file is that
> you couldn't set a normal filter plus a trigger.
> 
> That said a filter itself could be a trigger.
> 
> if (cond) filter
> 
> This is going to break some ABI though.
> 
> In fact having one file per trigger type is going to make the
> things much easier if you don't want to encumber with syntax parsing,
> and just reuse the filtering code as is with very few modification.
> This is going to be also easier for the users as they don't have to
> remember the syntax or the available triggers.
> 
> Say you are in an event directory:
> 
> $ ls triggers/
> 
> filter
> tracing_off
> tracing_on
> dump_trace
> 
> $ echo "(a == 1 && b == 2)" > tracing_off
> 
> So in the above example, you just reuse the filtering code,
> no need to parse an if or a command.
> The filter becomes a command. I've listed it in the triggers
> directory but this just to express the fact it can be treated
> like whatever trigger command, this is just an implementation
> POV. In fact we can just keep it in the event directory.


I like this. Heck, all registered triggers can be shown here.

# cat event/sched/sched_switch/triggers/tracing_off
disabled

Or it can be a filter, or enabled.

This could also allow a user to do:

echo "(a > 100)" > tracing_on
echo "(a < 100)" > tracing_off

-- Steve

Re: request to add trace off and trace on with events

[Frederic Weisbecker]

On Mon, Apr 19, 2010 at 05:37:54PM -0400, Steven Rostedt wrote:
> On Mon, 2010-04-19 at 23:29 +0200, Frederic Weisbecker wrote:
> 
> > The problem with having triggers defined in the filter file is that
> > you couldn't set a normal filter plus a trigger.
> > 
> > That said a filter itself could be a trigger.
> > 
> > if (cond) filter
> > 
> > This is going to break some ABI though.
> > 
> > In fact having one file per trigger type is going to make the
> > things much easier if you don't want to encumber with syntax parsing,
> > and just reuse the filtering code as is with very few modification.
> > This is going to be also easier for the users as they don't have to
> > remember the syntax or the available triggers.
> > 
> > Say you are in an event directory:
> > 
> > $ ls triggers/
> > 
> > filter
> > tracing_off
> > tracing_on
> > dump_trace
> > 
> > $ echo "(a == 1 && b == 2)" > tracing_off
> > 
> > So in the above example, you just reuse the filtering code,
> > no need to parse an if or a command.
> > The filter becomes a command. I've listed it in the triggers
> > directory but this just to express the fact it can be treated
> > like whatever trigger command, this is just an implementation
> > POV. In fact we can just keep it in the event directory.
> 
> 
> I like this. Heck, all registered triggers can be shown here.
> 
> # cat event/sched/sched_switch/triggers/tracing_off
> disabled
> 
> Or it can be a filter, or enabled.


Yep, since it would share exatly the same code than filter (as
filter basically becomes a trigger command), it can behave the
same: displaying "none" when there is no filter, or a filter.


> 
> This could also allow a user to do:
> 
> echo "(a > 100)" > tracing_on
> echo "(a < 100)" > tracing_off


Yeah :)
But if the scope of the "tracing off" is only for this event, then
rather use:

echo "(a < 100)" > filter

You could have tracing_off/on that have this event scope and
tracing_off/on_all for a global tracing scope.

Re: request to add trace off and trace on with events

[Steven Rostedt]

On Tue, 2010-04-20 at 00:04 +0200, Frederic Weisbecker wrote:
> On Mon, Apr 19, 2010 at 05:37:54PM -0400, Steven Rostedt wrote:

> > # cat event/sched/sched_switch/triggers/tracing_off
> > disabled
> > 
> > Or it can be a filter, or enabled.
> 
> 
> Yep, since it would share exatly the same code than filter (as
> filter basically becomes a trigger command), it can behave the
> same: displaying "none" when there is no filter, or a filter.
> 

Then do we make the triggers themselves directories too?

# ls event/sched/sched_switch/triggers/tracing_off
filter   enable

?

> 
> > 
> > This could also allow a user to do:
> > 
> > echo "(a > 100)" > tracing_on
> > echo "(a < 100)" > tracing_off
> 
> 
> Yeah :)
> But if the scope of the "tracing off" is only for this event, then
> rather use:
> 
> echo "(a < 100)" > filter
> 
> You could have tracing_off/on that have this event scope and
> tracing_off/on_all for a global tracing scope.

The two are not equivalent. In fact, just enabling a trigger does not
mean that the event itself will be traced.

-- Steve

Re: request to add trace off and trace on with events

[Frederic Weisbecker]

On Mon, Apr 19, 2010 at 06:13:47PM -0400, Steven Rostedt wrote:
> On Tue, 2010-04-20 at 00:04 +0200, Frederic Weisbecker wrote:
> > On Mon, Apr 19, 2010 at 05:37:54PM -0400, Steven Rostedt wrote:
> 
> > > # cat event/sched/sched_switch/triggers/tracing_off
> > > disabled
> > > 
> > > Or it can be a filter, or enabled.
> > 
> > 
> > Yep, since it would share exatly the same code than filter (as
> > filter basically becomes a trigger command), it can behave the
> > same: displaying "none" when there is no filter, or a filter.
> > 
> 
> Then do we make the triggers themselves directories too?
> 
> # ls event/sched/sched_switch/triggers/tracing_off
> filter   enable
> 
> ?


That would be perhaps an overkill.
Having a filter inside means it's on, otherwise it's off.



> 
> > 
> > > 
> > > This could also allow a user to do:
> > > 
> > > echo "(a > 100)" > tracing_on
> > > echo "(a < 100)" > tracing_off
> > 
> > 
> > Yeah :)
> > But if the scope of the "tracing off" is only for this event, then
> > rather use:
> > 
> > echo "(a < 100)" > filter
> > 
> > You could have tracing_off/on that have this event scope and
> > tracing_off/on_all for a global tracing scope.
> 
> The two are not equivalent. In fact, just enabling a trigger does not
> mean that the event itself will be traced.


Yeah, the enable file would first need to be activated before any
trigger to take effect on the event, just like filters.

In fact I was thinking of tracing_on/tracing_off as kinds of
local pause/resume.

And tracing_on_global/tracing_off_global would act like what does
/debug/tracing/tracing_on: something that disables every tracing.

But of course, before any of these conditional triggers to be
evaluated, you need to enable the corresponding event.

Re: request to add trace off and trace on with events

[Steven Rostedt]

On Tue, 2010-04-20 at 01:04 +0200, Frederic Weisbecker wrote:

> > # ls event/sched/sched_switch/triggers/tracing_off
> > filter   enable
> > 
> > ?
> 
> 
> That would be perhaps an overkill.

Perhaps, but I was also thinking of having triggers in the system level.
That way all events below it can trigger.

> Having a filter inside means it's on, otherwise it's off.
> 
> 
> 
> > 
> > > 
> > > > 
> > > > This could also allow a user to do:
> > > > 
> > > > echo "(a > 100)" > tracing_on
> > > > echo "(a < 100)" > tracing_off
> > > 
> > > 
> > > Yeah :)
> > > But if the scope of the "tracing off" is only for this event, then
> > > rather use:
> > > 
> > > echo "(a < 100)" > filter
> > > 
> > > You could have tracing_off/on that have this event scope and
> > > tracing_off/on_all for a global tracing scope.
> > 
> > The two are not equivalent. In fact, just enabling a trigger does not
> > mean that the event itself will be traced.
> 
> 
> Yeah, the enable file would first need to be activated before any
> trigger to take effect on the event, just like filters.
> 
> In fact I was thinking of tracing_on/tracing_off as kinds of
> local pause/resume.
> 
> And tracing_on_global/tracing_off_global would act like what does
> /debug/tracing/tracing_on: something that disables every tracing.
> 
> But of course, before any of these conditional triggers to be
> evaluated, you need to enable the corresponding event.

We could have a "trace_event_on" and "trace_event_off" trigger that only
enables the event when hit.

Actually, we can have these triggers enable other events, or make
dynamic triggers:

echo "enable_sched_switch" > events/sched/sched_wakeup/trigger/activate

or something similar.

-- Steve

Re: request to add trace off and trace on with events

[Tom Zanussi]

On Mon, 2010-04-19 at 19:59 -0400, Steven Rostedt wrote:
> On Tue, 2010-04-20 at 01:04 +0200, Frederic Weisbecker wrote:
> 
> > > # ls event/sched/sched_switch/triggers/tracing_off
> > > filter   enable
> > > 
> > > ?
> > 
> > 
> > That would be perhaps an overkill.
> 
> Perhaps, but I was also thinking of having triggers in the system level.
> That way all events below it can trigger.
> 
> > Having a filter inside means it's on, otherwise it's off.
> > 
> > 
> > 
> > > 
> > > > 
> > > > > 
> > > > > This could also allow a user to do:
> > > > > 
> > > > > echo "(a > 100)" > tracing_on
> > > > > echo "(a < 100)" > tracing_off
> > > > 
> > > > 
> > > > Yeah :)
> > > > But if the scope of the "tracing off" is only for this event, then
> > > > rather use:
> > > > 
> > > > echo "(a < 100)" > filter
> > > > 
> > > > You could have tracing_off/on that have this event scope and
> > > > tracing_off/on_all for a global tracing scope.
> > > 
> > > The two are not equivalent. In fact, just enabling a trigger does not
> > > mean that the event itself will be traced.
> > 
> > 
> > Yeah, the enable file would first need to be activated before any
> > trigger to take effect on the event, just like filters.
> > 
> > In fact I was thinking of tracing_on/tracing_off as kinds of
> > local pause/resume.
> > 
> > And tracing_on_global/tracing_off_global would act like what does
> > /debug/tracing/tracing_on: something that disables every tracing.
> > 
> > But of course, before any of these conditional triggers to be
> > evaluated, you need to enable the corresponding event.
> 
> We could have a "trace_event_on" and "trace_event_off" trigger that only
> enables the event when hit.
> 
> Actually, we can have these triggers enable other events, or make
> dynamic triggers:
> 
> echo "enable_sched_switch" > events/sched/sched_wakeup/trigger/activate
> 
> or something similar.
> 

Yeah, it could be pretty useful to have triggers be able to enable and
set filters on other events to see what's going on in lower layers under
some arbitrary condition e.g. just as a bogus example,

echo "enable_block_io("dev == sdb"), enable_pagecache if ("count > 128k
&& fd == 9999") > events/syscalls/sys_enter_read


Dynamic triggers that could modify their own filters could also provide
for some interesting applications.  For example, a trigger on e.g.
block_bio_complete could be used to track sectors that have been written
to over a certain period of time.  On each 'hit', the command would add
a predicate that describes the sector(xxx) and nr_sector(yyy) contained
in that event to its own filter e.g. ("!(sector >= xxx && sector <= xxx
+ yyy)") i.e. any event that matches the filter (isn't contained within
any of current sector predicates) invokes the command to add that
event's block to the filter.

At the end of the run, the filter itself would contain all of the
sectors that were written to; the resulting filter could simply be
dumped to retrieve them.  I know there are some virtual disk backup
companies out there that would probably find something like this pretty
useful...

Of course, for this to be feasible, the filter implementation would have
to be streamlined to handle large numbers of predicates e.g. managed in
a tree, predicate merging, etc.

I don't know if it's worth it just for this, but I'm sure there are
plenty of other examples where dynamic filters would be useful...

Tom 

> -- Steve
> 
> 
> 

Re: request to add trace off and trace on with events

[Tom Zanussi]

On Mon, 2010-04-19 at 16:04 -0400, Steven Rostedt wrote:
> Hi Tom,
> 
> Could you add a way to do a call to tracing_on() or tracing_off() via
> the filters. I would like to do something like:
> 
> 
> echo 'if (pid == 1234) traceoff' > events/sched/sched_wakeup/filter
> 
> Where, if the sched_wakeup event is hit with pid == 1234 it will turn
> tracing off.
> 
> I would also like to do just:
> 
> echo 'traceoff' > events/sched/sched_wakeup/filter
> 
> to disable tracing every time the event is hit.
> 
> Perhaps you can just add a call back where the kernel could register
> something to be called if a command is used in the filter.
> 
> register_event_command("traceoff", trace_off_cb);
> 
> where the trace_off_cb is a function that is called by the event if the
> traceoff command is hit. This would allow other commands to be added
> later.
> 
> Would something like this be doable, I was looking at the code, and it
> certain looks feasible, but it would take me longer to implement it than
> it would you :-)
> 

If this was all you wanted to do, I think it would be pretty simple to
just pluck off the 'if' and the 'command' from the ends of the filter
string and hook it up to the command callback.

If neither of those were present and you just had a bare filter string,
it would invoke the 'default command' which would do just what it does
now - log it into the trace buffer.

Putting just the 'command' into the filter would also work - it would
always match and unconditionally invoke the command.

The 'if' syntax kind of limits it to a single command per filter though.
If you kept it as an expression e.g.

traceoff(pid == 1234)

or to make it more readable

traceoff_if(pid == 1234)

then you could maybe do things like nesting to fire multiple commands
per hit:

traceoff(logevent((pid == 1234))

That's seems like kind of a stretch, though, and implies chaining.  

Maybe something like:

traceoff,logevent if (pid == 1234)

would be more intuitive (or not).

Anyway, all of these would be pretty easily doable by simply
preprocessing the filter string.  Adding it properly to the parser would
be a little more work, and probably the way to go especially considering
that this wouldn't be the last feature that would be added ;-)

But I think Frederic's idea of decoupling the filters from the triggers
is probably better anyway, and it also allows for different triggers to
be associated with different filters, which the above can't do...

Tom

> Thanks,
> 
> -- Steve
> 
>