2009-09-11 04:13:53

by Tom Zanussi

[permalink] [raw]
Subject: Re: [PATCH v2] tracing/filters: add filter Documentation

Documentation for event filters and formats.

v2 changes: fix a few problems noticed by Randy Dunlap.

Signed-off-by: Tom Zanussi <[email protected]>
Reviewed-by: Li Zefan <[email protected]>

---
Documentation/trace/events.txt | 184 +++++++++++++++++++++++++++++++++++++++-
1 files changed, 183 insertions(+), 1 deletions(-)

diff --git a/Documentation/trace/events.txt b/Documentation/trace/events.txt
index 2bcc8d4..27c62b3 100644
--- a/Documentation/trace/events.txt
+++ b/Documentation/trace/events.txt
@@ -1,7 +1,7 @@
Event Tracing

Documentation written by Theodore Ts'o
- Updated by Li Zefan
+ Updated by Li Zefan and Tom Zanussi

1. Introduction
===============
@@ -97,3 +97,185 @@ The format of this boot option is the same as described in section 2.1.

See The example provided in samples/trace_events

+4. Event formats
+================
+
+Each trace event has a 'format' file associated with it that contains
+a description of each field in a logged event. This information can
+be used to parse the binary trace stream, and is also the place to
+find the field names that can be used in event filters (see section 5).
+
+It also displays the format string that will be used to print the
+event in text mode, along with the event name and ID used for
+profiling.
+
+Every event has a set of 'common' fields associated with it; these are
+the fields prefixed with 'common_'. The other fields vary between
+events and correspond to the fields defined in the TRACE_EVENT
+definition for that event.
+
+Each field in the format has the form:
+
+ field:field-type field-name; offset:N; size:N;
+
+where offset is the offset of the field in the trace record and size
+is the size of the data item, in bytes.
+
+For example, here's the information displayed for the 'sched_wakeup'
+event:
+
+# cat /debug/tracing/events/sched/sched_wakeup/format
+
+name: sched_wakeup
+ID: 60
+format:
+ field:unsigned short common_type; offset:0; size:2;
+ field:unsigned char common_flags; offset:2; size:1;
+ field:unsigned char common_preempt_count; offset:3; size:1;
+ field:int common_pid; offset:4; size:4;
+ field:int common_tgid; offset:8; size:4;
+
+ field:char comm[TASK_COMM_LEN]; offset:12; size:16;
+ field:pid_t pid; offset:28; size:4;
+ field:int prio; offset:32; size:4;
+ field:int success; offset:36; size:4;
+ field:int cpu; offset:40; size:4;
+
+print fmt: "task %s:%d [%d] success=%d [%03d]", REC->comm, REC->pid,
+ REC->prio, REC->success, REC->cpu
+
+This event contains 10 fields, the first 5 common and the remaining 5
+event-specific. All the fields for this event are numeric, except for
+'comm' which is a string, a distinction important for event filtering.
+
+5. Event filtering
+==================
+
+Trace events can be filtered in the kernel by associating boolean
+'filter expressions' with them. As soon as an event is logged into
+the trace buffer, its fields are checked against the filter expression
+associated with that event type. An event with field values that
+'match' the filter will appear in the trace output, and an event whose
+values don't match will be discarded. An event with no filter
+associated with it matches everything, and is the default when no
+filter has been set for an event.
+
+5.1 Expression syntax
+---------------------
+
+A filter expression consists of one or more 'predicates' that can be
+combined using the logical operators '&&' and '||'. A predicate is
+simply a clause that compares the value of a field contained within a
+logged event with a constant value and returns either 0 or 1 depending
+on whether the field value matched (1) or didn't match (0):
+
+ field-name relational-operator value
+
+Parentheses can be used to provide arbitrary logical groupings and
+double-quotes can be used to prevent the shell from interpreting
+operators as shell metacharacters.
+
+The field-names available for use in filters can be found in the
+'format' files for trace events (see section 4).
+
+The relational-operators depend on the type of the field being tested:
+
+The operators available for numeric fields are:
+
+==, !=, <, <=, >, >=
+
+And for string fields they are:
+
+==, !=
+
+Currently, only exact string matches are supported.
+
+Currently, the maximum number of predicates in a filter is 16.
+
+5.2 Setting filters
+-------------------
+
+A filter for an individual event is set by writing a filter expression
+to the 'filter' file for the given event.
+
+For example:
+
+# cd /debug/tracing/events/sched/sched_wakeup
+# echo "common_preempt_count > 4" > filter
+
+A slightly more involved example:
+
+# cd /debug/tracing/events/sched/sched_signal_send
+# echo "((sig >= 10 && sig < 15) || sig == 17) && comm != bash" > filter
+
+If there is an error in the expression, you'll get an 'Invalid
+argument' error when setting it, and the erroneous string along with
+an error message can be seen by looking at the filter e.g.:
+
+# cd /debug/tracing/events/sched/sched_signal_send
+# echo "((sig >= 10 && sig < 15) || dsig == 17) && comm != bash" > filter
+-bash: echo: write error: Invalid argument
+# cat filter
+((sig >= 10 && sig < 15) || dsig == 17) && comm != bash
+^
+parse_error: Field not found
+
+Currently the caret ('^') for an error always appears at the beginning of
+the filter string; the error message should still be useful though
+even without more accurate position info.
+
+5.3 Clearing filters
+--------------------
+
+To clear the filter for an event, write a '0' to the event's filter
+file.
+
+To clear the filters for all events in a subsystem, write a '0' to the
+subsystem's filter file.
+
+5.3 Subsystem filters
+---------------------
+
+For convenience, filters for every event in a subsystem can be set or
+cleared as a group by writing a filter expression into the filter file
+at the root of the subsytem. Note however, that if a filter for any
+event within the subsystem lacks a field specified in the subsystem
+filter, or if the filter can't be applied for any other reason, the
+filter for that event will retain its previous setting. This can
+result in an unintended mixture of filters which could lead to
+confusing (to the user who might think different filters are in
+effect) trace output. Only filters that reference just the common
+fields can be guaranteed to propagate successfully to all events.
+
+Here are a few subsystem filter examples that also illustrate the
+above points:
+
+Clear the filters on all events in the sched subsytem:
+
+# cd /sys/kernel/debug/tracing/events/sched
+# echo 0 > filter
+# cat sched_switch/filter
+none
+# cat sched_wakeup/filter
+none
+
+Set a filter using only common fields for all events in the sched
+subsytem (all events end up with the same filter):
+
+# cd /sys/kernel/debug/tracing/events/sched
+# echo common_pid == 0 > filter
+# cat sched_switch/filter
+common_pid == 0
+# cat sched_wakeup/filter
+common_pid == 0
+
+Attempt to set a filter using a non-common field for all events in the
+sched subsytem (all events but those that have a prev_pid field retain
+their old filters):
+
+# cd /sys/kernel/debug/tracing/events/sched
+# echo prev_pid == 0 > filter
+# cat sched_switch/filter
+prev_pid == 0
+# cat sched_wakeup/filter
+common_pid == 0
--
1.5.6.3



