diff options
Diffstat (limited to 'tools')
29 files changed, 528 insertions, 390 deletions
diff --git a/tools/testing/ktest/config-bisect.pl b/tools/testing/ktest/config-bisect.pl index 6fd864935319..bee7cb34a289 100755 --- a/tools/testing/ktest/config-bisect.pl +++ b/tools/testing/ktest/config-bisect.pl @@ -741,9 +741,9 @@ if ($start) { die "Can not find file $bad\n"; } if ($val eq "good") { - run_command "cp $output_config $good" or die "failed to copy $config to $good\n"; + run_command "cp $output_config $good" or die "failed to copy $output_config to $good\n"; } elsif ($val eq "bad") { - run_command "cp $output_config $bad" or die "failed to copy $config to $bad\n"; + run_command "cp $output_config $bad" or die "failed to copy $output_config to $bad\n"; } } diff --git a/tools/testing/selftests/ftrace/ftracetest b/tools/testing/selftests/ftrace/ftracetest index cce72f8b03dc..3230bd54dba8 100755 --- a/tools/testing/selftests/ftrace/ftracetest +++ b/tools/testing/selftests/ftrace/ftracetest @@ -22,6 +22,7 @@ echo " --fail-unresolved Treat UNRESOLVED as a failure" echo " -d|--debug Debug mode (trace all shell commands)" echo " -l|--logdir <dir> Save logs on the <dir>" echo " If <dir> is -, all logs output in console only" +echo " --rv Run RV selftests instead of ftrace ones" exit $1 } @@ -133,6 +134,10 @@ parse_opts() { # opts LINK_PTR= shift 2 ;; + --rv) + RV_TEST=1 + shift 1 + ;; *.tc) if [ -f "$1" ]; then OPT_TEST_CASES="$OPT_TEST_CASES `abspath $1`" @@ -152,9 +157,13 @@ parse_opts() { # opts ;; esac done - if [ ! -z "$OPT_TEST_CASES" ]; then + if [ -n "$OPT_TEST_CASES" ]; then TEST_CASES=$OPT_TEST_CASES fi + if [ -n "$OPT_TEST_DIR" -a -f "$OPT_TEST_DIR"/test.d/functions ]; then + TOP_DIR=$OPT_TEST_DIR + TEST_DIR=$TOP_DIR/test.d + fi } # Parameters @@ -190,10 +199,6 @@ fi TOP_DIR=`absdir $0` TEST_DIR=$TOP_DIR/test.d TEST_CASES=`find_testcases $TEST_DIR` -LOG_TOP_DIR=$TOP_DIR/logs -LOG_DATE=`date +%Y%m%d-%H%M%S` -LOG_DIR=$LOG_TOP_DIR/$LOG_DATE/ -LINK_PTR=$LOG_TOP_DIR/latest KEEP_LOG=0 KTAP=0 DEBUG=0 @@ -201,14 +206,23 @@ VERBOSE=0 UNSUPPORTED_RESULT=0 UNRESOLVED_RESULT=0 STOP_FAILURE=0 +RV_TEST=0 # Parse command-line options parse_opts $* +LOG_TOP_DIR=$TOP_DIR/logs +LOG_DATE=`date +%Y%m%d-%H%M%S` +LOG_DIR=$LOG_TOP_DIR/$LOG_DATE/ +LINK_PTR=$LOG_TOP_DIR/latest + [ $DEBUG -ne 0 ] && set -x -# Verify parameters -if [ -z "$TRACING_DIR" -o ! -d "$TRACING_DIR" ]; then - errexit "No ftrace directory found" +if [ $RV_TEST -ne 0 ]; then + TRACING_DIR=$TRACING_DIR/rv + if [ ! -d "$TRACING_DIR" ]; then + err_ret=$err_skip + errexit "rv is not configured in this kernel" + fi fi # Preparing logs @@ -419,7 +433,7 @@ trap 'SIG_RESULT=$XFAIL' $SIG_XFAIL __run_test() { # testfile # setup PID and PPID, $$ is not updated. (cd $TRACING_DIR; read PID _ < /proc/self/stat; set -e; set -x; - checkreq $1; initialize_ftrace; . $1) + checkreq $1; initialize_system; . $1) [ $? -ne 0 ] && kill -s $SIG_FAIL $SIG_PID } @@ -496,7 +510,7 @@ for t in $TEST_CASES; do exit 1 fi done -(cd $TRACING_DIR; finish_ftrace) # for cleanup +(cd $TRACING_DIR; finish_system) # for cleanup prlog "" prlog "# of passed: " `echo $PASSED_CASES | wc -w` diff --git a/tools/testing/selftests/ftrace/test.d/00basic/mount_options.tc b/tools/testing/selftests/ftrace/test.d/00basic/mount_options.tc index 8a7ce647a60d..318939451caf 100644 --- a/tools/testing/selftests/ftrace/test.d/00basic/mount_options.tc +++ b/tools/testing/selftests/ftrace/test.d/00basic/mount_options.tc @@ -28,7 +28,7 @@ unmount_tracefs() { local mount_point="$1" # Need to make sure the mount isn't busy so that we can umount it - (cd $mount_point; finish_ftrace;) + (cd $mount_point; finish_system;) cleanup } diff --git a/tools/testing/selftests/ftrace/test.d/functions b/tools/testing/selftests/ftrace/test.d/functions index a1052bf460fc..e8e718139294 100644 --- a/tools/testing/selftests/ftrace/test.d/functions +++ b/tools/testing/selftests/ftrace/test.d/functions @@ -104,7 +104,7 @@ clear_dynamic_events() { # reset all current dynamic events done } -initialize_ftrace() { # Reset ftrace to initial-state +initialize_system() { # Reset ftrace to initial-state # As the initial state, ftrace will be set to nop tracer, # no events, no triggers, no filters, no function filters, # no probes, and tracing on. @@ -134,8 +134,8 @@ initialize_ftrace() { # Reset ftrace to initial-state enable_tracing } -finish_ftrace() { - initialize_ftrace +finish_system() { + initialize_system # And recover it to default. [ -f options/pause-on-trace ] && echo 0 > options/pause-on-trace } diff --git a/tools/testing/selftests/tpm2/tpm2.py b/tools/testing/selftests/tpm2/tpm2.py index bba8cb54548e..3d130c30bc7c 100644 --- a/tools/testing/selftests/tpm2/tpm2.py +++ b/tools/testing/selftests/tpm2/tpm2.py @@ -437,7 +437,7 @@ class Client: def extend_pcr(self, i, dig, bank_alg = TPM2_ALG_SHA1): ds = get_digest_size(bank_alg) - assert(ds == len(dig)) + assert ds == len(dig) auth_cmd = AuthCommand() @@ -589,7 +589,7 @@ class Client: def seal(self, parent_key, data, auth_value, policy_dig, name_alg = TPM2_ALG_SHA1): ds = get_digest_size(name_alg) - assert(not policy_dig or ds == len(policy_dig)) + assert not policy_dig or ds == len(policy_dig) attributes = 0 if not policy_dig: diff --git a/tools/testing/selftests/verification/.gitignore b/tools/testing/selftests/verification/.gitignore new file mode 100644 index 000000000000..2659417cb2c7 --- /dev/null +++ b/tools/testing/selftests/verification/.gitignore @@ -0,0 +1,2 @@ +# SPDX-License-Identifier: GPL-2.0-only +logs diff --git a/tools/testing/selftests/verification/Makefile b/tools/testing/selftests/verification/Makefile new file mode 100644 index 000000000000..aa8790c22a71 --- /dev/null +++ b/tools/testing/selftests/verification/Makefile @@ -0,0 +1,8 @@ +# SPDX-License-Identifier: GPL-2.0 +all: + +TEST_PROGS := verificationtest-ktap +TEST_FILES := test.d settings +EXTRA_CLEAN := $(OUTPUT)/logs/* + +include ../lib.mk diff --git a/tools/testing/selftests/verification/config b/tools/testing/selftests/verification/config new file mode 100644 index 000000000000..43072c1c38f4 --- /dev/null +++ b/tools/testing/selftests/verification/config @@ -0,0 +1 @@ +CONFIG_RV=y diff --git a/tools/testing/selftests/verification/settings b/tools/testing/selftests/verification/settings new file mode 100644 index 000000000000..e7b9417537fb --- /dev/null +++ b/tools/testing/selftests/verification/settings @@ -0,0 +1 @@ +timeout=0 diff --git a/tools/testing/selftests/verification/test.d/functions b/tools/testing/selftests/verification/test.d/functions new file mode 100644 index 000000000000..ec36a092f56e --- /dev/null +++ b/tools/testing/selftests/verification/test.d/functions @@ -0,0 +1,39 @@ +check_requires() { # Check required files, monitors and reactors + for i in "$@" ; do + p=${i%:program} + m=${i%:monitor} + r=${i%:reactor} + if [ $p != $i ]; then + if ! which $p ; then + echo "Required program $p is not found." + exit_unresolved + fi + elif [ $m != $i ]; then + if ! grep -wq $m available_monitors ; then + echo "Required monitor $m is not configured." + exit_unsupported + fi + elif [ $r != $i ]; then + if ! grep -wq $r available_reactors ; then + echo "Required reactor $r is not configured." + exit_unsupported + fi + elif [ ! -e $i ]; then + echo "Required feature interface $i doesn't exist." + exit_unsupported + fi + done +} + +initialize_system() { # Reset RV to initial-state + echo > enabled_monitors + for m in monitors/*; do + echo nop > $m/reactors || true + done + echo 1 > monitoring_on + echo 1 > reacting_on || true +} + +finish_system() { + initialize_system +} diff --git a/tools/testing/selftests/verification/test.d/rv_monitor_enable_disable.tc b/tools/testing/selftests/verification/test.d/rv_monitor_enable_disable.tc new file mode 100644 index 000000000000..f29236defb5a --- /dev/null +++ b/tools/testing/selftests/verification/test.d/rv_monitor_enable_disable.tc @@ -0,0 +1,75 @@ +#!/bin/sh +# SPDX-License-Identifier: GPL-2.0-or-later +# description: Test monitor enable/disable + +test_simple_monitor() { + local monitor="$1" + local prefix="$2" # nested monitors + + echo 1 > "monitors/$prefix$monitor/enable" + grep -q "$monitor$" enabled_monitors + + echo 0 > "monitors/$prefix$monitor/enable" + ! grep -q "$monitor$" enabled_monitors + + echo "$monitor" >> enabled_monitors + grep -q 1 "monitors/$prefix$monitor/enable" + + echo "!$monitor" >> enabled_monitors + grep -q 0 "monitors/$prefix$monitor/enable" +} + +test_container_monitor() { + local monitor="$1" + local nested + + echo 1 > "monitors/$monitor/enable" + grep -q "^$monitor$" enabled_monitors + + for nested_dir in "monitors/$monitor"/*; do + [ -d "$nested_dir" ] || continue + nested=$(basename "$nested_dir") + grep -q "^$monitor:$nested$" enabled_monitors + done + test -n "$nested" + + echo 0 > "monitors/$monitor/enable" + ! grep -q "^$monitor$" enabled_monitors + + for nested_dir in "monitors/$monitor"/*; do + [ -d "$nested_dir" ] || continue + nested=$(basename "$nested_dir") + ! grep -q "^$monitor:$nested$" enabled_monitors + done + + echo "$monitor" >> enabled_monitors + grep -q 1 "monitors/$monitor/enable" + + for nested_dir in "monitors/$monitor"/*; do + [ -d "$nested_dir" ] || continue + nested=$(basename "$nested_dir") + grep -q "^$monitor:$nested$" enabled_monitors + done + + echo "!$monitor" >> enabled_monitors + grep -q 0 "monitors/$monitor/enable" + + for nested_dir in "monitors/$monitor"/*; do + [ -d "$nested_dir" ] || continue + nested=$(basename "$nested_dir") + test_simple_monitor "$nested" "$monitor/" + done +} + +for monitor_dir in monitors/*; do + monitor=$(basename "$monitor_dir") + + if find "$monitor_dir" -mindepth 1 -type d | grep -q .; then + test_container_monitor "$monitor" + else + test_simple_monitor "$monitor" + fi +done + +! echo non_existent_monitor > enabled_monitors +! grep -q "^non_existent_monitor$" enabled_monitors diff --git a/tools/testing/selftests/verification/test.d/rv_monitor_reactor.tc b/tools/testing/selftests/verification/test.d/rv_monitor_reactor.tc new file mode 100644 index 000000000000..2958bf849338 --- /dev/null +++ b/tools/testing/selftests/verification/test.d/rv_monitor_reactor.tc @@ -0,0 +1,68 @@ +#!/bin/sh +# SPDX-License-Identifier: GPL-2.0-or-later +# description: Test monitor reactor setting +# requires: available_reactors + +test_monitor_reactor() { + local monitor="$1" + local prefix="$2" # nested monitors + + while read -r reactor; do + [ "$reactor" = nop ] && continue + + echo "$reactor" > "monitors/$prefix$monitor/reactors" + grep -q "\\[$reactor\\]" "monitors/$prefix$monitor/reactors" + done < available_reactors + + echo nop > "monitors/$prefix$monitor/reactors" + grep -q "\\[nop\\]" "monitors/$prefix$monitor/reactors" +} + +test_container_monitor() { + local monitor="$1" + local nested + + while read -r reactor; do + [ "$reactor" = nop ] && continue + + echo "$reactor" > "monitors/$monitor/reactors" + grep -q "\\[$reactor\\]" "monitors/$monitor/reactors" + + for nested_dir in "monitors/$monitor"/*; do + [ -d "$nested_dir" ] || continue + nested=$(basename "$nested_dir") + grep -q "\\[$reactor\\]" "monitors/$monitor/$nested/reactors" + done + done < available_reactors + test -n "$nested" + + echo nop > "monitors/$monitor/reactors" + grep -q "\\[nop\\]" "monitors/$monitor/reactors" + + for nested_dir in "monitors/$monitor"/*; do + [ -d "$nested_dir" ] || continue + nested=$(basename "$nested_dir") + grep -q "\\[nop\\]" "monitors/$monitor/$nested/reactors" + done + + for nested_dir in "monitors/$monitor"/*; do + [ -d "$nested_dir" ] || continue + nested=$(basename "$nested_dir") + test_monitor_reactor "$nested" "$monitor/" + done +} + +for monitor_dir in monitors/*; do + monitor=$(basename "$monitor_dir") + + if find "$monitor_dir" -mindepth 1 -type d | grep -q .; then + test_container_monitor "$monitor" + else + test_monitor_reactor "$monitor" + fi +done + +monitor=$(ls /sys/kernel/tracing/rv/monitors -1 | head -n 1) +test -f "monitors/$monitor/reactors" +! echo non_existent_reactor > "monitors/$monitor/reactors" +! grep -q "\\[non_existent_reactor\\]" "monitors/$monitor/reactors" diff --git a/tools/testing/selftests/verification/test.d/rv_monitors_available.tc b/tools/testing/selftests/verification/test.d/rv_monitors_available.tc new file mode 100644 index 000000000000..e6a4a1410690 --- /dev/null +++ b/tools/testing/selftests/verification/test.d/rv_monitors_available.tc @@ -0,0 +1,18 @@ +#!/bin/sh +# SPDX-License-Identifier: GPL-2.0-or-later +# description: Check available monitors + +for monitor_dir in monitors/*; do + monitor=$(basename "$monitor_dir") + + grep -q "^$monitor$" available_monitors + grep -q . "$monitor_dir"/desc + + for nested_dir in "$monitor_dir"/*; do + [ -d "$nested_dir" ] || continue + nested=$(basename "$nested_dir") + + grep -q "^$monitor:$nested$" available_monitors + grep -q . "$nested_dir"/desc + done +done diff --git a/tools/testing/selftests/verification/test.d/rv_wwnr_printk.tc b/tools/testing/selftests/verification/test.d/rv_wwnr_printk.tc new file mode 100644 index 000000000000..5a59432b1d93 --- /dev/null +++ b/tools/testing/selftests/verification/test.d/rv_wwnr_printk.tc @@ -0,0 +1,30 @@ +#!/bin/sh +# SPDX-License-Identifier: GPL-2.0-or-later +# description: Test wwnr monitor with printk reactor +# requires: available_reactors wwnr:monitor printk:reactor stress-ng:program + +load() { # returns true if there was a reaction + local lines_before num + num=$((($(nproc) + 1) / 2)) + lines_before=$(dmesg | wc -l) + stress-ng --cpu-sched "$num" --timer "$num" -t 5 -q + dmesg | tail -n $((lines_before + 1)) | grep -q "rv: monitor wwnr does not allow event" +} + +echo 1 > monitors/wwnr/enable +echo printk > monitors/wwnr/reactors + +load + +echo 0 > monitoring_on +! load +echo 1 > monitoring_on + +load + +echo 0 > reacting_on +! load +echo 1 > reacting_on + +echo nop > monitors/wwnr/reactors +echo 0 > monitors/wwnr/enable diff --git a/tools/testing/selftests/verification/verificationtest-ktap b/tools/testing/selftests/verification/verificationtest-ktap new file mode 100755 index 000000000000..18f7fe324e2f --- /dev/null +++ b/tools/testing/selftests/verification/verificationtest-ktap @@ -0,0 +1,8 @@ +#!/bin/sh -e +# SPDX-License-Identifier: GPL-2.0-only +# +# ftracetest-ktap: Wrapper to integrate ftracetest with the kselftest runner +# +# Copyright (C) Arm Ltd., 2023 + +../ftrace/ftracetest -K -v --rv ../verification diff --git a/tools/tracing/rtla/Makefile.rtla b/tools/tracing/rtla/Makefile.rtla index 08c1b40883d3..1743d91829d4 100644 --- a/tools/tracing/rtla/Makefile.rtla +++ b/tools/tracing/rtla/Makefile.rtla @@ -18,7 +18,7 @@ export CC AR STRIP PKG_CONFIG LD_SO_CONF_PATH LDCONFIG FOPTS := -flto=auto -ffat-lto-objects -fexceptions -fstack-protector-strong \ -fasynchronous-unwind-tables -fstack-clash-protection WOPTS := -O -Wall -Werror=format-security -Wp,-D_FORTIFY_SOURCE=2 \ - -Wp,-D_GLIBCXX_ASSERTIONS -Wno-maybe-uninitialized + -Wp,-D_GLIBCXX_ASSERTIONS ifeq ($(CC),clang) FOPTS := $(filter-out -flto=auto -ffat-lto-objects, $(FOPTS)) diff --git a/tools/tracing/rtla/src/common.c b/tools/tracing/rtla/src/common.c index 2e6e3dac1897..b197037fc58b 100644 --- a/tools/tracing/rtla/src/common.c +++ b/tools/tracing/rtla/src/common.c @@ -268,6 +268,10 @@ int top_main_loop(struct osnoise_tool *tool) tool->ops->print_stats(tool); if (osnoise_trace_is_off(tool, record)) { + if (stop_tracing) + /* stop tracing requested, do not perform actions */ + return 0; + actions_perform(¶ms->threshold_actions); if (!params->threshold_actions.continue_flag) @@ -315,20 +319,22 @@ int hist_main_loop(struct osnoise_tool *tool) } if (osnoise_trace_is_off(tool, tool->record)) { + if (stop_tracing) + /* stop tracing requested, do not perform actions */ + break; + actions_perform(¶ms->threshold_actions); - if (!params->threshold_actions.continue_flag) { + if (!params->threshold_actions.continue_flag) /* continue flag not set, break */ break; - /* continue action reached, re-enable tracing */ - if (tool->record) - trace_instance_start(&tool->record->trace); - if (tool->aa) - trace_instance_start(&tool->aa->trace); - trace_instance_start(&tool->trace); - } - break; + /* continue action reached, re-enable tracing */ + if (tool->record) + trace_instance_start(&tool->record->trace); + if (tool->aa) + trace_instance_start(&tool->aa->trace); + trace_instance_start(&tool->trace); } /* is there still any user-threads ? */ diff --git a/tools/tracing/rtla/src/common.h b/tools/tracing/rtla/src/common.h index 355f113a14a3..9ec2b7632c37 100644 --- a/tools/tracing/rtla/src/common.h +++ b/tools/tracing/rtla/src/common.h @@ -107,6 +107,10 @@ struct common_params { struct timerlat_u_params user; }; +#define for_each_monitored_cpu(cpu, nr_cpus, common) \ + for (cpu = 0; cpu < nr_cpus; cpu++) \ + if (!(common)->cpus || CPU_ISSET(cpu, &(common)->monitored_cpus)) + struct tool_ops; /* diff --git a/tools/tracing/rtla/src/osnoise_hist.c b/tools/tracing/rtla/src/osnoise_hist.c index dffb6d0a98d7..ff8c231e47c4 100644 --- a/tools/tracing/rtla/src/osnoise_hist.c +++ b/tools/tracing/rtla/src/osnoise_hist.c @@ -247,9 +247,7 @@ static void osnoise_hist_header(struct osnoise_tool *tool) if (!params->common.hist.no_index) trace_seq_printf(s, "Index"); - for (cpu = 0; cpu < data->nr_cpus; cpu++) { - if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) { if (!data->hist[cpu].count) continue; @@ -278,9 +276,7 @@ osnoise_print_summary(struct osnoise_params *params, if (!params->common.hist.no_index) trace_seq_printf(trace->seq, "count:"); - for (cpu = 0; cpu < data->nr_cpus; cpu++) { - if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) { if (!data->hist[cpu].count) continue; @@ -292,9 +288,7 @@ osnoise_print_summary(struct osnoise_params *params, if (!params->common.hist.no_index) trace_seq_printf(trace->seq, "min: "); - for (cpu = 0; cpu < data->nr_cpus; cpu++) { - if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) { if (!data->hist[cpu].count) continue; @@ -307,9 +301,7 @@ osnoise_print_summary(struct osnoise_params *params, if (!params->common.hist.no_index) trace_seq_printf(trace->seq, "avg: "); - for (cpu = 0; cpu < data->nr_cpus; cpu++) { - if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) { if (!data->hist[cpu].count) continue; @@ -325,9 +317,7 @@ osnoise_print_summary(struct osnoise_params *params, if (!params->common.hist.no_index) trace_seq_printf(trace->seq, "max: "); - for (cpu = 0; cpu < data->nr_cpus; cpu++) { - if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) { if (!data->hist[cpu].count) continue; @@ -362,9 +352,7 @@ osnoise_print_stats(struct osnoise_tool *tool) trace_seq_printf(trace->seq, "%-6d", bucket * data->bucket_size); - for (cpu = 0; cpu < data->nr_cpus; cpu++) { - if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) { if (!data->hist[cpu].count) continue; @@ -400,9 +388,7 @@ osnoise_print_stats(struct osnoise_tool *tool) if (!params->common.hist.no_index) trace_seq_printf(trace->seq, "over: "); - for (cpu = 0; cpu < data->nr_cpus; cpu++) { - if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) { if (!data->hist[cpu].count) continue; @@ -421,16 +407,16 @@ osnoise_print_stats(struct osnoise_tool *tool) /* * osnoise_hist_usage - prints osnoise hist usage message */ -static void osnoise_hist_usage(char *usage) +static void osnoise_hist_usage(void) { int i; static const char * const msg[] = { "", " usage: rtla osnoise hist [-h] [-D] [-d s] [-a us] [-p us] [-r us] [-s us] [-S us] \\", - " [-T us] [-t[file]] [-e sys[:event]] [--filter <filter>] [--trigger <trigger>] \\", + " [-T us] [-t [file]] [-e sys[:event]] [--filter <filter>] [--trigger <trigger>] \\", " [-c cpu-list] [-H cpu-list] [-P priority] [-b N] [-E N] [--no-header] [--no-summary] \\", - " [--no-index] [--with-zeros] [-C[=cgroup_name]] [--warm-up]", + " [--no-index] [--with-zeros] [-C [cgroup_name]] [--warm-up]", "", " -h/--help: print this menu", " -a/--auto: set automatic trace mode, stopping the session if argument in us sample is hit", @@ -441,10 +427,10 @@ static void osnoise_hist_usage(char *usage) " -T/--threshold us: the minimum delta to be considered a noise", " -c/--cpus cpu-list: list of cpus to run osnoise threads", " -H/--house-keeping cpus: run rtla control threads only on the given cpus", - " -C/--cgroup[=cgroup_name]: set cgroup, if no cgroup_name is passed, the rtla's cgroup will be inherited", + " -C/--cgroup [cgroup_name]: set cgroup, if no cgroup_name is passed, the rtla's cgroup will be inherited", " -d/--duration time[s|m|h|d]: duration of the session", " -D/--debug: print debug info", - " -t/--trace[file]: save the stopped trace to [file|osnoise_trace.txt]", + " -t/--trace [file]: save the stopped trace to [file|osnoise_trace.txt]", " -e/--event <sys:event>: enable the <sys:event> in the trace instance, multiple -e are allowed", " --filter <filter>: enable a trace event filter to the previous -e event", " --trigger <trigger>: enable a trace event trigger to the previous -e event", @@ -467,18 +453,12 @@ static void osnoise_hist_usage(char *usage) NULL, }; - if (usage) - fprintf(stderr, "%s\n", usage); - fprintf(stderr, "rtla osnoise hist: a per-cpu histogram of the OS noise (version %s)\n", VERSION); for (i = 0; msg[i]; i++) fprintf(stderr, "%s\n", msg[i]); - if (usage) - exit(EXIT_FAILURE); - exit(EXIT_SUCCESS); } @@ -538,11 +518,8 @@ static struct common_params {0, 0, 0, 0} }; - /* getopt_long stores the option index here. */ - int option_index = 0; - c = getopt_long(argc, argv, "a:c:C::b:d:e:E:DhH:p:P:r:s:S:t::T:01234:5:6:7:", - long_options, &option_index); + long_options, NULL); /* detect the end of the options. */ if (c == -1) @@ -557,30 +534,25 @@ static struct common_params params->threshold = 1; /* set trace */ - trace_output = "osnoise_trace.txt"; + if (!trace_output) + trace_output = "osnoise_trace.txt"; break; case 'b': params->common.hist.bucket_size = get_llong_from_str(optarg); if (params->common.hist.bucket_size == 0 || params->common.hist.bucket_size >= 1000000) - osnoise_hist_usage("Bucket size needs to be > 0 and <= 1000000\n"); + fatal("Bucket size needs to be > 0 and <= 1000000"); break; case 'c': retval = parse_cpu_set(optarg, ¶ms->common.monitored_cpus); if (retval) - osnoise_hist_usage("\nInvalid -c cpu list\n"); + fatal("Invalid -c cpu list"); params->common.cpus = optarg; break; case 'C': params->common.cgroup = 1; - if (!optarg) { - /* will inherit this cgroup */ - params->common.cgroup_name = NULL; - } else if (*optarg == '=') { - /* skip the = */ - params->common.cgroup_name = ++optarg; - } + params->common.cgroup_name = parse_optional_arg(argc, argv); break; case 'D': config_debug = 1; @@ -588,14 +560,12 @@ static struct common_params case 'd': params->common.duration = parse_seconds_duration(optarg); if (!params->common.duration) - osnoise_hist_usage("Invalid -D duration\n"); + fatal("Invalid -D duration"); break; case 'e': tevent = trace_event_alloc(optarg); - if (!tevent) { - err_msg("Error alloc trace event"); - exit(EXIT_FAILURE); - } + if (!tevent) + fatal("Error alloc trace event"); if (params->common.events) tevent->next = params->common.events; @@ -606,35 +576,33 @@ static struct common_params params->common.hist.entries = get_llong_from_str(optarg); if (params->common.hist.entries < 10 || params->common.hist.entries > 9999999) - osnoise_hist_usage("Entries must be > 10 and < 9999999\n"); + fatal("Entries must be > 10 and < 9999999"); break; case 'h': case '?': - osnoise_hist_usage(NULL); + osnoise_hist_usage(); break; case 'H': params->common.hk_cpus = 1; retval = parse_cpu_set(optarg, ¶ms->common.hk_cpu_set); - if (retval) { - err_msg("Error parsing house keeping CPUs\n"); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Error parsing house keeping CPUs"); break; case 'p': params->period = get_llong_from_str(optarg); if (params->period > 10000000) - osnoise_hist_usage("Period longer than 10 s\n"); + fatal("Period longer than 10 s"); break; case 'P': retval = parse_prio(optarg, ¶ms->common.sched_param); if (retval == -1) - osnoise_hist_usage("Invalid -P priority"); + fatal("Invalid -P priority"); params->common.set_sched = 1; break; case 'r': params->runtime = get_llong_from_str(optarg); if (params->runtime < 100) - osnoise_hist_usage("Runtime shorter than 100 us\n"); + fatal("Runtime shorter than 100 us"); break; case 's': params->common.stop_us = get_llong_from_str(optarg); @@ -646,14 +614,8 @@ static struct common_params params->threshold = get_llong_from_str(optarg); break; case 't': - if (optarg) { - if (optarg[0] == '=') - trace_output = &optarg[1]; - else - trace_output = &optarg[0]; - } else if (optind < argc && argv[optind][0] != '0') - trace_output = argv[optind]; - else + trace_output = parse_optional_arg(argc, argv); + if (!trace_output) trace_output = "osnoise_trace.txt"; break; case '0': /* no header */ @@ -671,23 +633,19 @@ static struct common_params case '4': /* trigger */ if (params->common.events) { retval = trace_event_add_trigger(params->common.events, optarg); - if (retval) { - err_msg("Error adding trigger %s\n", optarg); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Error adding trigger %s", optarg); } else { - osnoise_hist_usage("--trigger requires a previous -e\n"); + fatal("--trigger requires a previous -e"); } break; case '5': /* filter */ if (params->common.events) { retval = trace_event_add_filter(params->common.events, optarg); - if (retval) { - err_msg("Error adding filter %s\n", optarg); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Error adding filter %s", optarg); } else { - osnoise_hist_usage("--filter requires a previous -e\n"); + fatal("--filter requires a previous -e"); } break; case '6': @@ -699,34 +657,28 @@ static struct common_params case '8': retval = actions_parse(¶ms->common.threshold_actions, optarg, "osnoise_trace.txt"); - if (retval) { - err_msg("Invalid action %s\n", optarg); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Invalid action %s", optarg); break; case '9': retval = actions_parse(¶ms->common.end_actions, optarg, "osnoise_trace.txt"); - if (retval) { - err_msg("Invalid action %s\n", optarg); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Invalid action %s", optarg); break; default: - osnoise_hist_usage("Invalid option"); + fatal("Invalid option"); } } if (trace_output) actions_add_trace_output(¶ms->common.threshold_actions, trace_output); - if (geteuid()) { - err_msg("rtla needs root permission\n"); - exit(EXIT_FAILURE); - } + if (geteuid()) + fatal("rtla needs root permission"); if (params->common.hist.no_index && !params->common.hist.with_zeros) - osnoise_hist_usage("no-index set and with-zeros not set - it does not make sense"); + fatal("no-index set and with-zeros not set - it does not make sense"); return ¶ms->common; } diff --git a/tools/tracing/rtla/src/osnoise_top.c b/tools/tracing/rtla/src/osnoise_top.c index 95418f7ecc96..04c699bdd736 100644 --- a/tools/tracing/rtla/src/osnoise_top.c +++ b/tools/tracing/rtla/src/osnoise_top.c @@ -243,9 +243,7 @@ osnoise_print_stats(struct osnoise_tool *top) osnoise_top_header(top); - for (i = 0; i < nr_cpus; i++) { - if (params->common.cpus && !CPU_ISSET(i, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(i, nr_cpus, ¶ms->common) { osnoise_top_print(top, i); } @@ -257,14 +255,14 @@ osnoise_print_stats(struct osnoise_tool *top) /* * osnoise_top_usage - prints osnoise top usage message */ -static void osnoise_top_usage(struct osnoise_params *params, char *usage) +static void osnoise_top_usage(struct osnoise_params *params) { int i; static const char * const msg[] = { " [-h] [-q] [-D] [-d s] [-a us] [-p us] [-r us] [-s us] [-S us] \\", - " [-T us] [-t[file]] [-e sys[:event]] [--filter <filter>] [--trigger <trigger>] \\", - " [-c cpu-list] [-H cpu-list] [-P priority] [-C[=cgroup_name]] [--warm-up s]", + " [-T us] [-t [file]] [-e sys[:event]] [--filter <filter>] [--trigger <trigger>] \\", + " [-c cpu-list] [-H cpu-list] [-P priority] [-C [cgroup_name]] [--warm-up s]", "", " -h/--help: print this menu", " -a/--auto: set automatic trace mode, stopping the session if argument in us sample is hit", @@ -275,10 +273,10 @@ static void osnoise_top_usage(struct osnoise_params *params, char *usage) " -T/--threshold us: the minimum delta to be considered a noise", " -c/--cpus cpu-list: list of cpus to run osnoise threads", " -H/--house-keeping cpus: run rtla control threads only on the given cpus", - " -C/--cgroup[=cgroup_name]: set cgroup, if no cgroup_name is passed, the rtla's cgroup will be inherited", + " -C/--cgroup [cgroup_name]: set cgroup, if no cgroup_name is passed, the rtla's cgroup will be inherited", " -d/--duration time[s|m|h|d]: duration of the session", " -D/--debug: print debug info", - " -t/--trace[file]: save the stopped trace to [file|osnoise_trace.txt]", + " -t/--trace [file]: save the stopped trace to [file|osnoise_trace.txt]", " -e/--event <sys:event>: enable the <sys:event> in the trace instance, multiple -e are allowed", " --filter <filter>: enable a trace event filter to the previous -e event", " --trigger <trigger>: enable a trace event trigger to the previous -e event", @@ -296,9 +294,6 @@ static void osnoise_top_usage(struct osnoise_params *params, char *usage) NULL, }; - if (usage) - fprintf(stderr, "%s\n", usage); - if (params->mode == MODE_OSNOISE) { fprintf(stderr, "rtla osnoise top: a per-cpu summary of the OS noise (version %s)\n", @@ -318,9 +313,6 @@ static void osnoise_top_usage(struct osnoise_params *params, char *usage) for (i = 0; msg[i]; i++) fprintf(stderr, "%s\n", msg[i]); - if (usage) - exit(EXIT_FAILURE); - exit(EXIT_SUCCESS); } @@ -378,11 +370,8 @@ struct common_params *osnoise_top_parse_args(int argc, char **argv) {0, 0, 0, 0} }; - /* getopt_long stores the option index here. */ - int option_index = 0; - c = getopt_long(argc, argv, "a:c:C::d:De:hH:p:P:qr:s:S:t::T:0:1:2:3:", - long_options, &option_index); + long_options, NULL); /* Detect the end of the options. */ if (c == -1) @@ -397,24 +386,19 @@ struct common_params *osnoise_top_parse_args(int argc, char **argv) params->threshold = 1; /* set trace */ - trace_output = "osnoise_trace.txt"; + if (!trace_output) + trace_output = "osnoise_trace.txt"; break; case 'c': retval = parse_cpu_set(optarg, ¶ms->common.monitored_cpus); if (retval) - osnoise_top_usage(params, "\nInvalid -c cpu list\n"); + fatal("Invalid -c cpu list"); params->common.cpus = optarg; break; case 'C': params->common.cgroup = 1; - if (!optarg) { - /* will inherit this cgroup */ - params->common.cgroup_name = NULL; - } else if (*optarg == '=') { - /* skip the = */ - params->common.cgroup_name = ++optarg; - } + params->common.cgroup_name = parse_optional_arg(argc, argv); break; case 'D': config_debug = 1; @@ -422,14 +406,12 @@ struct common_params *osnoise_top_parse_args(int argc, char **argv) case 'd': params->common.duration = parse_seconds_duration(optarg); if (!params->common.duration) - osnoise_top_usage(params, "Invalid -d duration\n"); + fatal("Invalid -d duration"); break; case 'e': tevent = trace_event_alloc(optarg); - if (!tevent) { - err_msg("Error alloc trace event"); - exit(EXIT_FAILURE); - } + if (!tevent) + fatal("Error alloc trace event"); if (params->common.events) tevent->next = params->common.events; @@ -438,25 +420,23 @@ struct common_params *osnoise_top_parse_args(int argc, char **argv) break; case 'h': case '?': - osnoise_top_usage(params, NULL); + osnoise_top_usage(params); break; case 'H': params->common.hk_cpus = 1; retval = parse_cpu_set(optarg, ¶ms->common.hk_cpu_set); - if (retval) { - err_msg("Error parsing house keeping CPUs\n"); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Error parsing house keeping CPUs"); break; case 'p': params->period = get_llong_from_str(optarg); if (params->period > 10000000) - osnoise_top_usage(params, "Period longer than 10 s\n"); + fatal("Period longer than 10 s"); break; case 'P': retval = parse_prio(optarg, ¶ms->common.sched_param); if (retval == -1) - osnoise_top_usage(params, "Invalid -P priority"); + fatal("Invalid -P priority"); params->common.set_sched = 1; break; case 'q': @@ -465,7 +445,7 @@ struct common_params *osnoise_top_parse_args(int argc, char **argv) case 'r': params->runtime = get_llong_from_str(optarg); if (params->runtime < 100) - osnoise_top_usage(params, "Runtime shorter than 100 us\n"); + fatal("Runtime shorter than 100 us"); break; case 's': params->common.stop_us = get_llong_from_str(optarg); @@ -474,14 +454,8 @@ struct common_params *osnoise_top_parse_args(int argc, char **argv) params->common.stop_total_us = get_llong_from_str(optarg); break; case 't': - if (optarg) { - if (optarg[0] == '=') - trace_output = &optarg[1]; - else - trace_output = &optarg[0]; - } else if (optind < argc && argv[optind][0] != '-') - trace_output = argv[optind]; - else + trace_output = parse_optional_arg(argc, argv); + if (!trace_output) trace_output = "osnoise_trace.txt"; break; case 'T': @@ -490,23 +464,19 @@ struct common_params *osnoise_top_parse_args(int argc, char **argv) case '0': /* trigger */ if (params->common.events) { retval = trace_event_add_trigger(params->common.events, optarg); - if (retval) { - err_msg("Error adding trigger %s\n", optarg); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Error adding trigger %s", optarg); } else { - osnoise_top_usage(params, "--trigger requires a previous -e\n"); + fatal("--trigger requires a previous -e"); } break; case '1': /* filter */ if (params->common.events) { retval = trace_event_add_filter(params->common.events, optarg); - if (retval) { - err_msg("Error adding filter %s\n", optarg); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Error adding filter %s", optarg); } else { - osnoise_top_usage(params, "--filter requires a previous -e\n"); + fatal("--filter requires a previous -e"); } break; case '2': @@ -518,31 +488,25 @@ struct common_params *osnoise_top_parse_args(int argc, char **argv) case '4': retval = actions_parse(¶ms->common.threshold_actions, optarg, "osnoise_trace.txt"); - if (retval) { - err_msg("Invalid action %s\n", optarg); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Invalid action %s", optarg); break; case '5': retval = actions_parse(¶ms->common.end_actions, optarg, "osnoise_trace.txt"); - if (retval) { - err_msg("Invalid action %s\n", optarg); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Invalid action %s", optarg); break; default: - osnoise_top_usage(params, "Invalid option"); + fatal("Invalid option"); } } if (trace_output) actions_add_trace_output(¶ms->common.threshold_actions, trace_output); - if (geteuid()) { - err_msg("osnoise needs root permission\n"); - exit(EXIT_FAILURE); - } + if (geteuid()) + fatal("osnoise needs root permission"); return ¶ms->common; } diff --git a/tools/tracing/rtla/src/timerlat.bpf.c b/tools/tracing/rtla/src/timerlat.bpf.c index 084cd10c21fc..e2265b5d6491 100644 --- a/tools/tracing/rtla/src/timerlat.bpf.c +++ b/tools/tracing/rtla/src/timerlat.bpf.c @@ -148,6 +148,9 @@ int handle_timerlat_sample(struct trace_event_raw_timerlat_sample *tp_args) } else { update_main_hist(&hist_user, bucket); update_summary(&summary_user, latency, bucket); + + if (thread_threshold != 0 && latency_us >= thread_threshold) + set_stop_tracing(); } return 0; diff --git a/tools/tracing/rtla/src/timerlat.c b/tools/tracing/rtla/src/timerlat.c index b69212874127..df4f9bfe3433 100644 --- a/tools/tracing/rtla/src/timerlat.c +++ b/tools/tracing/rtla/src/timerlat.c @@ -126,9 +126,7 @@ int timerlat_enable(struct osnoise_tool *tool) nr_cpus = sysconf(_SC_NPROCESSORS_CONF); - for (i = 0; i < nr_cpus; i++) { - if (params->common.cpus && !CPU_ISSET(i, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(i, nr_cpus, ¶ms->common) { if (save_cpu_idle_disable_state(i) < 0) { err_msg("Could not save cpu idle state.\n"); return -1; @@ -215,16 +213,14 @@ void timerlat_analyze(struct osnoise_tool *tool, bool stopped) void timerlat_free(struct osnoise_tool *tool) { struct timerlat_params *params = to_timerlat_params(tool->params); - int nr_cpus, i; + int nr_cpus = sysconf(_SC_NPROCESSORS_CONF); + int i; timerlat_aa_destroy(); if (dma_latency_fd >= 0) close(dma_latency_fd); if (params->deepest_idle_state >= -1) { - for (i = 0; i < nr_cpus; i++) { - if (params->common.cpus && - !CPU_ISSET(i, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(i, nr_cpus, ¶ms->common) { restore_cpu_idle_disable_state(i); } } diff --git a/tools/tracing/rtla/src/timerlat_hist.c b/tools/tracing/rtla/src/timerlat_hist.c index 606c1688057b..1fb471a787b7 100644 --- a/tools/tracing/rtla/src/timerlat_hist.c +++ b/tools/tracing/rtla/src/timerlat_hist.c @@ -305,9 +305,7 @@ static void timerlat_hist_header(struct osnoise_tool *tool) if (!params->common.hist.no_index) trace_seq_printf(s, "Index"); - for (cpu = 0; cpu < data->nr_cpus; cpu++) { - if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) { if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count) continue; @@ -359,9 +357,7 @@ timerlat_print_summary(struct timerlat_params *params, if (!params->common.hist.no_index) trace_seq_printf(trace->seq, "count:"); - for (cpu = 0; cpu < data->nr_cpus; cpu++) { - if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) { if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count) continue; @@ -383,9 +379,7 @@ timerlat_print_summary(struct timerlat_params *params, if (!params->common.hist.no_index) trace_seq_printf(trace->seq, "min: "); - for (cpu = 0; cpu < data->nr_cpus; cpu++) { - if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) { if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count) continue; @@ -413,9 +407,7 @@ timerlat_print_summary(struct timerlat_params *params, if (!params->common.hist.no_index) trace_seq_printf(trace->seq, "avg: "); - for (cpu = 0; cpu < data->nr_cpus; cpu++) { - if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) { if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count) continue; @@ -443,9 +435,7 @@ timerlat_print_summary(struct timerlat_params *params, if (!params->common.hist.no_index) trace_seq_printf(trace->seq, "max: "); - for (cpu = 0; cpu < data->nr_cpus; cpu++) { - if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) { if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count) continue; @@ -490,9 +480,7 @@ timerlat_print_stats_all(struct timerlat_params *params, sum.min_thread = ~0; sum.min_user = ~0; - for (cpu = 0; cpu < data->nr_cpus; cpu++) { - if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) { if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count) continue; @@ -639,9 +627,7 @@ timerlat_print_stats(struct osnoise_tool *tool) trace_seq_printf(trace->seq, "%-6d", bucket * data->bucket_size); - for (cpu = 0; cpu < data->nr_cpus; cpu++) { - if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) { if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count) continue; @@ -679,9 +665,7 @@ timerlat_print_stats(struct osnoise_tool *tool) if (!params->common.hist.no_index) trace_seq_printf(trace->seq, "over: "); - for (cpu = 0; cpu < data->nr_cpus; cpu++) { - if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) { if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count) continue; @@ -710,16 +694,16 @@ timerlat_print_stats(struct osnoise_tool *tool) /* * timerlat_hist_usage - prints timerlat top usage message */ -static void timerlat_hist_usage(char *usage) +static void timerlat_hist_usage(void) { int i; char *msg[] = { "", " usage: [rtla] timerlat hist [-h] [-q] [-d s] [-D] [-n] [-a us] [-p us] [-i us] [-T us] [-s us] \\", - " [-t[file]] [-e sys[:event]] [--filter <filter>] [--trigger <trigger>] [-c cpu-list] [-H cpu-list]\\", + " [-t [file]] [-e sys[:event]] [--filter <filter>] [--trigger <trigger>] [-c cpu-list] [-H cpu-list]\\", " [-P priority] [-E N] [-b N] [--no-irq] [--no-thread] [--no-header] [--no-summary] \\", - " [--no-index] [--with-zeros] [--dma-latency us] [-C[=cgroup_name]] [--no-aa] [--dump-task] [-u|-k]", + " [--no-index] [--with-zeros] [--dma-latency us] [-C [cgroup_name]] [--no-aa] [--dump-task] [-u|-k]", " [--warm-up s] [--deepest-idle-state n]", "", " -h/--help: print this menu", @@ -730,11 +714,11 @@ static void timerlat_hist_usage(char *usage) " -s/--stack us: save the stack trace at the IRQ if a thread latency is higher than the argument in us", " -c/--cpus cpus: run the tracer only on the given cpus", " -H/--house-keeping cpus: run rtla control threads only on the given cpus", - " -C/--cgroup[=cgroup_name]: set cgroup, if no cgroup_name is passed, the rtla's cgroup will be inherited", + " -C/--cgroup [cgroup_name]: set cgroup, if no cgroup_name is passed, the rtla's cgroup will be inherited", " -d/--duration time[m|h|d]: duration of the session in seconds", " --dump-tasks: prints the task running on all CPUs if stop conditions are met (depends on !--no-aa)", " -D/--debug: print debug info", - " -t/--trace[file]: save the stopped trace to [file|timerlat_trace.txt]", + " -t/--trace [file]: save the stopped trace to [file|timerlat_trace.txt]", " -e/--event <sys:event>: enable the <sys:event> in the trace instance, multiple -e are allowed", " --filter <filter>: enable a trace event filter to the previous -e event", " --trigger <trigger>: enable a trace event trigger to the previous -e event", @@ -766,18 +750,12 @@ static void timerlat_hist_usage(char *usage) NULL, }; - if (usage) - fprintf(stderr, "%s\n", usage); - fprintf(stderr, "rtla timerlat hist: a per-cpu histogram of the timer latency (version %s)\n", VERSION); for (i = 0; msg[i]; i++) fprintf(stderr, "%s\n", msg[i]); - if (usage) - exit(EXIT_FAILURE); - exit(EXIT_SUCCESS); } @@ -856,11 +834,8 @@ static struct common_params {0, 0, 0, 0} }; - /* getopt_long stores the option index here. */ - int option_index = 0; - c = getopt_long(argc, argv, "a:c:C::b:d:e:E:DhH:i:knp:P:s:t::T:uU0123456:7:8:9\1\2:\3:", - long_options, &option_index); + long_options, NULL); /* detect the end of the options. */ if (c == -1) @@ -878,30 +853,25 @@ static struct common_params params->print_stack = auto_thresh; /* set trace */ - trace_output = "timerlat_trace.txt"; + if (!trace_output) + trace_output = "timerlat_trace.txt"; break; case 'c': retval = parse_cpu_set(optarg, ¶ms->common.monitored_cpus); if (retval) - timerlat_hist_usage("\nInvalid -c cpu list\n"); + fatal("Invalid -c cpu list"); params->common.cpus = optarg; break; case 'C': params->common.cgroup = 1; - if (!optarg) { - /* will inherit this cgroup */ - params->common.cgroup_name = NULL; - } else if (*optarg == '=') { - /* skip the = */ - params->common.cgroup_name = ++optarg; - } + params->common.cgroup_name = parse_optional_arg(argc, argv); break; case 'b': params->common.hist.bucket_size = get_llong_from_str(optarg); if (params->common.hist.bucket_size == 0 || params->common.hist.bucket_size >= 1000000) - timerlat_hist_usage("Bucket size needs to be > 0 and <= 1000000\n"); + fatal("Bucket size needs to be > 0 and <= 1000000"); break; case 'D': config_debug = 1; @@ -909,14 +879,12 @@ static struct common_params case 'd': params->common.duration = parse_seconds_duration(optarg); if (!params->common.duration) - timerlat_hist_usage("Invalid -D duration\n"); + fatal("Invalid -D duration"); break; case 'e': tevent = trace_event_alloc(optarg); - if (!tevent) { - err_msg("Error alloc trace event"); - exit(EXIT_FAILURE); - } + if (!tevent) + fatal("Error alloc trace event"); if (params->common.events) tevent->next = params->common.events; @@ -927,19 +895,17 @@ static struct common_params params->common.hist.entries = get_llong_from_str(optarg); if (params->common.hist.entries < 10 || params->common.hist.entries > 9999999) - timerlat_hist_usage("Entries must be > 10 and < 9999999\n"); + fatal("Entries must be > 10 and < 9999999"); break; case 'h': case '?': - timerlat_hist_usage(NULL); + timerlat_hist_usage(); break; case 'H': params->common.hk_cpus = 1; retval = parse_cpu_set(optarg, ¶ms->common.hk_cpu_set); - if (retval) { - err_msg("Error parsing house keeping CPUs\n"); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Error parsing house keeping CPUs"); break; case 'i': params->common.stop_us = get_llong_from_str(optarg); @@ -953,12 +919,12 @@ static struct common_params case 'p': params->timerlat_period_us = get_llong_from_str(optarg); if (params->timerlat_period_us > 1000000) - timerlat_hist_usage("Period longer than 1 s\n"); + fatal("Period longer than 1 s"); break; case 'P': retval = parse_prio(optarg, ¶ms->common.sched_param); if (retval == -1) - timerlat_hist_usage("Invalid -P priority"); + fatal("Invalid -P priority"); params->common.set_sched = 1; break; case 's': @@ -968,14 +934,8 @@ static struct common_params params->common.stop_total_us = get_llong_from_str(optarg); break; case 't': - if (optarg) { - if (optarg[0] == '=') - trace_output = &optarg[1]; - else - trace_output = &optarg[0]; - } else if (optind < argc && argv[optind][0] != '-') - trace_output = argv[optind]; - else + trace_output = parse_optional_arg(argc, argv); + if (!trace_output) trace_output = "timerlat_trace.txt"; break; case 'u': @@ -1005,31 +965,25 @@ static struct common_params case '6': /* trigger */ if (params->common.events) { retval = trace_event_add_trigger(params->common.events, optarg); - if (retval) { - err_msg("Error adding trigger %s\n", optarg); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Error adding trigger %s", optarg); } else { - timerlat_hist_usage("--trigger requires a previous -e\n"); + fatal("--trigger requires a previous -e"); } break; case '7': /* filter */ if (params->common.events) { retval = trace_event_add_filter(params->common.events, optarg); - if (retval) { - err_msg("Error adding filter %s\n", optarg); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Error adding filter %s", optarg); } else { - timerlat_hist_usage("--filter requires a previous -e\n"); + fatal("--filter requires a previous -e"); } break; case '8': params->dma_latency = get_llong_from_str(optarg); - if (params->dma_latency < 0 || params->dma_latency > 10000) { - err_msg("--dma-latency needs to be >= 0 and < 10000"); - exit(EXIT_FAILURE); - } + if (params->dma_latency < 0 || params->dma_latency > 10000) + fatal("--dma-latency needs to be >= 0 and < 10000"); break; case '9': params->no_aa = 1; @@ -1049,37 +1003,31 @@ static struct common_params case '\5': retval = actions_parse(¶ms->common.threshold_actions, optarg, "timerlat_trace.txt"); - if (retval) { - err_msg("Invalid action %s\n", optarg); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Invalid action %s", optarg); break; case '\6': retval = actions_parse(¶ms->common.end_actions, optarg, "timerlat_trace.txt"); - if (retval) { - err_msg("Invalid action %s\n", optarg); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Invalid action %s", optarg); break; default: - timerlat_hist_usage("Invalid option"); + fatal("Invalid option"); } } if (trace_output) actions_add_trace_output(¶ms->common.threshold_actions, trace_output); - if (geteuid()) { - err_msg("rtla needs root permission\n"); - exit(EXIT_FAILURE); - } + if (geteuid()) + fatal("rtla needs root permission"); if (params->common.hist.no_irq && params->common.hist.no_thread) - timerlat_hist_usage("no-irq and no-thread set, there is nothing to do here"); + fatal("no-irq and no-thread set, there is nothing to do here"); if (params->common.hist.no_index && !params->common.hist.with_zeros) - timerlat_hist_usage("no-index set with with-zeros is not set - it does not make sense"); + fatal("no-index set with with-zeros is not set - it does not make sense"); /* * Auto analysis only happens if stop tracing, thus: @@ -1088,7 +1036,7 @@ static struct common_params params->no_aa = 1; if (params->common.kernel_workload && params->common.user_workload) - timerlat_hist_usage("--kernel-threads and --user-threads are mutually exclusive!"); + fatal("--kernel-threads and --user-threads are mutually exclusive!"); /* * If auto-analysis or trace output is enabled, switch from BPF mode to diff --git a/tools/tracing/rtla/src/timerlat_top.c b/tools/tracing/rtla/src/timerlat_top.c index fc479a0dcb59..29c2c1f717ed 100644 --- a/tools/tracing/rtla/src/timerlat_top.c +++ b/tools/tracing/rtla/src/timerlat_top.c @@ -459,9 +459,7 @@ timerlat_print_stats(struct osnoise_tool *top) timerlat_top_header(params, top); - for (i = 0; i < nr_cpus; i++) { - if (params->common.cpus && !CPU_ISSET(i, ¶ms->common.monitored_cpus)) - continue; + for_each_monitored_cpu(i, nr_cpus, ¶ms->common) { timerlat_top_print(top, i); timerlat_top_update_sum(top, i, &summary); } @@ -476,15 +474,15 @@ timerlat_print_stats(struct osnoise_tool *top) /* * timerlat_top_usage - prints timerlat top usage message */ -static void timerlat_top_usage(char *usage) +static void timerlat_top_usage(void) { int i; static const char *const msg[] = { "", " usage: rtla timerlat [top] [-h] [-q] [-a us] [-d s] [-D] [-n] [-p us] [-i us] [-T us] [-s us] \\", - " [[-t[file]] [-e sys[:event]] [--filter <filter>] [--trigger <trigger>] [-c cpu-list] [-H cpu-list]\\", - " [-P priority] [--dma-latency us] [--aa-only us] [-C[=cgroup_name]] [-u|-k] [--warm-up s] [--deepest-idle-state n]", + " [[-t [file]] [-e sys[:event]] [--filter <filter>] [--trigger <trigger>] [-c cpu-list] [-H cpu-list]\\", + " [-P priority] [--dma-latency us] [--aa-only us] [-C [cgroup_name]] [-u|-k] [--warm-up s] [--deepest-idle-state n]", "", " -h/--help: print this menu", " -a/--auto: set automatic trace mode, stopping the session if argument in us latency is hit", @@ -495,11 +493,11 @@ static void timerlat_top_usage(char *usage) " -s/--stack us: save the stack trace at the IRQ if a thread latency is higher than the argument in us", " -c/--cpus cpus: run the tracer only on the given cpus", " -H/--house-keeping cpus: run rtla control threads only on the given cpus", - " -C/--cgroup[=cgroup_name]: set cgroup, if no cgroup_name is passed, the rtla's cgroup will be inherited", + " -C/--cgroup [cgroup_name]: set cgroup, if no cgroup_name is passed, the rtla's cgroup will be inherited", " -d/--duration time[s|m|h|d]: duration of the session", " -D/--debug: print debug info", " --dump-tasks: prints the task running on all CPUs if stop conditions are met (depends on !--no-aa)", - " -t/--trace[file]: save the stopped trace to [file|timerlat_trace.txt]", + " -t/--trace [file]: save the stopped trace to [file|timerlat_trace.txt]", " -e/--event <sys:event>: enable the <sys:event> in the trace instance, multiple -e are allowed", " --filter <command>: enable a trace event filter to the previous -e event", " --trigger <command>: enable a trace event trigger to the previous -e event", @@ -524,18 +522,12 @@ static void timerlat_top_usage(char *usage) NULL, }; - if (usage) - fprintf(stderr, "%s\n", usage); - fprintf(stderr, "rtla timerlat top: a per-cpu summary of the timer latency (version %s)\n", VERSION); for (i = 0; msg[i]; i++) fprintf(stderr, "%s\n", msg[i]); - if (usage) - exit(EXIT_FAILURE); - exit(EXIT_SUCCESS); } @@ -606,11 +598,8 @@ static struct common_params {0, 0, 0, 0} }; - /* getopt_long stores the option index here. */ - int option_index = 0; - c = getopt_long(argc, argv, "a:c:C::d:De:hH:i:knp:P:qs:t::T:uU0:1:2:345:6:7:", - long_options, &option_index); + long_options, NULL); /* detect the end of the options. */ if (c == -1) @@ -628,7 +617,8 @@ static struct common_params params->print_stack = auto_thresh; /* set trace */ - trace_output = "timerlat_trace.txt"; + if (!trace_output) + trace_output = "timerlat_trace.txt"; break; case '5': @@ -648,18 +638,12 @@ static struct common_params case 'c': retval = parse_cpu_set(optarg, ¶ms->common.monitored_cpus); if (retval) - timerlat_top_usage("\nInvalid -c cpu list\n"); + fatal("Invalid -c cpu list"); params->common.cpus = optarg; break; case 'C': params->common.cgroup = 1; - if (!optarg) { - /* will inherit this cgroup */ - params->common.cgroup_name = NULL; - } else if (*optarg == '=') { - /* skip the = */ - params->common.cgroup_name = ++optarg; - } + params->common.cgroup_name = optarg; break; case 'D': config_debug = 1; @@ -667,14 +651,12 @@ static struct common_params case 'd': params->common.duration = parse_seconds_duration(optarg); if (!params->common.duration) - timerlat_top_usage("Invalid -d duration\n"); + fatal("Invalid -d duration"); break; case 'e': tevent = trace_event_alloc(optarg); - if (!tevent) { - err_msg("Error alloc trace event"); - exit(EXIT_FAILURE); - } + if (!tevent) + fatal("Error alloc trace event"); if (params->common.events) tevent->next = params->common.events; @@ -682,15 +664,13 @@ static struct common_params break; case 'h': case '?': - timerlat_top_usage(NULL); + timerlat_top_usage(); break; case 'H': params->common.hk_cpus = 1; retval = parse_cpu_set(optarg, ¶ms->common.hk_cpu_set); - if (retval) { - err_msg("Error parsing house keeping CPUs\n"); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Error parsing house keeping CPUs"); break; case 'i': params->common.stop_us = get_llong_from_str(optarg); @@ -704,12 +684,12 @@ static struct common_params case 'p': params->timerlat_period_us = get_llong_from_str(optarg); if (params->timerlat_period_us > 1000000) - timerlat_top_usage("Period longer than 1 s\n"); + fatal("Period longer than 1 s"); break; case 'P': retval = parse_prio(optarg, ¶ms->common.sched_param); if (retval == -1) - timerlat_top_usage("Invalid -P priority"); + fatal("Invalid -P priority"); params->common.set_sched = 1; break; case 'q': @@ -722,14 +702,8 @@ static struct common_params params->common.stop_total_us = get_llong_from_str(optarg); break; case 't': - if (optarg) { - if (optarg[0] == '=') - trace_output = &optarg[1]; - else - trace_output = &optarg[0]; - } else if (optind < argc && argv[optind][0] != '-') - trace_output = argv[optind]; - else + trace_output = parse_optional_arg(argc, argv); + if (!trace_output) trace_output = "timerlat_trace.txt"; break; case 'u': @@ -741,31 +715,25 @@ static struct common_params case '0': /* trigger */ if (params->common.events) { retval = trace_event_add_trigger(params->common.events, optarg); - if (retval) { - err_msg("Error adding trigger %s\n", optarg); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Error adding trigger %s", optarg); } else { - timerlat_top_usage("--trigger requires a previous -e\n"); + fatal("--trigger requires a previous -e"); } break; case '1': /* filter */ if (params->common.events) { retval = trace_event_add_filter(params->common.events, optarg); - if (retval) { - err_msg("Error adding filter %s\n", optarg); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Error adding filter %s", optarg); } else { - timerlat_top_usage("--filter requires a previous -e\n"); + fatal("--filter requires a previous -e"); } break; case '2': /* dma-latency */ params->dma_latency = get_llong_from_str(optarg); - if (params->dma_latency < 0 || params->dma_latency > 10000) { - err_msg("--dma-latency needs to be >= 0 and < 10000"); - exit(EXIT_FAILURE); - } + if (params->dma_latency < 0 || params->dma_latency > 10000) + fatal("--dma-latency needs to be >= 0 and < 10000"); break; case '3': /* no-aa */ params->no_aa = 1; @@ -785,31 +753,25 @@ static struct common_params case '9': retval = actions_parse(¶ms->common.threshold_actions, optarg, "timerlat_trace.txt"); - if (retval) { - err_msg("Invalid action %s\n", optarg); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Invalid action %s", optarg); break; case '\1': retval = actions_parse(¶ms->common.end_actions, optarg, "timerlat_trace.txt"); - if (retval) { - err_msg("Invalid action %s\n", optarg); - exit(EXIT_FAILURE); - } + if (retval) + fatal("Invalid action %s", optarg); break; default: - timerlat_top_usage("Invalid option"); + fatal("Invalid option"); } } if (trace_output) actions_add_trace_output(¶ms->common.threshold_actions, trace_output); - if (geteuid()) { - err_msg("rtla needs root permission\n"); - exit(EXIT_FAILURE); - } + if (geteuid()) + fatal("rtla needs root permission"); /* * Auto analysis only happens if stop tracing, thus: @@ -818,10 +780,10 @@ static struct common_params params->no_aa = 1; if (params->no_aa && params->common.aa_only) - timerlat_top_usage("--no-aa and --aa-only are mutually exclusive!"); + fatal("--no-aa and --aa-only are mutually exclusive!"); if (params->common.kernel_workload && params->common.user_workload) - timerlat_top_usage("--kernel-threads and --user-threads are mutually exclusive!"); + fatal("--kernel-threads and --user-threads are mutually exclusive!"); /* * If auto-analysis or trace output is enabled, switch from BPF mode to @@ -916,7 +878,7 @@ timerlat_top_bpf_main_loop(struct osnoise_tool *tool) if (!params->common.quiet) timerlat_print_stats(tool); - if (wait_retval == 1) { + if (wait_retval != 0) { /* Stopping requested by tracer */ actions_perform(¶ms->common.threshold_actions); diff --git a/tools/tracing/rtla/src/timerlat_u.c b/tools/tracing/rtla/src/timerlat_u.c index 01dbf9a6b5a5..ce68e39d25fd 100644 --- a/tools/tracing/rtla/src/timerlat_u.c +++ b/tools/tracing/rtla/src/timerlat_u.c @@ -51,10 +51,8 @@ static int timerlat_u_main(int cpu, struct timerlat_u_params *params) if (!params->sched_param) { retval = sched_setscheduler(0, SCHED_FIFO, &sp); - if (retval < 0) { - err_msg("Error setting timerlat u default priority: %s\n", strerror(errno)); - exit(1); - } + if (retval < 0) + fatal("Error setting timerlat u default priority: %s", strerror(errno)); } else { retval = __set_sched_attr(getpid(), params->sched_param); if (retval) { @@ -78,10 +76,8 @@ static int timerlat_u_main(int cpu, struct timerlat_u_params *params) snprintf(buffer, sizeof(buffer), "osnoise/per_cpu/cpu%d/timerlat_fd", cpu); timerlat_fd = tracefs_instance_file_open(NULL, buffer, O_RDONLY); - if (timerlat_fd < 0) { - err_msg("Error opening %s:%s\n", buffer, strerror(errno)); - exit(1); - } + if (timerlat_fd < 0) + fatal("Error opening %s:%s", buffer, strerror(errno)); debug_msg("User-space timerlat pid %d on cpu %d\n", gettid(), cpu); diff --git a/tools/tracing/rtla/src/utils.c b/tools/tracing/rtla/src/utils.c index d6ab15dcb490..9cf5a0098e9a 100644 --- a/tools/tracing/rtla/src/utils.c +++ b/tools/tracing/rtla/src/utils.c @@ -57,6 +57,21 @@ void debug_msg(const char *fmt, ...) } /* + * fatal - print an error message and EOL to stderr and exit with ERROR + */ +void fatal(const char *fmt, ...) +{ + va_list ap; + + va_start(ap, fmt); + vfprintf(stderr, fmt, ap); + va_end(ap); + fprintf(stderr, "\n"); + + exit(ERROR); +} + +/* * get_llong_from_str - get a long long int from a string */ long long get_llong_from_str(char *start) @@ -959,3 +974,29 @@ int auto_house_keeping(cpu_set_t *monitored_cpus) return 1; } + +/** + * parse_optional_arg - Parse optional argument value + * + * Parse optional argument value, which can be in the form of: + * -sarg, -s/--long=arg, -s/--long arg + * + * Returns arg value if found, NULL otherwise. + */ +char *parse_optional_arg(int argc, char **argv) +{ + if (optarg) { + if (optarg[0] == '=') { + /* skip the = */ + return &optarg[1]; + } else { + return optarg; + } + /* parse argument of form -s [arg] and --long [arg]*/ + } else if (optind < argc && argv[optind][0] != '-') { + /* consume optind */ + return argv[optind++]; + } else { + return NULL; + } +} diff --git a/tools/tracing/rtla/src/utils.h b/tools/tracing/rtla/src/utils.h index a2a6f89f342d..091df4ba4587 100644 --- a/tools/tracing/rtla/src/utils.h +++ b/tools/tracing/rtla/src/utils.h @@ -19,11 +19,13 @@ extern int config_debug; void debug_msg(const char *fmt, ...); void err_msg(const char *fmt, ...); +void fatal(const char *fmt, ...); long parse_seconds_duration(char *val); void get_duration(time_t start_time, char *output, int output_size); int parse_cpu_list(char *cpu_list, char **monitored_cpus); +char *parse_optional_arg(int argc, char **argv); long long get_llong_from_str(char *start); static inline void diff --git a/tools/tracing/rtla/tests/osnoise.t b/tools/tracing/rtla/tests/osnoise.t index e3c89d45a6bb..396334608920 100644 --- a/tools/tracing/rtla/tests/osnoise.t +++ b/tools/tracing/rtla/tests/osnoise.t @@ -37,11 +37,11 @@ check "multiple actions" \ check "hist stop at failed action" \ "osnoise hist -S 2 --on-threshold shell,command='echo -n 1; false' --on-threshold shell,command='echo -n 2'" 2 "^1# RTLA osnoise histogram$" check "top stop at failed action" \ - "timerlat top -T 2 --on-threshold shell,command='echo -n abc; false' --on-threshold shell,command='echo -n defgh'" 2 "^abc" "defgh" + "osnoise top -S 2 --on-threshold shell,command='echo -n abc; false' --on-threshold shell,command='echo -n defgh'" 2 "^abc" "defgh" check "hist with continue" \ - "osnoise hist -S 2 -d 1s --on-threshold shell,command='echo TestOutput' --on-threshold continue" 0 "^TestOutput$" + "osnoise hist -S 2 -d 5s --on-threshold shell,command='echo TestOutput' --on-threshold continue" 0 "^TestOutput$" check "top with continue" \ - "osnoise top -q -S 2 -d 1s --on-threshold shell,command='echo TestOutput' --on-threshold continue" 0 "^TestOutput$" + "osnoise top -q -S 2 -d 5s --on-threshold shell,command='echo TestOutput' --on-threshold continue" 0 "^TestOutput$" check "hist with trace output at end" \ "osnoise hist -d 1s --on-end trace" 0 "^ Saving trace to osnoise_trace.txt$" check "top with trace output at end" \ diff --git a/tools/tracing/rtla/tests/timerlat.t b/tools/tracing/rtla/tests/timerlat.t index b5d1e7260a9b..bbaa1897d8a8 100644 --- a/tools/tracing/rtla/tests/timerlat.t +++ b/tools/tracing/rtla/tests/timerlat.t @@ -58,11 +58,11 @@ check "multiple actions" \ check "hist stop at failed action" \ "timerlat hist -T 2 --on-threshold shell,command='echo -n 1; false' --on-threshold shell,command='echo -n 2'" 2 "^1# RTLA timerlat histogram$" check "top stop at failed action" \ - "timerlat top -T 2 --on-threshold shell,command='echo -n 1; false' --on-threshold shell,command='echo -n 2'" 2 "^1ALL" + "timerlat top -T 2 --on-threshold shell,command='echo -n abc; false' --on-threshold shell,command='echo -n defgh'" 2 "^abc" "defgh" check "hist with continue" \ - "timerlat hist -T 2 -d 1s --on-threshold shell,command='echo TestOutput' --on-threshold continue" 0 "^TestOutput$" + "timerlat hist -T 2 -d 5s --on-threshold shell,command='echo TestOutput' --on-threshold continue" 0 "^TestOutput$" check "top with continue" \ - "timerlat top -q -T 2 -d 1s --on-threshold shell,command='echo TestOutput' --on-threshold continue" 0 "^TestOutput$" + "timerlat top -q -T 2 -d 5s --on-threshold shell,command='echo TestOutput' --on-threshold continue" 0 "^TestOutput$" check "hist with trace output at end" \ "timerlat hist -d 1s --on-end trace" 0 "^ Saving trace to timerlat_trace.txt$" check "top with trace output at end" \ |