Re: [PATCH v5 00/11] tracing: common error_log for ftrace
On Mon, 01 Apr 2019 08:31:08 -0500 Tom Zanussi wrote: > > > 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. > > > > I was going to, but there are a lot of error cases and a lot of them > aren't simple one-liners and require some more involved setup to > trigger. I'll submit a follow-on patch to add them as soon as I get > the chance. Agreed, I look forward your testcase :) Thank you, -- Masami Hiramatsu
Re: [PATCH v5 00/11] tracing: common error_log for ftrace
Hi Masami, On Mon, 2019-04-01 at 09:19 +0700, Masami Hiramatsu wrote: > Hi Tom, > > On Sun, 31 Mar 2019 18:48:14 -0500 > Tom Zanussi wrote: > > > From: Tom Zanussi > > > > 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 > Thanks! > 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. > I was going to, but there are a lot of error cases and a lot of them aren't simple one-liners and require some more involved setup to trigger. I'll submit a follow-on patch to add them as soon as I get the chance. Thanks, Tom > 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 > > > > #
Re: [PATCH v5 00/11] tracing: common error_log for ftrace
Hi Tom, On Sun, 31 Mar 2019 18:48:14 -0500 Tom Zanussi wrote: > From: Tom Zanussi > > 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 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 >
[PATCH v5 00/11] tracing: common error_log for ftrace
From: Tom Zanussi 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. 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()