2009-09-11 15:57:55

by Randy Dunlap

[permalink] [raw]
Subject: Re: [PATCH v2] tracing/filters: add filter Documentation

On Thu, 10 Sep 2009 23:13:51 -0500 Tom Zanussi wrote:

> Documentation for event filters and formats.
>
> v2 changes: fix a few problems noticed by Randy Dunlap.
>
> Signed-off-by: Tom Zanussi <[email protected]>
> Reviewed-by: Li Zefan <[email protected]>

Acked-by: Randy Dunlap <[email protected]>

Thanks.


>
> ---
> Documentation/trace/events.txt | 184 +++++++++++++++++++++++++++++++++++++++-
> 1 files changed, 183 insertions(+), 1 deletions(-)
>
> diff --git a/Documentation/trace/events.txt b/Documentation/trace/events.txt
> index 2bcc8d4..27c62b3 100644
> --- a/Documentation/trace/events.txt
> +++ b/Documentation/trace/events.txt
> @@ -1,7 +1,7 @@
> Event Tracing
>
> Documentation written by Theodore Ts'o
> - Updated by Li Zefan
> + Updated by Li Zefan and Tom Zanussi
>
> 1. Introduction
> ===============
> @@ -97,3 +97,185 @@ The format of this boot option is the same as described in section 2.1.
>
> See The example provided in samples/trace_events
>
> +4. Event formats
> +================
> +
> +Each trace event has a 'format' file associated with it that contains
> +a description of each field in a logged event. This information can
> +be used to parse the binary trace stream, and is also the place to
> +find the field names that can be used in event filters (see section 5).
> +
> +It also displays the format string that will be used to print the
> +event in text mode, along with the event name and ID used for
> +profiling.
> +
> +Every event has a set of 'common' fields associated with it; these are
> +the fields prefixed with 'common_'. The other fields vary between
> +events and correspond to the fields defined in the TRACE_EVENT
> +definition for that event.
> +
> +Each field in the format has the form:
> +
> + field:field-type field-name; offset:N; size:N;
> +
> +where offset is the offset of the field in the trace record and size
> +is the size of the data item, in bytes.
> +
> +For example, here's the information displayed for the 'sched_wakeup'
> +event:
> +
> +# cat /debug/tracing/events/sched/sched_wakeup/format
> +
> +name: sched_wakeup
> +ID: 60
> +format:
> + field:unsigned short common_type; offset:0; size:2;
> + field:unsigned char common_flags; offset:2; size:1;
> + field:unsigned char common_preempt_count; offset:3; size:1;
> + field:int common_pid; offset:4; size:4;
> + field:int common_tgid; offset:8; size:4;
> +
> + field:char comm[TASK_COMM_LEN]; offset:12; size:16;
> + field:pid_t pid; offset:28; size:4;
> + field:int prio; offset:32; size:4;
> + field:int success; offset:36; size:4;
> + field:int cpu; offset:40; size:4;
> +
> +print fmt: "task %s:%d [%d] success=%d [%03d]", REC->comm, REC->pid,
> + REC->prio, REC->success, REC->cpu
> +
> +This event contains 10 fields, the first 5 common and the remaining 5
> +event-specific. All the fields for this event are numeric, except for
> +'comm' which is a string, a distinction important for event filtering.
> +
> +5. Event filtering
> +==================
> +
> +Trace events can be filtered in the kernel by associating boolean
> +'filter expressions' with them. As soon as an event is logged into
> +the trace buffer, its fields are checked against the filter expression
> +associated with that event type. An event with field values that
> +'match' the filter will appear in the trace output, and an event whose
> +values don't match will be discarded. An event with no filter
> +associated with it matches everything, and is the default when no
> +filter has been set for an event.
> +
> +5.1 Expression syntax
> +---------------------
> +
> +A filter expression consists of one or more 'predicates' that can be
> +combined using the logical operators '&&' and '||'. A predicate is
> +simply a clause that compares the value of a field contained within a
> +logged event with a constant value and returns either 0 or 1 depending
> +on whether the field value matched (1) or didn't match (0):
> +
> + field-name relational-operator value
> +
> +Parentheses can be used to provide arbitrary logical groupings and
> +double-quotes can be used to prevent the shell from interpreting
> +operators as shell metacharacters.
> +
> +The field-names available for use in filters can be found in the
> +'format' files for trace events (see section 4).
> +
> +The relational-operators depend on the type of the field being tested:
> +
> +The operators available for numeric fields are:
> +
> +==, !=, <, <=, >, >=
> +
> +And for string fields they are:
> +
> +==, !=
> +
> +Currently, only exact string matches are supported.
> +
> +Currently, the maximum number of predicates in a filter is 16.
> +
> +5.2 Setting filters
> +-------------------
> +
> +A filter for an individual event is set by writing a filter expression
> +to the 'filter' file for the given event.
> +
> +For example:
> +
> +# cd /debug/tracing/events/sched/sched_wakeup
> +# echo "common_preempt_count > 4" > filter
> +
> +A slightly more involved example:
> +
> +# cd /debug/tracing/events/sched/sched_signal_send
> +# echo "((sig >= 10 && sig < 15) || sig == 17) && comm != bash" > filter
> +
> +If there is an error in the expression, you'll get an 'Invalid
> +argument' error when setting it, and the erroneous string along with
> +an error message can be seen by looking at the filter e.g.:
> +
> +# cd /debug/tracing/events/sched/sched_signal_send
> +# echo "((sig >= 10 && sig < 15) || dsig == 17) && comm != bash" > filter
> +-bash: echo: write error: Invalid argument
> +# cat filter
> +((sig >= 10 && sig < 15) || dsig == 17) && comm != bash
> +^
> +parse_error: Field not found
> +
> +Currently the caret ('^') for an error always appears at the beginning of
> +the filter string; the error message should still be useful though
> +even without more accurate position info.
> +
> +5.3 Clearing filters
> +--------------------
> +
> +To clear the filter for an event, write a '0' to the event's filter
> +file.
> +
> +To clear the filters for all events in a subsystem, write a '0' to the
> +subsystem's filter file.
> +
> +5.3 Subsystem filters
> +---------------------
> +
> +For convenience, filters for every event in a subsystem can be set or
> +cleared as a group by writing a filter expression into the filter file
> +at the root of the subsytem. Note however, that if a filter for any
> +event within the subsystem lacks a field specified in the subsystem
> +filter, or if the filter can't be applied for any other reason, the
> +filter for that event will retain its previous setting. This can
> +result in an unintended mixture of filters which could lead to
> +confusing (to the user who might think different filters are in
> +effect) trace output. Only filters that reference just the common
> +fields can be guaranteed to propagate successfully to all events.
> +
> +Here are a few subsystem filter examples that also illustrate the
> +above points:
> +
> +Clear the filters on all events in the sched subsytem:
> +
> +# cd /sys/kernel/debug/tracing/events/sched
> +# echo 0 > filter
> +# cat sched_switch/filter
> +none
> +# cat sched_wakeup/filter
> +none
> +
> +Set a filter using only common fields for all events in the sched
> +subsytem (all events end up with the same filter):
> +
> +# cd /sys/kernel/debug/tracing/events/sched
> +# echo common_pid == 0 > filter
> +# cat sched_switch/filter
> +common_pid == 0
> +# cat sched_wakeup/filter
> +common_pid == 0
> +
> +Attempt to set a filter using a non-common field for all events in the
> +sched subsytem (all events but those that have a prev_pid field retain
> +their old filters):
> +
> +# cd /sys/kernel/debug/tracing/events/sched
> +# echo prev_pid == 0 > filter
> +# cat sched_switch/filter
> +prev_pid == 0
> +# cat sched_wakeup/filter
> +common_pid == 0
> --
> 1.5.6.3
>
>
>


