[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-Id: <20190305230646.e7f99c46f86c0e099ac0cd30@kernel.org>
Date: Tue, 5 Mar 2019 23:06:46 +0900
From: Masami Hiramatsu <mhiramat@...nel.org>
To: Tom Zanussi <zanussi@...nel.org>
Cc: rostedt@...dmis.org, tglx@...utronix.de, mhiramat@...nel.org,
namhyung@...nel.org, bigeasy@...utronix.de, joel@...lfernandes.org,
linux-kernel@...r.kernel.org, linux-rt-users@...r.kernel.org
Subject: Re: [RFC PATCH v3 0/5] tracing: common error_log for ftrace
On Mon, 4 Mar 2019 17:36:43 -0600
Tom Zanussi <zanussi@...nel.org> wrote:
> From: Tom Zanussi <tom.zanussi@...ux.intel.com>
>
> Hi,
>
> This is v3 of the frace error_log RFC patchset, which is the same as
> the previous version but adds the numbering Masami suggested before
> each item in the log. Masami also said he was going to take over the
> kprobe events patch, but I left it in for now for completeness as it
> still provides a useful example of possible usage, for evaluation of
> the overall scheme. I'll remove it when it's no longer an RFC.
Ahh, sorry, I'm forcusing on fixing user-space access issue.
I'll take a look.
>
> Changes from v2:
>
> - Added [n] numbering as suggested by Masami
That's very good too me, thank you!
Thank you,
>
>
> Text from original post:
>
> Last April, I posted an RFC patchset [1] implementing a common
> error_log interface as suggested by Masami [2]. We were supposed to
> discuss it at Plumbers but that never happened, and Steve recently
> asked about patches for a follow-on discussion [3], so here they are.
>
> I incorporated comments from the previous discussion, the most
> important of which are:
>
> - Incorporated Steve's suggestion of using static strings as in the
> existing trace event filter code, along with err_info indexing into
> the string arrays and a position for the error caret.
>
> - Converted all the hist trigger errors and the existing trace event
> filter parse errors to use the new interface.
>
> - Converted a few kprobe_event errors to the new interface as
> examples, but these will require more work - I didn't spend much
> time figuring out how to get the full kprobe command into the error
> info, for instance.
>
> - Got rid of the custom single-page ring buffer and used standard
> lists instead.
>
> For now, this is implemented on top of the latest 'hist trigger
> snapshot and onchange additions' patchset [4].
>
> Below is an example session of a few failed commands and the
> corresponding error_log contents:
>
> # echo > /sys/kernel/debug/tracing/error_log
>
> # echo 'hist:keys=pid:ts0=common_timestamp.usecs if comm=="cyclictest"' >> /sys/kernel/debug/tracing/events/sched/sched_wakeup/trigger
> # echo 'hist:keys=pid:ts0=common_timestamp.usecs if comm=="cyclictest"' >> /sys/kernel/debug/tracing/events/sched/sched_wakeup/trigger
> -su: echo: write error: Invalid argument
>
> # cat /sys/kernel/debug/tracing/error_log
> [1] hist:sched:sched_wakeup: error: Variable already defined
> Command: keys=pid:ts0=common_timestamp.usecs if comm=="cyclictest"
> ^
>
> # echo 'hist:key=comm:p=prio:onchange($q).snapshot()' > /sys/kernel/debug/tracing/events/sched/sched_waking/trigger
> -su: echo: write error: Invalid argument
>
> # cat /sys/kernel/debug/tracing/error_log
> [1] hist:sched:sched_wakeup: error: Variable already defined
> Command: keys=pid:ts0=common_timestamp.usecs if comm=="cyclictest"
> ^
> [2] hist:sched:sched_waking: error: Couldn't find onmax or onchange variable
> Command: key=comm:p=prio:onchange($q).snapshot()
> ^
>
> # echo 'hist:keys=pid' >> /sys/kernel/debug/tracing/events/sched/sched_wakeup/trigger
> # echo 'hist:keys=pid' >> /sys/kernel/debug/tracing/events/sched/sched_wakeup/trigger
> -su: echo: write error: File exists
> # echo 'comm="cyclictest"' > /sys/kernel/debug/tracing/events/sched/sched_wakeup/filter
> -su: echo: write error: Invalid argument
>
> # cat /sys/kernel/debug/tracing/error_log
> [1] hist:sched:sched_wakeup: error: Variable already defined
> Command: keys=pid:ts0=common_timestamp.usecs if comm=="cyclictest"
> ^
> [2] hist:sched:sched_waking: error: Couldn't find onmax or onchange variable
> Command: key=comm:p=prio:onchange($q).snapshot()
> ^
> [3] hist:sched:sched_wakeup: error: Hist trigger already exists
> Command: keys=pid
> ^
> [4] event filter parse error: error: Invalid operator
> Command: comm="cyclictest"
> ^
>
> # echo "((sig >= 10 && sig < 15) || dsig == 17) && comm != bash" > /sys/kernel/debug/tracing/events/signal/signal_generate/filter
> -su: echo: write error: Invalid argument
>
> # cat /sys/kernel/debug/tracing/error_log
> [1] hist:sched:sched_wakeup: error: Variable already defined
> Command: keys=pid:ts0=common_timestamp.usecs if comm=="cyclictest"
> ^
> [2] hist:sched:sched_waking: error: Couldn't find onmax or onchange variable
> Command: key=comm:p=prio:onchange($q).snapshot()
> ^
> [3] hist:sched:sched_wakeup: error: Hist trigger already exists
> Command: keys=pid
> ^
> [4] event filter parse error: error: Invalid operator
> Command: comm="cyclictest"
> ^
> [5] event filter parse error: error: Field not found
> Command: ((sig >= 10 && sig < 15) || dsig == 17) && comm != bash
> ^
>
>
> Thanks,
>
> Tom
>
> [1] https://lore.kernel.org/lkml/cover.1523545519.git.tom.zanussi@linux.intel.com/
> [2] https://lore.kernel.org/lkml/20180406105309.b50ea1a21d2cbd9b0e39dbfd@kernel.org/
> [3] https://lore.kernel.org/lkml/e885d1fd02e76f121d6cc2bb28e58b523e2434a7.camel@linux.intel.com/
> [4] https://lore.kernel.org/lkml/cover.1549403369.git.tom.zanussi@linux.intel.com/
>
>
> The following changes since commit 9e5a36a3371f48fef0ebea6826d1d66f6201c522:
>
> tracing: Fix spelling mistake: "analagous" -> "analogous" (2019-02-20 13:51:08 -0500)
>
> are available in the git repository at:
>
> git://git.kernel.org/pub/scm/linux/kernel/git/zanussi/linux-trace.git ftrace/error_log_v3
>
> Tom Zanussi (5):
> tracing: Add tracing error log
> tracing: Save the last hist command's associated event name
> tracing: Use tracing error_log with hist triggers
> tracing: Use tracing error_log with kprobe events (incomplete)
> tracing: Use tracing error_log with trace event filters
>
> kernel/trace/trace.c | 217 ++++++++++++++++++++++++++++++++++++
> kernel/trace/trace.h | 4 +
> kernel/trace/trace_events_filter.c | 7 +-
> kernel/trace/trace_events_hist.c | 221 ++++++++++++++++++++-----------------
> kernel/trace/trace_probe.c | 24 +++-
> 5 files changed, 368 insertions(+), 105 deletions(-)
>
> --
> 2.14.1
>
--
Masami Hiramatsu <mhiramat@...nel.org>
Powered by blists - more mailing lists