xref: /linux/Documentation/trace/events.rst (revision 084100a1b579e6e08085dfc33caa4df31bb25696)
1=============
2Event Tracing
3=============
4
5:Author: Theodore Ts'o
6:Updated: Li Zefan and Tom Zanussi
7
81. Introduction
9===============
10
11Tracepoints (see Documentation/trace/tracepoints.rst) can be used
12without creating custom kernel modules to register probe functions
13using the event tracing infrastructure.
14
15Not all tracepoints can be traced using the event tracing system;
16the kernel developer must provide code snippets which define how the
17tracing information is saved into the tracing buffer, and how the
18tracing information should be printed.
19
202. Using Event Tracing
21======================
22
232.1 Via the 'set_event' interface
24---------------------------------
25
26The events which are available for tracing can be found in the file
27/sys/kernel/tracing/available_events.
28
29To enable a particular event, such as 'sched_wakeup', simply echo it
30to /sys/kernel/tracing/set_event. For example::
31
32	# echo sched_wakeup >> /sys/kernel/tracing/set_event
33
34.. Note:: '>>' is necessary, otherwise it will firstly disable all the events.
35
36To disable an event, echo the event name to the set_event file prefixed
37with an exclamation point::
38
39	# echo '!sched_wakeup' >> /sys/kernel/tracing/set_event
40
41To disable all events, echo an empty line to the set_event file::
42
43	# echo > /sys/kernel/tracing/set_event
44
45To enable all events, echo ``*:*`` or ``*:`` to the set_event file::
46
47	# echo *:* > /sys/kernel/tracing/set_event
48
49The events are organized into subsystems, such as ext4, irq, sched,
50etc., and a full event name looks like this: <subsystem>:<event>.  The
51subsystem name is optional, but it is displayed in the available_events
52file.  All of the events in a subsystem can be specified via the syntax
53``<subsystem>:*``; for example, to enable all irq events, you can use the
54command::
55
56	# echo 'irq:*' > /sys/kernel/tracing/set_event
57
58The set_event file may also be used to enable events associated to only
59a specific module::
60
61	# echo ':mod:<module>' > /sys/kernel/tracing/set_event
62
63Will enable all events in the module ``<module>``.  If the module is not yet
64loaded, the string will be saved and when a module is that matches ``<module>``
65is loaded, then it will apply the enabling of events then.
66
67The text before ``:mod:`` will be parsed to specify specific events that the
68module creates::
69
70	# echo '<match>:mod:<module>' > /sys/kernel/tracing/set_event
71
72The above will enable any system or event that ``<match>`` matches. If
73``<match>`` is ``"*"`` then it will match all events.
74
75To enable only a specific event within a system::
76
77	# echo '<system>:<event>:mod:<module>' > /sys/kernel/tracing/set_event
78
79If ``<event>`` is ``"*"`` then it will match all events within the system
80for a given module.
81
822.2 Via the 'enable' toggle
83---------------------------
84
85The events available are also listed in /sys/kernel/tracing/events/ hierarchy
86of directories.
87
88To enable event 'sched_wakeup'::
89
90	# echo 1 > /sys/kernel/tracing/events/sched/sched_wakeup/enable
91
92To disable it::
93
94	# echo 0 > /sys/kernel/tracing/events/sched/sched_wakeup/enable
95
96To enable all events in sched subsystem::
97
98	# echo 1 > /sys/kernel/tracing/events/sched/enable
99
100To enable all events::
101
102	# echo 1 > /sys/kernel/tracing/events/enable
103
104When reading one of these enable files, there are four results:
105
106 - 0 - all events this file affects are disabled
107 - 1 - all events this file affects are enabled
108 - X - there is a mixture of events enabled and disabled
109 - ? - this file does not affect any event
110
1112.3 Boot option
112---------------
113
114In order to facilitate early boot debugging, use boot option::
115
116	trace_event=[event-list]
117
118event-list is a comma separated list of events. See section 2.1 for event
119format.
120
121The boot option also supports the ``:filter:`` keyword to apply a filter.
122The ``:filter:`` keyword needs to be at the end of the event specification::
123
124	<system>:<event>:mod:<module>:filter:<filter>
125
1263. Defining an event-enabled tracepoint
127=======================================
128
129See The example provided in samples/trace_events
130
1314. Event formats
132================
133
134Each trace event has a 'format' file associated with it that contains
135a description of each field in a logged event.  This information can
136be used to parse the binary trace stream, and is also the place to
137find the field names that can be used in event filters (see section 5).
138
139It also displays the format string that will be used to print the
140event in text mode, along with the event name and ID used for
141profiling.
142
143Every event has a set of ``common`` fields associated with it; these are
144the fields prefixed with ``common_``.  The other fields vary between
145events and correspond to the fields defined in the TRACE_EVENT
146definition for that event.
147
148Each field in the format has the form::
149
150     field:field-type field-name; offset:N; size:N;
151
152where offset is the offset of the field in the trace record and size
153is the size of the data item, in bytes.
154
155For example, here's the information displayed for the 'sched_wakeup'
156event::
157
158	# cat /sys/kernel/tracing/events/sched/sched_wakeup/format
159
160	name: sched_wakeup
161	ID: 60
162	format:
163		field:unsigned short common_type;	offset:0;	size:2;
164		field:unsigned char common_flags;	offset:2;	size:1;
165		field:unsigned char common_preempt_count;	offset:3;	size:1;
166		field:int common_pid;	offset:4;	size:4;
167		field:int common_tgid;	offset:8;	size:4;
168
169		field:char comm[TASK_COMM_LEN];	offset:12;	size:16;
170		field:pid_t pid;	offset:28;	size:4;
171		field:int prio;	offset:32;	size:4;
172		field:int success;	offset:36;	size:4;
173		field:int cpu;	offset:40;	size:4;
174
175	print fmt: "task %s:%d [%d] success=%d [%03d]", REC->comm, REC->pid,
176		   REC->prio, REC->success, REC->cpu
177
178This event contains 10 fields, the first 5 common and the remaining 5
179event-specific.  All the fields for this event are numeric, except for
180'comm' which is a string, a distinction important for event filtering.
181
1825. Event filtering
183==================
184
185Trace events can be filtered in the kernel by associating boolean
186'filter expressions' with them.  As soon as an event is logged into
187the trace buffer, its fields are checked against the filter expression
188associated with that event type.  An event with field values that
189'match' the filter will appear in the trace output, and an event whose
190values don't match will be discarded.  An event with no filter
191associated with it matches everything, and is the default when no
192filter has been set for an event.
193
1945.1 Expression syntax
195---------------------
196
197A filter expression consists of one or more 'predicates' that can be
198combined using the logical operators '&&' and '||'.  A predicate is
199simply a clause that compares the value of a field contained within a
200logged event with a constant value and returns either 0 or 1 depending
201on whether the field value matched (1) or didn't match (0)::
202
203	  field-name relational-operator value
204
205Parentheses can be used to provide arbitrary logical groupings and
206double-quotes can be used to prevent the shell from interpreting
207operators as shell metacharacters.
208
209The field-names available for use in filters can be found in the
210'format' files for trace events (see section 4).
211
212The relational-operators depend on the type of the field being tested:
213
214The operators available for numeric fields are:
215
216==, !=, <, <=, >, >=, &
217
218And for string fields they are:
219
220==, !=, ~
221
222The glob (~) accepts a wild card character (\*,?) and character classes
223([). For example::
224
225  prev_comm ~ "*sh"
226  prev_comm ~ "sh*"
227  prev_comm ~ "*sh*"
228  prev_comm ~ "ba*sh"
229
230If the field is a pointer that points into user space (for example
231"filename" from sys_enter_openat), then you have to append ".ustring" to the
232field name::
233
234  filename.ustring ~ "password"
235
236As the kernel will have to know how to retrieve the memory that the pointer
237is at from user space.
238
239You can convert any long type to a function address and search by function name::
240
241  call_site.function == security_prepare_creds
242
243The above will filter when the field "call_site" falls on the address within
244"security_prepare_creds". That is, it will compare the value of "call_site" and
245the filter will return true if it is greater than or equal to the start of
246the function "security_prepare_creds" and less than the end of that function.
247
248The ".function" postfix can only be attached to values of size long, and can only
249be compared with "==" or "!=".
250
251The special field "within" can be used to filter events based on whether
252a specific function appears in the current call stack::
253
254  within == "function_name"
255  within != "function_name"
256
257For example, to only trace events where "vfs_read" is in the call stack::
258
259  # echo 'within == "vfs_read"' > events/sched/sched_switch/filter
260
261The within field supports only the "==" and "!=" operators.
262
263Cpumask fields or scalar fields that encode a CPU number can be filtered using
264a user-provided cpumask in cpulist format. The format is as follows::
265
266  CPUS{$cpulist}
267
268Operators available to cpumask filtering are:
269
270& (intersection), ==, !=
271
272For example, this will filter events that have their .target_cpu field present
273in the given cpumask::
274
275  target_cpu & CPUS{17-42}
276
2775.2 Setting filters
278-------------------
279
280A filter for an individual event is set by writing a filter expression
281to the 'filter' file for the given event.
282
283For example::
284
285	# cd /sys/kernel/tracing/events/sched/sched_wakeup
286	# echo "common_preempt_count > 4" > filter
287
288A slightly more involved example::
289
290	# cd /sys/kernel/tracing/events/signal/signal_generate
291	# echo "((sig >= 10 && sig < 15) || sig == 17) && comm != bash" > filter
292
293If there is an error in the expression, you'll get an 'Invalid
294argument' error when setting it, and the erroneous string along with
295an error message can be seen by looking at the filter e.g.::
296
297	# cd /sys/kernel/tracing/events/signal/signal_generate
298	# echo "((sig >= 10 && sig < 15) || dsig == 17) && comm != bash" > filter
299	-bash: echo: write error: Invalid argument
300	# cat filter
301	((sig >= 10 && sig < 15) || dsig == 17) && comm != bash
302	^
303	parse_error: Field not found
304
305Currently the caret ('^') for an error always appears at the beginning of
306the filter string; the error message should still be useful though
307even without more accurate position info.
308
3095.2.1 Filter limitations
310------------------------
311
312If a filter is placed on a string pointer ``(char *)`` that does not point
313to a string on the ring buffer, but instead points to kernel or user space
314memory, then, for safety reasons, at most 1024 bytes of the content is
315copied onto a temporary buffer to do the compare. If the copy of the memory
316faults (the pointer points to memory that should not be accessed), then the
317string compare will be treated as not matching.
318
3195.3 Clearing filters
320--------------------
321
322To clear the filter for an event, write a '0' to the event's filter
323file.
324
325To clear the filters for all events in a subsystem, write a '0' to the
326subsystem's filter file.
327
3285.4 Subsystem filters
329---------------------
330
331For convenience, filters for every event in a subsystem can be set or
332cleared as a group by writing a filter expression into the filter file
333at the root of the subsystem.  Note however, that if a filter for any
334event within the subsystem lacks a field specified in the subsystem
335filter, or if the filter can't be applied for any other reason, the
336filter for that event will retain its previous setting.  This can
337result in an unintended mixture of filters which could lead to
338confusing (to the user who might think different filters are in
339effect) trace output.  Only filters that reference just the common
340fields can be guaranteed to propagate successfully to all events.
341
342Here are a few subsystem filter examples that also illustrate the
343above points:
344
345Clear the filters on all events in the sched subsystem::
346
347	# cd /sys/kernel/tracing/events/sched
348	# echo 0 > filter
349	# cat sched_switch/filter
350	none
351	# cat sched_wakeup/filter
352	none
353
354Set a filter using only common fields for all events in the sched
355subsystem (all events end up with the same filter)::
356
357	# cd /sys/kernel/tracing/events/sched
358	# echo common_pid == 0 > filter
359	# cat sched_switch/filter
360	common_pid == 0
361	# cat sched_wakeup/filter
362	common_pid == 0
363
364Attempt to set a filter using a non-common field for all events in the
365sched subsystem (all events but those that have a prev_pid field retain
366their old filters)::
367
368	# cd /sys/kernel/tracing/events/sched
369	# echo prev_pid == 0 > filter
370	# cat sched_switch/filter
371	prev_pid == 0
372	# cat sched_wakeup/filter
373	common_pid == 0
374
3755.5 PID filtering
376-----------------
377
378The set_event_pid file in the same directory as the top events directory
379exists, will filter all events from tracing any task that does not have the
380PID listed in the set_event_pid file.
381::
382
383	# cd /sys/kernel/tracing
384	# echo $$ > set_event_pid
385	# echo 1 > events/enable
386
387Will only trace events for the current task.
388
389To add more PIDs without losing the PIDs already included, use '>>'.
390::
391
392	# echo 123 244 1 >> set_event_pid
393
394
3956. Event triggers
396=================
397
398Trace events can be made to conditionally invoke trigger 'commands'
399which can take various forms and are described in detail below;
400examples would be enabling or disabling other trace events or invoking
401a stack trace whenever the trace event is hit.  Whenever a trace event
402with attached triggers is invoked, the set of trigger commands
403associated with that event is invoked.  Any given trigger can
404additionally have an event filter of the same form as described in
405section 5 (Event filtering) associated with it - the command will only
406be invoked if the event being invoked passes the associated filter.
407If no filter is associated with the trigger, it always passes.
408
409Triggers are added to and removed from a particular event by writing
410trigger expressions to the 'trigger' file for the given event.
411
412A given event can have any number of triggers associated with it,
413subject to any restrictions that individual commands may have in that
414regard.
415
416Event triggers are implemented on top of "soft" mode, which means that
417whenever a trace event has one or more triggers associated with it,
418the event is activated even if it isn't actually enabled, but is
419disabled in a "soft" mode.  That is, the tracepoint will be called,
420but just will not be traced, unless of course it's actually enabled.
421This scheme allows triggers to be invoked even for events that aren't
422enabled, and also allows the current event filter implementation to be
423used for conditionally invoking triggers.
424
425The syntax for event triggers is roughly based on the syntax for
426set_ftrace_filter 'ftrace filter commands' (see the 'Filter commands'
427section of Documentation/trace/ftrace.rst), but there are major
428differences and the implementation isn't currently tied to it in any
429way, so beware about making generalizations between the two.
430
431.. Note::
432     Writing into trace_marker (See Documentation/trace/ftrace.rst)
433     can also enable triggers that are written into
434     /sys/kernel/tracing/events/ftrace/print/trigger
435
4366.1 Expression syntax
437---------------------
438
439Triggers are added by echoing the command to the 'trigger' file::
440
441  # echo 'command[:count] [if filter]' > trigger
442
443Triggers are removed by echoing the same command but starting with '!'
444to the 'trigger' file::
445
446  # echo '!command[:count] [if filter]' > trigger
447
448The [if filter] part isn't used in matching commands when removing, so
449leaving that off in a '!' command will accomplish the same thing as
450having it in.
451
452The filter syntax is the same as that described in the 'Event
453filtering' section above.
454
455For ease of use, writing to the trigger file using '>' currently just
456adds or removes a single trigger and there's no explicit '>>' support
457('>' actually behaves like '>>') or truncation support to remove all
458triggers (you have to use '!' for each one added.)
459
4606.2 Supported trigger commands
461------------------------------
462
463The following commands are supported:
464
465- enable_event/disable_event
466
467  These commands can enable or disable another trace event whenever
468  the triggering event is hit.  When these commands are registered,
469  the other trace event is activated, but disabled in a "soft" mode.
470  That is, the tracepoint will be called, but just will not be traced.
471  The event tracepoint stays in this mode as long as there's a trigger
472  in effect that can trigger it.
473
474  For example, the following trigger causes kmalloc events to be
475  traced when a read system call is entered, and the :1 at the end
476  specifies that this enablement happens only once::
477
478	  # echo 'enable_event:kmem:kmalloc:1' > \
479	      /sys/kernel/tracing/events/syscalls/sys_enter_read/trigger
480
481  The following trigger causes kmalloc events to stop being traced
482  when a read system call exits.  This disablement happens on every
483  read system call exit::
484
485	  # echo 'disable_event:kmem:kmalloc' > \
486	      /sys/kernel/tracing/events/syscalls/sys_exit_read/trigger
487
488  The format is::
489
490      enable_event:<system>:<event>[:count]
491      disable_event:<system>:<event>[:count]
492
493  To remove the above commands::
494
495	  # echo '!enable_event:kmem:kmalloc:1' > \
496	      /sys/kernel/tracing/events/syscalls/sys_enter_read/trigger
497
498	  # echo '!disable_event:kmem:kmalloc' > \
499	      /sys/kernel/tracing/events/syscalls/sys_exit_read/trigger
500
501  Note that there can be any number of enable/disable_event triggers
502  per triggering event, but there can only be one trigger per
503  triggered event. e.g. sys_enter_read can have triggers enabling both
504  kmem:kmalloc and sched:sched_switch, but can't have two kmem:kmalloc
505  versions such as kmem:kmalloc and kmem:kmalloc:1 or 'kmem:kmalloc if
506  bytes_req == 256' and 'kmem:kmalloc if bytes_alloc == 256' (they
507  could be combined into a single filter on kmem:kmalloc though).
508
509- stacktrace
510
511  This command dumps a stacktrace in the trace buffer whenever the
512  triggering event occurs.
513
514  For example, the following trigger dumps a stacktrace every time the
515  kmalloc tracepoint is hit::
516
517	  # echo 'stacktrace' > \
518		/sys/kernel/tracing/events/kmem/kmalloc/trigger
519
520  The following trigger dumps a stacktrace the first 5 times a kmalloc
521  request happens with a size >= 64K::
522
523	  # echo 'stacktrace:5 if bytes_req >= 65536' > \
524		/sys/kernel/tracing/events/kmem/kmalloc/trigger
525
526  The format is::
527
528      stacktrace[:count]
529
530  To remove the above commands::
531
532	  # echo '!stacktrace' > \
533		/sys/kernel/tracing/events/kmem/kmalloc/trigger
534
535	  # echo '!stacktrace:5 if bytes_req >= 65536' > \
536		/sys/kernel/tracing/events/kmem/kmalloc/trigger
537
538  The latter can also be removed more simply by the following (without
539  the filter)::
540
541	  # echo '!stacktrace:5' > \
542		/sys/kernel/tracing/events/kmem/kmalloc/trigger
543
544  Note that there can be only one stacktrace trigger per triggering
545  event.
546
547- snapshot
548
549  This command causes a snapshot to be triggered whenever the
550  triggering event occurs.
551
552  The following command creates a snapshot every time a block request
553  queue is unplugged with a depth > 1.  If you were tracing a set of
554  events or functions at the time, the snapshot trace buffer would
555  capture those events when the trigger event occurred::
556
557	  # echo 'snapshot if nr_rq > 1' > \
558		/sys/kernel/tracing/events/block/block_unplug/trigger
559
560  To only snapshot once::
561
562	  # echo 'snapshot:1 if nr_rq > 1' > \
563		/sys/kernel/tracing/events/block/block_unplug/trigger
564
565  To remove the above commands::
566
567	  # echo '!snapshot if nr_rq > 1' > \
568		/sys/kernel/tracing/events/block/block_unplug/trigger
569
570	  # echo '!snapshot:1 if nr_rq > 1' > \
571		/sys/kernel/tracing/events/block/block_unplug/trigger
572
573  Note that there can be only one snapshot trigger per triggering
574  event.
575
576- traceon/traceoff
577
578  These commands turn tracing on and off when the specified events are
579  hit. The parameter determines how many times the tracing system is
580  turned on and off. If unspecified, there is no limit.
581
582  The following command turns tracing off the first time a block
583  request queue is unplugged with a depth > 1.  If you were tracing a
584  set of events or functions at the time, you could then examine the
585  trace buffer to see the sequence of events that led up to the
586  trigger event::
587
588	  # echo 'traceoff:1 if nr_rq > 1' > \
589		/sys/kernel/tracing/events/block/block_unplug/trigger
590
591  To always disable tracing when nr_rq  > 1::
592
593	  # echo 'traceoff if nr_rq > 1' > \
594		/sys/kernel/tracing/events/block/block_unplug/trigger
595
596  To remove the above commands::
597
598	  # echo '!traceoff:1 if nr_rq > 1' > \
599		/sys/kernel/tracing/events/block/block_unplug/trigger
600
601	  # echo '!traceoff if nr_rq > 1' > \
602		/sys/kernel/tracing/events/block/block_unplug/trigger
603
604  Note that there can be only one traceon or traceoff trigger per
605  triggering event.
606
607- hist
608
609  This command aggregates event hits into a hash table keyed on one or
610  more trace event format fields (or stacktrace) and a set of running
611  totals derived from one or more trace event format fields and/or
612  event counts (hitcount).
613
614  See Documentation/trace/histogram.rst for details and examples.
615
6167. In-kernel trace event API
617============================
618
619In most cases, the command-line interface to trace events is more than
620sufficient.  Sometimes, however, applications might find the need for
621more complex relationships than can be expressed through a simple
622series of linked command-line expressions, or putting together sets of
623commands may be simply too cumbersome.  An example might be an
624application that needs to 'listen' to the trace stream in order to
625maintain an in-kernel state machine detecting, for instance, when an
626illegal kernel state occurs in the scheduler.
627
628The trace event subsystem provides an in-kernel API allowing modules
629or other kernel code to generate user-defined 'synthetic' events at
630will, which can be used to either augment the existing trace stream
631and/or signal that a particular important state has occurred.
632
633A similar in-kernel API is also available for creating kprobe and
634kretprobe events.
635
636Both the synthetic event and k/ret/probe event APIs are built on top
637of a lower-level "dynevent_cmd" event command API, which is also
638available for more specialized applications, or as the basis of other
639higher-level trace event APIs.
640
641The API provided for these purposes is describe below and allows the
642following:
643
644  - dynamically creating synthetic event definitions
645  - dynamically creating kprobe and kretprobe event definitions
646  - tracing synthetic events from in-kernel code
647  - the low-level "dynevent_cmd" API
648
6497.1 Dynamically creating synthetic event definitions
650----------------------------------------------------
651
652There are a couple ways to create a new synthetic event from a kernel
653module or other kernel code.
654
655The first creates the event in one step, using synth_event_create().
656In this method, the name of the event to create and an array defining
657the fields is supplied to synth_event_create().  If successful, a
658synthetic event with that name and fields will exist following that
659call.  For example, to create a new "schedtest" synthetic event::
660
661  ret = synth_event_create("schedtest", sched_fields,
662                           ARRAY_SIZE(sched_fields), THIS_MODULE);
663
664The sched_fields param in this example points to an array of struct
665synth_field_desc, each of which describes an event field by type and
666name::
667
668  static struct synth_field_desc sched_fields[] = {
669        { .type = "pid_t",              .name = "next_pid_field" },
670        { .type = "char[16]",           .name = "next_comm_field" },
671        { .type = "u64",                .name = "ts_ns" },
672        { .type = "u64",                .name = "ts_ms" },
673        { .type = "unsigned int",       .name = "cpu" },
674        { .type = "char[64]",           .name = "my_string_field" },
675        { .type = "int",                .name = "my_int_field" },
676  };
677
678See synth_field_size() for available types.
679
680If field_name contains [n], the field is considered to be a static array.
681
682If field_names contains[] (no subscript), the field is considered to
683be a dynamic array, which will only take as much space in the event as
684is required to hold the array.
685
686Because space for an event is reserved before assigning field values
687to the event, using dynamic arrays implies that the piecewise
688in-kernel API described below can't be used with dynamic arrays.  The
689other non-piecewise in-kernel APIs can, however, be used with dynamic
690arrays.
691
692If the event is created from within a module, a pointer to the module
693must be passed to synth_event_create().  This will ensure that the
694trace buffer won't contain unreadable events when the module is
695removed.
696
697At this point, the event object is ready to be used for generating new
698events.
699
700In the second method, the event is created in several steps.  This
701allows events to be created dynamically and without the need to create
702and populate an array of fields beforehand.
703
704To use this method, an empty or partially empty synthetic event should
705first be created using synth_event_gen_cmd_start() or
706synth_event_gen_cmd_array_start().  For synth_event_gen_cmd_start(),
707the name of the event along with one or more pairs of args each pair
708representing a 'type field_name;' field specification should be
709supplied.  For synth_event_gen_cmd_array_start(), the name of the
710event along with an array of struct synth_field_desc should be
711supplied. Before calling synth_event_gen_cmd_start() or
712synth_event_gen_cmd_array_start(), the user should create and
713initialize a dynevent_cmd object using synth_event_cmd_init().
714
715For example, to create a new "schedtest" synthetic event with two
716fields::
717
718  struct dynevent_cmd cmd;
719  char *buf;
720
721  /* Create a buffer to hold the generated command */
722  buf = kzalloc(MAX_DYNEVENT_CMD_LEN, GFP_KERNEL);
723
724  /* Before generating the command, initialize the cmd object */
725  synth_event_cmd_init(&cmd, buf, MAX_DYNEVENT_CMD_LEN);
726
727  ret = synth_event_gen_cmd_start(&cmd, "schedtest", THIS_MODULE,
728                                  "pid_t", "next_pid_field",
729                                  "u64", "ts_ns");
730
731Alternatively, using an array of struct synth_field_desc fields
732containing the same information::
733
734  ret = synth_event_gen_cmd_array_start(&cmd, "schedtest", THIS_MODULE,
735                                        fields, n_fields);
736
737Once the synthetic event object has been created, it can then be
738populated with more fields.  Fields are added one by one using
739synth_event_add_field(), supplying the dynevent_cmd object, a field
740type, and a field name.  For example, to add a new int field named
741"intfield", the following call should be made::
742
743  ret = synth_event_add_field(&cmd, "int", "intfield");
744
745See synth_field_size() for available types. If field_name contains [n]
746the field is considered to be an array.
747
748A group of fields can also be added all at once using an array of
749synth_field_desc with add_synth_fields().  For example, this would add
750just the first four sched_fields::
751
752  ret = synth_event_add_fields(&cmd, sched_fields, 4);
753
754If you already have a string of the form 'type field_name',
755synth_event_add_field_str() can be used to add it as-is; it will
756also automatically append a ';' to the string.
757
758Once all the fields have been added, the event should be finalized and
759registered by calling the synth_event_gen_cmd_end() function::
760
761  ret = synth_event_gen_cmd_end(&cmd);
762
763At this point, the event object is ready to be used for tracing new
764events.
765
7667.2 Tracing synthetic events from in-kernel code
767------------------------------------------------
768
769To trace a synthetic event, there are several options.  The first
770option is to trace the event in one call, using synth_event_trace()
771with a variable number of values, or synth_event_trace_array() with an
772array of values to be set.  A second option can be used to avoid the
773need for a pre-formed array of values or list of arguments, via
774synth_event_trace_start() and synth_event_trace_end() along with
775synth_event_add_next_val() or synth_event_add_val() to add the values
776piecewise.
777
7787.2.1 Tracing a synthetic event all at once
779-------------------------------------------
780
781To trace a synthetic event all at once, the synth_event_trace() or
782synth_event_trace_array() functions can be used.
783
784The synth_event_trace() function is passed the trace_event_file
785representing the synthetic event (which can be retrieved using
786trace_get_event_file() using the synthetic event name, "synthetic" as
787the system name, and the trace instance name (NULL if using the global
788trace array)), along with an variable number of u64 args, one for each
789synthetic event field, and the number of values being passed.
790
791So, to trace an event corresponding to the synthetic event definition
792above, code like the following could be used::
793
794  ret = synth_event_trace(create_synth_test, 7, /* number of values */
795                          444,             /* next_pid_field */
796                          (u64)"clackers", /* next_comm_field */
797                          1000000,         /* ts_ns */
798                          1000,            /* ts_ms */
799                          smp_processor_id(),/* cpu */
800                          (u64)"Thneed",   /* my_string_field */
801                          999);            /* my_int_field */
802
803All vals should be cast to u64, and string vals are just pointers to
804strings, cast to u64.  Strings will be copied into space reserved in
805the event for the string, using these pointers.
806
807Alternatively, the synth_event_trace_array() function can be used to
808accomplish the same thing.  It is passed the trace_event_file
809representing the synthetic event (which can be retrieved using
810trace_get_event_file() using the synthetic event name, "synthetic" as
811the system name, and the trace instance name (NULL if using the global
812trace array)), along with an array of u64, one for each synthetic
813event field.
814
815To trace an event corresponding to the synthetic event definition
816above, code like the following could be used::
817
818  u64 vals[7];
819
820  vals[0] = 777;                  /* next_pid_field */
821  vals[1] = (u64)"tiddlywinks";   /* next_comm_field */
822  vals[2] = 1000000;              /* ts_ns */
823  vals[3] = 1000;                 /* ts_ms */
824  vals[4] = smp_processor_id();   /* cpu */
825  vals[5] = (u64)"thneed";        /* my_string_field */
826  vals[6] = 398;                  /* my_int_field */
827
828The 'vals' array is just an array of u64, the number of which must
829match the number of field in the synthetic event, and which must be in
830the same order as the synthetic event fields.
831
832All vals should be cast to u64, and string vals are just pointers to
833strings, cast to u64.  Strings will be copied into space reserved in
834the event for the string, using these pointers.
835
836In order to trace a synthetic event, a pointer to the trace event file
837is needed.  The trace_get_event_file() function can be used to get
838it - it will find the file in the given trace instance (in this case
839NULL since the top trace array is being used) while at the same time
840preventing the instance containing it from going away::
841
842       schedtest_event_file = trace_get_event_file(NULL, "synthetic",
843                                                   "schedtest");
844
845Before tracing the event, it should be enabled in some way, otherwise
846the synthetic event won't actually show up in the trace buffer.
847
848To enable a synthetic event from the kernel, trace_array_set_clr_event()
849can be used (which is not specific to synthetic events, so does need
850the "synthetic" system name to be specified explicitly).
851
852To enable the event, pass 'true' to it::
853
854       trace_array_set_clr_event(schedtest_event_file->tr,
855                                 "synthetic", "schedtest", true);
856
857To disable it pass false::
858
859       trace_array_set_clr_event(schedtest_event_file->tr,
860                                 "synthetic", "schedtest", false);
861
862Finally, synth_event_trace_array() can be used to actually trace the
863event, which should be visible in the trace buffer afterwards::
864
865       ret = synth_event_trace_array(schedtest_event_file, vals,
866                                     ARRAY_SIZE(vals));
867
868To remove the synthetic event, the event should be disabled, and the
869trace instance should be 'put' back using trace_put_event_file()::
870
871       trace_array_set_clr_event(schedtest_event_file->tr,
872                                 "synthetic", "schedtest", false);
873       trace_put_event_file(schedtest_event_file);
874
875If those have been successful, synth_event_delete() can be called to
876remove the event::
877
878       ret = synth_event_delete("schedtest");
879
8807.2.2 Tracing a synthetic event piecewise
881-----------------------------------------
882
883To trace a synthetic using the piecewise method described above, the
884synth_event_trace_start() function is used to 'open' the synthetic
885event trace::
886
887       struct synth_event_trace_state trace_state;
888
889       ret = synth_event_trace_start(schedtest_event_file, &trace_state);
890
891It's passed the trace_event_file representing the synthetic event
892using the same methods as described above, along with a pointer to a
893struct synth_event_trace_state object, which will be zeroed before use and
894used to maintain state between this and following calls.
895
896Once the event has been opened, which means space for it has been
897reserved in the trace buffer, the individual fields can be set.  There
898are two ways to do that, either one after another for each field in
899the event, which requires no lookups, or by name, which does.  The
900tradeoff is flexibility in doing the assignments vs the cost of a
901lookup per field.
902
903To assign the values one after the other without lookups,
904synth_event_add_next_val() should be used.  Each call is passed the
905same synth_event_trace_state object used in the synth_event_trace_start(),
906along with the value to set the next field in the event.  After each
907field is set, the 'cursor' points to the next field, which will be set
908by the subsequent call, continuing until all the fields have been set
909in order.  The same sequence of calls as in the above examples using
910this method would be (without error-handling code)::
911
912       /* next_pid_field */
913       ret = synth_event_add_next_val(777, &trace_state);
914
915       /* next_comm_field */
916       ret = synth_event_add_next_val((u64)"slinky", &trace_state);
917
918       /* ts_ns */
919       ret = synth_event_add_next_val(1000000, &trace_state);
920
921       /* ts_ms */
922       ret = synth_event_add_next_val(1000, &trace_state);
923
924       /* cpu */
925       ret = synth_event_add_next_val(smp_processor_id(), &trace_state);
926
927       /* my_string_field */
928       ret = synth_event_add_next_val((u64)"thneed_2.01", &trace_state);
929
930       /* my_int_field */
931       ret = synth_event_add_next_val(395, &trace_state);
932
933To assign the values in any order, synth_event_add_val() should be
934used.  Each call is passed the same synth_event_trace_state object used in
935the synth_event_trace_start(), along with the field name of the field
936to set and the value to set it to.  The same sequence of calls as in
937the above examples using this method would be (without error-handling
938code)::
939
940       ret = synth_event_add_val("next_pid_field", 777, &trace_state);
941       ret = synth_event_add_val("next_comm_field", (u64)"silly putty",
942                                 &trace_state);
943       ret = synth_event_add_val("ts_ns", 1000000, &trace_state);
944       ret = synth_event_add_val("ts_ms", 1000, &trace_state);
945       ret = synth_event_add_val("cpu", smp_processor_id(), &trace_state);
946       ret = synth_event_add_val("my_string_field", (u64)"thneed_9",
947                                 &trace_state);
948       ret = synth_event_add_val("my_int_field", 3999, &trace_state);
949
950Note that synth_event_add_next_val() and synth_event_add_val() are
951incompatible if used within the same trace of an event - either one
952can be used but not both at the same time.
953
954Finally, the event won't be actually traced until it's 'closed',
955which is done using synth_event_trace_end(), which takes only the
956struct synth_event_trace_state object used in the previous calls::
957
958       ret = synth_event_trace_end(&trace_state);
959
960Note that synth_event_trace_end() must be called at the end regardless
961of whether any of the add calls failed (say due to a bad field name
962being passed in).
963
9647.3 Dynamically creating kprobe and kretprobe event definitions
965---------------------------------------------------------------
966
967To create a kprobe or kretprobe trace event from kernel code, the
968kprobe_event_gen_cmd_start() or kretprobe_event_gen_cmd_start()
969functions can be used.
970
971To create a kprobe event, an empty or partially empty kprobe event
972should first be created using kprobe_event_gen_cmd_start().  The name
973of the event and the probe location should be specified along with one
974or args each representing a probe field should be supplied to this
975function.  Before calling kprobe_event_gen_cmd_start(), the user
976should create and initialize a dynevent_cmd object using
977kprobe_event_cmd_init().
978
979For example, to create a new "schedtest" kprobe event with two fields::
980
981  struct dynevent_cmd cmd;
982  char *buf;
983
984  /* Create a buffer to hold the generated command */
985  buf = kzalloc(MAX_DYNEVENT_CMD_LEN, GFP_KERNEL);
986
987  /* Before generating the command, initialize the cmd object */
988  kprobe_event_cmd_init(&cmd, buf, MAX_DYNEVENT_CMD_LEN);
989
990  /*
991   * Define the gen_kprobe_test event with the first 2 kprobe
992   * fields.
993   */
994  ret = kprobe_event_gen_cmd_start(&cmd, "gen_kprobe_test", "do_sys_open",
995                                   "dfd=%ax", "filename=%dx");
996
997Once the kprobe event object has been created, it can then be
998populated with more fields.  Fields can be added using
999kprobe_event_add_fields(), supplying the dynevent_cmd object along
1000with a variable arg list of probe fields.  For example, to add a
1001couple additional fields, the following call could be made::
1002
1003  ret = kprobe_event_add_fields(&cmd, "flags=%cx", "mode=+4($stack)");
1004
1005Once all the fields have been added, the event should be finalized and
1006registered by calling the kprobe_event_gen_cmd_end() or
1007kretprobe_event_gen_cmd_end() functions, depending on whether a kprobe
1008or kretprobe command was started::
1009
1010  ret = kprobe_event_gen_cmd_end(&cmd);
1011
1012or::
1013
1014  ret = kretprobe_event_gen_cmd_end(&cmd);
1015
1016At this point, the event object is ready to be used for tracing new
1017events.
1018
1019Similarly, a kretprobe event can be created using
1020kretprobe_event_gen_cmd_start() with a probe name and location and
1021additional params such as $retval::
1022
1023  ret = kretprobe_event_gen_cmd_start(&cmd, "gen_kretprobe_test",
1024                                      "do_sys_open", "$retval");
1025
1026Similar to the synthetic event case, code like the following can be
1027used to enable the newly created kprobe event::
1028
1029  gen_kprobe_test = trace_get_event_file(NULL, "kprobes", "gen_kprobe_test");
1030
1031  ret = trace_array_set_clr_event(gen_kprobe_test->tr,
1032                                  "kprobes", "gen_kprobe_test", true);
1033
1034Finally, also similar to synthetic events, the following code can be
1035used to give the kprobe event file back and delete the event::
1036
1037  trace_put_event_file(gen_kprobe_test);
1038
1039  ret = kprobe_event_delete("gen_kprobe_test");
1040
10417.4 The "dynevent_cmd" low-level API
1042------------------------------------
1043
1044Both the in-kernel synthetic event and kprobe interfaces are built on
1045top of a lower-level "dynevent_cmd" interface.  This interface is
1046meant to provide the basis for higher-level interfaces such as the
1047synthetic and kprobe interfaces, which can be used as examples.
1048
1049The basic idea is simple and amounts to providing a general-purpose
1050layer that can be used to generate trace event commands.  The
1051generated command strings can then be passed to the command-parsing
1052and event creation code that already exists in the trace event
1053subsystem for creating the corresponding trace events.
1054
1055In a nutshell, the way it works is that the higher-level interface
1056code creates a struct dynevent_cmd object, then uses a couple
1057functions, dynevent_arg_add() and dynevent_arg_pair_add() to build up
1058a command string, which finally causes the command to be executed
1059using the dynevent_create() function.  The details of the interface
1060are described below.
1061
1062The first step in building a new command string is to create and
1063initialize an instance of a dynevent_cmd.  Here, for instance, we
1064create a dynevent_cmd on the stack and initialize it::
1065
1066  struct dynevent_cmd cmd;
1067  char *buf;
1068  int ret;
1069
1070  buf = kzalloc(MAX_DYNEVENT_CMD_LEN, GFP_KERNEL);
1071
1072  dynevent_cmd_init(cmd, buf, maxlen, DYNEVENT_TYPE_FOO,
1073                    foo_event_run_command);
1074
1075The dynevent_cmd initialization needs to be given a user-specified
1076buffer and the length of the buffer (MAX_DYNEVENT_CMD_LEN can be used
1077for this purpose - at 2k it's generally too big to be comfortably put
1078on the stack, so is dynamically allocated), a dynevent type id, which
1079is meant to be used to check that further API calls are for the
1080correct command type, and a pointer to an event-specific run_command()
1081callback that will be called to actually execute the event-specific
1082command function.
1083
1084Once that's done, the command string can be built up by successive
1085calls to argument-adding functions.
1086
1087To add a single argument, define and initialize a struct dynevent_arg
1088or struct dynevent_arg_pair object.  Here's an example of the simplest
1089possible arg addition, which is simply to append the given string as
1090a whitespace-separated argument to the command::
1091
1092  struct dynevent_arg arg;
1093
1094  dynevent_arg_init(&arg, NULL, 0);
1095
1096  arg.str = name;
1097
1098  ret = dynevent_arg_add(cmd, &arg);
1099
1100The arg object is first initialized using dynevent_arg_init() and in
1101this case the parameters are NULL or 0, which means there's no
1102optional sanity-checking function or separator appended to the end of
1103the arg.
1104
1105Here's another more complicated example using an 'arg pair', which is
1106used to create an argument that consists of a couple components added
1107together as a unit, for example, a 'type field_name;' arg or a simple
1108expression arg e.g. 'flags=%cx'::
1109
1110  struct dynevent_arg_pair arg_pair;
1111
1112  dynevent_arg_pair_init(&arg_pair, dynevent_foo_check_arg_fn, 0, ';');
1113
1114  arg_pair.lhs = type;
1115  arg_pair.rhs = name;
1116
1117  ret = dynevent_arg_pair_add(cmd, &arg_pair);
1118
1119Again, the arg_pair is first initialized, in this case with a callback
1120function used to check the sanity of the args (for example, that
1121neither part of the pair is NULL), along with a character to be used
1122to add an operator between the pair (here none) and a separator to be
1123appended onto the end of the arg pair (here ';').
1124
1125There's also a dynevent_str_add() function that can be used to simply
1126add a string as-is, with no spaces, delimiters, or arg check.
1127
1128Any number of dynevent_*_add() calls can be made to build up the string
1129(until its length surpasses cmd->maxlen).  When all the arguments have
1130been added and the command string is complete, the only thing left to
1131do is run the command, which happens by simply calling
1132dynevent_create()::
1133
1134  ret = dynevent_create(&cmd);
1135
1136At that point, if the return value is 0, the dynamic event has been
1137created and is ready to use.
1138
1139See the dynevent_cmd function definitions themselves for the details
1140of the API.
1141