Documentation/trace/events.txt

   1                              Event Tracing
   2
   3                 Documentation written by Theodore Ts'o
   4                 Updated by Li Zefan and Tom Zanussi
   5
   6 1. Introduction
   7 ===============
   8
   9 Tracepoints (see Documentation/trace/tracepoints.txt) can be used
  10 without creating custom kernel modules to register probe functions
  11 using the event tracing infrastructure.
  12
  13 Not all tracepoints can be traced using the event tracing system;
  14 the kernel developer must provide code snippets which define how the
  15 tracing information is saved into the tracing buffer, and how the
  16 tracing information should be printed.
  17
  18 2. Using Event Tracing
  19 ======================
  20
  21 2.1 Via the 'set_event' interface
  22 ---------------------------------
  23
  24 The events which are available for tracing can be found in the file
  25 /sys/kernel/debug/tracing/available_events.
  26
  27 To enable a particular event, such as 'sched_wakeup', simply echo it
  28 to /sys/kernel/debug/tracing/set_event. For example:
  29
  30         # echo sched_wakeup >> /sys/kernel/debug/tracing/set_event
  31
  32 [ Note: '>>' is necessary, otherwise it will firstly disable
  33   all the events. ]
  34
  35 To disable an event, echo the event name to the set_event file prefixed
  36 with an exclamation point:
  37
  38         # echo '!sched_wakeup' >> /sys/kernel/debug/tracing/set_event
  39
  40 To disable all events, echo an empty line to the set_event file:
  41
  42         # echo > /sys/kernel/debug/tracing/set_event
  43
  44 To enable all events, echo '*:*' or '*:' to the set_event file:
  45
  46         # echo *:* > /sys/kernel/debug/tracing/set_event
  47
  48 The events are organized into subsystems, such as ext4, irq, sched,
  49 etc., and a full event name looks like this: <subsystem>:<event>.  The
  50 subsystem name is optional, but it is displayed in the available_events
  51 file.  All of the events in a subsystem can be specified via the syntax
  52 "<subsystem>:*"; for example, to enable all irq events, you can use the
  53 command:
  54
  55         # echo 'irq:*' > /sys/kernel/debug/tracing/set_event
  56
  57 2.2 Via the 'enable' toggle
  58 ---------------------------
  59
  60 The events available are also listed in /sys/kernel/debug/tracing/events/ hierarchy
  61 of directories.
  62
  63 To enable event 'sched_wakeup':
  64
  65         # echo 1 > /sys/kernel/debug/tracing/events/sched/sched_wakeup/enable
  66
  67 To disable it:
  68
  69         # echo 0 > /sys/kernel/debug/tracing/events/sched/sched_wakeup/enable
  70
  71 To enable all events in sched subsystem:
  72
  73         # echo 1 > /sys/kernel/debug/tracing/events/sched/enable
  74
  75 To enable all events:
  76
  77         # echo 1 > /sys/kernel/debug/tracing/events/enable
  78
  79 When reading one of these enable files, there are four results:
  80
  81  0 - all events this file affects are disabled
  82  1 - all events this file affects are enabled
  83  X - there is a mixture of events enabled and disabled
  84  ? - this file does not affect any event
  85
  86 2.3 Boot option
  87 ---------------
  88
  89 In order to facilitate early boot debugging, use boot option:
  90
  91         trace_event=[event-list]
  92
  93 The format of this boot option is the same as described in section 2.1.
  94
  95 3. Defining an event-enabled tracepoint
  96 =======================================
  97
  98 See The example provided in samples/trace_events
  99
 100 4. Event formats
 101 ================
 102
 103 Each trace event has a 'format' file associated with it that contains
 104 a description of each field in a logged event.  This information can
 105 be used to parse the binary trace stream, and is also the place to
 106 find the field names that can be used in event filters (see section 5).
 107
 108 It also displays the format string that will be used to print the
 109 event in text mode, along with the event name and ID used for
 110 profiling.
 111
 112 Every event has a set of 'common' fields associated with it; these are
 113 the fields prefixed with 'common_'.  The other fields vary between
 114 events and correspond to the fields defined in the TRACE_EVENT
 115 definition for that event.
 116
 117 Each field in the format has the form:
 118
 119      field:field-type field-name; offset:N; size:N;
 120
 121 where offset is the offset of the field in the trace record and size
 122 is the size of the data item, in bytes.
 123
 124 For example, here's the information displayed for the 'sched_wakeup'
 125 event:
 126
 127 # cat /debug/tracing/events/sched/sched_wakeup/format
 128
 129 name: sched_wakeup
 130 ID: 60
 131 format:
 132         field:unsigned short common_type;       offset:0;       size:2;
 133         field:unsigned char common_flags;       offset:2;       size:1;
 134         field:unsigned char common_preempt_count;       offset:3;       size:1;
 135         field:int common_pid;   offset:4;       size:4;
 136         field:int common_tgid;  offset:8;       size:4;
 137
 138         field:char comm[TASK_COMM_LEN]; offset:12;      size:16;
 139         field:pid_t pid;        offset:28;      size:4;
 140         field:int prio; offset:32;      size:4;
 141         field:int success;      offset:36;      size:4;
 142         field:int cpu;  offset:40;      size:4;
 143
 144 print fmt: "task %s:%d [%d] success=%d [%03d]", REC->comm, REC->pid,
 145            REC->prio, REC->success, REC->cpu
 146
 147 This event contains 10 fields, the first 5 common and the remaining 5
 148 event-specific.  All the fields for this event are numeric, except for
 149 'comm' which is a string, a distinction important for event filtering.
 150
 151 5. Event filtering
 152 ==================
 153
 154 Trace events can be filtered in the kernel by associating boolean
 155 'filter expressions' with them.  As soon as an event is logged into
 156 the trace buffer, its fields are checked against the filter expression
 157 associated with that event type.  An event with field values that
 158 'match' the filter will appear in the trace output, and an event whose
 159 values don't match will be discarded.  An event with no filter
 160 associated with it matches everything, and is the default when no
 161 filter has been set for an event.
 162
 163 5.1 Expression syntax
 164 ---------------------
 165
 166 A filter expression consists of one or more 'predicates' that can be
 167 combined using the logical operators '&&' and '||'.  A predicate is
 168 simply a clause that compares the value of a field contained within a
 169 logged event with a constant value and returns either 0 or 1 depending
 170 on whether the field value matched (1) or didn't match (0):
 171
 172           field-name relational-operator value
 173
 174 Parentheses can be used to provide arbitrary logical groupings and
 175 double-quotes can be used to prevent the shell from interpreting
 176 operators as shell metacharacters.
 177
 178 The field-names available for use in filters can be found in the
 179 'format' files for trace events (see section 4).
 180
 181 The relational-operators depend on the type of the field being tested:
 182
 183 The operators available for numeric fields are:
 184
 185 ==, !=, <, <=, >, >=
 186
 187 And for string fields they are:
 188
 189 ==, !=
 190
 191 Currently, only exact string matches are supported.
 192
 193 Currently, the maximum number of predicates in a filter is 16.
 194
 195 5.2 Setting filters
 196 -------------------
 197
 198 A filter for an individual event is set by writing a filter expression
 199 to the 'filter' file for the given event.
 200
 201 For example:
 202
 203 # cd /debug/tracing/events/sched/sched_wakeup
 204 # echo "common_preempt_count > 4" > filter
 205
 206 A slightly more involved example:
 207
 208 # cd /debug/tracing/events/sched/sched_signal_send
 209 # echo "((sig >= 10 && sig < 15) || sig == 17) && comm != bash" > filter
 210
 211 If there is an error in the expression, you'll get an 'Invalid
 212 argument' error when setting it, and the erroneous string along with
 213 an error message can be seen by looking at the filter e.g.:
 214
 215 # cd /debug/tracing/events/sched/sched_signal_send
 216 # echo "((sig >= 10 && sig < 15) || dsig == 17) && comm != bash" > filter
 217 -bash: echo: write error: Invalid argument
 218 # cat filter
 219 ((sig >= 10 && sig < 15) || dsig == 17) && comm != bash
 220 ^
 221 parse_error: Field not found
 222
 223 Currently the caret ('^') for an error always appears at the beginning of
 224 the filter string; the error message should still be useful though
 225 even without more accurate position info.
 226
 227 5.3 Clearing filters
 228 --------------------
 229
 230 To clear the filter for an event, write a '0' to the event's filter
 231 file.
 232
 233 To clear the filters for all events in a subsystem, write a '0' to the
 234 subsystem's filter file.
 235
 236 5.3 Subsystem filters
 237 ---------------------
 238
 239 For convenience, filters for every event in a subsystem can be set or
 240 cleared as a group by writing a filter expression into the filter file
 241 at the root of the subsytem.  Note however, that if a filter for any
 242 event within the subsystem lacks a field specified in the subsystem
 243 filter, or if the filter can't be applied for any other reason, the
 244 filter for that event will retain its previous setting.  This can
 245 result in an unintended mixture of filters which could lead to
 246 confusing (to the user who might think different filters are in
 247 effect) trace output.  Only filters that reference just the common
 248 fields can be guaranteed to propagate successfully to all events.
 249
 250 Here are a few subsystem filter examples that also illustrate the
 251 above points:
 252
 253 Clear the filters on all events in the sched subsytem:
 254
 255 # cd /sys/kernel/debug/tracing/events/sched
 256 # echo 0 > filter
 257 # cat sched_switch/filter
 258 none
 259 # cat sched_wakeup/filter
 260 none
 261
 262 Set a filter using only common fields for all events in the sched
 263 subsytem (all events end up with the same filter):
 264
 265 # cd /sys/kernel/debug/tracing/events/sched
 266 # echo common_pid == 0 > filter
 267 # cat sched_switch/filter
 268 common_pid == 0
 269 # cat sched_wakeup/filter
 270 common_pid == 0
 271
 272 Attempt to set a filter using a non-common field for all events in the
 273 sched subsytem (all events but those that have a prev_pid field retain
 274 their old filters):
 275
 276 # cd /sys/kernel/debug/tracing/events/sched
 277 # echo prev_pid == 0 > filter
 278 # cat sched_switch/filter
 279 prev_pid == 0
 280 # cat sched_wakeup/filter
 281 common_pid == 0