| Message ID | 20231212151632.25c9b67d@gandalf.local.home |
|---|---|
| State | Superseded |
| Headers | show |
| Series | [v2] tracing/selftests: Add test to test max subbuf size with trace_marker | expand |
On Tue, 12 Dec 2023 15:16:32 -0500 Steven Rostedt <rostedt@goodmis.org> wrote: > From: "Steven Rostedt (Google)" <rostedt@goodmis.org> > > Now that the trace_marker can write up to the max size of the sub buffer. > Add a test to see if it actually can happen. > > The README is updated to state that the trace_marker writes can be broken > up, and the test checks the README for that statement so that it does not > fail on older kernels that does not support this. I think it is better that the feature patch include README update or a separate patch because it identifies the feature is implemented or not. > > If the README does not have the specified update, the test will still test > if all the string is written, as that should work with older kernels. > > Cc: Shuah Khan <shuah@kernel.org> > Cc: linux-kselftest@vger.kernel.org > Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org> > --- > Changes since v1: https://lore.kernel.org/linux-trace-kernel/20231212135441.0337c3e9@gandalf.local.home/ > > - Fix description as it was a cut and paste from the subbuffer size tests > that are not added yet. > > kernel/trace/trace.c | 1 + > .../ftrace/test.d/00basic/trace_marker.tc | 112 ++++++++++++++++++ > 2 files changed, 113 insertions(+) > create mode 100755 tools/testing/selftests/ftrace/test.d/00basic/trace_marker.tc > > diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c > index 2f8d59834c00..cbfcdd882590 100644 > --- a/kernel/trace/trace.c > +++ b/kernel/trace/trace.c > @@ -5595,6 +5595,7 @@ static const char readme_msg[] = > " delta: Delta difference against a buffer-wide timestamp\n" > " absolute: Absolute (standalone) timestamp\n" > "\n trace_marker\t\t- Writes into this file writes into the kernel buffer\n" > + "\n May be broken into multiple events based on sub-buffer size.\n" > "\n trace_marker_raw\t\t- Writes into this file writes binary data into the kernel buffer\n" > " tracing_cpumask\t- Limit which CPUs to trace\n" > " instances\t\t- Make sub-buffers with: mkdir instances/foo\n" > diff --git a/tools/testing/selftests/ftrace/test.d/00basic/trace_marker.tc b/tools/testing/selftests/ftrace/test.d/00basic/trace_marker.tc > new file mode 100755 > index 000000000000..bf7f6f50c88a > --- /dev/null > +++ b/tools/testing/selftests/ftrace/test.d/00basic/trace_marker.tc > @@ -0,0 +1,112 @@ > +#!/bin/sh > +# SPDX-License-Identifier: GPL-2.0 > +# description: Basic tests on writing to trace_marker > +# requires: trace_marker > +# flags: instance > + > +get_buffer_data_size() { > + sed -ne 's/^.*data.*size:\([0-9][0-9]*\).*/\1/p' events/header_page > +} > + > +get_buffer_data_offset() { > + sed -ne 's/^.*data.*offset:\([0-9][0-9]*\).*/\1/p' events/header_page > +} > + > +get_event_header_size() { > + type_len=`sed -ne 's/^.*type_len.*:[^0-9]*\([0-9][0-9]*\).*/\1/p' events/header_event` > + time_len=`sed -ne 's/^.*time_delta.*:[^0-9]*\([0-9][0-9]*\).*/\1/p' events/header_event` > + array_len=`sed -ne 's/^.*array.*:[^0-9]*\([0-9][0-9]*\).*/\1/p' events/header_event` > + total_bits=$((type_len+time_len+array_len)) > + total_bits=$((total_bits+7)) > + echo $((total_bits/8)) > +} > + > +get_print_event_buf_offset() { > + sed -ne 's/^.*buf.*offset:\([0-9][0-9]*\).*/\1/p' events/ftrace/print/format > +} > + > +event_header_size=`get_event_header_size` > +print_header_size=`get_print_event_buf_offset` > + > +# Find the README > +README="" > +if [ -f README ]; then > + README="README" > +# instance? > +elif [ -f ../../README ]; then > + README="../../README" > +fi > + > +testone=0 > +if [ ! -z "$README" ]; then > + if grep -q "May be broken into multiple events based on sub-buffer size" $README; then > + testone=1 > + fi > +fi Hmm, this should be a common function if we see this pattern somewhere else. > + > +data_offset=`get_buffer_data_offset` > + > +marker_meta=$((event_header_size+print_header_size)) > + > +make_str() { > + cnt=$1 > + # subtract two for \n\0 as marker adds these > + cnt=$((cnt-2)) > + printf -- 'X%.0s' $(seq $cnt) > +} > + > +write_buffer() { > + size=$1 > + > + str=`make_str $size` > + > + # clear the buffer > + echo > trace > + > + # write the string into the marker > + echo -n $str > trace_marker > + > + echo $str > +} > + > +test_buffer() { > + > + size=`get_buffer_data_size` > + oneline_size=$((size-marker_meta)) > + echo size = $size > + echo meta size = $marker_meta > + > + if [ $testone -eq 1 ]; then > + echo oneline size = $oneline_size > + > + str=`write_buffer $oneline_size` > + > + # Should be in one single event > + new_str=`awk ' /tracing_mark_write:/ { sub(/^.*tracing_mark_write: */,"");printf "%s", $0; exit}' trace` > + > + if [ "$new_str" != "$str" ]; then > + exit fail; > + fi > + fi Or, maybe we can split this part into another testcase. Thank you, > + > + # Now add a little more the meta data overhead will overflow > + > + str=`write_buffer $size` > + > + # Make sure the line was broken > + new_str=`awk ' /tracing_mark_write:/ { sub(/^.*tracing_mark_write: /,"");printf "%s", $0; exit}' trace` > + > + if [ "$new_str" = "$str" ]; then > + exit fail; > + fi > + > + # Make sure the entire line can be found > + new_str=`awk ' /tracing_mark_write:/ { sub(/^.*tracing_mark_write: */,"");printf "%s", $0; }' trace` > + > + if [ "$new_str" != "$str" ]; then > + exit fail; > + fi > +} > + > +test_buffer > + > -- > 2.42.0 >
On Wed, 13 Dec 2023 09:33:18 +0900 Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote: > On Tue, 12 Dec 2023 15:16:32 -0500 > Steven Rostedt <rostedt@goodmis.org> wrote: > > > From: "Steven Rostedt (Google)" <rostedt@goodmis.org> > > > > Now that the trace_marker can write up to the max size of the sub buffer. > > Add a test to see if it actually can happen. > > > > The README is updated to state that the trace_marker writes can be broken > > up, and the test checks the README for that statement so that it does not > > fail on older kernels that does not support this. > > I think it is better that the feature patch include README update or a separate > patch because it identifies the feature is implemented or not. > No need, my v3 removes all this as I found it will not work with the sub buffer resize update. > > > > If the README does not have the specified update, the test will still test > > if all the string is written, as that should work with older kernels. > > > > Cc: Shuah Khan <shuah@kernel.org> > > Cc: linux-kselftest@vger.kernel.org > > Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org> > > --- > > Changes since v1: https://lore.kernel.org/linux-trace-kernel/20231212135441.0337c3e9@gandalf.local.home/ > > > > - Fix description as it was a cut and paste from the subbuffer size tests > > that are not added yet. > > > > kernel/trace/trace.c | 1 + > > .../ftrace/test.d/00basic/trace_marker.tc | 112 ++++++++++++++++++ > > 2 files changed, 113 insertions(+) > > create mode 100755 tools/testing/selftests/ftrace/test.d/00basic/trace_marker.tc > > > > diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c > > index 2f8d59834c00..cbfcdd882590 100644 > > --- a/kernel/trace/trace.c > > +++ b/kernel/trace/trace.c > > @@ -5595,6 +5595,7 @@ static const char readme_msg[] = > > " delta: Delta difference against a buffer-wide timestamp\n" > > " absolute: Absolute (standalone) timestamp\n" > > "\n trace_marker\t\t- Writes into this file writes into the kernel buffer\n" > > + "\n May be broken into multiple events based on sub-buffer size.\n" > > "\n trace_marker_raw\t\t- Writes into this file writes binary data into the kernel buffer\n" > > " tracing_cpumask\t- Limit which CPUs to trace\n" > > " instances\t\t- Make sub-buffers with: mkdir instances/foo\n" > > diff --git a/tools/testing/selftests/ftrace/test.d/00basic/trace_marker.tc b/tools/testing/selftests/ftrace/test.d/00basic/trace_marker.tc > > new file mode 100755 > > index 000000000000..bf7f6f50c88a > > --- /dev/null > > +++ b/tools/testing/selftests/ftrace/test.d/00basic/trace_marker.tc > > @@ -0,0 +1,112 @@ > > +#!/bin/sh > > +# SPDX-License-Identifier: GPL-2.0 > > +# description: Basic tests on writing to trace_marker > > +# requires: trace_marker > > +# flags: instance > > + > > +get_buffer_data_size() { > > + sed -ne 's/^.*data.*size:\([0-9][0-9]*\).*/\1/p' events/header_page > > +} > > + > > +get_buffer_data_offset() { > > + sed -ne 's/^.*data.*offset:\([0-9][0-9]*\).*/\1/p' events/header_page > > +} > > + > > +get_event_header_size() { > > + type_len=`sed -ne 's/^.*type_len.*:[^0-9]*\([0-9][0-9]*\).*/\1/p' events/header_event` > > + time_len=`sed -ne 's/^.*time_delta.*:[^0-9]*\([0-9][0-9]*\).*/\1/p' events/header_event` > > + array_len=`sed -ne 's/^.*array.*:[^0-9]*\([0-9][0-9]*\).*/\1/p' events/header_event` > > + total_bits=$((type_len+time_len+array_len)) > > + total_bits=$((total_bits+7)) > > + echo $((total_bits/8)) > > +} > > + > > +get_print_event_buf_offset() { > > + sed -ne 's/^.*buf.*offset:\([0-9][0-9]*\).*/\1/p' events/ftrace/print/format > > +} > > + > > +event_header_size=`get_event_header_size` > > +print_header_size=`get_print_event_buf_offset` > > + > > +# Find the README > > +README="" > > +if [ -f README ]; then > > + README="README" > > +# instance? > > +elif [ -f ../../README ]; then > > + README="../../README" > > +fi > > + > > +testone=0 > > +if [ ! -z "$README" ]; then > > + if grep -q "May be broken into multiple events based on sub-buffer size" $README; then > > + testone=1 > > + fi > > +fi > > Hmm, this should be a common function if we see this pattern somewhere else. I remove this in the next version. But yeah, there's a bug in the selftests that if a test has an instance flag set, then the requirements will not check the README, as the instance has no README. > > > + > > +data_offset=`get_buffer_data_offset` > > + > > +marker_meta=$((event_header_size+print_header_size)) > > + > > +make_str() { > > + cnt=$1 > > + # subtract two for \n\0 as marker adds these > > + cnt=$((cnt-2)) > > + printf -- 'X%.0s' $(seq $cnt) > > +} > > + > > +write_buffer() { > > + size=$1 > > + > > + str=`make_str $size` > > + > > + # clear the buffer > > + echo > trace > > + > > + # write the string into the marker > > + echo -n $str > trace_marker > > + > > + echo $str > > +} > > + > > +test_buffer() { > > + > > + size=`get_buffer_data_size` > > + oneline_size=$((size-marker_meta)) > > + echo size = $size > > + echo meta size = $marker_meta > > + > > + if [ $testone -eq 1 ]; then > > + echo oneline size = $oneline_size > > + > > + str=`write_buffer $oneline_size` > > + > > + # Should be in one single event > > + new_str=`awk ' /tracing_mark_write:/ { sub(/^.*tracing_mark_write: */,"");printf "%s", $0; exit}' trace` > > + > > + if [ "$new_str" != "$str" ]; then > > + exit fail; > > + fi > > + fi > > Or, maybe we can split this part into another testcase. I removed this anyway. But it may come back in the future if we can get dynamically sized trace_seq working. -- Steve > > > + > > + # Now add a little more the meta data overhead will overflow > > + > > + str=`write_buffer $size` > > + > > + # Make sure the line was broken > > + new_str=`awk ' /tracing_mark_write:/ { sub(/^.*tracing_mark_write: /,"");printf "%s", $0; exit}' trace` > > + > > + if [ "$new_str" = "$str" ]; then > > + exit fail; > > + fi > > + > > + # Make sure the entire line can be found > > + new_str=`awk ' /tracing_mark_write:/ { sub(/^.*tracing_mark_write: */,"");printf "%s", $0; }' trace` > > + > > + if [ "$new_str" != "$str" ]; then > > + exit fail; > > + fi > > +} > > + > > +test_buffer > > + > > -- > > 2.42.0 > > > >
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index 2f8d59834c00..cbfcdd882590 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -5595,6 +5595,7 @@ static const char readme_msg[] = " delta: Delta difference against a buffer-wide timestamp\n" " absolute: Absolute (standalone) timestamp\n" "\n trace_marker\t\t- Writes into this file writes into the kernel buffer\n" + "\n May be broken into multiple events based on sub-buffer size.\n" "\n trace_marker_raw\t\t- Writes into this file writes binary data into the kernel buffer\n" " tracing_cpumask\t- Limit which CPUs to trace\n" " instances\t\t- Make sub-buffers with: mkdir instances/foo\n" diff --git a/tools/testing/selftests/ftrace/test.d/00basic/trace_marker.tc b/tools/testing/selftests/ftrace/test.d/00basic/trace_marker.tc new file mode 100755 index 000000000000..bf7f6f50c88a --- /dev/null +++ b/tools/testing/selftests/ftrace/test.d/00basic/trace_marker.tc @@ -0,0 +1,112 @@ +#!/bin/sh +# SPDX-License-Identifier: GPL-2.0 +# description: Basic tests on writing to trace_marker +# requires: trace_marker +# flags: instance + +get_buffer_data_size() { + sed -ne 's/^.*data.*size:\([0-9][0-9]*\).*/\1/p' events/header_page +} + +get_buffer_data_offset() { + sed -ne 's/^.*data.*offset:\([0-9][0-9]*\).*/\1/p' events/header_page +} + +get_event_header_size() { + type_len=`sed -ne 's/^.*type_len.*:[^0-9]*\([0-9][0-9]*\).*/\1/p' events/header_event` + time_len=`sed -ne 's/^.*time_delta.*:[^0-9]*\([0-9][0-9]*\).*/\1/p' events/header_event` + array_len=`sed -ne 's/^.*array.*:[^0-9]*\([0-9][0-9]*\).*/\1/p' events/header_event` + total_bits=$((type_len+time_len+array_len)) + total_bits=$((total_bits+7)) + echo $((total_bits/8)) +} + +get_print_event_buf_offset() { + sed -ne 's/^.*buf.*offset:\([0-9][0-9]*\).*/\1/p' events/ftrace/print/format +} + +event_header_size=`get_event_header_size` +print_header_size=`get_print_event_buf_offset` + +# Find the README +README="" +if [ -f README ]; then + README="README" +# instance? +elif [ -f ../../README ]; then + README="../../README" +fi + +testone=0 +if [ ! -z "$README" ]; then + if grep -q "May be broken into multiple events based on sub-buffer size" $README; then + testone=1 + fi +fi + +data_offset=`get_buffer_data_offset` + +marker_meta=$((event_header_size+print_header_size)) + +make_str() { + cnt=$1 + # subtract two for \n\0 as marker adds these + cnt=$((cnt-2)) + printf -- 'X%.0s' $(seq $cnt) +} + +write_buffer() { + size=$1 + + str=`make_str $size` + + # clear the buffer + echo > trace + + # write the string into the marker + echo -n $str > trace_marker + + echo $str +} + +test_buffer() { + + size=`get_buffer_data_size` + oneline_size=$((size-marker_meta)) + echo size = $size + echo meta size = $marker_meta + + if [ $testone -eq 1 ]; then + echo oneline size = $oneline_size + + str=`write_buffer $oneline_size` + + # Should be in one single event + new_str=`awk ' /tracing_mark_write:/ { sub(/^.*tracing_mark_write: */,"");printf "%s", $0; exit}' trace` + + if [ "$new_str" != "$str" ]; then + exit fail; + fi + fi + + # Now add a little more the meta data overhead will overflow + + str=`write_buffer $size` + + # Make sure the line was broken + new_str=`awk ' /tracing_mark_write:/ { sub(/^.*tracing_mark_write: /,"");printf "%s", $0; exit}' trace` + + if [ "$new_str" = "$str" ]; then + exit fail; + fi + + # Make sure the entire line can be found + new_str=`awk ' /tracing_mark_write:/ { sub(/^.*tracing_mark_write: */,"");printf "%s", $0; }' trace` + + if [ "$new_str" != "$str" ]; then + exit fail; + fi +} + +test_buffer +