Back to home page

OSCL-LXR

 
 

    


0001 =============
0002 Event Tracing
0003 =============
0004 
0005 :Author: Theodore Ts'o
0006 :Updated: Li Zefan and Tom Zanussi
0007 
0008 1. Introduction
0009 ===============
0010 
0011 Tracepoints (see Documentation/trace/tracepoints.rst) can be used
0012 without creating custom kernel modules to register probe functions
0013 using the event tracing infrastructure.
0014 
0015 Not all tracepoints can be traced using the event tracing system;
0016 the kernel developer must provide code snippets which define how the
0017 tracing information is saved into the tracing buffer, and how the
0018 tracing information should be printed.
0019 
0020 2. Using Event Tracing
0021 ======================
0022 
0023 2.1 Via the 'set_event' interface
0024 ---------------------------------
0025 
0026 The events which are available for tracing can be found in the file
0027 /sys/kernel/debug/tracing/available_events.
0028 
0029 To enable a particular event, such as 'sched_wakeup', simply echo it
0030 to /sys/kernel/debug/tracing/set_event. For example::
0031 
0032         # echo sched_wakeup >> /sys/kernel/debug/tracing/set_event
0033 
0034 .. Note:: '>>' is necessary, otherwise it will firstly disable all the events.
0035 
0036 To disable an event, echo the event name to the set_event file prefixed
0037 with an exclamation point::
0038 
0039         # echo '!sched_wakeup' >> /sys/kernel/debug/tracing/set_event
0040 
0041 To disable all events, echo an empty line to the set_event file::
0042 
0043         # echo > /sys/kernel/debug/tracing/set_event
0044 
0045 To enable all events, echo ``*:*`` or ``*:`` to the set_event file::
0046 
0047         # echo *:* > /sys/kernel/debug/tracing/set_event
0048 
0049 The events are organized into subsystems, such as ext4, irq, sched,
0050 etc., and a full event name looks like this: <subsystem>:<event>.  The
0051 subsystem name is optional, but it is displayed in the available_events
0052 file.  All of the events in a subsystem can be specified via the syntax
0053 ``<subsystem>:*``; for example, to enable all irq events, you can use the
0054 command::
0055 
0056         # echo 'irq:*' > /sys/kernel/debug/tracing/set_event
0057 
0058 2.2 Via the 'enable' toggle
0059 ---------------------------
0060 
0061 The events available are also listed in /sys/kernel/debug/tracing/events/ hierarchy
0062 of directories.
0063 
0064 To enable event 'sched_wakeup'::
0065 
0066         # echo 1 > /sys/kernel/debug/tracing/events/sched/sched_wakeup/enable
0067 
0068 To disable it::
0069 
0070         # echo 0 > /sys/kernel/debug/tracing/events/sched/sched_wakeup/enable
0071 
0072 To enable all events in sched subsystem::
0073 
0074         # echo 1 > /sys/kernel/debug/tracing/events/sched/enable
0075 
0076 To enable all events::
0077 
0078         # echo 1 > /sys/kernel/debug/tracing/events/enable
0079 
0080 When reading one of these enable files, there are four results:
0081 
0082  - 0 - all events this file affects are disabled
0083  - 1 - all events this file affects are enabled
0084  - X - there is a mixture of events enabled and disabled
0085  - ? - this file does not affect any event
0086 
0087 2.3 Boot option
0088 ---------------
0089 
0090 In order to facilitate early boot debugging, use boot option::
0091 
0092         trace_event=[event-list]
0093 
0094 event-list is a comma separated list of events. See section 2.1 for event
0095 format.
0096 
0097 3. Defining an event-enabled tracepoint
0098 =======================================
0099 
0100 See The example provided in samples/trace_events
0101 
0102 4. Event formats
0103 ================
0104 
0105 Each trace event has a 'format' file associated with it that contains
0106 a description of each field in a logged event.  This information can
0107 be used to parse the binary trace stream, and is also the place to
0108 find the field names that can be used in event filters (see section 5).
0109 
0110 It also displays the format string that will be used to print the
0111 event in text mode, along with the event name and ID used for
0112 profiling.
0113 
0114 Every event has a set of ``common`` fields associated with it; these are
0115 the fields prefixed with ``common_``.  The other fields vary between
0116 events and correspond to the fields defined in the TRACE_EVENT
0117 definition for that event.
0118 
0119 Each field in the format has the form::
0120 
0121      field:field-type field-name; offset:N; size:N;
0122 
0123 where offset is the offset of the field in the trace record and size
0124 is the size of the data item, in bytes.
0125 
0126 For example, here's the information displayed for the 'sched_wakeup'
0127 event::
0128 
0129         # cat /sys/kernel/debug/tracing/events/sched/sched_wakeup/format
0130 
0131         name: sched_wakeup
0132         ID: 60
0133         format:
0134                 field:unsigned short common_type;       offset:0;       size:2;
0135                 field:unsigned char common_flags;       offset:2;       size:1;
0136                 field:unsigned char common_preempt_count;       offset:3;       size:1;
0137                 field:int common_pid;   offset:4;       size:4;
0138                 field:int common_tgid;  offset:8;       size:4;
0139 
0140                 field:char comm[TASK_COMM_LEN]; offset:12;      size:16;
0141                 field:pid_t pid;        offset:28;      size:4;
0142                 field:int prio; offset:32;      size:4;
0143                 field:int success;      offset:36;      size:4;
0144                 field:int cpu;  offset:40;      size:4;
0145 
0146         print fmt: "task %s:%d [%d] success=%d [%03d]", REC->comm, REC->pid,
0147                    REC->prio, REC->success, REC->cpu
0148 
0149 This event contains 10 fields, the first 5 common and the remaining 5
0150 event-specific.  All the fields for this event are numeric, except for
0151 'comm' which is a string, a distinction important for event filtering.
0152 
0153 5. Event filtering
0154 ==================
0155 
0156 Trace events can be filtered in the kernel by associating boolean
0157 'filter expressions' with them.  As soon as an event is logged into
0158 the trace buffer, its fields are checked against the filter expression
0159 associated with that event type.  An event with field values that
0160 'match' the filter will appear in the trace output, and an event whose
0161 values don't match will be discarded.  An event with no filter
0162 associated with it matches everything, and is the default when no
0163 filter has been set for an event.
0164 
0165 5.1 Expression syntax
0166 ---------------------
0167 
0168 A filter expression consists of one or more 'predicates' that can be
0169 combined using the logical operators '&&' and '||'.  A predicate is
0170 simply a clause that compares the value of a field contained within a
0171 logged event with a constant value and returns either 0 or 1 depending
0172 on whether the field value matched (1) or didn't match (0)::
0173 
0174           field-name relational-operator value
0175 
0176 Parentheses can be used to provide arbitrary logical groupings and
0177 double-quotes can be used to prevent the shell from interpreting
0178 operators as shell metacharacters.
0179 
0180 The field-names available for use in filters can be found in the
0181 'format' files for trace events (see section 4).
0182 
0183 The relational-operators depend on the type of the field being tested:
0184 
0185 The operators available for numeric fields are:
0186 
0187 ==, !=, <, <=, >, >=, &
0188 
0189 And for string fields they are:
0190 
0191 ==, !=, ~
0192 
0193 The glob (~) accepts a wild card character (\*,?) and character classes
0194 ([). For example::
0195 
0196   prev_comm ~ "*sh"
0197   prev_comm ~ "sh*"
0198   prev_comm ~ "*sh*"
0199   prev_comm ~ "ba*sh"
0200 
0201 If the field is a pointer that points into user space (for example
0202 "filename" from sys_enter_openat), then you have to append ".ustring" to the
0203 field name::
0204 
0205   filename.ustring ~ "password"
0206 
0207 As the kernel will have to know how to retrieve the memory that the pointer
0208 is at from user space.
0209 
0210 5.2 Setting filters
0211 -------------------
0212 
0213 A filter for an individual event is set by writing a filter expression
0214 to the 'filter' file for the given event.
0215 
0216 For example::
0217 
0218         # cd /sys/kernel/debug/tracing/events/sched/sched_wakeup
0219         # echo "common_preempt_count > 4" > filter
0220 
0221 A slightly more involved example::
0222 
0223         # cd /sys/kernel/debug/tracing/events/signal/signal_generate
0224         # echo "((sig >= 10 && sig < 15) || sig == 17) && comm != bash" > filter
0225 
0226 If there is an error in the expression, you'll get an 'Invalid
0227 argument' error when setting it, and the erroneous string along with
0228 an error message can be seen by looking at the filter e.g.::
0229 
0230         # cd /sys/kernel/debug/tracing/events/signal/signal_generate
0231         # echo "((sig >= 10 && sig < 15) || dsig == 17) && comm != bash" > filter
0232         -bash: echo: write error: Invalid argument
0233         # cat filter
0234         ((sig >= 10 && sig < 15) || dsig == 17) && comm != bash
0235         ^
0236         parse_error: Field not found
0237 
0238 Currently the caret ('^') for an error always appears at the beginning of
0239 the filter string; the error message should still be useful though
0240 even without more accurate position info.
0241 
0242 5.2.1 Filter limitations
0243 ------------------------
0244 
0245 If a filter is placed on a string pointer ``(char *)`` that does not point
0246 to a string on the ring buffer, but instead points to kernel or user space
0247 memory, then, for safety reasons, at most 1024 bytes of the content is
0248 copied onto a temporary buffer to do the compare. If the copy of the memory
0249 faults (the pointer points to memory that should not be accessed), then the
0250 string compare will be treated as not matching.
0251 
0252 5.3 Clearing filters
0253 --------------------
0254 
0255 To clear the filter for an event, write a '0' to the event's filter
0256 file.
0257 
0258 To clear the filters for all events in a subsystem, write a '0' to the
0259 subsystem's filter file.
0260 
0261 5.3 Subsystem filters
0262 ---------------------
0263 
0264 For convenience, filters for every event in a subsystem can be set or
0265 cleared as a group by writing a filter expression into the filter file
0266 at the root of the subsystem.  Note however, that if a filter for any
0267 event within the subsystem lacks a field specified in the subsystem
0268 filter, or if the filter can't be applied for any other reason, the
0269 filter for that event will retain its previous setting.  This can
0270 result in an unintended mixture of filters which could lead to
0271 confusing (to the user who might think different filters are in
0272 effect) trace output.  Only filters that reference just the common
0273 fields can be guaranteed to propagate successfully to all events.
0274 
0275 Here are a few subsystem filter examples that also illustrate the
0276 above points:
0277 
0278 Clear the filters on all events in the sched subsystem::
0279 
0280         # cd /sys/kernel/debug/tracing/events/sched
0281         # echo 0 > filter
0282         # cat sched_switch/filter
0283         none
0284         # cat sched_wakeup/filter
0285         none
0286 
0287 Set a filter using only common fields for all events in the sched
0288 subsystem (all events end up with the same filter)::
0289 
0290         # cd /sys/kernel/debug/tracing/events/sched
0291         # echo common_pid == 0 > filter
0292         # cat sched_switch/filter
0293         common_pid == 0
0294         # cat sched_wakeup/filter
0295         common_pid == 0
0296 
0297 Attempt to set a filter using a non-common field for all events in the
0298 sched subsystem (all events but those that have a prev_pid field retain
0299 their old filters)::
0300 
0301         # cd /sys/kernel/debug/tracing/events/sched
0302         # echo prev_pid == 0 > filter
0303         # cat sched_switch/filter
0304         prev_pid == 0
0305         # cat sched_wakeup/filter
0306         common_pid == 0
0307 
0308 5.4 PID filtering
0309 -----------------
0310 
0311 The set_event_pid file in the same directory as the top events directory
0312 exists, will filter all events from tracing any task that does not have the
0313 PID listed in the set_event_pid file.
0314 ::
0315 
0316         # cd /sys/kernel/debug/tracing
0317         # echo $$ > set_event_pid
0318         # echo 1 > events/enable
0319 
0320 Will only trace events for the current task.
0321 
0322 To add more PIDs without losing the PIDs already included, use '>>'.
0323 ::
0324 
0325         # echo 123 244 1 >> set_event_pid
0326 
0327 
0328 6. Event triggers
0329 =================
0330 
0331 Trace events can be made to conditionally invoke trigger 'commands'
0332 which can take various forms and are described in detail below;
0333 examples would be enabling or disabling other trace events or invoking
0334 a stack trace whenever the trace event is hit.  Whenever a trace event
0335 with attached triggers is invoked, the set of trigger commands
0336 associated with that event is invoked.  Any given trigger can
0337 additionally have an event filter of the same form as described in
0338 section 5 (Event filtering) associated with it - the command will only
0339 be invoked if the event being invoked passes the associated filter.
0340 If no filter is associated with the trigger, it always passes.
0341 
0342 Triggers are added to and removed from a particular event by writing
0343 trigger expressions to the 'trigger' file for the given event.
0344 
0345 A given event can have any number of triggers associated with it,
0346 subject to any restrictions that individual commands may have in that
0347 regard.
0348 
0349 Event triggers are implemented on top of "soft" mode, which means that
0350 whenever a trace event has one or more triggers associated with it,
0351 the event is activated even if it isn't actually enabled, but is
0352 disabled in a "soft" mode.  That is, the tracepoint will be called,
0353 but just will not be traced, unless of course it's actually enabled.
0354 This scheme allows triggers to be invoked even for events that aren't
0355 enabled, and also allows the current event filter implementation to be
0356 used for conditionally invoking triggers.
0357 
0358 The syntax for event triggers is roughly based on the syntax for
0359 set_ftrace_filter 'ftrace filter commands' (see the 'Filter commands'
0360 section of Documentation/trace/ftrace.rst), but there are major
0361 differences and the implementation isn't currently tied to it in any
0362 way, so beware about making generalizations between the two.
0363 
0364 .. Note::
0365      Writing into trace_marker (See Documentation/trace/ftrace.rst)
0366      can also enable triggers that are written into
0367      /sys/kernel/tracing/events/ftrace/print/trigger
0368 
0369 6.1 Expression syntax
0370 ---------------------
0371 
0372 Triggers are added by echoing the command to the 'trigger' file::
0373 
0374   # echo 'command[:count] [if filter]' > trigger
0375 
0376 Triggers are removed by echoing the same command but starting with '!'
0377 to the 'trigger' file::
0378 
0379   # echo '!command[:count] [if filter]' > trigger
0380 
0381 The [if filter] part isn't used in matching commands when removing, so
0382 leaving that off in a '!' command will accomplish the same thing as
0383 having it in.
0384 
0385 The filter syntax is the same as that described in the 'Event
0386 filtering' section above.
0387 
0388 For ease of use, writing to the trigger file using '>' currently just
0389 adds or removes a single trigger and there's no explicit '>>' support
0390 ('>' actually behaves like '>>') or truncation support to remove all
0391 triggers (you have to use '!' for each one added.)
0392 
0393 6.2 Supported trigger commands
0394 ------------------------------
0395 
0396 The following commands are supported:
0397 
0398 - enable_event/disable_event
0399 
0400   These commands can enable or disable another trace event whenever
0401   the triggering event is hit.  When these commands are registered,
0402   the other trace event is activated, but disabled in a "soft" mode.
0403   That is, the tracepoint will be called, but just will not be traced.
0404   The event tracepoint stays in this mode as long as there's a trigger
0405   in effect that can trigger it.
0406 
0407   For example, the following trigger causes kmalloc events to be
0408   traced when a read system call is entered, and the :1 at the end
0409   specifies that this enablement happens only once::
0410 
0411           # echo 'enable_event:kmem:kmalloc:1' > \
0412               /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/trigger
0413 
0414   The following trigger causes kmalloc events to stop being traced
0415   when a read system call exits.  This disablement happens on every
0416   read system call exit::
0417 
0418           # echo 'disable_event:kmem:kmalloc' > \
0419               /sys/kernel/debug/tracing/events/syscalls/sys_exit_read/trigger
0420 
0421   The format is::
0422 
0423       enable_event:<system>:<event>[:count]
0424       disable_event:<system>:<event>[:count]
0425 
0426   To remove the above commands::
0427 
0428           # echo '!enable_event:kmem:kmalloc:1' > \
0429               /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/trigger
0430 
0431           # echo '!disable_event:kmem:kmalloc' > \
0432               /sys/kernel/debug/tracing/events/syscalls/sys_exit_read/trigger
0433 
0434   Note that there can be any number of enable/disable_event triggers
0435   per triggering event, but there can only be one trigger per
0436   triggered event. e.g. sys_enter_read can have triggers enabling both
0437   kmem:kmalloc and sched:sched_switch, but can't have two kmem:kmalloc
0438   versions such as kmem:kmalloc and kmem:kmalloc:1 or 'kmem:kmalloc if
0439   bytes_req == 256' and 'kmem:kmalloc if bytes_alloc == 256' (they
0440   could be combined into a single filter on kmem:kmalloc though).
0441 
0442 - stacktrace
0443 
0444   This command dumps a stacktrace in the trace buffer whenever the
0445   triggering event occurs.
0446 
0447   For example, the following trigger dumps a stacktrace every time the
0448   kmalloc tracepoint is hit::
0449 
0450           # echo 'stacktrace' > \
0451                 /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
0452 
0453   The following trigger dumps a stacktrace the first 5 times a kmalloc
0454   request happens with a size >= 64K::
0455 
0456           # echo 'stacktrace:5 if bytes_req >= 65536' > \
0457                 /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
0458 
0459   The format is::
0460 
0461       stacktrace[:count]
0462 
0463   To remove the above commands::
0464 
0465           # echo '!stacktrace' > \
0466                 /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
0467 
0468           # echo '!stacktrace:5 if bytes_req >= 65536' > \
0469                 /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
0470 
0471   The latter can also be removed more simply by the following (without
0472   the filter)::
0473 
0474           # echo '!stacktrace:5' > \
0475                 /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
0476 
0477   Note that there can be only one stacktrace trigger per triggering
0478   event.
0479 
0480 - snapshot
0481 
0482   This command causes a snapshot to be triggered whenever the
0483   triggering event occurs.
0484 
0485   The following command creates a snapshot every time a block request
0486   queue is unplugged with a depth > 1.  If you were tracing a set of
0487   events or functions at the time, the snapshot trace buffer would
0488   capture those events when the trigger event occurred::
0489 
0490           # echo 'snapshot if nr_rq > 1' > \
0491                 /sys/kernel/debug/tracing/events/block/block_unplug/trigger
0492 
0493   To only snapshot once::
0494 
0495           # echo 'snapshot:1 if nr_rq > 1' > \
0496                 /sys/kernel/debug/tracing/events/block/block_unplug/trigger
0497 
0498   To remove the above commands::
0499 
0500           # echo '!snapshot if nr_rq > 1' > \
0501                 /sys/kernel/debug/tracing/events/block/block_unplug/trigger
0502 
0503           # echo '!snapshot:1 if nr_rq > 1' > \
0504                 /sys/kernel/debug/tracing/events/block/block_unplug/trigger
0505 
0506   Note that there can be only one snapshot trigger per triggering
0507   event.
0508 
0509 - traceon/traceoff
0510 
0511   These commands turn tracing on and off when the specified events are
0512   hit. The parameter determines how many times the tracing system is
0513   turned on and off. If unspecified, there is no limit.
0514 
0515   The following command turns tracing off the first time a block
0516   request queue is unplugged with a depth > 1.  If you were tracing a
0517   set of events or functions at the time, you could then examine the
0518   trace buffer to see the sequence of events that led up to the
0519   trigger event::
0520 
0521           # echo 'traceoff:1 if nr_rq > 1' > \
0522                 /sys/kernel/debug/tracing/events/block/block_unplug/trigger
0523 
0524   To always disable tracing when nr_rq  > 1::
0525 
0526           # echo 'traceoff if nr_rq > 1' > \
0527                 /sys/kernel/debug/tracing/events/block/block_unplug/trigger
0528 
0529   To remove the above commands::
0530 
0531           # echo '!traceoff:1 if nr_rq > 1' > \
0532                 /sys/kernel/debug/tracing/events/block/block_unplug/trigger
0533 
0534           # echo '!traceoff if nr_rq > 1' > \
0535                 /sys/kernel/debug/tracing/events/block/block_unplug/trigger
0536 
0537   Note that there can be only one traceon or traceoff trigger per
0538   triggering event.
0539 
0540 - hist
0541 
0542   This command aggregates event hits into a hash table keyed on one or
0543   more trace event format fields (or stacktrace) and a set of running
0544   totals derived from one or more trace event format fields and/or
0545   event counts (hitcount).
0546 
0547   See Documentation/trace/histogram.rst for details and examples.
0548 
0549 7. In-kernel trace event API
0550 ============================
0551 
0552 In most cases, the command-line interface to trace events is more than
0553 sufficient.  Sometimes, however, applications might find the need for
0554 more complex relationships than can be expressed through a simple
0555 series of linked command-line expressions, or putting together sets of
0556 commands may be simply too cumbersome.  An example might be an
0557 application that needs to 'listen' to the trace stream in order to
0558 maintain an in-kernel state machine detecting, for instance, when an
0559 illegal kernel state occurs in the scheduler.
0560 
0561 The trace event subsystem provides an in-kernel API allowing modules
0562 or other kernel code to generate user-defined 'synthetic' events at
0563 will, which can be used to either augment the existing trace stream
0564 and/or signal that a particular important state has occurred.
0565 
0566 A similar in-kernel API is also available for creating kprobe and
0567 kretprobe events.
0568 
0569 Both the synthetic event and k/ret/probe event APIs are built on top
0570 of a lower-level "dynevent_cmd" event command API, which is also
0571 available for more specialized applications, or as the basis of other
0572 higher-level trace event APIs.
0573 
0574 The API provided for these purposes is describe below and allows the
0575 following:
0576 
0577   - dynamically creating synthetic event definitions
0578   - dynamically creating kprobe and kretprobe event definitions
0579   - tracing synthetic events from in-kernel code
0580   - the low-level "dynevent_cmd" API
0581 
0582 7.1 Dyamically creating synthetic event definitions
0583 ---------------------------------------------------
0584 
0585 There are a couple ways to create a new synthetic event from a kernel
0586 module or other kernel code.
0587 
0588 The first creates the event in one step, using synth_event_create().
0589 In this method, the name of the event to create and an array defining
0590 the fields is supplied to synth_event_create().  If successful, a
0591 synthetic event with that name and fields will exist following that
0592 call.  For example, to create a new "schedtest" synthetic event::
0593 
0594   ret = synth_event_create("schedtest", sched_fields,
0595                            ARRAY_SIZE(sched_fields), THIS_MODULE);
0596 
0597 The sched_fields param in this example points to an array of struct
0598 synth_field_desc, each of which describes an event field by type and
0599 name::
0600 
0601   static struct synth_field_desc sched_fields[] = {
0602         { .type = "pid_t",              .name = "next_pid_field" },
0603         { .type = "char[16]",           .name = "next_comm_field" },
0604         { .type = "u64",                .name = "ts_ns" },
0605         { .type = "u64",                .name = "ts_ms" },
0606         { .type = "unsigned int",       .name = "cpu" },
0607         { .type = "char[64]",           .name = "my_string_field" },
0608         { .type = "int",                .name = "my_int_field" },
0609   };
0610 
0611 See synth_field_size() for available types.
0612 
0613 If field_name contains [n], the field is considered to be a static array.
0614 
0615 If field_names contains[] (no subscript), the field is considered to
0616 be a dynamic array, which will only take as much space in the event as
0617 is required to hold the array.
0618 
0619 Because space for an event is reserved before assigning field values
0620 to the event, using dynamic arrays implies that the piecewise
0621 in-kernel API described below can't be used with dynamic arrays.  The
0622 other non-piecewise in-kernel APIs can, however, be used with dynamic
0623 arrays.
0624 
0625 If the event is created from within a module, a pointer to the module
0626 must be passed to synth_event_create().  This will ensure that the
0627 trace buffer won't contain unreadable events when the module is
0628 removed.
0629 
0630 At this point, the event object is ready to be used for generating new
0631 events.
0632 
0633 In the second method, the event is created in several steps.  This
0634 allows events to be created dynamically and without the need to create
0635 and populate an array of fields beforehand.
0636 
0637 To use this method, an empty or partially empty synthetic event should
0638 first be created using synth_event_gen_cmd_start() or
0639 synth_event_gen_cmd_array_start().  For synth_event_gen_cmd_start(),
0640 the name of the event along with one or more pairs of args each pair
0641 representing a 'type field_name;' field specification should be
0642 supplied.  For synth_event_gen_cmd_array_start(), the name of the
0643 event along with an array of struct synth_field_desc should be
0644 supplied. Before calling synth_event_gen_cmd_start() or
0645 synth_event_gen_cmd_array_start(), the user should create and
0646 initialize a dynevent_cmd object using synth_event_cmd_init().
0647 
0648 For example, to create a new "schedtest" synthetic event with two
0649 fields::
0650 
0651   struct dynevent_cmd cmd;
0652   char *buf;
0653 
0654   /* Create a buffer to hold the generated command */
0655   buf = kzalloc(MAX_DYNEVENT_CMD_LEN, GFP_KERNEL);
0656 
0657   /* Before generating the command, initialize the cmd object */
0658   synth_event_cmd_init(&cmd, buf, MAX_DYNEVENT_CMD_LEN);
0659 
0660   ret = synth_event_gen_cmd_start(&cmd, "schedtest", THIS_MODULE,
0661                                   "pid_t", "next_pid_field",
0662                                   "u64", "ts_ns");
0663 
0664 Alternatively, using an array of struct synth_field_desc fields
0665 containing the same information::
0666 
0667   ret = synth_event_gen_cmd_array_start(&cmd, "schedtest", THIS_MODULE,
0668                                         fields, n_fields);
0669 
0670 Once the synthetic event object has been created, it can then be
0671 populated with more fields.  Fields are added one by one using
0672 synth_event_add_field(), supplying the dynevent_cmd object, a field
0673 type, and a field name.  For example, to add a new int field named
0674 "intfield", the following call should be made::
0675 
0676   ret = synth_event_add_field(&cmd, "int", "intfield");
0677 
0678 See synth_field_size() for available types. If field_name contains [n]
0679 the field is considered to be an array.
0680 
0681 A group of fields can also be added all at once using an array of
0682 synth_field_desc with add_synth_fields().  For example, this would add
0683 just the first four sched_fields::
0684 
0685   ret = synth_event_add_fields(&cmd, sched_fields, 4);
0686 
0687 If you already have a string of the form 'type field_name',
0688 synth_event_add_field_str() can be used to add it as-is; it will
0689 also automatically append a ';' to the string.
0690 
0691 Once all the fields have been added, the event should be finalized and
0692 registered by calling the synth_event_gen_cmd_end() function::
0693 
0694   ret = synth_event_gen_cmd_end(&cmd);
0695 
0696 At this point, the event object is ready to be used for tracing new
0697 events.
0698 
0699 7.2 Tracing synthetic events from in-kernel code
0700 ------------------------------------------------
0701 
0702 To trace a synthetic event, there are several options.  The first
0703 option is to trace the event in one call, using synth_event_trace()
0704 with a variable number of values, or synth_event_trace_array() with an
0705 array of values to be set.  A second option can be used to avoid the
0706 need for a pre-formed array of values or list of arguments, via
0707 synth_event_trace_start() and synth_event_trace_end() along with
0708 synth_event_add_next_val() or synth_event_add_val() to add the values
0709 piecewise.
0710 
0711 7.2.1 Tracing a synthetic event all at once
0712 -------------------------------------------
0713 
0714 To trace a synthetic event all at once, the synth_event_trace() or
0715 synth_event_trace_array() functions can be used.
0716 
0717 The synth_event_trace() function is passed the trace_event_file
0718 representing the synthetic event (which can be retrieved using
0719 trace_get_event_file() using the synthetic event name, "synthetic" as
0720 the system name, and the trace instance name (NULL if using the global
0721 trace array)), along with an variable number of u64 args, one for each
0722 synthetic event field, and the number of values being passed.
0723 
0724 So, to trace an event corresponding to the synthetic event definition
0725 above, code like the following could be used::
0726 
0727   ret = synth_event_trace(create_synth_test, 7, /* number of values */
0728                           444,             /* next_pid_field */
0729                           (u64)"clackers", /* next_comm_field */
0730                           1000000,         /* ts_ns */
0731                           1000,            /* ts_ms */
0732                           smp_processor_id(),/* cpu */
0733                           (u64)"Thneed",   /* my_string_field */
0734                           999);            /* my_int_field */
0735 
0736 All vals should be cast to u64, and string vals are just pointers to
0737 strings, cast to u64.  Strings will be copied into space reserved in
0738 the event for the string, using these pointers.
0739 
0740 Alternatively, the synth_event_trace_array() function can be used to
0741 accomplish the same thing.  It is passed the trace_event_file
0742 representing the synthetic event (which can be retrieved using
0743 trace_get_event_file() using the synthetic event name, "synthetic" as
0744 the system name, and the trace instance name (NULL if using the global
0745 trace array)), along with an array of u64, one for each synthetic
0746 event field.
0747 
0748 To trace an event corresponding to the synthetic event definition
0749 above, code like the following could be used::
0750 
0751   u64 vals[7];
0752 
0753   vals[0] = 777;                  /* next_pid_field */
0754   vals[1] = (u64)"tiddlywinks";   /* next_comm_field */
0755   vals[2] = 1000000;              /* ts_ns */
0756   vals[3] = 1000;                 /* ts_ms */
0757   vals[4] = smp_processor_id();   /* cpu */
0758   vals[5] = (u64)"thneed";        /* my_string_field */
0759   vals[6] = 398;                  /* my_int_field */
0760 
0761 The 'vals' array is just an array of u64, the number of which must
0762 match the number of field in the synthetic event, and which must be in
0763 the same order as the synthetic event fields.
0764 
0765 All vals should be cast to u64, and string vals are just pointers to
0766 strings, cast to u64.  Strings will be copied into space reserved in
0767 the event for the string, using these pointers.
0768 
0769 In order to trace a synthetic event, a pointer to the trace event file
0770 is needed.  The trace_get_event_file() function can be used to get
0771 it - it will find the file in the given trace instance (in this case
0772 NULL since the top trace array is being used) while at the same time
0773 preventing the instance containing it from going away::
0774 
0775        schedtest_event_file = trace_get_event_file(NULL, "synthetic",
0776                                                    "schedtest");
0777 
0778 Before tracing the event, it should be enabled in some way, otherwise
0779 the synthetic event won't actually show up in the trace buffer.
0780 
0781 To enable a synthetic event from the kernel, trace_array_set_clr_event()
0782 can be used (which is not specific to synthetic events, so does need
0783 the "synthetic" system name to be specified explicitly).
0784 
0785 To enable the event, pass 'true' to it::
0786 
0787        trace_array_set_clr_event(schedtest_event_file->tr,
0788                                  "synthetic", "schedtest", true);
0789 
0790 To disable it pass false::
0791 
0792        trace_array_set_clr_event(schedtest_event_file->tr,
0793                                  "synthetic", "schedtest", false);
0794 
0795 Finally, synth_event_trace_array() can be used to actually trace the
0796 event, which should be visible in the trace buffer afterwards::
0797 
0798        ret = synth_event_trace_array(schedtest_event_file, vals,
0799                                      ARRAY_SIZE(vals));
0800 
0801 To remove the synthetic event, the event should be disabled, and the
0802 trace instance should be 'put' back using trace_put_event_file()::
0803 
0804        trace_array_set_clr_event(schedtest_event_file->tr,
0805                                  "synthetic", "schedtest", false);
0806        trace_put_event_file(schedtest_event_file);
0807 
0808 If those have been successful, synth_event_delete() can be called to
0809 remove the event::
0810 
0811        ret = synth_event_delete("schedtest");
0812 
0813 7.2.2 Tracing a synthetic event piecewise
0814 -----------------------------------------
0815 
0816 To trace a synthetic using the piecewise method described above, the
0817 synth_event_trace_start() function is used to 'open' the synthetic
0818 event trace::
0819 
0820        struct synth_event_trace_state trace_state;
0821 
0822        ret = synth_event_trace_start(schedtest_event_file, &trace_state);
0823 
0824 It's passed the trace_event_file representing the synthetic event
0825 using the same methods as described above, along with a pointer to a
0826 struct synth_event_trace_state object, which will be zeroed before use and
0827 used to maintain state between this and following calls.
0828 
0829 Once the event has been opened, which means space for it has been
0830 reserved in the trace buffer, the individual fields can be set.  There
0831 are two ways to do that, either one after another for each field in
0832 the event, which requires no lookups, or by name, which does.  The
0833 tradeoff is flexibility in doing the assignments vs the cost of a
0834 lookup per field.
0835 
0836 To assign the values one after the other without lookups,
0837 synth_event_add_next_val() should be used.  Each call is passed the
0838 same synth_event_trace_state object used in the synth_event_trace_start(),
0839 along with the value to set the next field in the event.  After each
0840 field is set, the 'cursor' points to the next field, which will be set
0841 by the subsequent call, continuing until all the fields have been set
0842 in order.  The same sequence of calls as in the above examples using
0843 this method would be (without error-handling code)::
0844 
0845        /* next_pid_field */
0846        ret = synth_event_add_next_val(777, &trace_state);
0847 
0848        /* next_comm_field */
0849        ret = synth_event_add_next_val((u64)"slinky", &trace_state);
0850 
0851        /* ts_ns */
0852        ret = synth_event_add_next_val(1000000, &trace_state);
0853 
0854        /* ts_ms */
0855        ret = synth_event_add_next_val(1000, &trace_state);
0856 
0857        /* cpu */
0858        ret = synth_event_add_next_val(smp_processor_id(), &trace_state);
0859 
0860        /* my_string_field */
0861        ret = synth_event_add_next_val((u64)"thneed_2.01", &trace_state);
0862 
0863        /* my_int_field */
0864        ret = synth_event_add_next_val(395, &trace_state);
0865 
0866 To assign the values in any order, synth_event_add_val() should be
0867 used.  Each call is passed the same synth_event_trace_state object used in
0868 the synth_event_trace_start(), along with the field name of the field
0869 to set and the value to set it to.  The same sequence of calls as in
0870 the above examples using this method would be (without error-handling
0871 code)::
0872 
0873        ret = synth_event_add_val("next_pid_field", 777, &trace_state);
0874        ret = synth_event_add_val("next_comm_field", (u64)"silly putty",
0875                                  &trace_state);
0876        ret = synth_event_add_val("ts_ns", 1000000, &trace_state);
0877        ret = synth_event_add_val("ts_ms", 1000, &trace_state);
0878        ret = synth_event_add_val("cpu", smp_processor_id(), &trace_state);
0879        ret = synth_event_add_val("my_string_field", (u64)"thneed_9",
0880                                  &trace_state);
0881        ret = synth_event_add_val("my_int_field", 3999, &trace_state);
0882 
0883 Note that synth_event_add_next_val() and synth_event_add_val() are
0884 incompatible if used within the same trace of an event - either one
0885 can be used but not both at the same time.
0886 
0887 Finally, the event won't be actually traced until it's 'closed',
0888 which is done using synth_event_trace_end(), which takes only the
0889 struct synth_event_trace_state object used in the previous calls::
0890 
0891        ret = synth_event_trace_end(&trace_state);
0892 
0893 Note that synth_event_trace_end() must be called at the end regardless
0894 of whether any of the add calls failed (say due to a bad field name
0895 being passed in).
0896 
0897 7.3 Dyamically creating kprobe and kretprobe event definitions
0898 --------------------------------------------------------------
0899 
0900 To create a kprobe or kretprobe trace event from kernel code, the
0901 kprobe_event_gen_cmd_start() or kretprobe_event_gen_cmd_start()
0902 functions can be used.
0903 
0904 To create a kprobe event, an empty or partially empty kprobe event
0905 should first be created using kprobe_event_gen_cmd_start().  The name
0906 of the event and the probe location should be specfied along with one
0907 or args each representing a probe field should be supplied to this
0908 function.  Before calling kprobe_event_gen_cmd_start(), the user
0909 should create and initialize a dynevent_cmd object using
0910 kprobe_event_cmd_init().
0911 
0912 For example, to create a new "schedtest" kprobe event with two fields::
0913 
0914   struct dynevent_cmd cmd;
0915   char *buf;
0916 
0917   /* Create a buffer to hold the generated command */
0918   buf = kzalloc(MAX_DYNEVENT_CMD_LEN, GFP_KERNEL);
0919 
0920   /* Before generating the command, initialize the cmd object */
0921   kprobe_event_cmd_init(&cmd, buf, MAX_DYNEVENT_CMD_LEN);
0922 
0923   /*
0924    * Define the gen_kprobe_test event with the first 2 kprobe
0925    * fields.
0926    */
0927   ret = kprobe_event_gen_cmd_start(&cmd, "gen_kprobe_test", "do_sys_open",
0928                                    "dfd=%ax", "filename=%dx");
0929 
0930 Once the kprobe event object has been created, it can then be
0931 populated with more fields.  Fields can be added using
0932 kprobe_event_add_fields(), supplying the dynevent_cmd object along
0933 with a variable arg list of probe fields.  For example, to add a
0934 couple additional fields, the following call could be made::
0935 
0936   ret = kprobe_event_add_fields(&cmd, "flags=%cx", "mode=+4($stack)");
0937 
0938 Once all the fields have been added, the event should be finalized and
0939 registered by calling the kprobe_event_gen_cmd_end() or
0940 kretprobe_event_gen_cmd_end() functions, depending on whether a kprobe
0941 or kretprobe command was started::
0942 
0943   ret = kprobe_event_gen_cmd_end(&cmd);
0944 
0945 or::
0946 
0947   ret = kretprobe_event_gen_cmd_end(&cmd);
0948 
0949 At this point, the event object is ready to be used for tracing new
0950 events.
0951 
0952 Similarly, a kretprobe event can be created using
0953 kretprobe_event_gen_cmd_start() with a probe name and location and
0954 additional params such as $retval::
0955 
0956   ret = kretprobe_event_gen_cmd_start(&cmd, "gen_kretprobe_test",
0957                                       "do_sys_open", "$retval");
0958 
0959 Similar to the synthetic event case, code like the following can be
0960 used to enable the newly created kprobe event::
0961 
0962   gen_kprobe_test = trace_get_event_file(NULL, "kprobes", "gen_kprobe_test");
0963 
0964   ret = trace_array_set_clr_event(gen_kprobe_test->tr,
0965                                   "kprobes", "gen_kprobe_test", true);
0966 
0967 Finally, also similar to synthetic events, the following code can be
0968 used to give the kprobe event file back and delete the event::
0969 
0970   trace_put_event_file(gen_kprobe_test);
0971 
0972   ret = kprobe_event_delete("gen_kprobe_test");
0973 
0974 7.4 The "dynevent_cmd" low-level API
0975 ------------------------------------
0976 
0977 Both the in-kernel synthetic event and kprobe interfaces are built on
0978 top of a lower-level "dynevent_cmd" interface.  This interface is
0979 meant to provide the basis for higher-level interfaces such as the
0980 synthetic and kprobe interfaces, which can be used as examples.
0981 
0982 The basic idea is simple and amounts to providing a general-purpose
0983 layer that can be used to generate trace event commands.  The
0984 generated command strings can then be passed to the command-parsing
0985 and event creation code that already exists in the trace event
0986 subystem for creating the corresponding trace events.
0987 
0988 In a nutshell, the way it works is that the higher-level interface
0989 code creates a struct dynevent_cmd object, then uses a couple
0990 functions, dynevent_arg_add() and dynevent_arg_pair_add() to build up
0991 a command string, which finally causes the command to be executed
0992 using the dynevent_create() function.  The details of the interface
0993 are described below.
0994 
0995 The first step in building a new command string is to create and
0996 initialize an instance of a dynevent_cmd.  Here, for instance, we
0997 create a dynevent_cmd on the stack and initialize it::
0998 
0999   struct dynevent_cmd cmd;
1000   char *buf;
1001   int ret;
1002 
1003   buf = kzalloc(MAX_DYNEVENT_CMD_LEN, GFP_KERNEL);
1004 
1005   dynevent_cmd_init(cmd, buf, maxlen, DYNEVENT_TYPE_FOO,
1006                     foo_event_run_command);
1007 
1008 The dynevent_cmd initialization needs to be given a user-specified
1009 buffer and the length of the buffer (MAX_DYNEVENT_CMD_LEN can be used
1010 for this purpose - at 2k it's generally too big to be comfortably put
1011 on the stack, so is dynamically allocated), a dynevent type id, which
1012 is meant to be used to check that further API calls are for the
1013 correct command type, and a pointer to an event-specific run_command()
1014 callback that will be called to actually execute the event-specific
1015 command function.
1016 
1017 Once that's done, the command string can by built up by successive
1018 calls to argument-adding functions.
1019 
1020 To add a single argument, define and initialize a struct dynevent_arg
1021 or struct dynevent_arg_pair object.  Here's an example of the simplest
1022 possible arg addition, which is simply to append the given string as
1023 a whitespace-separated argument to the command::
1024 
1025   struct dynevent_arg arg;
1026 
1027   dynevent_arg_init(&arg, NULL, 0);
1028 
1029   arg.str = name;
1030 
1031   ret = dynevent_arg_add(cmd, &arg);
1032 
1033 The arg object is first initialized using dynevent_arg_init() and in
1034 this case the parameters are NULL or 0, which means there's no
1035 optional sanity-checking function or separator appended to the end of
1036 the arg.
1037 
1038 Here's another more complicated example using an 'arg pair', which is
1039 used to create an argument that consists of a couple components added
1040 together as a unit, for example, a 'type field_name;' arg or a simple
1041 expression arg e.g. 'flags=%cx'::
1042 
1043   struct dynevent_arg_pair arg_pair;
1044 
1045   dynevent_arg_pair_init(&arg_pair, dynevent_foo_check_arg_fn, 0, ';');
1046 
1047   arg_pair.lhs = type;
1048   arg_pair.rhs = name;
1049 
1050   ret = dynevent_arg_pair_add(cmd, &arg_pair);
1051 
1052 Again, the arg_pair is first initialized, in this case with a callback
1053 function used to check the sanity of the args (for example, that
1054 neither part of the pair is NULL), along with a character to be used
1055 to add an operator between the pair (here none) and a separator to be
1056 appended onto the end of the arg pair (here ';').
1057 
1058 There's also a dynevent_str_add() function that can be used to simply
1059 add a string as-is, with no spaces, delimeters, or arg check.
1060 
1061 Any number of dynevent_*_add() calls can be made to build up the string
1062 (until its length surpasses cmd->maxlen).  When all the arguments have
1063 been added and the command string is complete, the only thing left to
1064 do is run the command, which happens by simply calling
1065 dynevent_create()::
1066 
1067   ret = dynevent_create(&cmd);
1068 
1069 At that point, if the return value is 0, the dynamic event has been
1070 created and is ready to use.
1071 
1072 See the dynevent_cmd function definitions themselves for the details
1073 of the API.