lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [day] [month] [year] [list]
Message-Id: <4dc514d1d5dc353c537a466a9b5af44c266b6da2.1680106912.git.bristot@kernel.org>
Date:   Wed, 29 Mar 2023 18:23:32 +0200
From:   Daniel Bristot de Oliveira <bristot@...nel.org>
To:     Steven Rostedt <rostedt@...dmis.org>,
        Daniel Bristot de Oliveira <bristot@...nel.org>
Cc:     linux-trace-devel@...r.kernel.org, linux-doc@...r.kernel.org,
        linux-kernel@...r.kernel.org, Jonathan Corbet <corbet@....net>
Subject: [PATCH] rtla/timerlat: Add auto-analysis only option

Parsing and formating timerlat data might consume a reasonable
amount of CPU time on very large systems, or when timerlat
has a too short period.

Add an option to run timerlat with auto-analysis enabled while
skipping the statistics parsing. In this mode, rtla timerlat
periodically checks if the tracing is on, going to sleep waiting
for the stop tracing condition to stop tracing, or for the
tracing session to finish.

If the stop tracing condition is hit, the tool prints the auto
analysis. Otherwise, the tool prints the max observed latency and
exit. The max observed latency is captured via tracing_max_latency.

Cc: Daniel Bristot de Oliveira <bristot@...nel.org>
Cc: Steven Rostedt <rostedt@...dmis.org>
Cc: Jonathan Corbet <corbet@....net>
Signed-off-by: Daniel Bristot de Oliveira <bristot@...nel.org>
---
 .../tools/rtla/common_timerlat_aa.rst         |  7 +++
 tools/tracing/rtla/src/timerlat_top.c         | 49 +++++++++++++++++--
 2 files changed, 51 insertions(+), 5 deletions(-)

diff --git a/Documentation/tools/rtla/common_timerlat_aa.rst b/Documentation/tools/rtla/common_timerlat_aa.rst
index 077029e6b289..795b9fbcbc6d 100644
--- a/Documentation/tools/rtla/common_timerlat_aa.rst
+++ b/Documentation/tools/rtla/common_timerlat_aa.rst
@@ -5,3 +5,10 @@
 **--no-aa**
 
         disable auto-analysis, reducing rtla timerlat cpu usage