---
~Randy
LPC 2009, Sept. 23-25, Portland, Oregon
http://linuxplumbersconf.org/2009/

2009-09-13 15:03:34

by Tom Zanussi

[permalink] [raw]
Subject: [tip:tracing/core] tracing/filters: add filter Documentation

Commit-ID: 95b696088c1cf152c3bb62560bbe3a441922d68b
Gitweb: http://git.kernel.org/tip/95b696088c1cf152c3bb62560bbe3a441922d68b
Author: Tom Zanussi <[email protected]>
AuthorDate: Thu, 10 Sep 2009 23:13:51 -0500
Committer: Steven Rostedt <[email protected]>
CommitDate: Sat, 12 Sep 2009 22:33:12 -0400

tracing/filters: add filter Documentation

Documentation for event filters and formats.

v2 changes: fix a few problems noticed by Randy Dunlap.

Reviewed-by: Li Zefan <[email protected]>
Acked-by: Randy Dunlap <[email protected]>
Signed-off-by: Tom Zanussi <[email protected]>
LKML-Reference: <1252642431.8016.9.camel@tropicana>
Signed-off-by: Steven Rostedt <[email protected]>


---
Documentation/trace/events.txt | 184 +++++++++++++++++++++++++++++++++++++++-
1 files changed, 183 insertions(+), 1 deletions(-)

