On Mon, 4 Mar 2019 17:36:43 -0600 Tom Zanussi <zanussi@xxxxxxxxxx> wrote: > From: Tom Zanussi <tom.zanussi@xxxxxxxxxxxxxxx> > > 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@xxxxxxxxxxxxxxx/ > [2] https://lore.kernel.org/lkml/20180406105309.b50ea1a21d2cbd9b0e39dbfd@xxxxxxxxxx/ > [3] https://lore.kernel.org/lkml/e885d1fd02e76f121d6cc2bb28e58b523e2434a7.camel@xxxxxxxxxxxxxxx/ > [4] https://lore.kernel.org/lkml/cover.1549403369.git.tom.zanussi@xxxxxxxxxxxxxxx/ > > > 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@xxxxxxxxxx>