+
+**--aa-only** *us*
+
+        Set stop tracing conditions and run without collecting and displaying statistics.
+        Print the auto-analysis if the system hits the stop tracing condition. This option
+        is useful to reduce rtla timerlat CPU, enabling the debug without the overhead of
+        collecting the statistics.
diff --git a/tools/tracing/rtla/src/timerlat_top.c b/tools/tracing/rtla/src/timerlat_top.c
index eea5b3357e27..92c658c64f28 100644
--- a/tools/tracing/rtla/src/timerlat_top.c
+++ b/tools/tracing/rtla/src/timerlat_top.c
@@ -33,6 +33,7 @@ struct timerlat_top_params {
 	int			set_sched;
 	int			dma_latency;
 	int			no_aa;
+	int			aa_only;
 	int			dump_tasks;
 	struct sched_attr	sched_param;
 	struct trace_events	*events;
@@ -142,10 +143,12 @@ timerlat_top_handler(struct trace_seq *s, struct tep_record *record,
 	top = container_of(trace, struct osnoise_tool, trace);
 	params = top->params;
 
-	tep_get_field_val(s, event, "context", record, &thread, 1);
-	tep_get_field_val(s, event, "timer_latency", record, &latency, 1);
+	if (!params->aa_only) {
+		tep_get_field_val(s, event, "context", record, &thread, 1);
+		tep_get_field_val(s, event, "timer_latency", record, &latency, 1);
 
-	timerlat_top_update(top, cpu, thread, latency);
+		timerlat_top_update(top, cpu, thread, latency);
+	}
 
 	if (!params->no_aa)
 		timerlat_aa_handler(s, record, event, context);
@@ -250,6 +253,9 @@ timerlat_print_stats(struct timerlat_top_params *params, struct osnoise_tool *to
 	static int nr_cpus = -1;
 	int i;
 
+	if (params->aa_only)
+		return;
+
 	if (nr_cpus == -1)
 		nr_cpus = sysconf(_SC_NPROCESSORS_CONF);
 
@@ -279,10 +285,11 @@ static void timerlat_top_usage(char *usage)
 		"",
 		"  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] \\",
-		"	  [-P priority] [--dma-latency us]",
+		"	  [-P priority] [--dma-latency us] [--aa-only us]",
 		"",
 		"	  -h/--help: print this menu",
 		"	  -a/--auto: set automatic trace mode, stopping the session if argument in us latency is hit",
+		"	     --aa-only us: stop if <us> latency is hit, only printing the auto analysis (reduces CPU usage)",
 		"	  -p/--period us: timerlat period in us",
 		"	  -i/--irq us: stop trace if the irq latency is higher than the argument in us",
 		"	  -T/--thread us: stop trace if the thread latency is higher than the argument in us",
@@ -362,13 +369,14 @@ static struct timerlat_top_params
 			{"dma-latency",		required_argument,	0, '2'},
 			{"no-aa",		no_argument,		0, '3'},
 			{"dump-tasks",		no_argument,		0, '4'},
+			{"aa-only",		required_argument,	0, '5'},
 			{0, 0, 0, 0}
 		};
 
 		/* getopt_long stores the option index here. */
 		int option_index = 0;
 
-		c = getopt_long(argc, argv, "a:c:d:De:hi:np:P:qs:t::T:0:1:2:34",
+		c = getopt_long(argc, argv, "a:c:d:De:hi:np:P:qs:t::T:0:1:2:345:",
 				 long_options, &option_index);
 
 		/* detect the end of the options. */
@@ -389,6 +397,20 @@ static struct timerlat_top_params
 			/* set trace */
 			params->trace_output = "timerlat_trace.txt";
 			break;
+		case '5':
+			/* it is here because it is similar to -a */
+			auto_thresh = get_llong_from_str(optarg);
+
+			/* set thread stop to auto_thresh */
+			params->stop_total_us = auto_thresh;
+			params->stop_us = auto_thresh;
+
+			/* get stack trace */
+			params->print_stack = auto_thresh;
+
+			/* set aa_only to avoid parsing the trace */
+			params->aa_only = 1;
+			break;
 		case 'c':
 			retval = parse_cpu_list(optarg, &params->monitored_cpus);
 			if (retval)
@@ -503,6 +525,9 @@ static struct timerlat_top_params
 	if (!params->stop_us && !params->stop_total_us)
 		params->no_aa = 1;
 
+	if (params->no_aa && params->aa_only)
+		timerlat_top_usage("--no-aa and --aa-only are mutually exclusive!");
+
 	return params;
 }
 
@@ -634,6 +659,7 @@ int timerlat_top_main(int argc, char *argv[])
 	struct trace_instance *trace;
 	int dma_latency_fd = -1;
 	int return_value = 1;
+	char *max_lat;
 	int retval;
 
 	params = timerlat_top_parse_args(argc, argv);
@@ -700,6 +726,9 @@ int timerlat_top_main(int argc, char *argv[])
 	while (!stop_tracing) {
 		sleep(params->sleep_time);
 
+		if (params->aa_only && !trace_is_off(&top->trace, &record->trace))
+			continue;
+
 		retval = tracefs_iterate_raw_events(trace->tep,
 						    trace->inst,
 						    NULL,
@@ -733,6 +762,16 @@ int timerlat_top_main(int argc, char *argv[])
 			printf("  Saving trace to %s\n", params->trace_output);
 			save_trace_to_file(record->trace.inst, params->trace_output);
 		}
+	} else if (params->aa_only) {
+		/*
+		 * If the trace did not stop with --aa-only, at least print the
+		 * max known latency.
+		 */
+		max_lat = tracefs_instance_file_read(trace->inst, "tracing_max_latency", NULL);
+		if (max_lat) {
+			printf("  Max latency was %s\n", max_lat);
+			free(max_lat);
+		}
 	}
 
 out_top:
-- 
2.38.1

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