Re: [RFC PATCH 0/3] tracing/boot: Add histogram syntax support in boot-time tracing
From: Masami Hiramatsu
Date: Tue Aug 03 2021 - 06:28:54 EST
On Tue, 3 Aug 2021 00:30:10 +0900
Masami Hiramatsu <mhiramat@xxxxxxxxxx> wrote:
> Hi,
>
> Here is a series of patches for boot-time tracing to add histogram
> syntax extension and fixes a build issue.
>
> Currently, the boot-time tracing only supports per-event actions
> for setting trigger actions. This is enough for short actions
> like 'traceon', 'traceoff', 'snapshot' etc. However, it is not good
> for the 'hist' trigger action because it is usually too long to write
> it in a single string especially if it has an 'onmatch' action.
>
> Here is the new syntax.
>
> ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist {
> keys = <KEY>[,...]
> values = <VAL>[,...]
> sort = <SORT-KEY>[,...]
> size = <ENTRIES>
> name = <HISTNAME>
> var { <VAR> = <EXPR> ... }
> pause|continue|clear
> onmax|onchange { var = <VAR>, <ACTION> [= <PARAM>] }
> onmatch { event = <EVENT>, <ACTION> [= <PARAM>] }
Oops, these must use ';' as below.
onmax|onchange { var = <VAR>; <ACTION> [= <PARAM>] }
onmatch { event = <EVENT>; <ACTION> [= <PARAM>] }
> filter = <FILTER>
> }
Hmm, I found that one histogram can have several actions.
"hist:keys=func:lat=common_timestamp.usecs-$ts0:onmatch(A).trace(initcall_latency,func,$lat):onmatch(B).trace(initcall_latency,func,$lat)"
This syntax can be used for the case that measures the elapsed time
from A to C, and from B to C,
event A -> event C
event B -> event C
So,
onmatch.GROUP.EVENT.<ACTION> = <PARAMS>
allows us to define multiple "onmatch" on one histogram.
onmatch.groupA.eventA.trace = synthevent, arg1, arg2
onmatch.groupB.eventB.trace = synthevent, arg1, arg2
However, there is another problem on "onmax" and "onchange".
Those will take a variable name that starts from "$", but we can not
use "$" in the subkey in bootconfig.
onmax.$lat.trace = synthevent, arg1, arg2 # this will cause error because of "$lat"
Thus, maybe we can expand the original one as
onmax|onchange[.#NUM] { var = <VAR>; <ACTION> [= <PARAM>] }
onmatch[.#NUM] { event = <EVENT>; <ACTION> [= <PARAM>] }
Then, we can add multiple handler-actions in one histogram.
onmatch.1 {
event = ...
trace = ...
}
onmatch.2 {
event = ...
trace = ...
}
Thank you,
>
> Where <ACTION> is one of below;
>
> trace = <EVENT>, <ARG1>[, ...]
> save = <ARG1>[, ...]
> snapshot
>
> For example,
>
> initcall.initcall_finish.actions =
> "hist:keys=func:lat=common_timestamp.usecs-$ts0:onmatch(initcall.initcall_start).trace(initcall_latency,func,$lat)"
>
> This can be written as below;
>
> initcall.initcall_finish.hist {
> keys = func
> var.lat = common_timestamp.usecs-$ts0
> onmatch {
> event = initcall.initcall_start
> trace = initcall_latency, func, $lat
> }
> }
>
> Also, you can add comments for each options.
>
>
> TODO
> ====
> - This version doesn't support multiple histograms on an event. For
> that purpose, you still need to use per-event 'actions' option.
> Maybe it can be extended to support multiple instance by adding
> '_#NUM' subkey, e.g. "hist._1.keys = ...; hist._2.keys = ...".
> - This also doesn't support multiple 'onmatch'/'onmax'/'onchange'
> handler actions.
> - Need to expand ktest testcase for checking this syntax.
>
> Tom, this version doesn't make pause/continue/clear mutually exclusive.
> And onmatch/onmax/onchange, too. As far as I can see the code, those
> can be set on one histogram. But maybe I'm wrong. Please tell me if
> there is some limitations or exclusiveness among those options.
>
> Thank you,
>
> ---
>
> Masami Hiramatsu (3):
> tracing/boot: Fix a hist trigger dependency for boot time tracing
> tracing/boot: Add per-event histogram action options
> Documentation: tracing: Add histogram syntax to boot-time tracing
>
>
> Documentation/trace/boottime-trace.rst | 81 ++++++++++++-
> kernel/trace/trace_boot.c | 203 ++++++++++++++++++++++++++++++++
> 2 files changed, 278 insertions(+), 6 deletions(-)
>
> --
> Masami Hiramatsu (Linaro) <mhiramat@xxxxxxxxxx>
--
Masami Hiramatsu <mhiramat@xxxxxxxxxx>