lkml.org 
[lkml]   [2019]   [Mar]   [31]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    Date
    From
    SubjectRe: [PATCH v5 00/11] tracing: common error_log for ftrace
    Hi Tom,

    On Sun, 31 Mar 2019 18:48:14 -0500
    Tom Zanussi <zanussi@kernel.org> wrote:

    > From: Tom Zanussi <tom.zanussi@linux.intel.com>
    >
    > Hi,
    >
    > This is v5 of the frace error_log patchset. This version updates the
    > patches according to suggestions from Masami and Namhyung and moves
    > some of the selftest code from the kprobe/uprobe testcases to a common
    > function that can be reused by multiple testcases, including the new
    > error_log testcase.

    Thanks for updating!

    This series looks good to me.

    Acked-by: Masami Hiramatsu <mhiramat@kernel.org>

    BTW, could you also add a testcase which tests all (or most of)
    error cases of hist_err() ?
    That will be good to find regressions in future changes.

    Thanks,

    >
    > Changes from v4:
    >
    > - Merged in the >& -> 2> redirection patch into '[PATCH v5 06/11]
    > selftests/ftrace: Add error_log testcase for probe errors'
    > - Added new patch, '[PATCH v5 07/11] selftests/ftrace: Move
    > kprobe/uprobe check_error() to test.d/functions' that adds a new
    > ftrace_errlog_check() to test.d/functions, which is based on
    > check_error() from '[PATCH v5 06/11] selftests/ftrace: Add
    > error_log testcase for probe errors'
    > - Modified the kprobe/uprobe test cases to use the common
    > ftrace_errlog_check()
    > - Modified the error_log test cases to display the error position
    > using the common ftrace_errlog_check()
    > - Updated subject for '[PATCH v5 08/11] selftests/ftrace: Remove
    > trigger-extended-error-support testcase
    > - Streamlined the error_log open and write file operations as
    > suggested by Masami
    > - Fixed the long lines in '[PATCH v4 04/11] tracing: Use tracing
    > error_log with trace event filters' as suggested by Namhyung
    >
    > Changes from v3:
    >
    > - Added Masami's [PATCH 05/11] tracing: Use tracing error_log with probe events
    > - Added Masami's [PATCH 06/11] selftests/ftrace: Add error_log testcase for probe
    > - Added [PATCH 11/11] to fix [PATCH 06/11]
    > - Removed [RFC PATCH v3 4/5] tracing: Use tracing error_log with kprobe events
    > - Added [PATCH 08/11] selftests/ftrace: Add tracing/error_log testcase
    > - Removed trigger-extended-error-support testcase
    > - Changed [n] numbering to [timestamp] numbering as suggested by Masami
    > - Updated Documentation and README
    >
    > Changes from v2:
    >
    > - Added [n] numbering as suggested by Masami
    >
    >
    > 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
    > [ 217.431858] 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
    > [ 217.431858] hist:sched:sched_wakeup: error: Variable already defined
    > Command: keys=pid:ts0=common_timestamp.usecs if comm=="cyclictest"
    > ^
    > [ 311.554978] 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
    > [ 217.431858] hist:sched:sched_wakeup: error: Variable already defined
    > Command: keys=pid:ts0=common_timestamp.usecs if comm=="cyclictest"
    > ^
    > [ 311.554978] hist:sched:sched_waking: error: Couldn't find onmax or onchange variable
    > Command: key=comm:p=prio:onchange($q).snapshot()
    > ^
    > [ 715.626153] hist:sched:sched_wakeup: error: Hist trigger already exists
    > Command: keys=pid
    > ^
    > [ 730.480310] 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
    > [ 217.431858] hist:sched:sched_wakeup: error: Variable already defined
    > Command: keys=pid:ts0=common_timestamp.usecs if comm=="cyclictest"
    > ^
    > [ 311.554978] hist:sched:sched_waking: error: Couldn't find onmax or onchange variable
    > Command: key=comm:p=prio:onchange($q).snapshot()
    > ^
    > [ 715.626153] hist:sched:sched_wakeup: error: Hist trigger already exists
    > Command: keys=pid
    > ^
    > [ 730.480310] event filter parse error: error: Invalid operator
    > Command: comm="cyclictest"
    > ^
    > [ 800.548673] 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 01c4e8042fc949018b70ded769f959bc3d80e8b6:
    >
    > tracing: initialize variable in create_dyn_event() (2019-03-22 15:19:34 -0400)
    >
    > are available in the git repository at:
    >
    > git://git.kernel.org/pub/scm/linux/kernel/git/zanussi/linux-trace.git ftrace/error_log_v5
    >
    > Masami Hiramatsu (2):
    > tracing: Use tracing error_log with probe events
    > selftests/ftrace: Add error_log testcase for probe errors
    >
    > Tom Zanussi (9):
    > 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 trace event filters
    > selftests/ftrace: Move kprobe/uprobe check_error() to test.d/functions
    > selftests/ftrace: Remove trigger-extended-error-support testcase
    > selftests/ftrace: Add tracing/error_log testcase
    > tracing: Add tracing/error_log Documentation
    > tracing: Add error_log to README
    >
    > Documentation/trace/ftrace.rst | 31 +++
    > Documentation/trace/histogram.rst | 16 +-
    > kernel/trace/trace.c | 219 ++++++++++++++++
    > kernel/trace/trace.h | 4 +
    > kernel/trace/trace_events_filter.c | 11 +-
    > kernel/trace/trace_events_hist.c | 221 +++++++++--------
    > kernel/trace/trace_kprobe.c | 77 +++---
    > kernel/trace/trace_probe.c | 274 +++++++++++++++------
    > kernel/trace/trace_probe.h | 77 +++++-
    > kernel/trace/trace_uprobe.c | 44 +++-
    > .../ftrace/test.d/ftrace/tracing-error-log.tc | 19 ++
    > tools/testing/selftests/ftrace/test.d/functions | 12 +
    > .../ftrace/test.d/kprobe/kprobe_syntax_errors.tc | 85 +++++++
    > .../ftrace/test.d/kprobe/uprobe_syntax_errors.tc | 23 ++
    > .../inter-event/trigger-extended-error-support.tc | 28 ---
    > 15 files changed, 874 insertions(+), 267 deletions(-)
    > create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/tracing-error-log.tc
    > create mode 100644 tools/testing/selftests/ftrace/test.d/kprobe/kprobe_syntax_errors.tc
    > create mode 100644 tools/testing/selftests/ftrace/test.d/kprobe/uprobe_syntax_errors.tc
    > delete mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-extended-error-support.tc
    >
    > --
    > 2.14.1
    >


    --
    Masami Hiramatsu <mhiramat@kernel.org>

    \
     
     \ /
      Last update: 2019-04-01 04:20    [W:3.339 / U:0.388 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site