ɨsphinx.addnodesdocument)}( rawsourcechildren]( translations LanguagesNode)}(hhh](h pending_xref)}(hhh]docutils.nodesTextChinese (Simplified)}parenthsba attributes}(ids]classes]names]dupnames]backrefs] refdomainstdreftypedoc reftarget%/translations/zh_CN/trace/fprobetracemodnameN classnameN refexplicitutagnamehhh ubh)}(hhh]hChinese (Traditional)}hh2sbah}(h]h ]h"]h$]h&] refdomainh)reftypeh+ reftarget%/translations/zh_TW/trace/fprobetracemodnameN classnameN refexplicituh1hhh ubh)}(hhh]hItalian}hhFsbah}(h]h ]h"]h$]h&] refdomainh)reftypeh+ reftarget%/translations/it_IT/trace/fprobetracemodnameN classnameN refexplicituh1hhh ubh)}(hhh]hJapanese}hhZsbah}(h]h ]h"]h$]h&] refdomainh)reftypeh+ reftarget%/translations/ja_JP/trace/fprobetracemodnameN classnameN refexplicituh1hhh ubh)}(hhh]hKorean}hhnsbah}(h]h ]h"]h$]h&] refdomainh)reftypeh+ reftarget%/translations/ko_KR/trace/fprobetracemodnameN classnameN refexplicituh1hhh ubh)}(hhh]hSpanish}hhsbah}(h]h ]h"]h$]h&] refdomainh)reftypeh+ reftarget%/translations/sp_SP/trace/fprobetracemodnameN classnameN refexplicituh1hhh ubeh}(h]h ]h"]h$]h&]current_languageEnglishuh1h hh _documenthsourceNlineNubhcomment)}(h SPDX-License-Identifier: GPL-2.0h]h SPDX-License-Identifier: GPL-2.0}hhsbah}(h]h ]h"]h$]h&] xml:spacepreserveuh1hhhhhh?/var/lib/git/docbuild/linux/Documentation/trace/fprobetrace.rsthKubhsection)}(hhh](htitle)}(hFprobe-based Event Tracingh]hFprobe-based Event Tracing}(hhhhhNhNubah}(h]h ]h"]h$]h&]uh1hhhhhhhhKubh)}(h.Author: Masami Hiramatsu h]h.Author: Masami Hiramatsu }hhsbah}(h]h ]h"]h$]h&]hhuh1hhhhhhhhKubh)}(hhh](h)}(hOverviewh]hOverview}(hhhhhNhNubah}(h]h ]h"]h$]h&]uh1hhhhhhhhK ubh paragraph)}(hFprobe event is similar to the kprobe event, but limited to probe on the function entry and exit only. It is good enough for many use cases which only traces some specific functions.h]hFprobe event is similar to the kprobe event, but limited to probe on the function entry and exit only. It is good enough for many use cases which only traces some specific functions.}(hhhhhNhNubah}(h]h ]h"]h$]h&]uh1hhhhK hhhhubh)}(hThis document also covers tracepoint probe events (tprobe) since this is also works only on the tracepoint entry. User can trace a part of tracepoint argument, or the tracepoint without trace-event, which is not exposed on tracefs.h]hThis document also covers tracepoint probe events (tprobe) since this is also works only on the tracepoint entry. User can trace a part of tracepoint argument, or the tracepoint without trace-event, which is not exposed on tracefs.}(hhhhhNhNubah}(h]h ]h"]h$]h&]uh1hhhhKhhhhubh)}(hAs same as other dynamic events, fprobe events and tracepoint probe events are defined via `dynamic_events` interface file on tracefs.h](h[As same as other dynamic events, fprobe events and tracepoint probe events are defined via }(hjhhhNhNubhtitle_reference)}(h`dynamic_events`h]hdynamic_events}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh interface file on tracefs.}(hjhhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhKhhhhubeh}(h]overviewah ]h"]overviewah$]h&]uh1hhhhhhhhK ubh)}(hhh](h)}(hSynopsis of fprobe-eventsh]hSynopsis of fprobe-events}(hj3hhhNhNubah}(h]h ]h"]h$]h&]uh1hhj0hhhhhKubh literal_block)}(hX f[:[GRP1/][EVENT1]] SYM [FETCHARGS] : Probe on function entry f[MAXACTIVE][:[GRP1/][EVENT1]] SYM%return [FETCHARGS] : Probe on function exit t[:[GRP2/][EVENT2]] TRACEPOINT [FETCHARGS] : Probe on tracepoint GRP1 : Group name for fprobe. If omitted, use "fprobes" for it. GRP2 : Group name for tprobe. If omitted, use "tracepoints" for it. EVENT1 : Event name for fprobe. If omitted, the event name is "SYM__entry" or "SYM__exit". EVENT2 : Event name for tprobe. If omitted, the event name is the same as "TRACEPOINT", but if the "TRACEPOINT" starts with a digit character, "_TRACEPOINT" is used. MAXACTIVE : Maximum number of instances of the specified function that can be probed simultaneously, or 0 for the default value as defined in Documentation/trace/fprobe.rst FETCHARGS : Arguments. Each probe can have up to 128 args. ARG : Fetch "ARG" function argument using BTF (only for function entry or tracepoint.) (\*1) @ADDR : Fetch memory at ADDR (ADDR should be in kernel) @SYM[+|-offs] : Fetch memory at SYM +|- offs (SYM should be a data symbol) $stackN : Fetch Nth entry of stack (N >= 0) $stack : Fetch stack address. $argN : Fetch the Nth function argument. (N >= 1) (\*2) $retval : Fetch return value.(\*3) $comm : Fetch current task comm. +|-[u]OFFS(FETCHARG) : Fetch memory at FETCHARG +|- OFFS address.(\*4)(\*5) \IMM : Store an immediate value to the argument. NAME=FETCHARG : Set NAME as the argument name of FETCHARG. FETCHARG:TYPE : Set TYPE as the type of FETCHARG. Currently, basic types (u8/u16/u32/u64/s8/s16/s32/s64), hexadecimal types (x8/x16/x32/x64), "char", "string", "ustring", "symbol", "symstr" and bitfield are supported. (\*1) This is available only when BTF is enabled. (\*2) only for the probe on function entry (offs == 0). Note, this argument access is best effort, because depending on the argument type, it may be passed on the stack. But this only support the arguments via registers. (\*3) only for return probe. Note that this is also best effort. Depending on the return value type, it might be passed via a pair of registers. But this only accesses one register. (\*4) this is useful for fetching a field of data structures. (\*5) "u" means user-space dereference.h]hX f[:[GRP1/][EVENT1]] SYM [FETCHARGS] : Probe on function entry f[MAXACTIVE][:[GRP1/][EVENT1]] SYM%return [FETCHARGS] : Probe on function exit t[:[GRP2/][EVENT2]] TRACEPOINT [FETCHARGS] : Probe on tracepoint GRP1 : Group name for fprobe. If omitted, use "fprobes" for it. GRP2 : Group name for tprobe. If omitted, use "tracepoints" for it. EVENT1 : Event name for fprobe. If omitted, the event name is "SYM__entry" or "SYM__exit". EVENT2 : Event name for tprobe. If omitted, the event name is the same as "TRACEPOINT", but if the "TRACEPOINT" starts with a digit character, "_TRACEPOINT" is used. MAXACTIVE : Maximum number of instances of the specified function that can be probed simultaneously, or 0 for the default value as defined in Documentation/trace/fprobe.rst FETCHARGS : Arguments. Each probe can have up to 128 args. ARG : Fetch "ARG" function argument using BTF (only for function entry or tracepoint.) (\*1) @ADDR : Fetch memory at ADDR (ADDR should be in kernel) @SYM[+|-offs] : Fetch memory at SYM +|- offs (SYM should be a data symbol) $stackN : Fetch Nth entry of stack (N >= 0) $stack : Fetch stack address. $argN : Fetch the Nth function argument. (N >= 1) (\*2) $retval : Fetch return value.(\*3) $comm : Fetch current task comm. +|-[u]OFFS(FETCHARG) : Fetch memory at FETCHARG +|- OFFS address.(\*4)(\*5) \IMM : Store an immediate value to the argument. NAME=FETCHARG : Set NAME as the argument name of FETCHARG. FETCHARG:TYPE : Set TYPE as the type of FETCHARG. Currently, basic types (u8/u16/u32/u64/s8/s16/s32/s64), hexadecimal types (x8/x16/x32/x64), "char", "string", "ustring", "symbol", "symstr" and bitfield are supported. (\*1) This is available only when BTF is enabled. (\*2) only for the probe on function entry (offs == 0). Note, this argument access is best effort, because depending on the argument type, it may be passed on the stack. But this only support the arguments via registers. (\*3) only for return probe. Note that this is also best effort. Depending on the return value type, it might be passed via a pair of registers. But this only accesses one register. (\*4) this is useful for fetching a field of data structures. (\*5) "u" means user-space dereference.}hjCsbah}(h]h ]h"]h$]h&]hhuh1jAhhhKhj0hhubh)}(hRFor the details of TYPE, see :ref:`kprobetrace documentation `.h](hFor the details of TYPE, see }(hjQhhhNhNubh)}(h4:ref:`kprobetrace documentation `h]hinline)}(hj[h]hkprobetrace documentation}(hj_hhhNhNubah}(h]h ](xrefstdstd-refeh"]h$]h&]uh1j]hjYubah}(h]h ]h"]h$]h&]refdoctrace/fprobetrace refdomainjjreftyperef refexplicitrefwarn reftargetkprobetrace_typesuh1hhhhKGhjQubh.}(hjQhhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhKGhj0hhubeh}(h]synopsis-of-fprobe-eventsah ]h"]synopsis of fprobe-eventsah$]h&]uh1hhhhhhhhKubh)}(hhh](h)}(hFunction arguments at exith]hFunction arguments at exit}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1hhjhhhhhKJubh)}(hXcFunction arguments can be accessed at exit probe using $arg fetcharg. This is useful to record the function parameter and return value at once, and trace the difference of structure fields (for debugging a function whether it correctly updates the given data structure or not) See the :ref:`sample` below for how it works.h](hX Function arguments can be accessed at exit probe using $arg fetcharg. This is useful to record the function parameter and return value at once, and trace the difference of structure fields (for debugging a function whether it correctly updates the given data structure or not) See the }(hjhhhNhNubh)}(h+:ref:`sample`h]j^)}(hjh]hsample}(hjhhhNhNubah}(h]h ](jistdstd-refeh"]h$]h&]uh1j]hjubah}(h]h ]h"]h$]h&]refdocjv refdomainjreftyperef refexplicitrefwarnj|fprobetrace_exit_args_sampleuh1hhhhKKhjubh below for how it works.}(hjhhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhKKhjhhubeh}(h]function-arguments-at-exitah ]h"]function arguments at exitah$]h&]uh1hhhhhhhhKJubh)}(hhh](h)}(h BTF argumentsh]h BTF arguments}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1hhjhhhhhKRubh)}(hXRBTF (BPF Type Format) argument allows user to trace function and tracepoint parameters by its name instead of ``$argN``. This feature is available if the kernel is configured with CONFIG_BPF_SYSCALL and CONFIG_DEBUG_INFO_BTF. If user only specify the BTF argument, the event's argument name is also automatically set by the given name. ::h](hnBTF (BPF Type Format) argument allows user to trace function and tracepoint parameters by its name instead of }(hjhhhNhNubhliteral)}(h ``$argN``h]h$argN}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh. This feature is available if the kernel is configured with CONFIG_BPF_SYSCALL and CONFIG_DEBUG_INFO_BTF. If user only specify the BTF argument, the event’s argument name is also automatically set by the given name.}(hjhhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhKShjhhubjB)}(h{# echo 'f:myprobe vfs_read count pos' >> dynamic_events # cat dynamic_events f:fprobes/myprobe vfs_read count=count pos=posh]h{# echo 'f:myprobe vfs_read count pos' >> dynamic_events # cat dynamic_events f:fprobes/myprobe vfs_read count=count pos=pos}hjsbah}(h]h ]h"]h$]h&]hhuh1jAhhhKYhjhhubh)}(hIt also chooses the fetch type from BTF information. For example, in the above example, the ``count`` is unsigned long, and the ``pos`` is a pointer. Thus, both are converted to 64bit unsigned long, but only ``pos`` has "%Lx" print-format as below ::h](h\It also chooses the fetch type from BTF information. For example, in the above example, the }(hjhhhNhNubj)}(h ``count``h]hcount}(hj$hhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh is unsigned long, and the }(hjhhhNhNubj)}(h``pos``h]hpos}(hj6hhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubhI is a pointer. Thus, both are converted to 64bit unsigned long, but only }(hjhhhNhNubj)}(h``pos``h]hpos}(hjHhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh$ has “%Lx” print-format as below}(hjhhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhK]hjhhubjB)}(hX# cat events/fprobes/myprobe/format name: myprobe ID: 1313 format: field:unsigned short common_type; offset:0; size:2; signed:0; field:unsigned char common_flags; offset:2; size:1; signed:0; field:unsigned char common_preempt_count; offset:3; size:1; signed:0; field:int common_pid; offset:4; size:4; signed:1; field:unsigned long __probe_ip; offset:8; size:8; signed:0; field:u64 count; offset:16; size:8; signed:0; field:u64 pos; offset:24; size:8; signed:0; print fmt: "(%lx) count=%Lu pos=0x%Lx", REC->__probe_ip, REC->count, REC->posh]hX# cat events/fprobes/myprobe/format name: myprobe ID: 1313 format: field:unsigned short common_type; offset:0; size:2; signed:0; field:unsigned char common_flags; offset:2; size:1; signed:0; field:unsigned char common_preempt_count; offset:3; size:1; signed:0; field:int common_pid; offset:4; size:4; signed:1; field:unsigned long __probe_ip; offset:8; size:8; signed:0; field:u64 count; offset:16; size:8; signed:0; field:u64 pos; offset:24; size:8; signed:0; print fmt: "(%lx) count=%Lu pos=0x%Lx", REC->__probe_ip, REC->count, REC->pos}hj`sbah}(h]h ]h"]h$]h&]hhuh1jAhhhKbhjhhubh)}(hIf user unsures the name of arguments, ``$arg*`` will be helpful. The ``$arg*`` is expanded to all function arguments of the function or the tracepoint. ::h](h'If user unsures the name of arguments, }(hjnhhhNhNubj)}(h ``$arg*``h]h$arg*}(hjvhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjnubh will be helpful. The }(hjnhhhNhNubj)}(h ``$arg*``h]h$arg*}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjnubhI is expanded to all function arguments of the function or the tracepoint.}(hjnhhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhKqhjhhubjB)}(h# echo 'f:myprobe vfs_read $arg*' >> dynamic_events # cat dynamic_events f:fprobes/myprobe vfs_read file=file buf=buf count=count pos=posh]h# echo 'f:myprobe vfs_read $arg*' >> dynamic_events # cat dynamic_events f:fprobes/myprobe vfs_read file=file buf=buf count=count pos=pos}hjsbah}(h]h ]h"]h$]h&]hhuh1jAhhhKthjhhubh)}(hBTF also affects the ``$retval``. If user doesn't set any type, the retval type is automatically picked from the BTF. If the function returns ``void``, ``$retval`` is rejected.h](hBTF also affects the }(hjhhhNhNubj)}(h ``$retval``h]h$retval}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubhp. If user doesn’t set any type, the retval type is automatically picked from the BTF. If the function returns }(hjhhhNhNubj)}(h``void``h]hvoid}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh, }(hjhhhNhNubj)}(h ``$retval``h]h$retval}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh is rejected.}(hjhhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhKxhjhhubh)}(hYou can access the data fields of a data structure using allow operator ``->`` (for pointer type) and dot operator ``.`` (for data structure type.)::h](hHYou can access the data fields of a data structure using allow operator }(hjhhhNhNubj)}(h``->``h]h->}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh% (for pointer type) and dot operator }(hjhhhNhNubj)}(h``.``h]h.}(hj hhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh (for data structure type.):}(hjhhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhK|hjhhubjB)}(hW# echo 't sched_switch preempt prev_pid=prev->pid next_pid=next->pid' >> dynamic_eventsh]hW# echo 't sched_switch preempt prev_pid=prev->pid next_pid=next->pid' >> dynamic_events}hj$sbah}(h]h ]h"]h$]h&]hhuh1jAhhhKhjhhubh)}(hXThe field access operators, ``->`` and ``.`` can be combined for accessing deeper members and other structure members pointed by the member. e.g. ``foo->bar.baz->qux`` If there is non-name union member, you can directly access it as the C code does. For example::h](hThe field access operators, }(hj2hhhNhNubj)}(h``->``h]h->}(hj:hhhNhNubah}(h]h ]h"]h$]h&]uh1jhj2ubh and }(hj2hhhNhNubj)}(h``.``h]h.}(hjLhhhNhNubah}(h]h ]h"]h$]h&]uh1jhj2ubhf can be combined for accessing deeper members and other structure members pointed by the member. e.g. }(hj2hhhNhNubj)}(h``foo->bar.baz->qux``h]hfoo->bar.baz->qux}(hj^hhhNhNubah}(h]h ]h"]h$]h&]uh1jhj2ubh_ If there is non-name union member, you can directly access it as the C code does. For example:}(hj2hhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhKhjhhubjB)}(hEstruct { union { int a; int b; }; } *foo;h]hEstruct { union { int a; int b; }; } *foo;}hjvsbah}(h]h ]h"]h$]h&]hhuh1jAhhhKhjhhubh)}(hFTo access ``a`` and ``b``, use ``foo->a`` and ``foo->b`` in this case.h](h To access }(hjhhhNhNubj)}(h``a``h]ha}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh and }(hjhhhNhNubj)}(h``b``h]hb}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh, use }(hjhhhNhNubj)}(h ``foo->a``h]hfoo->a}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh and }hjsbj)}(h ``foo->b``h]hfoo->b}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh in this case.}(hjhhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhKhjhhubh)}(haThis data field access is available for the return value via ``$retval``, e.g. ``$retval->name``.h](h=This data field access is available for the return value via }(hjhhhNhNubj)}(h ``$retval``h]h$retval}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh, e.g. }(hjhhhNhNubj)}(h``$retval->name``h]h $retval->name}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh.}(hjhhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhKhjhhubh)}(hXFor these BTF arguments and fields, ``:string`` and ``:ustring`` change the behavior. If these are used for BTF argument or field, it checks whether the BTF type of the argument or the data field is ``char *`` or ``char []``, or not. If not, it rejects applying the string types. Also, with the BTF support, you don't need a memory dereference operator (``+0(PTR)``) for accessing the string pointed by a ``PTR``. It automatically adds the memory dereference operator according to the BTF type. e.g. ::h](h$For these BTF arguments and fields, }(hj hhhNhNubj)}(h ``:string``h]h:string}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhj ubh and }(hj hhhNhNubj)}(h ``:ustring``h]h:ustring}(hj&hhhNhNubah}(h]h ]h"]h$]h&]uh1jhj ubh change the behavior. If these are used for BTF argument or field, it checks whether the BTF type of the argument or the data field is }(hj hhhNhNubj)}(h ``char *``h]hchar *}(hj8hhhNhNubah}(h]h ]h"]h$]h&]uh1jhj ubh or }(hj hhhNhNubj)}(h ``char []``h]hchar []}(hjJhhhNhNubah}(h]h ]h"]h$]h&]uh1jhj ubh, or not. If not, it rejects applying the string types. Also, with the BTF support, you don’t need a memory dereference operator (}(hj hhhNhNubj)}(h ``+0(PTR)``h]h+0(PTR)}(hj\hhhNhNubah}(h]h ]h"]h$]h&]uh1jhj ubh() for accessing the string pointed by a }(hj hhhNhNubj)}(h``PTR``h]hPTR}(hjnhhhNhNubah}(h]h ]h"]h$]h&]uh1jhj ubhW. It automatically adds the memory dereference operator according to the BTF type. e.g.}(hj hhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhKhjhhubjB)}(h# echo 't sched_switch prev->comm:string' >> dynamic_events # echo 'f getname_flags%return $retval->name:string' >> dynamic_eventsh]h# echo 't sched_switch prev->comm:string' >> dynamic_events # echo 'f getname_flags%return $retval->name:string' >> dynamic_events}hjsbah}(h]h ]h"]h$]h&]hhuh1jAhhhKhjhhubh)}(hThe ``prev->comm`` is an embedded char array in the data structure, and ``$retval->name`` is a char pointer in the data structure. But in both cases, you can use ``:string`` type to get the string.h](hThe }(hjhhhNhNubj)}(h``prev->comm``h]h prev->comm}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh6 is an embedded char array in the data structure, and }(hjhhhNhNubj)}(h``$retval->name``h]h $retval->name}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubhI is a char pointer in the data structure. But in both cases, you can use }(hjhhhNhNubj)}(h ``:string``h]h:string}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh type to get the string.}(hjhhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhKhjhhubeh}(h] btf-argumentsah ]h"] btf argumentsah$]h&]uh1hhhhhhhhKRubh)}(hhh](h)}(hUsage examplesh]hUsage examples}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1hhjhhhhhKubh)}(hiHere is an example to add fprobe events on ``vfs_read()`` function entry and exit, with BTF arguments. ::h](h+Here is an example to add fprobe events on }(hjhhhNhNubj)}(h``vfs_read()``h]h vfs_read()}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubh- function entry and exit, with BTF arguments.}(hjhhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhKhjhhubjB)}(hX # echo 'f vfs_read $arg*' >> dynamic_events # echo 'f vfs_read%return $retval' >> dynamic_events # cat dynamic_events f:fprobes/vfs_read__entry vfs_read file=file buf=buf count=count pos=pos f:fprobes/vfs_read__exit vfs_read%return arg1=$retval # echo 1 > events/fprobes/enable # head -n 20 trace | tail # TASK-PID CPU# ||||| TIMESTAMP FUNCTION # | | | ||||| | | sh-70 [000] ...1. 335.883195: vfs_read__entry: (vfs_read+0x4/0x340) file=0xffff888005cf9a80 buf=0x7ffef36c6879 count=1 pos=0xffffc900005aff08 sh-70 [000] ..... 335.883208: vfs_read__exit: (ksys_read+0x75/0x100 <- vfs_read) arg1=1 sh-70 [000] ...1. 335.883220: vfs_read__entry: (vfs_read+0x4/0x340) file=0xffff888005cf9a80 buf=0x7ffef36c6879 count=1 pos=0xffffc900005aff08 sh-70 [000] ..... 335.883224: vfs_read__exit: (ksys_read+0x75/0x100 <- vfs_read) arg1=1 sh-70 [000] ...1. 335.883232: vfs_read__entry: (vfs_read+0x4/0x340) file=0xffff888005cf9a80 buf=0x7ffef36c687a count=1 pos=0xffffc900005aff08 sh-70 [000] ..... 335.883237: vfs_read__exit: (ksys_read+0x75/0x100 <- vfs_read) arg1=1 sh-70 [000] ...1. 336.050329: vfs_read__entry: (vfs_read+0x4/0x340) file=0xffff888005cf9a80 buf=0x7ffef36c6879 count=1 pos=0xffffc900005aff08 sh-70 [000] ..... 336.050343: vfs_read__exit: (ksys_read+0x75/0x100 <- vfs_read) arg1=1h]hX # echo 'f vfs_read $arg*' >> dynamic_events # echo 'f vfs_read%return $retval' >> dynamic_events # cat dynamic_events f:fprobes/vfs_read__entry vfs_read file=file buf=buf count=count pos=pos f:fprobes/vfs_read__exit vfs_read%return arg1=$retval # echo 1 > events/fprobes/enable # head -n 20 trace | tail # TASK-PID CPU# ||||| TIMESTAMP FUNCTION # | | | ||||| | | sh-70 [000] ...1. 335.883195: vfs_read__entry: (vfs_read+0x4/0x340) file=0xffff888005cf9a80 buf=0x7ffef36c6879 count=1 pos=0xffffc900005aff08 sh-70 [000] ..... 335.883208: vfs_read__exit: (ksys_read+0x75/0x100 <- vfs_read) arg1=1 sh-70 [000] ...1. 335.883220: vfs_read__entry: (vfs_read+0x4/0x340) file=0xffff888005cf9a80 buf=0x7ffef36c6879 count=1 pos=0xffffc900005aff08 sh-70 [000] ..... 335.883224: vfs_read__exit: (ksys_read+0x75/0x100 <- vfs_read) arg1=1 sh-70 [000] ...1. 335.883232: vfs_read__entry: (vfs_read+0x4/0x340) file=0xffff888005cf9a80 buf=0x7ffef36c687a count=1 pos=0xffffc900005aff08 sh-70 [000] ..... 335.883237: vfs_read__exit: (ksys_read+0x75/0x100 <- vfs_read) arg1=1 sh-70 [000] ...1. 336.050329: vfs_read__entry: (vfs_read+0x4/0x340) file=0xffff888005cf9a80 buf=0x7ffef36c6879 count=1 pos=0xffffc900005aff08 sh-70 [000] ..... 336.050343: vfs_read__exit: (ksys_read+0x75/0x100 <- vfs_read) arg1=1}hjsbah}(h]h ]h"]h$]h&]hhuh1jAhhhKhjhhubh)}(hPYou can see all function arguments and return values are recorded as signed int.h]hPYou can see all function arguments and return values are recorded as signed int.}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1hhhhKhjhhubh)}(hAlso, here is an example of tracepoint events on ``sched_switch`` tracepoint. To compare the result, this also enables the ``sched_switch`` traceevent too. ::h](h1Also, here is an example of tracepoint events on }(hj-hhhNhNubj)}(h``sched_switch``h]h sched_switch}(hj5hhhNhNubah}(h]h ]h"]h$]h&]uh1jhj-ubh: tracepoint. To compare the result, this also enables the }(hj-hhhNhNubj)}(h``sched_switch``h]h sched_switch}(hjGhhhNhNubah}(h]h ]h"]h$]h&]uh1jhj-ubh traceevent too.}(hj-hhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhKhjhhubjB)}(hX # echo 't sched_switch $arg*' >> dynamic_events # echo 1 > events/sched/sched_switch/enable # echo 1 > events/tracepoints/sched_switch/enable # echo > trace # head -n 20 trace | tail # TASK-PID CPU# ||||| TIMESTAMP FUNCTION # | | | ||||| | | sh-70 [000] d..2. 3912.083993: sched_switch: prev_comm=sh prev_pid=70 prev_prio=120 prev_state=S ==> next_comm=swapper/0 next_pid=0 next_prio=120 sh-70 [000] d..3. 3912.083995: sched_switch: (__probestub_sched_switch+0x4/0x10) preempt=0 prev=0xffff88800664e100 next=0xffffffff828229c0 prev_state=1 -0 [000] d..2. 3912.084183: sched_switch: prev_comm=swapper/0 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=rcu_preempt next_pid=16 next_prio=120 -0 [000] d..3. 3912.084184: sched_switch: (__probestub_sched_switch+0x4/0x10) preempt=0 prev=0xffffffff828229c0 next=0xffff888004208000 prev_state=0 rcu_preempt-16 [000] d..2. 3912.084196: sched_switch: prev_comm=rcu_preempt prev_pid=16 prev_prio=120 prev_state=I ==> next_comm=swapper/0 next_pid=0 next_prio=120 rcu_preempt-16 [000] d..3. 3912.084196: sched_switch: (__probestub_sched_switch+0x4/0x10) preempt=0 prev=0xffff888004208000 next=0xffffffff828229c0 prev_state=1026 -0 [000] d..2. 3912.085191: sched_switch: prev_comm=swapper/0 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=rcu_preempt next_pid=16 next_prio=120 -0 [000] d..3. 3912.085191: sched_switch: (__probestub_sched_switch+0x4/0x10) preempt=0 prev=0xffffffff828229c0 next=0xffff888004208000 prev_state=0h]hX # echo 't sched_switch $arg*' >> dynamic_events # echo 1 > events/sched/sched_switch/enable # echo 1 > events/tracepoints/sched_switch/enable # echo > trace # head -n 20 trace | tail # TASK-PID CPU# ||||| TIMESTAMP FUNCTION # | | | ||||| | | sh-70 [000] d..2. 3912.083993: sched_switch: prev_comm=sh prev_pid=70 prev_prio=120 prev_state=S ==> next_comm=swapper/0 next_pid=0 next_prio=120 sh-70 [000] d..3. 3912.083995: sched_switch: (__probestub_sched_switch+0x4/0x10) preempt=0 prev=0xffff88800664e100 next=0xffffffff828229c0 prev_state=1 -0 [000] d..2. 3912.084183: sched_switch: prev_comm=swapper/0 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=rcu_preempt next_pid=16 next_prio=120 -0 [000] d..3. 3912.084184: sched_switch: (__probestub_sched_switch+0x4/0x10) preempt=0 prev=0xffffffff828229c0 next=0xffff888004208000 prev_state=0 rcu_preempt-16 [000] d..2. 3912.084196: sched_switch: prev_comm=rcu_preempt prev_pid=16 prev_prio=120 prev_state=I ==> next_comm=swapper/0 next_pid=0 next_prio=120 rcu_preempt-16 [000] d..3. 3912.084196: sched_switch: (__probestub_sched_switch+0x4/0x10) preempt=0 prev=0xffff888004208000 next=0xffffffff828229c0 prev_state=1026 -0 [000] d..2. 3912.085191: sched_switch: prev_comm=swapper/0 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=rcu_preempt next_pid=16 next_prio=120 -0 [000] d..3. 3912.085191: sched_switch: (__probestub_sched_switch+0x4/0x10) preempt=0 prev=0xffffffff828229c0 next=0xffff888004208000 prev_state=0}hj_sbah}(h]h ]h"]h$]h&]hhuh1jAhhhKhjhhubh)}(hXAs you can see, the ``sched_switch`` trace-event shows *cooked* parameters, on the other hand, the ``sched_switch`` tracepoint probe event shows *raw* parameters. This means you can access any field values in the task structure pointed by the ``prev`` and ``next`` arguments.h](hAs you can see, the }(hjmhhhNhNubj)}(h``sched_switch``h]h sched_switch}(hjuhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjmubh trace-event shows }(hjmhhhNhNubhemphasis)}(h*cooked*h]hcooked}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjmubh$ parameters, on the other hand, the }(hjmhhhNhNubj)}(h``sched_switch``h]h sched_switch}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjmubh tracepoint probe event shows }(hjmhhhNhNubj)}(h*raw*h]hraw}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjmubh] parameters. This means you can access any field values in the task structure pointed by the }(hjmhhhNhNubj)}(h``prev``h]hprev}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjmubh and }(hjmhhhNhNubj)}(h``next``h]hnext}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjmubh arguments.}(hjmhhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhKhjhhubh)}(hFor example, usually ``task_struct::start_time`` is not traced, but with this traceprobe event, you can trace that field as below. ::h](hFor example, usually }(hjhhhNhNubj)}(h``task_struct::start_time``h]htask_struct::start_time}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjubhR is not traced, but with this traceprobe event, you can trace that field as below.}(hjhhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhKhjhhubjB)}(hX] # echo 't sched_switch comm=next->comm:string next->start_time' > dynamic_events # head -n 20 trace | tail # TASK-PID CPU# ||||| TIMESTAMP FUNCTION # | | | ||||| | | sh-70 [000] d..3. 5606.686577: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="rcu_preempt" usage=1 start_time=245000000 rcu_preempt-16 [000] d..3. 5606.686602: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="sh" usage=1 start_time=1596095526 sh-70 [000] d..3. 5606.686637: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="swapper/0" usage=2 start_time=0 -0 [000] d..3. 5606.687190: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="rcu_preempt" usage=1 start_time=245000000 rcu_preempt-16 [000] d..3. 5606.687202: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="swapper/0" usage=2 start_time=0 -0 [000] d..3. 5606.690317: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="kworker/0:1" usage=1 start_time=137000000 kworker/0:1-14 [000] d..3. 5606.690339: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="swapper/0" usage=2 start_time=0 -0 [000] d..3. 5606.692368: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="kworker/0:1" usage=1 start_time=137000000h]hX] # echo 't sched_switch comm=next->comm:string next->start_time' > dynamic_events # head -n 20 trace | tail # TASK-PID CPU# ||||| TIMESTAMP FUNCTION # | | | ||||| | | sh-70 [000] d..3. 5606.686577: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="rcu_preempt" usage=1 start_time=245000000 rcu_preempt-16 [000] d..3. 5606.686602: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="sh" usage=1 start_time=1596095526 sh-70 [000] d..3. 5606.686637: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="swapper/0" usage=2 start_time=0 -0 [000] d..3. 5606.687190: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="rcu_preempt" usage=1 start_time=245000000 rcu_preempt-16 [000] d..3. 5606.687202: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="swapper/0" usage=2 start_time=0 -0 [000] d..3. 5606.690317: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="kworker/0:1" usage=1 start_time=137000000 kworker/0:1-14 [000] d..3. 5606.690339: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="swapper/0" usage=2 start_time=0 -0 [000] d..3. 5606.692368: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="kworker/0:1" usage=1 start_time=137000000}hj sbah}(h]h ]h"]h$]h&]hhuh1jAhhhKhjhhubhtarget)}(h!.. _fprobetrace_exit_args_sample:h]h}(h]h ]h"]h$]h&]refidfprobetrace-exit-args-sampleuh1jhKhjhhhhubh)}(hThe return probe allows us to access the results of some functions, which returns the error code and its results are passed via function parameter, such as an structure-initialization function.h]hThe return probe allows us to access the results of some functions, which returns the error code and its results are passed via function parameter, such as an structure-initialization function.}(hj%hhhNhNubah}(h]j$ah ]h"]fprobetrace_exit_args_sampleah$]h&]uh1hhhhKhjhhexpect_referenced_by_name}j1jsexpect_referenced_by_id}j$jsubh)}(hFor example, vfs_open() will link the file structure to the inode and update mode. You can trace that changes with return probe. ::h]hFor example, vfs_open() will link the file structure to the inode and update mode. You can trace that changes with return probe.}(hj8hhhNhNubah}(h]h ]h"]h$]h&]uh1hhhhKhjhhubjB)}(hX# echo 'f vfs_open mode=file->f_mode:x32 inode=file->f_inode:x64' >> dynamic_events # echo 'f vfs_open%%return mode=file->f_mode:x32 inode=file->f_inode:x64' >> dynamic_events # echo 1 > events/fprobes/enable # cat trace sh-131 [006] ...1. 1945.714346: vfs_open__entry: (vfs_open+0x4/0x40) mode=0x2 inode=0x0 sh-131 [006] ...1. 1945.714358: vfs_open__exit: (do_open+0x274/0x3d0 <- vfs_open) mode=0x4d801e inode=0xffff888008470168 cat-143 [007] ...1. 1945.717949: vfs_open__entry: (vfs_open+0x4/0x40) mode=0x1 inode=0x0 cat-143 [007] ...1. 1945.717956: vfs_open__exit: (do_open+0x274/0x3d0 <- vfs_open) mode=0x4a801d inode=0xffff888005f78d28 cat-143 [007] ...1. 1945.720616: vfs_open__entry: (vfs_open+0x4/0x40) mode=0x1 inode=0x0 cat-143 [007] ...1. 1945.728263: vfs_open__exit: (do_open+0x274/0x3d0 <- vfs_open) mode=0xa800d inode=0xffff888004ada8d8h]hX# echo 'f vfs_open mode=file->f_mode:x32 inode=file->f_inode:x64' >> dynamic_events # echo 'f vfs_open%%return mode=file->f_mode:x32 inode=file->f_inode:x64' >> dynamic_events # echo 1 > events/fprobes/enable # cat trace sh-131 [006] ...1. 1945.714346: vfs_open__entry: (vfs_open+0x4/0x40) mode=0x2 inode=0x0 sh-131 [006] ...1. 1945.714358: vfs_open__exit: (do_open+0x274/0x3d0 <- vfs_open) mode=0x4d801e inode=0xffff888008470168 cat-143 [007] ...1. 1945.717949: vfs_open__entry: (vfs_open+0x4/0x40) mode=0x1 inode=0x0 cat-143 [007] ...1. 1945.717956: vfs_open__exit: (do_open+0x274/0x3d0 <- vfs_open) mode=0x4a801d inode=0xffff888005f78d28 cat-143 [007] ...1. 1945.720616: vfs_open__entry: (vfs_open+0x4/0x40) mode=0x1 inode=0x0 cat-143 [007] ...1. 1945.728263: vfs_open__exit: (do_open+0x274/0x3d0 <- vfs_open) mode=0xa800d inode=0xffff888004ada8d8}hjFsbah}(h]h ]h"]h$]h&]hhuh1jAhhhKhjhhubh)}(hOYou can see the `file::f_mode` and `file::f_inode` are updated in `vfs_open()`.h](hYou can see the }(hjThhhNhNubj)}(h`file::f_mode`h]h file::f_mode}(hj\hhhNhNubah}(h]h ]h"]h$]h&]uh1jhjTubh and }(hjThhhNhNubj)}(h`file::f_inode`h]h file::f_inode}(hjnhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjTubh are updated in }(hjThhhNhNubj)}(h `vfs_open()`h]h vfs_open()}(hjhhhNhNubah}(h]h ]h"]h$]h&]uh1jhjTubh.}(hjThhhNhNubeh}(h]h ]h"]h$]h&]uh1hhhhKhjhhubeh}(h]usage-examplesah ]h"]usage examplesah$]h&]uh1hhhhhhhhKubeh}(h]fprobe-based-event-tracingah ]h"]fprobe-based event tracingah$]h&]uh1hhhhhhhhKubeh}(h]h ]h"]h$]h&]sourcehuh1hcurrent_sourceN current_lineNsettingsdocutils.frontendValues)}(hN generatorN datestampN source_linkN source_urlN toc_backlinksentryfootnote_backlinksK sectnum_xformKstrip_commentsNstrip_elements_with_classesN strip_classesN report_levelK halt_levelKexit_status_levelKdebugNwarning_streamN tracebackinput_encoding utf-8-siginput_encoding_error_handlerstrictoutput_encodingutf-8output_encoding_error_handlerjerror_encodingutf-8error_encoding_error_handlerbackslashreplace language_codeenrecord_dependenciesNconfigN id_prefixhauto_id_prefixid dump_settingsNdump_internalsNdump_transformsNdump_pseudo_xmlNexpose_internalsNstrict_visitorN_disable_configN_sourceh _destinationN _config_files]7/var/lib/git/docbuild/linux/Documentation/docutils.confafile_insertion_enabled raw_enabledKline_length_limitM'pep_referencesN pep_base_urlhttps://peps.python.org/pep_file_url_templatepep-%04drfc_referencesN rfc_base_url&https://datatracker.ietf.org/doc/html/ tab_widthKtrim_footnote_reference_spacesyntax_highlightlong smart_quotessmartquotes_locales]character_level_inline_markupdoctitle_xform docinfo_xformKsectsubtitle_xform image_loadinglinkembed_stylesheetcloak_email_addressessection_self_linkenvNubreporterNindirect_targets]substitution_defs}substitution_names}refnames}refids}j$]jasnameids}(jjj-j*jjjjjjjjj1j$u nametypes}(jj-jjjjj1uh}(jhj*hjj0jjjjjjj$j%u footnote_refs} citation_refs} autofootnotes]autofootnote_refs]symbol_footnotes]symbol_footnote_refs] footnotes] citations]autofootnote_startKsymbol_footnote_startK id_counter collectionsCounter}Rparse_messages]transform_messages]hsystem_message)}(hhh]h)}(hhh]hBHyperlink target "fprobetrace-exit-args-sample" is not referenced.}hj5sbah}(h]h ]h"]h$]h&]uh1hhj2ubah}(h]h ]h"]h$]h&]levelKtypeINFOsourcehlineKuh1j0uba transformerN include_log] decorationNhhub.