12345678910111213141516171819202122232425262728293031323334353637383940414243444546474849505152535455565758596061626364656667686970717273747576777879808182838485868788899091929394959697989910010110210310410510610710810911011111211311411511611711811912012112212312412512612712812913013113213313413513613713813914014114214314414514614714814915015115215315415515615715815916016116216316416516616716816917017117217317417517617717817918018118218318418518618718818919019119219319419519619719819920020120220320420520620720820921021121221321421521621721821922022122222322422522622722822923023123223323423523623723823924024124224324424524624724824925025125225325425525625725825926026126226326426526626726826927027127227327427527627727827928028128228328428528628728828929029129229329429529629729829930030130230330430530630730830931031131231331431531631731831932032132232332432532632732832933033133233333433533633733833934034134234334434534634734834935035135235335435535635735835936036136236336436536636736836937037137237337437537637737837938038138238338438538638738838939039139239339439539639739839940040140240340440540640740840941041141241341441541641741841942042142242342442542642742842943043143243343443543643743843944044144244344444544644744844945045145245345445545645745845946046146246346446546646746846947047147247347447547647747847948048148248348448548648748848949049149249349449549649749849950050150250350450550650750850951051151251351451551651751851952052152252352452552652752852953053153253353453553653753853954054154254354454554654754854955055155255355455555655755855956056156256356456556656756856957057157257357457557657757857958058158258358458558658758858959059159259359459559659759859960060160260360460560660760860961061161261361461561661761861962062162262362462562662762862963063163263363463563663763863964064164264364464564664764864965065165265365465565665765865966066166266366466566666766866967067167267367467567667767867968068168268368468568668768868969069169269369469569669769869970070170270370470570670770870971071171271371471571671771871972072172272372472572672772872973073173273373473573673773873974074174274374474574674774874975075175275375475575675775875976076176276376476576676776876977077177277377477577677777877978078178278378478578678778878979079179279379479579679779879980080180280380480580680780880981081181281381481581681781881982082182282382482582682782882983083183283383483583683783883984084184284384484584684784884985085185285385485585685785885986086186286386486586686786886987087187287387487587687787887988088188288388488588688788888989089189289389489589689789889990090190290390490590690790890991091191291391491591691791891992092192292392492592692792892993093193293393493593693793893994094194294394494594694794894995095195295395495595695795895996096196296396496596696796896997097197297397497597697797897998098198298398498598698798898999099199299399499599699799899910001001100210031004100510061007100810091010101110121013101410151016101710181019102010211022102310241025102610271028102910301031103210331034103510361037103810391040104110421043104410451046104710481049105010511052105310541055105610571058105910601061106210631064106510661067106810691070107110721073 |
- =============
- Event Tracing
- =============
- :Author: Theodore Ts'o
- :Updated: Li Zefan and Tom Zanussi
- 1. Introduction
- ===============
- Tracepoints (see Documentation/trace/tracepoints.rst) can be used
- without creating custom kernel modules to register probe functions
- using the event tracing infrastructure.
- Not all tracepoints can be traced using the event tracing system;
- the kernel developer must provide code snippets which define how the
- tracing information is saved into the tracing buffer, and how the
- tracing information should be printed.
- 2. Using Event Tracing
- ======================
- 2.1 Via the 'set_event' interface
- ---------------------------------
- The events which are available for tracing can be found in the file
- /sys/kernel/debug/tracing/available_events.
- To enable a particular event, such as 'sched_wakeup', simply echo it
- to /sys/kernel/debug/tracing/set_event. For example::
- # echo sched_wakeup >> /sys/kernel/debug/tracing/set_event
- .. Note:: '>>' is necessary, otherwise it will firstly disable all the events.
- To disable an event, echo the event name to the set_event file prefixed
- with an exclamation point::
- # echo '!sched_wakeup' >> /sys/kernel/debug/tracing/set_event
- To disable all events, echo an empty line to the set_event file::
- # echo > /sys/kernel/debug/tracing/set_event
- To enable all events, echo ``*:*`` or ``*:`` to the set_event file::
- # echo *:* > /sys/kernel/debug/tracing/set_event
- The events are organized into subsystems, such as ext4, irq, sched,
- etc., and a full event name looks like this: <subsystem>:<event>. The
- subsystem name is optional, but it is displayed in the available_events
- file. All of the events in a subsystem can be specified via the syntax
- ``<subsystem>:*``; for example, to enable all irq events, you can use the
- command::
- # echo 'irq:*' > /sys/kernel/debug/tracing/set_event
- 2.2 Via the 'enable' toggle
- ---------------------------
- The events available are also listed in /sys/kernel/debug/tracing/events/ hierarchy
- of directories.
- To enable event 'sched_wakeup'::
- # echo 1 > /sys/kernel/debug/tracing/events/sched/sched_wakeup/enable
- To disable it::
- # echo 0 > /sys/kernel/debug/tracing/events/sched/sched_wakeup/enable
- To enable all events in sched subsystem::
- # echo 1 > /sys/kernel/debug/tracing/events/sched/enable
- To enable all events::
- # echo 1 > /sys/kernel/debug/tracing/events/enable
- When reading one of these enable files, there are four results:
- - 0 - all events this file affects are disabled
- - 1 - all events this file affects are enabled
- - X - there is a mixture of events enabled and disabled
- - ? - this file does not affect any event
- 2.3 Boot option
- ---------------
- In order to facilitate early boot debugging, use boot option::
- trace_event=[event-list]
- event-list is a comma separated list of events. See section 2.1 for event
- format.
- 3. Defining an event-enabled tracepoint
- =======================================
- See The example provided in samples/trace_events
- 4. Event formats
- ================
- Each trace event has a 'format' file associated with it that contains
- a description of each field in a logged event. This information can
- be used to parse the binary trace stream, and is also the place to
- find the field names that can be used in event filters (see section 5).
- It also displays the format string that will be used to print the
- event in text mode, along with the event name and ID used for
- profiling.
- Every event has a set of ``common`` fields associated with it; these are
- the fields prefixed with ``common_``. The other fields vary between
- events and correspond to the fields defined in the TRACE_EVENT
- definition for that event.
- Each field in the format has the form::
- field:field-type field-name; offset:N; size:N;
- where offset is the offset of the field in the trace record and size
- is the size of the data item, in bytes.
- For example, here's the information displayed for the 'sched_wakeup'
- event::
- # cat /sys/kernel/debug/tracing/events/sched/sched_wakeup/format
- name: sched_wakeup
- ID: 60
- format:
- field:unsigned short common_type; offset:0; size:2;
- field:unsigned char common_flags; offset:2; size:1;
- field:unsigned char common_preempt_count; offset:3; size:1;
- field:int common_pid; offset:4; size:4;
- field:int common_tgid; offset:8; size:4;
- field:char comm[TASK_COMM_LEN]; offset:12; size:16;
- field:pid_t pid; offset:28; size:4;
- field:int prio; offset:32; size:4;
- field:int success; offset:36; size:4;
- field:int cpu; offset:40; size:4;
- print fmt: "task %s:%d [%d] success=%d [%03d]", REC->comm, REC->pid,
- REC->prio, REC->success, REC->cpu
- This event contains 10 fields, the first 5 common and the remaining 5
- event-specific. All the fields for this event are numeric, except for
- 'comm' which is a string, a distinction important for event filtering.
- 5. Event filtering
- ==================
- Trace events can be filtered in the kernel by associating boolean
- 'filter expressions' with them. As soon as an event is logged into
- the trace buffer, its fields are checked against the filter expression
- associated with that event type. An event with field values that
- 'match' the filter will appear in the trace output, and an event whose
- values don't match will be discarded. An event with no filter
- associated with it matches everything, and is the default when no
- filter has been set for an event.
- 5.1 Expression syntax
- ---------------------
- A filter expression consists of one or more 'predicates' that can be
- combined using the logical operators '&&' and '||'. A predicate is
- simply a clause that compares the value of a field contained within a
- logged event with a constant value and returns either 0 or 1 depending
- on whether the field value matched (1) or didn't match (0)::
- field-name relational-operator value
- Parentheses can be used to provide arbitrary logical groupings and
- double-quotes can be used to prevent the shell from interpreting
- operators as shell metacharacters.
- The field-names available for use in filters can be found in the
- 'format' files for trace events (see section 4).
- The relational-operators depend on the type of the field being tested:
- The operators available for numeric fields are:
- ==, !=, <, <=, >, >=, &
- And for string fields they are:
- ==, !=, ~
- The glob (~) accepts a wild card character (\*,?) and character classes
- ([). For example::
- prev_comm ~ "*sh"
- prev_comm ~ "sh*"
- prev_comm ~ "*sh*"
- prev_comm ~ "ba*sh"
- If the field is a pointer that points into user space (for example
- "filename" from sys_enter_openat), then you have to append ".ustring" to the
- field name::
- filename.ustring ~ "password"
- As the kernel will have to know how to retrieve the memory that the pointer
- is at from user space.
- 5.2 Setting filters
- -------------------
- A filter for an individual event is set by writing a filter expression
- to the 'filter' file for the given event.
- For example::
- # cd /sys/kernel/debug/tracing/events/sched/sched_wakeup
- # echo "common_preempt_count > 4" > filter
- A slightly more involved example::
- # cd /sys/kernel/debug/tracing/events/signal/signal_generate
- # echo "((sig >= 10 && sig < 15) || sig == 17) && comm != bash" > filter
- If there is an error in the expression, you'll get an 'Invalid
- argument' error when setting it, and the erroneous string along with
- an error message can be seen by looking at the filter e.g.::
- # cd /sys/kernel/debug/tracing/events/signal/signal_generate
- # echo "((sig >= 10 && sig < 15) || dsig == 17) && comm != bash" > filter
- -bash: echo: write error: Invalid argument
- # cat filter
- ((sig >= 10 && sig < 15) || dsig == 17) && comm != bash
- ^
- parse_error: Field not found
- Currently the caret ('^') for an error always appears at the beginning of
- the filter string; the error message should still be useful though
- even without more accurate position info.
- 5.2.1 Filter limitations
- ------------------------
- If a filter is placed on a string pointer ``(char *)`` that does not point
- to a string on the ring buffer, but instead points to kernel or user space
- memory, then, for safety reasons, at most 1024 bytes of the content is
- copied onto a temporary buffer to do the compare. If the copy of the memory
- faults (the pointer points to memory that should not be accessed), then the
- string compare will be treated as not matching.
- 5.3 Clearing filters
- --------------------
- To clear the filter for an event, write a '0' to the event's filter
- file.
- To clear the filters for all events in a subsystem, write a '0' to the
- subsystem's filter file.
- 5.3 Subsystem filters
- ---------------------
- For convenience, filters for every event in a subsystem can be set or
- cleared as a group by writing a filter expression into the filter file
- at the root of the subsystem. Note however, that if a filter for any
- event within the subsystem lacks a field specified in the subsystem
- filter, or if the filter can't be applied for any other reason, the
- filter for that event will retain its previous setting. This can
- result in an unintended mixture of filters which could lead to
- confusing (to the user who might think different filters are in
- effect) trace output. Only filters that reference just the common
- fields can be guaranteed to propagate successfully to all events.
- Here are a few subsystem filter examples that also illustrate the
- above points:
- Clear the filters on all events in the sched subsystem::
- # cd /sys/kernel/debug/tracing/events/sched
- # echo 0 > filter
- # cat sched_switch/filter
- none
- # cat sched_wakeup/filter
- none
- Set a filter using only common fields for all events in the sched
- subsystem (all events end up with the same filter)::
- # cd /sys/kernel/debug/tracing/events/sched
- # echo common_pid == 0 > filter
- # cat sched_switch/filter
- common_pid == 0
- # cat sched_wakeup/filter
- common_pid == 0
- Attempt to set a filter using a non-common field for all events in the
- sched subsystem (all events but those that have a prev_pid field retain
- their old filters)::
- # cd /sys/kernel/debug/tracing/events/sched
- # echo prev_pid == 0 > filter
- # cat sched_switch/filter
- prev_pid == 0
- # cat sched_wakeup/filter
- common_pid == 0
- 5.4 PID filtering
- -----------------
- The set_event_pid file in the same directory as the top events directory
- exists, will filter all events from tracing any task that does not have the
- PID listed in the set_event_pid file.
- ::
- # cd /sys/kernel/debug/tracing
- # echo $$ > set_event_pid
- # echo 1 > events/enable
- Will only trace events for the current task.
- To add more PIDs without losing the PIDs already included, use '>>'.
- ::
- # echo 123 244 1 >> set_event_pid
- 6. Event triggers
- =================
- Trace events can be made to conditionally invoke trigger 'commands'
- which can take various forms and are described in detail below;
- examples would be enabling or disabling other trace events or invoking
- a stack trace whenever the trace event is hit. Whenever a trace event
- with attached triggers is invoked, the set of trigger commands
- associated with that event is invoked. Any given trigger can
- additionally have an event filter of the same form as described in
- section 5 (Event filtering) associated with it - the command will only
- be invoked if the event being invoked passes the associated filter.
- If no filter is associated with the trigger, it always passes.
- Triggers are added to and removed from a particular event by writing
- trigger expressions to the 'trigger' file for the given event.
- A given event can have any number of triggers associated with it,
- subject to any restrictions that individual commands may have in that
- regard.
- Event triggers are implemented on top of "soft" mode, which means that
- whenever a trace event has one or more triggers associated with it,
- the event is activated even if it isn't actually enabled, but is
- disabled in a "soft" mode. That is, the tracepoint will be called,
- but just will not be traced, unless of course it's actually enabled.
- This scheme allows triggers to be invoked even for events that aren't
- enabled, and also allows the current event filter implementation to be
- used for conditionally invoking triggers.
- The syntax for event triggers is roughly based on the syntax for
- set_ftrace_filter 'ftrace filter commands' (see the 'Filter commands'
- section of Documentation/trace/ftrace.rst), but there are major
- differences and the implementation isn't currently tied to it in any
- way, so beware about making generalizations between the two.
- .. Note::
- Writing into trace_marker (See Documentation/trace/ftrace.rst)
- can also enable triggers that are written into
- /sys/kernel/tracing/events/ftrace/print/trigger
- 6.1 Expression syntax
- ---------------------
- Triggers are added by echoing the command to the 'trigger' file::
- # echo 'command[:count] [if filter]' > trigger
- Triggers are removed by echoing the same command but starting with '!'
- to the 'trigger' file::
- # echo '!command[:count] [if filter]' > trigger
- The [if filter] part isn't used in matching commands when removing, so
- leaving that off in a '!' command will accomplish the same thing as
- having it in.
- The filter syntax is the same as that described in the 'Event
- filtering' section above.
- For ease of use, writing to the trigger file using '>' currently just
- adds or removes a single trigger and there's no explicit '>>' support
- ('>' actually behaves like '>>') or truncation support to remove all
- triggers (you have to use '!' for each one added.)
- 6.2 Supported trigger commands
- ------------------------------
- The following commands are supported:
- - enable_event/disable_event
- These commands can enable or disable another trace event whenever
- the triggering event is hit. When these commands are registered,
- the other trace event is activated, but disabled in a "soft" mode.
- That is, the tracepoint will be called, but just will not be traced.
- The event tracepoint stays in this mode as long as there's a trigger
- in effect that can trigger it.
- For example, the following trigger causes kmalloc events to be
- traced when a read system call is entered, and the :1 at the end
- specifies that this enablement happens only once::
- # echo 'enable_event:kmem:kmalloc:1' > \
- /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/trigger
- The following trigger causes kmalloc events to stop being traced
- when a read system call exits. This disablement happens on every
- read system call exit::
- # echo 'disable_event:kmem:kmalloc' > \
- /sys/kernel/debug/tracing/events/syscalls/sys_exit_read/trigger
- The format is::
- enable_event:<system>:<event>[:count]
- disable_event:<system>:<event>[:count]
- To remove the above commands::
- # echo '!enable_event:kmem:kmalloc:1' > \
- /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/trigger
- # echo '!disable_event:kmem:kmalloc' > \
- /sys/kernel/debug/tracing/events/syscalls/sys_exit_read/trigger
- Note that there can be any number of enable/disable_event triggers
- per triggering event, but there can only be one trigger per
- triggered event. e.g. sys_enter_read can have triggers enabling both
- kmem:kmalloc and sched:sched_switch, but can't have two kmem:kmalloc
- versions such as kmem:kmalloc and kmem:kmalloc:1 or 'kmem:kmalloc if
- bytes_req == 256' and 'kmem:kmalloc if bytes_alloc == 256' (they
- could be combined into a single filter on kmem:kmalloc though).
- - stacktrace
- This command dumps a stacktrace in the trace buffer whenever the
- triggering event occurs.
- For example, the following trigger dumps a stacktrace every time the
- kmalloc tracepoint is hit::
- # echo 'stacktrace' > \
- /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
- The following trigger dumps a stacktrace the first 5 times a kmalloc
- request happens with a size >= 64K::
- # echo 'stacktrace:5 if bytes_req >= 65536' > \
- /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
- The format is::
- stacktrace[:count]
- To remove the above commands::
- # echo '!stacktrace' > \
- /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
- # echo '!stacktrace:5 if bytes_req >= 65536' > \
- /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
- The latter can also be removed more simply by the following (without
- the filter)::
- # echo '!stacktrace:5' > \
- /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
- Note that there can be only one stacktrace trigger per triggering
- event.
- - snapshot
- This command causes a snapshot to be triggered whenever the
- triggering event occurs.
- The following command creates a snapshot every time a block request
- queue is unplugged with a depth > 1. If you were tracing a set of
- events or functions at the time, the snapshot trace buffer would
- capture those events when the trigger event occurred::
- # echo 'snapshot if nr_rq > 1' > \
- /sys/kernel/debug/tracing/events/block/block_unplug/trigger
- To only snapshot once::
- # echo 'snapshot:1 if nr_rq > 1' > \
- /sys/kernel/debug/tracing/events/block/block_unplug/trigger
- To remove the above commands::
- # echo '!snapshot if nr_rq > 1' > \
- /sys/kernel/debug/tracing/events/block/block_unplug/trigger
- # echo '!snapshot:1 if nr_rq > 1' > \
- /sys/kernel/debug/tracing/events/block/block_unplug/trigger
- Note that there can be only one snapshot trigger per triggering
- event.
- - traceon/traceoff
- These commands turn tracing on and off when the specified events are
- hit. The parameter determines how many times the tracing system is
- turned on and off. If unspecified, there is no limit.
- The following command turns tracing off the first time a block
- request queue is unplugged with a depth > 1. If you were tracing a
- set of events or functions at the time, you could then examine the
- trace buffer to see the sequence of events that led up to the
- trigger event::
- # echo 'traceoff:1 if nr_rq > 1' > \
- /sys/kernel/debug/tracing/events/block/block_unplug/trigger
- To always disable tracing when nr_rq > 1::
- # echo 'traceoff if nr_rq > 1' > \
- /sys/kernel/debug/tracing/events/block/block_unplug/trigger
- To remove the above commands::
- # echo '!traceoff:1 if nr_rq > 1' > \
- /sys/kernel/debug/tracing/events/block/block_unplug/trigger
- # echo '!traceoff if nr_rq > 1' > \
- /sys/kernel/debug/tracing/events/block/block_unplug/trigger
- Note that there can be only one traceon or traceoff trigger per
- triggering event.
- - hist
- This command aggregates event hits into a hash table keyed on one or
- more trace event format fields (or stacktrace) and a set of running
- totals derived from one or more trace event format fields and/or
- event counts (hitcount).
- See Documentation/trace/histogram.rst for details and examples.
- 7. In-kernel trace event API
- ============================
- In most cases, the command-line interface to trace events is more than
- sufficient. Sometimes, however, applications might find the need for
- more complex relationships than can be expressed through a simple
- series of linked command-line expressions, or putting together sets of
- commands may be simply too cumbersome. An example might be an
- application that needs to 'listen' to the trace stream in order to
- maintain an in-kernel state machine detecting, for instance, when an
- illegal kernel state occurs in the scheduler.
- The trace event subsystem provides an in-kernel API allowing modules
- or other kernel code to generate user-defined 'synthetic' events at
- will, which can be used to either augment the existing trace stream
- and/or signal that a particular important state has occurred.
- A similar in-kernel API is also available for creating kprobe and
- kretprobe events.
- Both the synthetic event and k/ret/probe event APIs are built on top
- of a lower-level "dynevent_cmd" event command API, which is also
- available for more specialized applications, or as the basis of other
- higher-level trace event APIs.
- The API provided for these purposes is describe below and allows the
- following:
- - dynamically creating synthetic event definitions
- - dynamically creating kprobe and kretprobe event definitions
- - tracing synthetic events from in-kernel code
- - the low-level "dynevent_cmd" API
- 7.1 Dyamically creating synthetic event definitions
- ---------------------------------------------------
- There are a couple ways to create a new synthetic event from a kernel
- module or other kernel code.
- The first creates the event in one step, using synth_event_create().
- In this method, the name of the event to create and an array defining
- the fields is supplied to synth_event_create(). If successful, a
- synthetic event with that name and fields will exist following that
- call. For example, to create a new "schedtest" synthetic event::
- ret = synth_event_create("schedtest", sched_fields,
- ARRAY_SIZE(sched_fields), THIS_MODULE);
- The sched_fields param in this example points to an array of struct
- synth_field_desc, each of which describes an event field by type and
- name::
- static struct synth_field_desc sched_fields[] = {
- { .type = "pid_t", .name = "next_pid_field" },
- { .type = "char[16]", .name = "next_comm_field" },
- { .type = "u64", .name = "ts_ns" },
- { .type = "u64", .name = "ts_ms" },
- { .type = "unsigned int", .name = "cpu" },
- { .type = "char[64]", .name = "my_string_field" },
- { .type = "int", .name = "my_int_field" },
- };
- See synth_field_size() for available types.
- If field_name contains [n], the field is considered to be a static array.
- If field_names contains[] (no subscript), the field is considered to
- be a dynamic array, which will only take as much space in the event as
- is required to hold the array.
- Because space for an event is reserved before assigning field values
- to the event, using dynamic arrays implies that the piecewise
- in-kernel API described below can't be used with dynamic arrays. The
- other non-piecewise in-kernel APIs can, however, be used with dynamic
- arrays.
- If the event is created from within a module, a pointer to the module
- must be passed to synth_event_create(). This will ensure that the
- trace buffer won't contain unreadable events when the module is
- removed.
- At this point, the event object is ready to be used for generating new
- events.
- In the second method, the event is created in several steps. This
- allows events to be created dynamically and without the need to create
- and populate an array of fields beforehand.
- To use this method, an empty or partially empty synthetic event should
- first be created using synth_event_gen_cmd_start() or
- synth_event_gen_cmd_array_start(). For synth_event_gen_cmd_start(),
- the name of the event along with one or more pairs of args each pair
- representing a 'type field_name;' field specification should be
- supplied. For synth_event_gen_cmd_array_start(), the name of the
- event along with an array of struct synth_field_desc should be
- supplied. Before calling synth_event_gen_cmd_start() or
- synth_event_gen_cmd_array_start(), the user should create and
- initialize a dynevent_cmd object using synth_event_cmd_init().
- For example, to create a new "schedtest" synthetic event with two
- fields::
- struct dynevent_cmd cmd;
- char *buf;
- /* Create a buffer to hold the generated command */
- buf = kzalloc(MAX_DYNEVENT_CMD_LEN, GFP_KERNEL);
- /* Before generating the command, initialize the cmd object */
- synth_event_cmd_init(&cmd, buf, MAX_DYNEVENT_CMD_LEN);
- ret = synth_event_gen_cmd_start(&cmd, "schedtest", THIS_MODULE,
- "pid_t", "next_pid_field",
- "u64", "ts_ns");
- Alternatively, using an array of struct synth_field_desc fields
- containing the same information::
- ret = synth_event_gen_cmd_array_start(&cmd, "schedtest", THIS_MODULE,
- fields, n_fields);
- Once the synthetic event object has been created, it can then be
- populated with more fields. Fields are added one by one using
- synth_event_add_field(), supplying the dynevent_cmd object, a field
- type, and a field name. For example, to add a new int field named
- "intfield", the following call should be made::
- ret = synth_event_add_field(&cmd, "int", "intfield");
- See synth_field_size() for available types. If field_name contains [n]
- the field is considered to be an array.
- A group of fields can also be added all at once using an array of
- synth_field_desc with add_synth_fields(). For example, this would add
- just the first four sched_fields::
- ret = synth_event_add_fields(&cmd, sched_fields, 4);
- If you already have a string of the form 'type field_name',
- synth_event_add_field_str() can be used to add it as-is; it will
- also automatically append a ';' to the string.
- Once all the fields have been added, the event should be finalized and
- registered by calling the synth_event_gen_cmd_end() function::
- ret = synth_event_gen_cmd_end(&cmd);
- At this point, the event object is ready to be used for tracing new
- events.
- 7.2 Tracing synthetic events from in-kernel code
- ------------------------------------------------
- To trace a synthetic event, there are several options. The first
- option is to trace the event in one call, using synth_event_trace()
- with a variable number of values, or synth_event_trace_array() with an
- array of values to be set. A second option can be used to avoid the
- need for a pre-formed array of values or list of arguments, via
- synth_event_trace_start() and synth_event_trace_end() along with
- synth_event_add_next_val() or synth_event_add_val() to add the values
- piecewise.
- 7.2.1 Tracing a synthetic event all at once
- -------------------------------------------
- To trace a synthetic event all at once, the synth_event_trace() or
- synth_event_trace_array() functions can be used.
- The synth_event_trace() function is passed the trace_event_file
- representing the synthetic event (which can be retrieved using
- trace_get_event_file() using the synthetic event name, "synthetic" as
- the system name, and the trace instance name (NULL if using the global
- trace array)), along with an variable number of u64 args, one for each
- synthetic event field, and the number of values being passed.
- So, to trace an event corresponding to the synthetic event definition
- above, code like the following could be used::
- ret = synth_event_trace(create_synth_test, 7, /* number of values */
- 444, /* next_pid_field */
- (u64)"clackers", /* next_comm_field */
- 1000000, /* ts_ns */
- 1000, /* ts_ms */
- smp_processor_id(),/* cpu */
- (u64)"Thneed", /* my_string_field */
- 999); /* my_int_field */
- All vals should be cast to u64, and string vals are just pointers to
- strings, cast to u64. Strings will be copied into space reserved in
- the event for the string, using these pointers.
- Alternatively, the synth_event_trace_array() function can be used to
- accomplish the same thing. It is passed the trace_event_file
- representing the synthetic event (which can be retrieved using
- trace_get_event_file() using the synthetic event name, "synthetic" as
- the system name, and the trace instance name (NULL if using the global
- trace array)), along with an array of u64, one for each synthetic
- event field.
- To trace an event corresponding to the synthetic event definition
- above, code like the following could be used::
- u64 vals[7];
- vals[0] = 777; /* next_pid_field */
- vals[1] = (u64)"tiddlywinks"; /* next_comm_field */
- vals[2] = 1000000; /* ts_ns */
- vals[3] = 1000; /* ts_ms */
- vals[4] = smp_processor_id(); /* cpu */
- vals[5] = (u64)"thneed"; /* my_string_field */
- vals[6] = 398; /* my_int_field */
- The 'vals' array is just an array of u64, the number of which must
- match the number of field in the synthetic event, and which must be in
- the same order as the synthetic event fields.
- All vals should be cast to u64, and string vals are just pointers to
- strings, cast to u64. Strings will be copied into space reserved in
- the event for the string, using these pointers.
- In order to trace a synthetic event, a pointer to the trace event file
- is needed. The trace_get_event_file() function can be used to get
- it - it will find the file in the given trace instance (in this case
- NULL since the top trace array is being used) while at the same time
- preventing the instance containing it from going away::
- schedtest_event_file = trace_get_event_file(NULL, "synthetic",
- "schedtest");
- Before tracing the event, it should be enabled in some way, otherwise
- the synthetic event won't actually show up in the trace buffer.
- To enable a synthetic event from the kernel, trace_array_set_clr_event()
- can be used (which is not specific to synthetic events, so does need
- the "synthetic" system name to be specified explicitly).
- To enable the event, pass 'true' to it::
- trace_array_set_clr_event(schedtest_event_file->tr,
- "synthetic", "schedtest", true);
- To disable it pass false::
- trace_array_set_clr_event(schedtest_event_file->tr,
- "synthetic", "schedtest", false);
- Finally, synth_event_trace_array() can be used to actually trace the
- event, which should be visible in the trace buffer afterwards::
- ret = synth_event_trace_array(schedtest_event_file, vals,
- ARRAY_SIZE(vals));
- To remove the synthetic event, the event should be disabled, and the
- trace instance should be 'put' back using trace_put_event_file()::
- trace_array_set_clr_event(schedtest_event_file->tr,
- "synthetic", "schedtest", false);
- trace_put_event_file(schedtest_event_file);
- If those have been successful, synth_event_delete() can be called to
- remove the event::
- ret = synth_event_delete("schedtest");
- 7.2.2 Tracing a synthetic event piecewise
- -----------------------------------------
- To trace a synthetic using the piecewise method described above, the
- synth_event_trace_start() function is used to 'open' the synthetic
- event trace::
- struct synth_event_trace_state trace_state;
- ret = synth_event_trace_start(schedtest_event_file, &trace_state);
- It's passed the trace_event_file representing the synthetic event
- using the same methods as described above, along with a pointer to a
- struct synth_event_trace_state object, which will be zeroed before use and
- used to maintain state between this and following calls.
- Once the event has been opened, which means space for it has been
- reserved in the trace buffer, the individual fields can be set. There
- are two ways to do that, either one after another for each field in
- the event, which requires no lookups, or by name, which does. The
- tradeoff is flexibility in doing the assignments vs the cost of a
- lookup per field.
- To assign the values one after the other without lookups,
- synth_event_add_next_val() should be used. Each call is passed the
- same synth_event_trace_state object used in the synth_event_trace_start(),
- along with the value to set the next field in the event. After each
- field is set, the 'cursor' points to the next field, which will be set
- by the subsequent call, continuing until all the fields have been set
- in order. The same sequence of calls as in the above examples using
- this method would be (without error-handling code)::
- /* next_pid_field */
- ret = synth_event_add_next_val(777, &trace_state);
- /* next_comm_field */
- ret = synth_event_add_next_val((u64)"slinky", &trace_state);
- /* ts_ns */
- ret = synth_event_add_next_val(1000000, &trace_state);
- /* ts_ms */
- ret = synth_event_add_next_val(1000, &trace_state);
- /* cpu */
- ret = synth_event_add_next_val(smp_processor_id(), &trace_state);
- /* my_string_field */
- ret = synth_event_add_next_val((u64)"thneed_2.01", &trace_state);
- /* my_int_field */
- ret = synth_event_add_next_val(395, &trace_state);
- To assign the values in any order, synth_event_add_val() should be
- used. Each call is passed the same synth_event_trace_state object used in
- the synth_event_trace_start(), along with the field name of the field
- to set and the value to set it to. The same sequence of calls as in
- the above examples using this method would be (without error-handling
- code)::
- ret = synth_event_add_val("next_pid_field", 777, &trace_state);
- ret = synth_event_add_val("next_comm_field", (u64)"silly putty",
- &trace_state);
- ret = synth_event_add_val("ts_ns", 1000000, &trace_state);
- ret = synth_event_add_val("ts_ms", 1000, &trace_state);
- ret = synth_event_add_val("cpu", smp_processor_id(), &trace_state);
- ret = synth_event_add_val("my_string_field", (u64)"thneed_9",
- &trace_state);
- ret = synth_event_add_val("my_int_field", 3999, &trace_state);
- Note that synth_event_add_next_val() and synth_event_add_val() are
- incompatible if used within the same trace of an event - either one
- can be used but not both at the same time.
- Finally, the event won't be actually traced until it's 'closed',
- which is done using synth_event_trace_end(), which takes only the
- struct synth_event_trace_state object used in the previous calls::
- ret = synth_event_trace_end(&trace_state);
- Note that synth_event_trace_end() must be called at the end regardless
- of whether any of the add calls failed (say due to a bad field name
- being passed in).
- 7.3 Dyamically creating kprobe and kretprobe event definitions
- --------------------------------------------------------------
- To create a kprobe or kretprobe trace event from kernel code, the
- kprobe_event_gen_cmd_start() or kretprobe_event_gen_cmd_start()
- functions can be used.
- To create a kprobe event, an empty or partially empty kprobe event
- should first be created using kprobe_event_gen_cmd_start(). The name
- of the event and the probe location should be specfied along with one
- or args each representing a probe field should be supplied to this
- function. Before calling kprobe_event_gen_cmd_start(), the user
- should create and initialize a dynevent_cmd object using
- kprobe_event_cmd_init().
- For example, to create a new "schedtest" kprobe event with two fields::
- struct dynevent_cmd cmd;
- char *buf;
- /* Create a buffer to hold the generated command */
- buf = kzalloc(MAX_DYNEVENT_CMD_LEN, GFP_KERNEL);
- /* Before generating the command, initialize the cmd object */
- kprobe_event_cmd_init(&cmd, buf, MAX_DYNEVENT_CMD_LEN);
- /*
- * Define the gen_kprobe_test event with the first 2 kprobe
- * fields.
- */
- ret = kprobe_event_gen_cmd_start(&cmd, "gen_kprobe_test", "do_sys_open",
- "dfd=%ax", "filename=%dx");
- Once the kprobe event object has been created, it can then be
- populated with more fields. Fields can be added using
- kprobe_event_add_fields(), supplying the dynevent_cmd object along
- with a variable arg list of probe fields. For example, to add a
- couple additional fields, the following call could be made::
- ret = kprobe_event_add_fields(&cmd, "flags=%cx", "mode=+4($stack)");
- Once all the fields have been added, the event should be finalized and
- registered by calling the kprobe_event_gen_cmd_end() or
- kretprobe_event_gen_cmd_end() functions, depending on whether a kprobe
- or kretprobe command was started::
- ret = kprobe_event_gen_cmd_end(&cmd);
- or::
- ret = kretprobe_event_gen_cmd_end(&cmd);
- At this point, the event object is ready to be used for tracing new
- events.
- Similarly, a kretprobe event can be created using
- kretprobe_event_gen_cmd_start() with a probe name and location and
- additional params such as $retval::
- ret = kretprobe_event_gen_cmd_start(&cmd, "gen_kretprobe_test",
- "do_sys_open", "$retval");
- Similar to the synthetic event case, code like the following can be
- used to enable the newly created kprobe event::
- gen_kprobe_test = trace_get_event_file(NULL, "kprobes", "gen_kprobe_test");
- ret = trace_array_set_clr_event(gen_kprobe_test->tr,
- "kprobes", "gen_kprobe_test", true);
- Finally, also similar to synthetic events, the following code can be
- used to give the kprobe event file back and delete the event::
- trace_put_event_file(gen_kprobe_test);
- ret = kprobe_event_delete("gen_kprobe_test");
- 7.4 The "dynevent_cmd" low-level API
- ------------------------------------
- Both the in-kernel synthetic event and kprobe interfaces are built on
- top of a lower-level "dynevent_cmd" interface. This interface is
- meant to provide the basis for higher-level interfaces such as the
- synthetic and kprobe interfaces, which can be used as examples.
- The basic idea is simple and amounts to providing a general-purpose
- layer that can be used to generate trace event commands. The
- generated command strings can then be passed to the command-parsing
- and event creation code that already exists in the trace event
- subystem for creating the corresponding trace events.
- In a nutshell, the way it works is that the higher-level interface
- code creates a struct dynevent_cmd object, then uses a couple
- functions, dynevent_arg_add() and dynevent_arg_pair_add() to build up
- a command string, which finally causes the command to be executed
- using the dynevent_create() function. The details of the interface
- are described below.
- The first step in building a new command string is to create and
- initialize an instance of a dynevent_cmd. Here, for instance, we
- create a dynevent_cmd on the stack and initialize it::
- struct dynevent_cmd cmd;
- char *buf;
- int ret;
- buf = kzalloc(MAX_DYNEVENT_CMD_LEN, GFP_KERNEL);
- dynevent_cmd_init(cmd, buf, maxlen, DYNEVENT_TYPE_FOO,
- foo_event_run_command);
- The dynevent_cmd initialization needs to be given a user-specified
- buffer and the length of the buffer (MAX_DYNEVENT_CMD_LEN can be used
- for this purpose - at 2k it's generally too big to be comfortably put
- on the stack, so is dynamically allocated), a dynevent type id, which
- is meant to be used to check that further API calls are for the
- correct command type, and a pointer to an event-specific run_command()
- callback that will be called to actually execute the event-specific
- command function.
- Once that's done, the command string can by built up by successive
- calls to argument-adding functions.
- To add a single argument, define and initialize a struct dynevent_arg
- or struct dynevent_arg_pair object. Here's an example of the simplest
- possible arg addition, which is simply to append the given string as
- a whitespace-separated argument to the command::
- struct dynevent_arg arg;
- dynevent_arg_init(&arg, NULL, 0);
- arg.str = name;
- ret = dynevent_arg_add(cmd, &arg);
- The arg object is first initialized using dynevent_arg_init() and in
- this case the parameters are NULL or 0, which means there's no
- optional sanity-checking function or separator appended to the end of
- the arg.
- Here's another more complicated example using an 'arg pair', which is
- used to create an argument that consists of a couple components added
- together as a unit, for example, a 'type field_name;' arg or a simple
- expression arg e.g. 'flags=%cx'::
- struct dynevent_arg_pair arg_pair;
- dynevent_arg_pair_init(&arg_pair, dynevent_foo_check_arg_fn, 0, ';');
- arg_pair.lhs = type;
- arg_pair.rhs = name;
- ret = dynevent_arg_pair_add(cmd, &arg_pair);
- Again, the arg_pair is first initialized, in this case with a callback
- function used to check the sanity of the args (for example, that
- neither part of the pair is NULL), along with a character to be used
- to add an operator between the pair (here none) and a separator to be
- appended onto the end of the arg pair (here ';').
- There's also a dynevent_str_add() function that can be used to simply
- add a string as-is, with no spaces, delimeters, or arg check.
- Any number of dynevent_*_add() calls can be made to build up the string
- (until its length surpasses cmd->maxlen). When all the arguments have
- been added and the command string is complete, the only thing left to
- do is run the command, which happens by simply calling
- dynevent_create()::
- ret = dynevent_create(&cmd);
- At that point, if the return value is 0, the dynamic event has been
- created and is ready to use.
- See the dynevent_cmd function definitions themselves for the details
- of the API.
|