diff --git a/Documentation/trace/events.txt b/Documentation/trace/events.txt
index 2bcc8d4..6e5f35e 100644
--- a/Documentation/trace/events.txt
+++ b/Documentation/trace/events.txt
@@ -1,7 +1,7 @@
Event Tracing

Documentation written by Theodore Ts'o
- Updated by Li Zefan
+ Updated by Li Zefan and Tom Zanussi

1. Introduction
===============
@@ -97,3 +97,185 @@ The format of this boot option is the same as described in section 2.1.

See The example provided in samples/trace_events

+4. Event formats
+================
+
+Each trace event has a 'format' file associated with it that contains
+a description of each field in a logged event. This information can
+be used to parse the binary trace stream, and is also the place to
+find the field names that can be used in event filters (see section 5).
+
+It also displays the format string that will be used to print the
+event in text mode, along with the event name and ID used for
+profiling.
+
+Every event has a set of 'common' fields associated with it; these are
+the fields prefixed with 'common_'. The other fields vary between
+events and correspond to the fields defined in the TRACE_EVENT
+definition for that event.
+
+Each field in the format has the form:
+
+ field:field-type field-name; offset:N; size:N;
+
+where offset is the offset of the field in the trace record and size
+is the size of the data item, in bytes.
+
+For example, here's the information displayed for the 'sched_wakeup'
+event:
+
+# cat /debug/tracing/events/sched/sched_wakeup/format
+
+name: sched_wakeup
+ID: 60
+format:
+ field:unsigned short common_type; offset:0; size:2;
+ field:unsigned char common_flags; offset:2; size:1;
+ field:unsigned char common_preempt_count; offset:3; size:1;
+ field:int common_pid; offset:4; size:4;
+ field:int common_tgid; offset:8; size:4;
+
+ field:char comm[TASK_COMM_LEN]; offset:12; size:16;
+ field:pid_t pid; offset:28; size:4;
+ field:int prio; offset:32; size:4;
+ field:int success; offset:36; size:4;
+ field:int cpu; offset:40; size:4;
+
+print fmt: "task %s:%d [%d] success=%d [%03d]", REC->comm, REC->pid,
+ REC->prio, REC->success, REC->cpu
+
+This event contains 10 fields, the first 5 common and the remaining 5
+event-specific. All the fields for this event are numeric, except for
+'comm' which is a string, a distinction important for event filtering.
+
+5. Event filtering
+==================
+
+Trace events can be filtered in the kernel by associating boolean
+'filter expressions' with them. As soon as an event is logged into
+the trace buffer, its fields are checked against the filter expression
+associated with that event type. An event with field values that
+'match' the filter will appear in the trace output, and an event whose
+values don't match will be discarded. An event with no filter
+associated with it matches everything, and is the default when no
+filter has been set for an event.
+
+5.1 Expression syntax
+---------------------
+
+A filter expression consists of one or more 'predicates' that can be
+combined using the logical operators '&&' and '||'. A predicate is
+simply a clause that compares the value of a field contained within a
+logged event with a constant value and returns either 0 or 1 depending
+on whether the field value matched (1) or didn't match (0):
+
+ field-name relational-operator value
+
+Parentheses can be used to provide arbitrary logical groupings and
+double-quotes can be used to prevent the shell from interpreting
+operators as shell metacharacters.
+
+The field-names available for use in filters can be found in the
+'format' files for trace events (see section 4).
+
+The relational-operators depend on the type of the field being tested:
+
+The operators available for numeric fields are:
+
+==, !=, <, <=, >, >=
+
+And for string fields they are:
+
+==, !=
+
+Currently, only exact string matches are supported.
+
+Currently, the maximum number of predicates in a filter is 16.
+
+5.2 Setting filters
+-------------------
+
+A filter for an individual event is set by writing a filter expression
+to the 'filter' file for the given event.
+
+For example:
+
+# cd /debug/tracing/events/sched/sched_wakeup
+# echo "common_preempt_count > 4" > filter
+
+A slightly more involved example:
+
+# cd /debug/tracing/events/sched/sched_signal_send
+# echo "((sig >= 10 && sig < 15) || sig == 17) && comm != bash" > filter
+
+If there is an error in the expression, you'll get an 'Invalid
+argument' error when setting it, and the erroneous string along with
+an error message can be seen by looking at the filter e.g.:
+
+# cd /debug/tracing/events/sched/sched_signal_send
+# echo "((sig >= 10 && sig < 15) || dsig == 17) && comm != bash" > filter
+-bash: echo: write error: Invalid argument
+# cat filter
+((sig >= 10 && sig < 15) || dsig == 17) && comm != bash
+^
+parse_error: Field not found
+
+Currently the caret ('^') for an error always appears at the beginning of
+the filter string; the error message should still be useful though
+even without more accurate position info.
+
+5.3 Clearing filters
+--------------------
+
+To clear the filter for an event, write a '0' to the event's filter
+file.
+
+To clear the filters for all events in a subsystem, write a '0' to the
+subsystem's filter file.
+
+5.3 Subsystem filters
+---------------------
+
+For convenience, filters for every event in a subsystem can be set or
+cleared as a group by writing a filter expression into the filter file
+at the root of the subsytem. Note however, that if a filter for any
+event within the subsystem lacks a field specified in the subsystem
+filter, or if the filter can't be applied for any other reason, the
+filter for that event will retain its previous setting. This can
+result in an unintended mixture of filters which could lead to
+confusing (to the user who might think different filters are in
+effect) trace output. Only filters that reference just the common
+fields can be guaranteed to propagate successfully to all events.
+
+Here are a few subsystem filter examples that also illustrate the
+above points:
+
+Clear the filters on all events in the sched subsytem:
+
+# cd /sys/kernel/debug/tracing/events/sched
+# echo 0 > filter
+# cat sched_switch/filter
+none
+# cat sched_wakeup/filter
+none
+
+Set a filter using only common fields for all events in the sched
+subsytem (all events end up with the same filter):
+
+# cd /sys/kernel/debug/tracing/events/sched
+# echo common_pid == 0 > filter
+# cat sched_switch/filter
+common_pid == 0
+# cat sched_wakeup/filter
+common_pid == 0
+
+Attempt to set a filter using a non-common field for all events in the
+sched subsytem (all events but those that have a prev_pid field retain
+their old filters):
+
+# cd /sys/kernel/debug/tracing/events/sched
+# echo prev_pid == 0 > filter
+# cat sched_switch/filter
+prev_pid == 0
+# cat sched_wakeup/filter
+common_pid == 0