summaryrefslogtreecommitdiff
path: root/tools/tracing/rtla/src
diff options
context:
space:
mode:
Diffstat (limited to 'tools/tracing/rtla/src')
-rw-r--r--tools/tracing/rtla/src/Build11
-rw-r--r--tools/tracing/rtla/src/osnoise.c38
-rw-r--r--tools/tracing/rtla/src/osnoise.h2
-rw-r--r--tools/tracing/rtla/src/osnoise_hist.c75
-rw-r--r--tools/tracing/rtla/src/osnoise_top.c92
-rw-r--r--tools/tracing/rtla/src/timerlat_aa.c109
-rw-r--r--tools/tracing/rtla/src/timerlat_hist.c438
-rw-r--r--tools/tracing/rtla/src/timerlat_top.c350
-rw-r--r--tools/tracing/rtla/src/trace.c70
-rw-r--r--tools/tracing/rtla/src/trace.h5
-rw-r--r--tools/tracing/rtla/src/utils.c186
-rw-r--r--tools/tracing/rtla/src/utils.h15
12 files changed, 1145 insertions, 246 deletions
diff --git a/tools/tracing/rtla/src/Build b/tools/tracing/rtla/src/Build
new file mode 100644
index 000000000000..dbed9e31829b
--- /dev/null
+++ b/tools/tracing/rtla/src/Build
@@ -0,0 +1,11 @@
+rtla-y += trace.o
+rtla-y += utils.o
+rtla-y += osnoise.o
+rtla-y += osnoise_top.o
+rtla-y += osnoise_hist.o
+rtla-y += timerlat.o
+rtla-y += timerlat_top.o
+rtla-y += timerlat_hist.o
+rtla-y += timerlat_u.o
+rtla-y += timerlat_aa.o
+rtla-y += rtla.o
diff --git a/tools/tracing/rtla/src/osnoise.c b/tools/tracing/rtla/src/osnoise.c
index 245e9344932b..85f398b89597 100644
--- a/tools/tracing/rtla/src/osnoise.c
+++ b/tools/tracing/rtla/src/osnoise.c
@@ -867,7 +867,7 @@ int osnoise_set_workload(struct osnoise_context *context, bool onoff)
retval = osnoise_options_set_option("OSNOISE_WORKLOAD", onoff);
if (retval < 0)
- return -1;
+ return -2;
context->opt_workload = onoff;
@@ -1079,6 +1079,42 @@ out_err:
return NULL;
}
+bool osnoise_trace_is_off(struct osnoise_tool *tool, struct osnoise_tool *record)
+{
+ /*
+ * The tool instance is always present, it is the one used to collect
+ * data.
+ */
+ if (!tracefs_trace_is_on(tool->trace.inst))
+ return true;
+
+ /*
+ * The trace record instance is only enabled when -t is set. IOW, when the system
+ * is tracing.
+ */
+ return record && !tracefs_trace_is_on(record->trace.inst);
+}
+
+/*
+ * osnoise_report_missed_events - report number of events dropped by trace
+ * buffer
+ */
+void
+osnoise_report_missed_events(struct osnoise_tool *tool)
+{
+ unsigned long long total_events;
+
+ if (tool->trace.missed_events == UINT64_MAX)
+ printf("unknown number of events missed, results might not be accurate\n");
+ else if (tool->trace.missed_events > 0) {
+ total_events = tool->trace.processed_events + tool->trace.missed_events;
+
+ printf("%lld (%.2f%%) events missed, results might not be accurate\n",
+ tool->trace.missed_events,
+ (double) tool->trace.missed_events / total_events * 100.0);
+ }
+}
+
static void osnoise_usage(int err)
{
int i;
diff --git a/tools/tracing/rtla/src/osnoise.h b/tools/tracing/rtla/src/osnoise.h
index 555f4f4903cc..91835a7d8c2b 100644
--- a/tools/tracing/rtla/src/osnoise.h
+++ b/tools/tracing/rtla/src/osnoise.h
@@ -104,6 +104,8 @@ struct osnoise_tool {
void osnoise_destroy_tool(struct osnoise_tool *top);
struct osnoise_tool *osnoise_init_tool(char *tool_name);
struct osnoise_tool *osnoise_init_trace_tool(char *tracer);
+void osnoise_report_missed_events(struct osnoise_tool *tool);
+bool osnoise_trace_is_off(struct osnoise_tool *tool, struct osnoise_tool *record);
int osnoise_hist_main(int argc, char *argv[]);
int osnoise_top_main(int argc, char **argv);
diff --git a/tools/tracing/rtla/src/osnoise_hist.c b/tools/tracing/rtla/src/osnoise_hist.c
index 01870d50942a..b4930b835b0a 100644
--- a/tools/tracing/rtla/src/osnoise_hist.c
+++ b/tools/tracing/rtla/src/osnoise_hist.c
@@ -36,13 +36,14 @@ struct osnoise_hist_params {
cpu_set_t hk_cpu_set;
struct sched_attr sched_param;
struct trace_events *events;
-
char no_header;
char no_summary;
char no_index;
char with_zeros;
int bucket_size;
int entries;
+ int warmup;
+ int buffer_size;
};
struct osnoise_hist_cpu {
@@ -373,6 +374,7 @@ osnoise_print_stats(struct osnoise_hist_params *params, struct osnoise_tool *too
{
struct osnoise_hist_data *data = tool->data;
struct trace_instance *trace = &tool->trace;
+ int has_samples = 0;
int bucket, cpu;
int total;
@@ -401,11 +403,25 @@ osnoise_print_stats(struct osnoise_hist_params *params, struct osnoise_tool *too
continue;
}
+ /* There are samples above the threshold */
+ has_samples = 1;
trace_seq_printf(trace->seq, "\n");
trace_seq_do_printf(trace->seq);
trace_seq_reset(trace->seq);
}
+ /*
+ * If no samples were recorded, skip calculations, print zeroed statistics
+ * and return.
+ */
+ if (!has_samples) {
+ trace_seq_reset(trace->seq);
+ trace_seq_printf(trace->seq, "over: 0\ncount: 0\nmin: 0\navg: 0\nmax: 0\n");
+ trace_seq_do_printf(trace->seq);
+ trace_seq_reset(trace->seq);
+ return;
+ }
+
if (!params->no_index)
trace_seq_printf(trace->seq, "over: ");
@@ -424,6 +440,7 @@ osnoise_print_stats(struct osnoise_hist_params *params, struct osnoise_tool *too
trace_seq_reset(trace->seq);
osnoise_print_summary(params, trace, data);
+ osnoise_report_missed_events(tool);
}
/*
@@ -436,9 +453,9 @@ static void osnoise_hist_usage(char *usage)
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]]",
+ " [--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",
@@ -452,7 +469,7 @@ static void osnoise_hist_usage(char *usage)
" -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",
@@ -468,6 +485,8 @@ static void osnoise_hist_usage(char *usage)
" f:prio - use SCHED_FIFO with prio",
" d:runtime[us|ms|s]:period[us|ms|s] - use SCHED_DEADLINE with runtime and period",
" in nanoseconds",
+ " --warm-up: let the workload run for s seconds before collecting data",
+ " --trace-buffer-size kB: set the per-cpu trace buffer size in kB",
NULL,
};
@@ -531,13 +550,15 @@ static struct osnoise_hist_params
{"with-zeros", no_argument, 0, '3'},
{"trigger", required_argument, 0, '4'},
{"filter", required_argument, 0, '5'},
+ {"warm-up", required_argument, 0, '6'},
+ {"trace-buffer-size", required_argument, 0, '7'},
{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:",
+ 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);
/* detect the end of the options. */
@@ -640,9 +661,13 @@ static struct osnoise_hist_params
params->threshold = get_llong_from_str(optarg);
break;
case 't':
- if (optarg)
- /* skip = */
- params->trace_output = &optarg[1];
+ if (optarg) {
+ if (optarg[0] == '=')
+ params->trace_output = &optarg[1];
+ else
+ params->trace_output = &optarg[0];
+ } else if (optind < argc && argv[optind][0] != '0')
+ params->trace_output = argv[optind];
else
params->trace_output = "osnoise_trace.txt";
break;
@@ -680,6 +705,12 @@ static struct osnoise_hist_params
osnoise_hist_usage("--filter requires a previous -e\n");
}
break;
+ case '6':
+ params->warmup = get_llong_from_str(optarg);
+ break;
+ case '7':
+ params->buffer_size = get_llong_from_str(optarg);
+ break;
default:
osnoise_hist_usage("Invalid option");
}
@@ -886,6 +917,11 @@ int osnoise_hist_main(int argc, char *argv[])
goto out_hist;
}
+ if (params->buffer_size > 0) {
+ retval = trace_set_buffer_size(&record->trace, params->buffer_size);
+ if (retval)
+ goto out_hist;
+ }
}
/*
@@ -899,6 +935,25 @@ int osnoise_hist_main(int argc, char *argv[])
trace_instance_start(&record->trace);
trace_instance_start(trace);
+ if (params->warmup > 0) {
+ debug_msg("Warming up for %d seconds\n", params->warmup);
+ sleep(params->warmup);
+ if (stop_tracing)
+ goto out_hist;
+
+ /*
+ * Clean up the buffer. The osnoise workload do not run
+ * with tracing off to avoid creating a performance penalty
+ * when not needed.
+ */
+ retval = tracefs_instance_file_write(trace->inst, "trace", "");
+ if (retval < 0) {
+ debug_msg("Error cleaning up the buffer");
+ goto out_hist;
+ }
+
+ }
+
tool->start_time = time(NULL);
osnoise_hist_set_signals(params);
@@ -916,7 +971,7 @@ int osnoise_hist_main(int argc, char *argv[])
goto out_hist;
}
- if (trace_is_off(&tool->trace, &record->trace))
+ if (osnoise_trace_is_off(tool, record))
break;
}
@@ -926,7 +981,7 @@ int osnoise_hist_main(int argc, char *argv[])
return_value = 0;
- if (trace_is_off(&tool->trace, &record->trace)) {
+ if (osnoise_trace_is_off(tool, record)) {
printf("rtla osnoise hit stop tracing\n");
if (params->trace_output) {
printf(" Saving trace to %s\n", params->trace_output);
diff --git a/tools/tracing/rtla/src/osnoise_top.c b/tools/tracing/rtla/src/osnoise_top.c
index 457360db0767..4772677ac762 100644
--- a/tools/tracing/rtla/src/osnoise_top.c
+++ b/tools/tracing/rtla/src/osnoise_top.c
@@ -40,6 +40,9 @@ struct osnoise_top_params {
int set_sched;
int cgroup;
int hk_cpus;
+ int warmup;
+ int buffer_size;
+ int pretty_output;
cpu_set_t hk_cpu_set;
struct sched_attr sched_param;
struct trace_events *events;
@@ -161,7 +164,9 @@ static void osnoise_top_header(struct osnoise_tool *top)
get_duration(top->start_time, duration, sizeof(duration));
- trace_seq_printf(s, "\033[2;37;40m");
+ if (params->pretty_output)
+ trace_seq_printf(s, "\033[2;37;40m");
+
trace_seq_printf(s, " ");
if (params->mode == MODE_OSNOISE) {
@@ -172,12 +177,16 @@ static void osnoise_top_header(struct osnoise_tool *top)
}
trace_seq_printf(s, " ");
- trace_seq_printf(s, "\033[0;0;0m");
+
+ if (params->pretty_output)
+ trace_seq_printf(s, "\033[0;0;0m");
trace_seq_printf(s, "\n");
trace_seq_printf(s, "duration: %9s | time is in us\n", duration);
- trace_seq_printf(s, "\033[2;30;47m");
+ if (params->pretty_output)
+ trace_seq_printf(s, "\033[2;30;47m");
+
trace_seq_printf(s, "CPU Period Runtime ");
trace_seq_printf(s, " Noise ");
trace_seq_printf(s, " %% CPU Aval ");
@@ -190,7 +199,8 @@ static void osnoise_top_header(struct osnoise_tool *top)
trace_seq_printf(s, " IRQ Softirq Thread");
eol:
- trace_seq_printf(s, "\033[0;0;0m");
+ if (params->pretty_output)
+ trace_seq_printf(s, "\033[0;0;0m");
trace_seq_printf(s, "\n");
}
@@ -270,6 +280,7 @@ osnoise_print_stats(struct osnoise_top_params *params, struct osnoise_tool *top)
trace_seq_do_printf(trace->seq);
trace_seq_reset(trace->seq);
+ osnoise_report_missed_events(top);
}
/*
@@ -281,8 +292,8 @@ static void osnoise_top_usage(struct osnoise_top_params *params, char *usage)
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]]",
+ " [-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",
@@ -296,7 +307,7 @@ static void osnoise_top_usage(struct osnoise_top_params *params, char *usage)
" -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",
@@ -307,6 +318,8 @@ static void osnoise_top_usage(struct osnoise_top_params *params, char *usage)
" f:prio - use SCHED_FIFO with prio",
" d:runtime[us|ms|s]:period[us|ms|s] - use SCHED_DEADLINE with runtime and period",
" in nanoseconds",
+ " --warm-up s: let the workload run for s seconds before collecting data",
+ " --trace-buffer-size kB: set the per-cpu trace buffer size in kB",
NULL,
};
@@ -381,13 +394,15 @@ struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
{"trace", optional_argument, 0, 't'},
{"trigger", required_argument, 0, '0'},
{"filter", required_argument, 0, '1'},
+ {"warm-up", required_argument, 0, '2'},
+ {"trace-buffer-size", required_argument, 0, '3'},
{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:",
+ 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);
/* Detect the end of the options. */
@@ -428,7 +443,7 @@ struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
case 'd':
params->duration = parse_seconds_duration(optarg);
if (!params->duration)
- osnoise_top_usage(params, "Invalid -D duration\n");
+ osnoise_top_usage(params, "Invalid -d duration\n");
break;
case 'e':
tevent = trace_event_alloc(optarg);
@@ -480,9 +495,13 @@ struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
params->stop_total_us = get_llong_from_str(optarg);
break;
case 't':
- if (optarg)
- /* skip = */
- params->trace_output = &optarg[1];
+ if (optarg) {
+ if (optarg[0] == '=')
+ params->trace_output = &optarg[1];
+ else
+ params->trace_output = &optarg[0];
+ } else if (optind < argc && argv[optind][0] != '-')
+ params->trace_output = argv[optind];
else
params->trace_output = "osnoise_trace.txt";
break;
@@ -511,6 +530,12 @@ struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
osnoise_top_usage(params, "--filter requires a previous -e\n");
}
break;
+ case '2':
+ params->warmup = get_llong_from_str(optarg);
+ break;
+ case '3':
+ params->buffer_size = get_llong_from_str(optarg);
+ break;
default:
osnoise_top_usage(params, "Invalid option");
}
@@ -603,6 +628,9 @@ osnoise_top_apply_config(struct osnoise_tool *tool, struct osnoise_top_params *p
auto_house_keeping(&params->monitored_cpus);
}
+ if (isatty(STDOUT_FILENO) && !params->quiet)
+ params->pretty_output = 1;
+
return 0;
out_err:
@@ -624,8 +652,10 @@ struct osnoise_tool *osnoise_init_top(struct osnoise_top_params *params)
return NULL;
tool->data = osnoise_alloc_top(nr_cpus);
- if (!tool->data)
- goto out_err;
+ if (!tool->data) {
+ osnoise_destroy_tool(tool);
+ return NULL;
+ }
tool->params = params;
@@ -633,11 +663,6 @@ struct osnoise_tool *osnoise_init_top(struct osnoise_top_params *params)
osnoise_top_handler, NULL);
return tool;
-
-out_err:
- osnoise_free_top(tool->data);
- osnoise_destroy_tool(tool);
- return NULL;
}
static int stop_tracing;
@@ -719,6 +744,12 @@ int osnoise_top_main(int argc, char **argv)
if (retval)
goto out_top;
}
+
+ if (params->buffer_size > 0) {
+ retval = trace_set_buffer_size(&record->trace, params->buffer_size);
+ if (retval)
+ goto out_top;
+ }
}
/*
@@ -732,6 +763,25 @@ int osnoise_top_main(int argc, char **argv)
trace_instance_start(&record->trace);
trace_instance_start(trace);
+ if (params->warmup > 0) {
+ debug_msg("Warming up for %d seconds\n", params->warmup);
+ sleep(params->warmup);
+ if (stop_tracing)
+ goto out_top;
+
+ /*
+ * Clean up the buffer. The osnoise workload do not run
+ * with tracing off to avoid creating a performance penalty
+ * when not needed.
+ */
+ retval = tracefs_instance_file_write(trace->inst, "trace", "");
+ if (retval < 0) {
+ debug_msg("Error cleaning up the buffer");
+ goto out_top;
+ }
+
+ }
+
tool->start_time = time(NULL);
osnoise_top_set_signals(params);
@@ -752,7 +802,7 @@ int osnoise_top_main(int argc, char **argv)
if (!params->quiet)
osnoise_print_stats(params, tool);
- if (trace_is_off(&tool->trace, &record->trace))
+ if (osnoise_trace_is_off(tool, record))
break;
}
@@ -761,7 +811,7 @@ int osnoise_top_main(int argc, char **argv)
return_value = 0;
- if (trace_is_off(&tool->trace, &record->trace)) {
+ if (osnoise_trace_is_off(tool, record)) {
printf("osnoise hit stop tracing\n");
if (params->trace_output) {
printf(" Saving trace to %s\n", params->trace_output);
diff --git a/tools/tracing/rtla/src/timerlat_aa.c b/tools/tracing/rtla/src/timerlat_aa.c
index 7093fd5333be..7bd80ee2a5b4 100644
--- a/tools/tracing/rtla/src/timerlat_aa.c
+++ b/tools/tracing/rtla/src/timerlat_aa.c
@@ -16,6 +16,9 @@ enum timelat_state {
TIMERLAT_WAITING_THREAD,
};
+/* Used to fill spaces in the output */
+static const char *spaces = " ";
+
#define MAX_COMM 24
/*
@@ -274,14 +277,17 @@ static int timerlat_aa_nmi_handler(struct trace_seq *s, struct tep_record *recor
taa_data->prev_irq_timstamp = start;
trace_seq_reset(taa_data->prev_irqs_seq);
- trace_seq_printf(taa_data->prev_irqs_seq, "\t%24s \t\t\t%9.2f us\n",
- "nmi", ns_to_usf(duration));
+ trace_seq_printf(taa_data->prev_irqs_seq, " %24s %.*s %9.2f us\n",
+ "nmi",
+ 24, spaces,
+ ns_to_usf(duration));
return 0;
}
taa_data->thread_nmi_sum += duration;
- trace_seq_printf(taa_data->nmi_seq, " %24s \t\t\t%9.2f us\n",
- "nmi", ns_to_usf(duration));
+ trace_seq_printf(taa_data->nmi_seq, " %24s %.*s %9.2f us\n",
+ "nmi",
+ 24, spaces, ns_to_usf(duration));
return 0;
}
@@ -323,8 +329,10 @@ static int timerlat_aa_irq_handler(struct trace_seq *s, struct tep_record *recor
taa_data->prev_irq_timstamp = start;
trace_seq_reset(taa_data->prev_irqs_seq);
- trace_seq_printf(taa_data->prev_irqs_seq, "\t%24s:%-3llu \t\t%9.2f us\n",
- desc, vector, ns_to_usf(duration));
+ trace_seq_printf(taa_data->prev_irqs_seq, " %24s:%-3llu %.*s %9.2f us\n",
+ desc, vector,
+ 15, spaces,
+ ns_to_usf(duration));
return 0;
}
@@ -372,8 +380,10 @@ static int timerlat_aa_irq_handler(struct trace_seq *s, struct tep_record *recor
* IRQ interference.
*/
taa_data->thread_irq_sum += duration;
- trace_seq_printf(taa_data->irqs_seq, " %24s:%-3llu \t %9.2f us\n",
- desc, vector, ns_to_usf(duration));
+ trace_seq_printf(taa_data->irqs_seq, " %24s:%-3llu %.*s %9.2f us\n",
+ desc, vector,
+ 24, spaces,
+ ns_to_usf(duration));
return 0;
}
@@ -408,8 +418,10 @@ static int timerlat_aa_softirq_handler(struct trace_seq *s, struct tep_record *r
taa_data->thread_softirq_sum += duration;
- trace_seq_printf(taa_data->softirqs_seq, "\t%24s:%-3llu \t %9.2f us\n",
- softirq_name[vector], vector, ns_to_usf(duration));
+ trace_seq_printf(taa_data->softirqs_seq, " %24s:%-3llu %.*s %9.2f us\n",
+ softirq_name[vector], vector,
+ 24, spaces,
+ ns_to_usf(duration));
return 0;
}
@@ -452,8 +464,10 @@ static int timerlat_aa_thread_handler(struct trace_seq *s, struct tep_record *re
} else {
taa_data->thread_thread_sum += duration;
- trace_seq_printf(taa_data->threads_seq, "\t%24s:%-3llu \t\t%9.2f us\n",
- comm, pid, ns_to_usf(duration));
+ trace_seq_printf(taa_data->threads_seq, " %24s:%-12llu %.*s %9.2f us\n",
+ comm, pid,
+ 15, spaces,
+ ns_to_usf(duration));
}
return 0;
@@ -482,7 +496,8 @@ static int timerlat_aa_stack_handler(struct trace_seq *s, struct tep_record *rec
function = tep_find_function(taa_ctx->tool->trace.tep, caller[i]);
if (!function)
break;
- trace_seq_printf(taa_data->stack_seq, "\t\t-> %s\n", function);
+ trace_seq_printf(taa_data->stack_seq, " %.*s -> %s\n",
+ 14, spaces, function);
}
}
return 0;
@@ -568,23 +583,24 @@ static void timerlat_thread_analysis(struct timerlat_aa_data *taa_data, int cpu,
exp_irq_ts = taa_data->timer_irq_start_time - taa_data->timer_irq_start_delay;
if (exp_irq_ts < taa_data->prev_irq_timstamp + taa_data->prev_irq_duration) {
if (taa_data->prev_irq_timstamp < taa_data->timer_irq_start_time)
- printf(" Previous IRQ interference: \t\t up to %9.2f us\n",
- ns_to_usf(taa_data->prev_irq_duration));
+ printf(" Previous IRQ interference: %.*s up to %9.2f us\n",
+ 16, spaces,
+ ns_to_usf(taa_data->prev_irq_duration));
}
/*
* The delay that the IRQ suffered before starting.
*/
- printf(" IRQ handler delay: %16s %9.2f us (%.2f %%)\n",
- (ns_to_usf(taa_data->timer_exit_from_idle) > 10) ? "(exit from idle)" : "",
- ns_to_usf(taa_data->timer_irq_start_delay),
- ns_to_per(total, taa_data->timer_irq_start_delay));
+ printf(" IRQ handler delay: %.*s %16s %9.2f us (%.2f %%)\n", 16, spaces,
+ (ns_to_usf(taa_data->timer_exit_from_idle) > 10) ? "(exit from idle)" : "",
+ ns_to_usf(taa_data->timer_irq_start_delay),
+ ns_to_per(total, taa_data->timer_irq_start_delay));
/*
* Timerlat IRQ.
*/
- printf(" IRQ latency: \t\t\t\t %9.2f us\n",
- ns_to_usf(taa_data->tlat_irq_latency));
+ printf(" IRQ latency: %.*s %9.2f us\n", 40, spaces,
+ ns_to_usf(taa_data->tlat_irq_latency));
if (irq) {
/*
@@ -595,15 +611,16 @@ static void timerlat_thread_analysis(struct timerlat_aa_data *taa_data, int cpu,
* so it will be displayed, it is the key.
*/
printf(" Blocking thread:\n");
- printf(" %24s:%-9llu\n",
- taa_data->run_thread_comm, taa_data->run_thread_pid);
+ printf(" %.*s %24s:%-9llu\n", 6, spaces, taa_data->run_thread_comm,
+ taa_data->run_thread_pid);
} else {
/*
* The duration of the IRQ handler that handled the timerlat IRQ.
*/
- printf(" Timerlat IRQ duration: \t\t %9.2f us (%.2f %%)\n",
- ns_to_usf(taa_data->timer_irq_duration),
- ns_to_per(total, taa_data->timer_irq_duration));
+ printf(" Timerlat IRQ duration: %.*s %9.2f us (%.2f %%)\n",
+ 30, spaces,
+ ns_to_usf(taa_data->timer_irq_duration),
+ ns_to_per(total, taa_data->timer_irq_duration));
/*
* The amount of time that the current thread postponed the scheduler.
@@ -611,13 +628,13 @@ static void timerlat_thread_analysis(struct timerlat_aa_data *taa_data, int cpu,
* Recalling that it is net from NMI/IRQ/Softirq interference, so there
* is no need to compute values here.
*/
- printf(" Blocking thread: \t\t\t %9.2f us (%.2f %%)\n",
- ns_to_usf(taa_data->thread_blocking_duration),
- ns_to_per(total, taa_data->thread_blocking_duration));
+ printf(" Blocking thread: %.*s %9.2f us (%.2f %%)\n", 36, spaces,
+ ns_to_usf(taa_data->thread_blocking_duration),
+ ns_to_per(total, taa_data->thread_blocking_duration));
- printf(" %24s:%-9llu %9.2f us\n",
- taa_data->run_thread_comm, taa_data->run_thread_pid,
- ns_to_usf(taa_data->thread_blocking_duration));
+ printf(" %.*s %24s:%-9llu %.*s %9.2f us\n", 6, spaces,
+ taa_data->run_thread_comm, taa_data->run_thread_pid,
+ 12, spaces, ns_to_usf(taa_data->thread_blocking_duration));
}
/*
@@ -629,9 +646,9 @@ static void timerlat_thread_analysis(struct timerlat_aa_data *taa_data, int cpu,
* NMIs can happen during the IRQ, so they are always possible.
*/
if (taa_data->thread_nmi_sum)
- printf(" NMI interference \t\t\t %9.2f us (%.2f %%)\n",
- ns_to_usf(taa_data->thread_nmi_sum),
- ns_to_per(total, taa_data->thread_nmi_sum));
+ printf(" NMI interference %.*s %9.2f us (%.2f %%)\n", 36, spaces,
+ ns_to_usf(taa_data->thread_nmi_sum),
+ ns_to_per(total, taa_data->thread_nmi_sum));
/*
* If it is an IRQ latency, the other factors can be skipped.
@@ -643,9 +660,9 @@ static void timerlat_thread_analysis(struct timerlat_aa_data *taa_data, int cpu,
* Prints the interference caused by IRQs to the thread latency.
*/
if (taa_data->thread_irq_sum) {
- printf(" IRQ interference \t\t\t %9.2f us (%.2f %%)\n",
- ns_to_usf(taa_data->thread_irq_sum),
- ns_to_per(total, taa_data->thread_irq_sum));
+ printf(" IRQ interference %.*s %9.2f us (%.2f %%)\n", 36, spaces,
+ ns_to_usf(taa_data->thread_irq_sum),
+ ns_to_per(total, taa_data->thread_irq_sum));
trace_seq_do_printf(taa_data->irqs_seq);
}
@@ -654,9 +671,9 @@ static void timerlat_thread_analysis(struct timerlat_aa_data *taa_data, int cpu,
* Prints the interference caused by Softirqs to the thread latency.
*/
if (taa_data->thread_softirq_sum) {
- printf(" Softirq interference \t\t\t %9.2f us (%.2f %%)\n",
- ns_to_usf(taa_data->thread_softirq_sum),
- ns_to_per(total, taa_data->thread_softirq_sum));
+ printf(" Softirq interference %.*s %9.2f us (%.2f %%)\n", 32, spaces,
+ ns_to_usf(taa_data->thread_softirq_sum),
+ ns_to_per(total, taa_data->thread_softirq_sum));
trace_seq_do_printf(taa_data->softirqs_seq);
}
@@ -670,9 +687,9 @@ static void timerlat_thread_analysis(struct timerlat_aa_data *taa_data, int cpu,
* timer handling latency.
*/
if (taa_data->thread_thread_sum) {
- printf(" Thread interference \t\t\t %9.2f us (%.2f %%)\n",
- ns_to_usf(taa_data->thread_thread_sum),
- ns_to_per(total, taa_data->thread_thread_sum));
+ printf(" Thread interference %.*s %9.2f us (%.2f %%)\n", 33, spaces,
+ ns_to_usf(taa_data->thread_thread_sum),
+ ns_to_per(total, taa_data->thread_thread_sum));
trace_seq_do_printf(taa_data->threads_seq);
}
@@ -682,8 +699,8 @@ static void timerlat_thread_analysis(struct timerlat_aa_data *taa_data, int cpu,
*/
print_total:
printf("------------------------------------------------------------------------\n");
- printf(" %s latency: \t\t\t %9.2f us (100%%)\n", irq ? "IRQ" : "Thread",
- ns_to_usf(total));
+ printf(" %s latency: %.*s %9.2f us (100%%)\n", irq ? " IRQ" : "Thread",
+ 37, spaces, ns_to_usf(total));
}
static int timerlat_auto_analysis_collect_trace(struct timerlat_aa_context *taa_ctx)
diff --git a/tools/tracing/rtla/src/timerlat_hist.c b/tools/tracing/rtla/src/timerlat_hist.c
index dbf154082f95..6d7d0a2d45b4 100644
--- a/tools/tracing/rtla/src/timerlat_hist.c
+++ b/tools/tracing/rtla/src/timerlat_hist.c
@@ -39,6 +39,8 @@ struct timerlat_hist_params {
int hk_cpus;
int no_aa;
int dump_tasks;
+ int user_workload;
+ int kernel_workload;
int user_hist;
cpu_set_t hk_cpu_set;
struct sched_attr sched_param;
@@ -51,6 +53,9 @@ struct timerlat_hist_params {
char with_zeros;
int bucket_size;
int entries;
+ int warmup;
+ int buffer_size;
+ int deepest_idle_state;
};
struct timerlat_hist_cpu {
@@ -58,9 +63,9 @@ struct timerlat_hist_cpu {
int *thread;
int *user;
- int irq_count;
- int thread_count;
- int user_count;
+ unsigned long long irq_count;
+ unsigned long long thread_count;
+ unsigned long long user_count;
unsigned long long min_irq;
unsigned long long sum_irq;
@@ -277,6 +282,21 @@ static void timerlat_hist_header(struct osnoise_tool *tool)
}
/*
+ * format_summary_value - format a line of summary value (min, max or avg)
+ * of hist data
+ */
+static void format_summary_value(struct trace_seq *seq,
+ int count,
+ unsigned long long val,
+ bool avg)
+{
+ if (count)
+ trace_seq_printf(seq, "%9llu ", avg ? val / count : val);
+ else
+ trace_seq_printf(seq, "%9c ", '-');
+}
+
+/*
* timerlat_print_summary - print the summary of the hist data to the output
*/
static void
@@ -300,15 +320,15 @@ timerlat_print_summary(struct timerlat_hist_params *params,
continue;
if (!params->no_irq)
- trace_seq_printf(trace->seq, "%9d ",
+ trace_seq_printf(trace->seq, "%9llu ",
data->hist[cpu].irq_count);
if (!params->no_thread)
- trace_seq_printf(trace->seq, "%9d ",
+ trace_seq_printf(trace->seq, "%9llu ",
data->hist[cpu].thread_count);
if (params->user_hist)
- trace_seq_printf(trace->seq, "%9d ",
+ trace_seq_printf(trace->seq, "%9llu ",
data->hist[cpu].user_count);
}
trace_seq_printf(trace->seq, "\n");
@@ -324,16 +344,22 @@ timerlat_print_summary(struct timerlat_hist_params *params,
continue;
if (!params->no_irq)
- trace_seq_printf(trace->seq, "%9llu ",
- data->hist[cpu].min_irq);
+ format_summary_value(trace->seq,
+ data->hist[cpu].irq_count,
+ data->hist[cpu].min_irq,
+ false);
if (!params->no_thread)
- trace_seq_printf(trace->seq, "%9llu ",
- data->hist[cpu].min_thread);
+ format_summary_value(trace->seq,
+ data->hist[cpu].thread_count,
+ data->hist[cpu].min_thread,
+ false);
if (params->user_hist)
- trace_seq_printf(trace->seq, "%9llu ",
- data->hist[cpu].min_user);
+ format_summary_value(trace->seq,
+ data->hist[cpu].user_count,
+ data->hist[cpu].min_user,
+ false);
}
trace_seq_printf(trace->seq, "\n");
@@ -347,29 +373,23 @@ timerlat_print_summary(struct timerlat_hist_params *params,
if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)
continue;
- if (!params->no_irq) {
- if (data->hist[cpu].irq_count)
- trace_seq_printf(trace->seq, "%9llu ",
- data->hist[cpu].sum_irq / data->hist[cpu].irq_count);
- else
- trace_seq_printf(trace->seq, " - ");
- }
+ if (!params->no_irq)
+ format_summary_value(trace->seq,
+ data->hist[cpu].irq_count,
+ data->hist[cpu].sum_irq,
+ true);
- if (!params->no_thread) {
- if (data->hist[cpu].thread_count)
- trace_seq_printf(trace->seq, "%9llu ",
- data->hist[cpu].sum_thread / data->hist[cpu].thread_count);
- else
- trace_seq_printf(trace->seq, " - ");
- }
+ if (!params->no_thread)
+ format_summary_value(trace->seq,
+ data->hist[cpu].thread_count,
+ data->hist[cpu].sum_thread,
+ true);
- if (params->user_hist) {
- if (data->hist[cpu].user_count)
- trace_seq_printf(trace->seq, "%9llu ",
- data->hist[cpu].sum_user / data->hist[cpu].user_count);
- else
- trace_seq_printf(trace->seq, " - ");
- }
+ if (params->user_hist)
+ format_summary_value(trace->seq,
+ data->hist[cpu].user_count,
+ data->hist[cpu].sum_user,
+ true);
}
trace_seq_printf(trace->seq, "\n");
@@ -384,24 +404,175 @@ timerlat_print_summary(struct timerlat_hist_params *params,
continue;
if (!params->no_irq)
- trace_seq_printf(trace->seq, "%9llu ",
- data->hist[cpu].max_irq);
+ format_summary_value(trace->seq,
+ data->hist[cpu].irq_count,
+ data->hist[cpu].max_irq,
+ false);
if (!params->no_thread)
- trace_seq_printf(trace->seq, "%9llu ",
- data->hist[cpu].max_thread);
+ format_summary_value(trace->seq,
+ data->hist[cpu].thread_count,
+ data->hist[cpu].max_thread,
+ false);
if (params->user_hist)
- trace_seq_printf(trace->seq, "%9llu ",
- data->hist[cpu].max_user);
+ format_summary_value(trace->seq,
+ data->hist[cpu].user_count,
+ data->hist[cpu].max_user,
+ false);
}
trace_seq_printf(trace->seq, "\n");
trace_seq_do_printf(trace->seq);
trace_seq_reset(trace->seq);
}
+static void
+timerlat_print_stats_all(struct timerlat_hist_params *params,
+ struct trace_instance *trace,
+ struct timerlat_hist_data *data)
+{
+ struct timerlat_hist_cpu *cpu_data;
+ struct timerlat_hist_cpu sum;
+ int cpu;
+
+ if (params->no_summary)
+ return;
+
+ memset(&sum, 0, sizeof(sum));
+ sum.min_irq = ~0;
+ sum.min_thread = ~0;
+ sum.min_user = ~0;
+
+ for (cpu = 0; cpu < data->nr_cpus; cpu++) {
+ if (params->cpus && !CPU_ISSET(cpu, &params->monitored_cpus))
+ continue;
+
+ if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)
+ continue;
+
+ cpu_data = &data->hist[cpu];
+
+ sum.irq_count += cpu_data->irq_count;
+ update_min(&sum.min_irq, &cpu_data->min_irq);
+ update_sum(&sum.sum_irq, &cpu_data->sum_irq);
+ update_max(&sum.max_irq, &cpu_data->max_irq);
+
+ sum.thread_count += cpu_data->thread_count;
+ update_min(&sum.min_thread, &cpu_data->min_thread);
+ update_sum(&sum.sum_thread, &cpu_data->sum_thread);
+ update_max(&sum.max_thread, &cpu_data->max_thread);
+
+ sum.user_count += cpu_data->user_count;
+ update_min(&sum.min_user, &cpu_data->min_user);
+ update_sum(&sum.sum_user, &cpu_data->sum_user);
+ update_max(&sum.max_user, &cpu_data->max_user);
+ }
+
+ if (!params->no_index)
+ trace_seq_printf(trace->seq, "ALL: ");
+
+ if (!params->no_irq)
+ trace_seq_printf(trace->seq, " IRQ");
+
+ if (!params->no_thread)
+ trace_seq_printf(trace->seq, " Thr");
+
+ if (params->user_hist)
+ trace_seq_printf(trace->seq, " Usr");
+
+ trace_seq_printf(trace->seq, "\n");
+
+ if (!params->no_index)
+ trace_seq_printf(trace->seq, "count:");
+
+ if (!params->no_irq)
+ trace_seq_printf(trace->seq, "%9llu ",
+ sum.irq_count);
+
+ if (!params->no_thread)
+ trace_seq_printf(trace->seq, "%9llu ",
+ sum.thread_count);
+
+ if (params->user_hist)
+ trace_seq_printf(trace->seq, "%9llu ",
+ sum.user_count);
+
+ trace_seq_printf(trace->seq, "\n");
+
+ if (!params->no_index)
+ trace_seq_printf(trace->seq, "min: ");
+
+ if (!params->no_irq)
+ format_summary_value(trace->seq,
+ sum.irq_count,
+ sum.min_irq,
+ false);
+
+ if (!params->no_thread)
+ format_summary_value(trace->seq,
+ sum.thread_count,
+ sum.min_thread,
+ false);
+
+ if (params->user_hist)
+ format_summary_value(trace->seq,
+ sum.user_count,
+ sum.min_user,
+ false);
+
+ trace_seq_printf(trace->seq, "\n");
+
+ if (!params->no_index)
+ trace_seq_printf(trace->seq, "avg: ");
+
+ if (!params->no_irq)
+ format_summary_value(trace->seq,
+ sum.irq_count,
+ sum.sum_irq,
+ true);
+
+ if (!params->no_thread)
+ format_summary_value(trace->seq,
+ sum.thread_count,
+ sum.sum_thread,
+ true);
+
+ if (params->user_hist)
+ format_summary_value(trace->seq,
+ sum.user_count,
+ sum.sum_user,
+ true);
+
+ trace_seq_printf(trace->seq, "\n");
+
+ if (!params->no_index)
+ trace_seq_printf(trace->seq, "max: ");
+
+ if (!params->no_irq)
+ format_summary_value(trace->seq,
+ sum.irq_count,
+ sum.max_irq,
+ false);
+
+ if (!params->no_thread)
+ format_summary_value(trace->seq,
+ sum.thread_count,
+ sum.max_thread,
+ false);
+
+ if (params->user_hist)
+ format_summary_value(trace->seq,
+ sum.user_count,
+ sum.max_user,
+ false);
+
+ trace_seq_printf(trace->seq, "\n");
+ trace_seq_do_printf(trace->seq);
+ trace_seq_reset(trace->seq);
+}
+
/*
- * timerlat_print_stats - print data for all CPUs
+ * timerlat_print_stats - print data for each CPUs
*/
static void
timerlat_print_stats(struct timerlat_hist_params *params, struct osnoise_tool *tool)
@@ -484,6 +655,8 @@ timerlat_print_stats(struct timerlat_hist_params *params, struct osnoise_tool *t
trace_seq_reset(trace->seq);
timerlat_print_summary(params, trace, data);
+ timerlat_print_stats_all(params, trace, data);
+ osnoise_report_missed_events(tool);
}
/*
@@ -496,9 +669,10 @@ static void timerlat_hist_usage(char *usage)
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]",
+ " [--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",
" -a/--auto: set automatic trace mode, stopping the session if argument in us latency is hit",
@@ -512,7 +686,7 @@ static void timerlat_hist_usage(char *usage)
" -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",
@@ -533,7 +707,12 @@ static void timerlat_hist_usage(char *usage)
" f:prio - use SCHED_FIFO with prio",
" d:runtime[us|ms|s]:period[us|ms|s] - use SCHED_DEADLINE with runtime and period",
" in nanoseconds",
- " -u/--user-threads: use rtla user-space threads instead of in-kernel timerlat threads",
+ " -u/--user-threads: use rtla user-space threads instead of kernel-space timerlat threads",
+ " -k/--kernel-threads: use timerlat kernel-space threads instead of rtla user-space threads",
+ " -U/--user-load: enable timerlat for user-defined user-space workload",
+ " --warm-up s: let the workload run for s seconds before collecting data",
+ " --trace-buffer-size kB: set the per-cpu trace buffer size in kB",
+ " --deepest-idle-state n: only go down to idle state n on cpus used by timerlat to reduce exit from idle latency",
NULL,
};
@@ -571,6 +750,9 @@ static struct timerlat_hist_params
/* disabled by default */
params->dma_latency = -1;
+ /* disabled by default */
+ params->deepest_idle_state = -2;
+
/* display data in microseconds */
params->output_divisor = 1000;
params->bucket_size = 1;
@@ -595,6 +777,8 @@ static struct timerlat_hist_params
{"thread", required_argument, 0, 'T'},
{"trace", optional_argument, 0, 't'},
{"user-threads", no_argument, 0, 'u'},
+ {"kernel-threads", no_argument, 0, 'k'},
+ {"user-load", no_argument, 0, 'U'},
{"event", required_argument, 0, 'e'},
{"no-irq", no_argument, 0, '0'},
{"no-thread", no_argument, 0, '1'},
@@ -607,13 +791,16 @@ static struct timerlat_hist_params
{"dma-latency", required_argument, 0, '8'},
{"no-aa", no_argument, 0, '9'},
{"dump-task", no_argument, 0, '\1'},
+ {"warm-up", required_argument, 0, '\2'},
+ {"trace-buffer-size", required_argument, 0, '\3'},
+ {"deepest-idle-state", required_argument, 0, '\4'},
{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:np:P:s:t::T:u0123456:7:8:9\1",
+ 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);
/* detect the end of the options. */
@@ -696,6 +883,9 @@ static struct timerlat_hist_params
case 'i':
params->stop_us = get_llong_from_str(optarg);
break;
+ case 'k':
+ params->kernel_workload = 1;
+ break;
case 'n':
params->output_divisor = 1;
break;
@@ -717,13 +907,20 @@ static struct timerlat_hist_params
params->stop_total_us = get_llong_from_str(optarg);
break;
case 't':
- if (optarg)
- /* skip = */
- params->trace_output = &optarg[1];
+ if (optarg) {
+ if (optarg[0] == '=')
+ params->trace_output = &optarg[1];
+ else
+ params->trace_output = &optarg[0];
+ } else if (optind < argc && argv[optind][0] != '-')
+ params->trace_output = argv[optind];
else
params->trace_output = "timerlat_trace.txt";
break;
case 'u':
+ params->user_workload = 1;
+ /* fallback: -u implies in -U */
+ case 'U':
params->user_hist = 1;
break;
case '0': /* no irq */
@@ -779,6 +976,15 @@ static struct timerlat_hist_params
case '\1':
params->dump_tasks = 1;
break;
+ case '\2':
+ params->warmup = get_llong_from_str(optarg);
+ break;
+ case '\3':
+ params->buffer_size = get_llong_from_str(optarg);
+ break;
+ case '\4':
+ params->deepest_idle_state = get_llong_from_str(optarg);
+ break;
default:
timerlat_hist_usage("Invalid option");
}
@@ -801,6 +1007,9 @@ static struct timerlat_hist_params
if (!params->stop_us && !params->stop_total_us)
params->no_aa = 1;
+ if (params->kernel_workload && params->user_workload)
+ timerlat_hist_usage("--kernel-threads and --user-threads are mutually exclusive!");
+
return params;
}
@@ -876,14 +1085,33 @@ timerlat_hist_apply_config(struct osnoise_tool *tool, struct timerlat_hist_param
auto_house_keeping(&params->monitored_cpus);
}
- if (params->user_hist) {
- retval = osnoise_set_workload(tool->context, 0);
+ /*
+ * If the user did not specify a type of thread, try user-threads first.
+ * Fall back to kernel threads otherwise.
+ */
+ if (!params->kernel_workload && !params->user_hist) {
+ retval = tracefs_file_exists(NULL, "osnoise/per_cpu/cpu0/timerlat_fd");
if (retval) {
- err_msg("Failed to set OSNOISE_WORKLOAD option\n");
- goto out_err;
+ debug_msg("User-space interface detected, setting user-threads\n");
+ params->user_workload = 1;
+ params->user_hist = 1;
+ } else {
+ debug_msg("User-space interface not detected, setting kernel-threads\n");
+ params->kernel_workload = 1;
}
}
+ /*
+ * Set workload according to type of thread if the kernel supports it.
+ * On kernels without support, user threads will have already failed
+ * on missing timerlat_fd, and kernel threads do not need it.
+ */
+ retval = osnoise_set_workload(tool->context, params->kernel_workload);
+ if (retval < -1) {
+ err_msg("Failed to set OSNOISE_WORKLOAD option\n");
+ goto out_err;
+ }
+
return 0;
out_err:
@@ -922,9 +1150,20 @@ out_err:
}
static int stop_tracing;
+static struct trace_instance *hist_inst = NULL;
static void stop_hist(int sig)
{
+ if (stop_tracing) {
+ /*
+ * Stop requested twice in a row; abort event processing and
+ * exit immediately
+ */
+ tracefs_iterate_stop(hist_inst->inst);
+ return;
+ }
stop_tracing = 1;
+ if (hist_inst)
+ trace_instance_stop(hist_inst);
}
/*
@@ -952,6 +1191,7 @@ int timerlat_hist_main(int argc, char *argv[])
int return_value = 1;
pthread_t timerlat_u;
int retval;
+ int nr_cpus, i;
params = timerlat_hist_parse_args(argc, argv);
if (!params)
@@ -970,6 +1210,12 @@ int timerlat_hist_main(int argc, char *argv[])
}
trace = &tool->trace;
+ /*
+ * Save trace instance into global variable so that SIGINT can stop
+ * the timerlat tracer.
+ * Otherwise, rtla could loop indefinitely when overloaded.
+ */
+ hist_inst = trace;
retval = enable_timerlat(trace);
if (retval) {
@@ -985,7 +1231,7 @@ int timerlat_hist_main(int argc, char *argv[])
}
}
- if (params->cgroup && !params->user_hist) {
+ if (params->cgroup && !params->user_workload) {
retval = set_comm_cgroup("timerlat/", params->cgroup_name);
if (!retval) {
err_msg("Failed to move threads to cgroup\n");
@@ -1001,6 +1247,28 @@ int timerlat_hist_main(int argc, char *argv[])
}
}
+ if (params->deepest_idle_state >= -1) {
+ if (!have_libcpupower_support()) {
+ err_msg("rtla built without libcpupower, --deepest-idle-state is not supported\n");
+ goto out_free;
+ }
+
+ nr_cpus = sysconf(_SC_NPROCESSORS_CONF);
+
+ for (i = 0; i < nr_cpus; i++) {
+ if (params->cpus && !CPU_ISSET(i, &params->monitored_cpus))
+ continue;
+ if (save_cpu_idle_disable_state(i) < 0) {
+ err_msg("Could not save cpu idle state.\n");
+ goto out_free;
+ }
+ if (set_deepest_cpu_idle_state(i, params->deepest_idle_state) < 0) {
+ err_msg("Could not set deepest cpu idle state.\n");
+ goto out_free;
+ }
+ }
+ }
+
if (params->trace_output) {
record = osnoise_init_trace_tool("timerlat");
if (!record) {
@@ -1013,6 +1281,12 @@ int timerlat_hist_main(int argc, char *argv[])
if (retval)
goto out_hist;
}
+
+ if (params->buffer_size > 0) {
+ retval = trace_set_buffer_size(&record->trace, params->buffer_size);
+ if (retval)
+ goto out_hist;
+ }
}
if (!params->no_aa) {
@@ -1033,23 +1307,7 @@ int timerlat_hist_main(int argc, char *argv[])
}
}
- /*
- * Start the tracers here, after having set all instances.
- *
- * Let the trace instance start first for the case of hitting a stop
- * tracing while enabling other instances. The trace instance is the
- * one with most valuable information.
- */
- if (params->trace_output)
- trace_instance_start(&record->trace);
- if (!params->no_aa)
- trace_instance_start(&aa->trace);
- trace_instance_start(trace);
-
- tool->start_time = time(NULL);
- timerlat_hist_set_signals(params);
-
- if (params->user_hist) {
+ if (params->user_workload) {
/* rtla asked to stop */
params_u.should_run = 1;
/* all threads left */
@@ -1068,6 +1326,29 @@ int timerlat_hist_main(int argc, char *argv[])
err_msg("Error creating timerlat user-space threads\n");
}
+ if (params->warmup > 0) {
+ debug_msg("Warming up for %d seconds\n", params->warmup);
+ sleep(params->warmup);
+ if (stop_tracing)
+ goto out_hist;
+ }
+
+ /*
+ * Start the tracers here, after having set all instances.
+ *
+ * Let the trace instance start first for the case of hitting a stop
+ * tracing while enabling other instances. The trace instance is the
+ * one with most valuable information.
+ */
+ if (params->trace_output)
+ trace_instance_start(&record->trace);
+ if (!params->no_aa)
+ trace_instance_start(&aa->trace);
+ trace_instance_start(trace);
+
+ tool->start_time = time(NULL);
+ timerlat_hist_set_signals(params);
+
while (!stop_tracing) {
sleep(params->sleep_time);
@@ -1082,18 +1363,19 @@ int timerlat_hist_main(int argc, char *argv[])
goto out_hist;
}
- if (trace_is_off(&tool->trace, &record->trace))
+ if (osnoise_trace_is_off(tool, record))
break;
/* is there still any user-threads ? */
- if (params->user_hist) {
+ if (params->user_workload) {
if (params_u.stopped_running) {
debug_msg("timerlat user-space threads stopped!\n");
break;
}
}
}
- if (params->user_hist && !params_u.stopped_running) {
+
+ if (params->user_workload && !params_u.stopped_running) {
params_u.should_run = 0;
sleep(1);
}
@@ -1102,7 +1384,7 @@ int timerlat_hist_main(int argc, char *argv[])
return_value = 0;
- if (trace_is_off(&tool->trace, &record->trace)) {
+ if (osnoise_trace_is_off(tool, record) && !stop_tracing) {
printf("rtla timerlat hit stop tracing\n");
if (!params->no_aa)
@@ -1118,6 +1400,13 @@ out_hist:
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->cpus && !CPU_ISSET(i, &params->monitored_cpus))
+ continue;
+ restore_cpu_idle_disable_state(i);
+ }
+ }
trace_events_destroy(&record->trace, params->events);
params->events = NULL;
out_free:
@@ -1126,6 +1415,7 @@ out_free:
osnoise_destroy_tool(record);
osnoise_destroy_tool(tool);
free(params);
+ free_cpu_idle_disable_states();
out_exit:
exit(return_value);
}
diff --git a/tools/tracing/rtla/src/timerlat_top.c b/tools/tracing/rtla/src/timerlat_top.c
index 3e9af2c38688..05a9403b01d2 100644
--- a/tools/tracing/rtla/src/timerlat_top.c
+++ b/tools/tracing/rtla/src/timerlat_top.c
@@ -43,15 +43,21 @@ struct timerlat_top_params {
int cgroup;
int hk_cpus;
int user_top;
+ int user_workload;
+ int kernel_workload;
+ int pretty_output;
+ int warmup;
+ int buffer_size;
+ int deepest_idle_state;
cpu_set_t hk_cpu_set;
struct sched_attr sched_param;
struct trace_events *events;
};
struct timerlat_top_cpu {
- int irq_count;
- int thread_count;
- int user_count;
+ unsigned long long irq_count;
+ unsigned long long thread_count;
+ unsigned long long user_count;
unsigned long long cur_irq;
unsigned long long min_irq;
@@ -117,6 +123,37 @@ cleanup:
return NULL;
}
+static void
+timerlat_top_reset_sum(struct timerlat_top_cpu *summary)
+{
+ memset(summary, 0, sizeof(*summary));
+ summary->min_irq = ~0;
+ summary->min_thread = ~0;
+ summary->min_user = ~0;
+}
+
+static void
+timerlat_top_update_sum(struct osnoise_tool *tool, int cpu, struct timerlat_top_cpu *sum)
+{
+ struct timerlat_top_data *data = tool->data;
+ struct timerlat_top_cpu *cpu_data = &data->cpu_data[cpu];
+
+ sum->irq_count += cpu_data->irq_count;
+ update_min(&sum->min_irq, &cpu_data->min_irq);
+ update_sum(&sum->sum_irq, &cpu_data->sum_irq);
+ update_max(&sum->max_irq, &cpu_data->max_irq);
+
+ sum->thread_count += cpu_data->thread_count;
+ update_min(&sum->min_thread, &cpu_data->min_thread);
+ update_sum(&sum->sum_thread, &cpu_data->sum_thread);
+ update_max(&sum->max_thread, &cpu_data->max_thread);
+
+ sum->user_count += cpu_data->user_count;
+ update_min(&sum->min_user, &cpu_data->min_user);
+ update_sum(&sum->sum_user, &cpu_data->sum_user);
+ update_max(&sum->max_user, &cpu_data->max_user);
+}
+
/*
* timerlat_hist_update - record a new timerlat occurent on cpu, updating data
*/
@@ -178,19 +215,22 @@ timerlat_top_handler(struct trace_seq *s, struct tep_record *record,
/*
* timerlat_top_header - print the header of the tool output
*/
-static void timerlat_top_header(struct osnoise_tool *top)
+static void timerlat_top_header(struct timerlat_top_params *params, struct osnoise_tool *top)
{
- struct timerlat_top_params *params = top->params;
struct trace_seq *s = top->trace.seq;
char duration[26];
get_duration(top->start_time, duration, sizeof(duration));
- trace_seq_printf(s, "\033[2;37;40m");
+ if (params->pretty_output)
+ trace_seq_printf(s, "\033[2;37;40m");
+
trace_seq_printf(s, " Timer Latency ");
if (params->user_top)
trace_seq_printf(s, " ");
- trace_seq_printf(s, "\033[0;0;0m");
+
+ if (params->pretty_output)
+ trace_seq_printf(s, "\033[0;0;0m");
trace_seq_printf(s, "\n");
trace_seq_printf(s, "%-6s | IRQ Timer Latency (%s) | Thread Timer Latency (%s)", duration,
@@ -203,14 +243,20 @@ static void timerlat_top_header(struct osnoise_tool *top)
}
trace_seq_printf(s, "\n");
- trace_seq_printf(s, "\033[2;30;47m");
+ if (params->pretty_output)
+ trace_seq_printf(s, "\033[2;30;47m");
+
trace_seq_printf(s, "CPU COUNT | cur min avg max | cur min avg max");
if (params->user_top)
trace_seq_printf(s, " | cur min avg max");
- trace_seq_printf(s, "\033[0;0;0m");
+
+ if (params->pretty_output)
+ trace_seq_printf(s, "\033[0;0;0m");
trace_seq_printf(s, "\n");
}
+static const char *no_value = " -";
+
/*
* timerlat_top_print - prints the output of a given CPU
*/
@@ -235,13 +281,10 @@ static void timerlat_top_print(struct osnoise_tool *top, int cpu)
/*
* Unless trace is being lost, IRQ counter is always the max.
*/
- trace_seq_printf(s, "%3d #%-9d |", cpu, cpu_data->irq_count);
+ trace_seq_printf(s, "%3d #%-9llu |", cpu, cpu_data->irq_count);
if (!cpu_data->irq_count) {
- trace_seq_printf(s, " - ");
- trace_seq_printf(s, " - ");
- trace_seq_printf(s, " - ");
- trace_seq_printf(s, " - |");
+ trace_seq_printf(s, "%s %s %s %s |", no_value, no_value, no_value, no_value);
} else {
trace_seq_printf(s, "%9llu ", cpu_data->cur_irq / params->output_divisor);
trace_seq_printf(s, "%9llu ", cpu_data->min_irq / params->output_divisor);
@@ -250,10 +293,7 @@ static void timerlat_top_print(struct osnoise_tool *top, int cpu)
}
if (!cpu_data->thread_count) {
- trace_seq_printf(s, " - ");
- trace_seq_printf(s, " - ");
- trace_seq_printf(s, " - ");
- trace_seq_printf(s, " -\n");
+ trace_seq_printf(s, "%s %s %s %s", no_value, no_value, no_value, no_value);
} else {
trace_seq_printf(s, "%9llu ", cpu_data->cur_thread / divisor);
trace_seq_printf(s, "%9llu ", cpu_data->min_thread / divisor);
@@ -270,10 +310,7 @@ static void timerlat_top_print(struct osnoise_tool *top, int cpu)
trace_seq_printf(s, " |");
if (!cpu_data->user_count) {
- trace_seq_printf(s, " - ");
- trace_seq_printf(s, " - ");
- trace_seq_printf(s, " - ");
- trace_seq_printf(s, " -\n");
+ trace_seq_printf(s, "%s %s %s %s\n", no_value, no_value, no_value, no_value);
} else {
trace_seq_printf(s, "%9llu ", cpu_data->cur_user / divisor);
trace_seq_printf(s, "%9llu ", cpu_data->min_user / divisor);
@@ -284,6 +321,77 @@ static void timerlat_top_print(struct osnoise_tool *top, int cpu)
}
/*
+ * timerlat_top_print_sum - prints the summary output
+ */
+static void
+timerlat_top_print_sum(struct osnoise_tool *top, struct timerlat_top_cpu *summary)
+{
+ const char *split = "----------------------------------------";
+ struct timerlat_top_params *params = top->params;
+ unsigned long long count = summary->irq_count;
+ int divisor = params->output_divisor;
+ struct trace_seq *s = top->trace.seq;
+ int e = 0;
+
+ if (divisor == 0)
+ return;
+
+ /*
+ * Skip if no data is available: is this cpu offline?
+ */
+ if (!summary->irq_count && !summary->thread_count)
+ return;
+
+ while (count > 999999) {
+ e++;
+ count /= 10;
+ }
+
+ trace_seq_printf(s, "%.*s|%.*s|%.*s", 15, split, 40, split, 39, split);
+ if (params->user_top)
+ trace_seq_printf(s, "-|%.*s", 39, split);
+ trace_seq_printf(s, "\n");
+
+ trace_seq_printf(s, "ALL #%-6llu e%d |", count, e);
+
+ if (!summary->irq_count) {
+ trace_seq_printf(s, " %s %s %s |", no_value, no_value, no_value);
+ } else {
+ trace_seq_printf(s, " ");
+ trace_seq_printf(s, "%9llu ", summary->min_irq / params->output_divisor);
+ trace_seq_printf(s, "%9llu ", (summary->sum_irq / summary->irq_count) / divisor);
+ trace_seq_printf(s, "%9llu |", summary->max_irq / divisor);
+ }
+
+ if (!summary->thread_count) {
+ trace_seq_printf(s, "%s %s %s %s", no_value, no_value, no_value, no_value);
+ } else {
+ trace_seq_printf(s, " ");
+ trace_seq_printf(s, "%9llu ", summary->min_thread / divisor);
+ trace_seq_printf(s, "%9llu ",
+ (summary->sum_thread / summary->thread_count) / divisor);
+ trace_seq_printf(s, "%9llu", summary->max_thread / divisor);
+ }
+
+ if (!params->user_top) {
+ trace_seq_printf(s, "\n");
+ return;
+ }
+
+ trace_seq_printf(s, " |");
+
+ if (!summary->user_count) {
+ trace_seq_printf(s, " %s %s %s |", no_value, no_value, no_value);
+ } else {
+ trace_seq_printf(s, " ");
+ trace_seq_printf(s, "%9llu ", summary->min_user / divisor);
+ trace_seq_printf(s, "%9llu ",
+ (summary->sum_user / summary->user_count) / divisor);
+ trace_seq_printf(s, "%9llu\n", summary->max_user / divisor);
+ }
+}
+
+/*
* clear_terminal - clears the output terminal
*/
static void clear_terminal(struct trace_seq *seq)
@@ -299,6 +407,7 @@ static void
timerlat_print_stats(struct timerlat_top_params *params, struct osnoise_tool *top)
{
struct trace_instance *trace = &top->trace;
+ struct timerlat_top_cpu summary;
static int nr_cpus = -1;
int i;
@@ -311,16 +420,22 @@ timerlat_print_stats(struct timerlat_top_params *params, struct osnoise_tool *to
if (!params->quiet)
clear_terminal(trace->seq);
- timerlat_top_header(top);
+ timerlat_top_reset_sum(&summary);
+
+ timerlat_top_header(params, top);
for (i = 0; i < nr_cpus; i++) {
if (params->cpus && !CPU_ISSET(i, &params->monitored_cpus))
continue;
timerlat_top_print(top, i);
+ timerlat_top_update_sum(top, i, &summary);
}
+ timerlat_top_print_sum(top, &summary);
+
trace_seq_do_printf(trace->seq);
trace_seq_reset(trace->seq);
+ osnoise_report_missed_events(top);
}
/*
@@ -333,8 +448,8 @@ static void timerlat_top_usage(char *usage)
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]",
+ " [[-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",
@@ -346,10 +461,10 @@ static void timerlat_top_usage(char *usage)
" -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",
- " -d/--duration time[m|h|d]: duration of the session in seconds",
+ " -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",
@@ -363,7 +478,12 @@ static void timerlat_top_usage(char *usage)
" f:prio - use SCHED_FIFO with prio",
" d:runtime[us|ms|s]:period[us|ms|s] - use SCHED_DEADLINE with runtime and period",
" in nanoseconds",
- " -u/--user-threads: use rtla user-space threads instead of in-kernel timerlat threads",
+ " -u/--user-threads: use rtla user-space threads instead of kernel-space timerlat threads",
+ " -k/--kernel-threads: use timerlat kernel-space threads instead of rtla user-space threads",
+ " -U/--user-load: enable timerlat for user-defined user-space workload",
+ " --warm-up s: let the workload run for s seconds before collecting data",
+ " --trace-buffer-size kB: set the per-cpu trace buffer size in kB",
+ " --deepest-idle-state n: only go down to idle state n on cpus used by timerlat to reduce exit from idle latency",
NULL,
};
@@ -401,6 +521,9 @@ static struct timerlat_top_params
/* disabled by default */
params->dma_latency = -1;
+ /* disabled by default */
+ params->deepest_idle_state = -2;
+
/* display data in microseconds */
params->output_divisor = 1000;
@@ -423,19 +546,24 @@ static struct timerlat_top_params
{"thread", required_argument, 0, 'T'},
{"trace", optional_argument, 0, 't'},
{"user-threads", no_argument, 0, 'u'},
+ {"kernel-threads", no_argument, 0, 'k'},
+ {"user-load", no_argument, 0, 'U'},
{"trigger", required_argument, 0, '0'},
{"filter", required_argument, 0, '1'},
{"dma-latency", required_argument, 0, '2'},
{"no-aa", no_argument, 0, '3'},
{"dump-tasks", no_argument, 0, '4'},
{"aa-only", required_argument, 0, '5'},
+ {"warm-up", required_argument, 0, '6'},
+ {"trace-buffer-size", required_argument, 0, '7'},
+ {"deepest-idle-state", required_argument, 0, '8'},
{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:np:P:qs:t::T:u0:1:2:345:",
+ 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);
/* detect the end of the options. */
@@ -492,7 +620,7 @@ static struct timerlat_top_params
case 'd':
params->duration = parse_seconds_duration(optarg);
if (!params->duration)
- timerlat_top_usage("Invalid -D duration\n");
+ timerlat_top_usage("Invalid -d duration\n");
break;
case 'e':
tevent = trace_event_alloc(optarg);
@@ -520,6 +648,9 @@ static struct timerlat_top_params
case 'i':
params->stop_us = get_llong_from_str(optarg);
break;
+ case 'k':
+ params->kernel_workload = true;
+ break;
case 'n':
params->output_divisor = 1;
break;
@@ -544,14 +675,21 @@ static struct timerlat_top_params
params->stop_total_us = get_llong_from_str(optarg);
break;
case 't':
- if (optarg)
- /* skip = */
- params->trace_output = &optarg[1];
+ if (optarg) {
+ if (optarg[0] == '=')
+ params->trace_output = &optarg[1];
+ else
+ params->trace_output = &optarg[0];
+ } else if (optind < argc && argv[optind][0] != '-')
+ params->trace_output = argv[optind];
else
params->trace_output = "timerlat_trace.txt";
break;
case 'u':
+ params->user_workload = true;
+ /* fallback: -u implies -U */
+ case 'U':
params->user_top = true;
break;
case '0': /* trigger */
@@ -589,6 +727,15 @@ static struct timerlat_top_params
case '4':
params->dump_tasks = 1;
break;
+ case '6':
+ params->warmup = get_llong_from_str(optarg);
+ break;
+ case '7':
+ params->buffer_size = get_llong_from_str(optarg);
+ break;
+ case '8':
+ params->deepest_idle_state = get_llong_from_str(optarg);
+ break;
default:
timerlat_top_usage("Invalid option");
}
@@ -608,6 +755,9 @@ static struct timerlat_top_params
if (params->no_aa && params->aa_only)
timerlat_top_usage("--no-aa and --aa-only are mutually exclusive!");
+ if (params->kernel_workload && params->user_workload)
+ timerlat_top_usage("--kernel-threads and --user-threads are mutually exclusive!");
+
return params;
}
@@ -686,14 +836,36 @@ timerlat_top_apply_config(struct osnoise_tool *top, struct timerlat_top_params *
auto_house_keeping(&params->monitored_cpus);
}
- if (params->user_top) {
- retval = osnoise_set_workload(top->context, 0);
+ /*
+ * If the user did not specify a type of thread, try user-threads first.
+ * Fall back to kernel threads otherwise.
+ */
+ if (!params->kernel_workload && !params->user_top) {
+ retval = tracefs_file_exists(NULL, "osnoise/per_cpu/cpu0/timerlat_fd");
if (retval) {
- err_msg("Failed to set OSNOISE_WORKLOAD option\n");
- goto out_err;
+ debug_msg("User-space interface detected, setting user-threads\n");
+ params->user_workload = 1;
+ params->user_top = 1;
+ } else {
+ debug_msg("User-space interface not detected, setting kernel-threads\n");
+ params->kernel_workload = 1;
}
}
+ /*
+ * Set workload according to type of thread if the kernel supports it.
+ * On kernels without support, user threads will have already failed
+ * on missing timerlat_fd, and kernel threads do not need it.
+ */
+ retval = osnoise_set_workload(top->context, params->kernel_workload);
+ if (retval < -1) {
+ err_msg("Failed to set OSNOISE_WORKLOAD option\n");
+ goto out_err;
+ }
+
+ if (isatty(STDOUT_FILENO) && !params->quiet)
+ params->pretty_output = 1;
+
return 0;
out_err:
@@ -732,9 +904,20 @@ out_err:
}
static int stop_tracing;
+static struct trace_instance *top_inst = NULL;
static void stop_top(int sig)
{
+ if (stop_tracing) {
+ /*
+ * Stop requested twice in a row; abort event processing and
+ * exit immediately
+ */
+ tracefs_iterate_stop(top_inst->inst);
+ return;
+ }
stop_tracing = 1;
+ if (top_inst)
+ trace_instance_stop(top_inst);
}
/*
@@ -763,6 +946,7 @@ int timerlat_top_main(int argc, char *argv[])
int return_value = 1;
char *max_lat;
int retval;
+ int nr_cpus, i;
params = timerlat_top_parse_args(argc, argv);
if (!params)
@@ -781,6 +965,13 @@ int timerlat_top_main(int argc, char *argv[])
}
trace = &top->trace;
+ /*
+ * Save trace instance into global variable so that SIGINT can stop
+ * the timerlat tracer.
+ * Otherwise, rtla could loop indefinitely when overloaded.
+ */
+ top_inst = trace;
+
retval = enable_timerlat(trace);
if (retval) {
@@ -812,6 +1003,28 @@ int timerlat_top_main(int argc, char *argv[])
}
}
+ if (params->deepest_idle_state >= -1) {
+ if (!have_libcpupower_support()) {
+ err_msg("rtla built without libcpupower, --deepest-idle-state is not supported\n");
+ goto out_free;
+ }
+
+ nr_cpus = sysconf(_SC_NPROCESSORS_CONF);
+
+ for (i = 0; i < nr_cpus; i++) {
+ if (params->cpus && !CPU_ISSET(i, &params->monitored_cpus))
+ continue;
+ if (save_cpu_idle_disable_state(i) < 0) {
+ err_msg("Could not save cpu idle state.\n");
+ goto out_free;
+ }
+ if (set_deepest_cpu_idle_state(i, params->deepest_idle_state) < 0) {
+ err_msg("Could not set deepest cpu idle state.\n");
+ goto out_free;
+ }
+ }
+ }
+
if (params->trace_output) {
record = osnoise_init_trace_tool("timerlat");
if (!record) {
@@ -824,6 +1037,12 @@ int timerlat_top_main(int argc, char *argv[])
if (retval)
goto out_top;
}
+
+ if (params->buffer_size > 0) {
+ retval = trace_set_buffer_size(&record->trace, params->buffer_size);
+ if (retval)
+ goto out_top;
+ }
}
if (!params->no_aa) {
@@ -853,23 +1072,7 @@ int timerlat_top_main(int argc, char *argv[])
}
}
- /*
- * Start the tracers here, after having set all instances.
- *
- * Let the trace instance start first for the case of hitting a stop
- * tracing while enabling other instances. The trace instance is the
- * one with most valuable information.
- */
- if (params->trace_output)
- trace_instance_start(&record->trace);
- if (!params->no_aa && aa != top)
- trace_instance_start(&aa->trace);
- trace_instance_start(trace);
-
- top->start_time = time(NULL);
- timerlat_top_set_signals(params);
-
- if (params->user_top) {
+ if (params->user_workload) {
/* rtla asked to stop */
params_u.should_run = 1;
/* all threads left */
@@ -888,10 +1091,31 @@ int timerlat_top_main(int argc, char *argv[])
err_msg("Error creating timerlat user-space threads\n");
}
+ if (params->warmup > 0) {
+ debug_msg("Warming up for %d seconds\n", params->warmup);
+ sleep(params->warmup);
+ }
+
+ /*
+ * Start the tracers here, after having set all instances.
+ *
+ * Let the trace instance start first for the case of hitting a stop
+ * tracing while enabling other instances. The trace instance is the
+ * one with most valuable information.
+ */
+ if (params->trace_output)
+ trace_instance_start(&record->trace);
+ if (!params->no_aa && aa != top)
+ trace_instance_start(&aa->trace);
+ trace_instance_start(trace);
+
+ top->start_time = time(NULL);
+ timerlat_top_set_signals(params);
+
while (!stop_tracing) {
sleep(params->sleep_time);
- if (params->aa_only && !trace_is_off(&top->trace, &record->trace))
+ if (params->aa_only && !osnoise_trace_is_off(top, record))
continue;
retval = tracefs_iterate_raw_events(trace->tep,
@@ -908,11 +1132,11 @@ int timerlat_top_main(int argc, char *argv[])
if (!params->quiet)
timerlat_print_stats(params, top);
- if (trace_is_off(&top->trace, &record->trace))
+ if (osnoise_trace_is_off(top, record))
break;
/* is there still any user-threads ? */
- if (params->user_top) {
+ if (params->user_workload) {
if (params_u.stopped_running) {
debug_msg("timerlat user space threads stopped!\n");
break;
@@ -920,7 +1144,7 @@ int timerlat_top_main(int argc, char *argv[])
}
}
- if (params->user_top && !params_u.stopped_running) {
+ if (params->user_workload && !params_u.stopped_running) {
params_u.should_run = 0;
sleep(1);
}
@@ -929,7 +1153,7 @@ int timerlat_top_main(int argc, char *argv[])
return_value = 0;
- if (trace_is_off(&top->trace, &record->trace)) {
+ if (osnoise_trace_is_off(top, record) && !stop_tracing) {
printf("rtla timerlat hit stop tracing\n");
if (!params->no_aa)
@@ -955,6 +1179,13 @@ out_top:
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->cpus && !CPU_ISSET(i, &params->monitored_cpus))
+ continue;
+ restore_cpu_idle_disable_state(i);
+ }
+ }
trace_events_destroy(&record->trace, params->events);
params->events = NULL;
out_free:
@@ -964,6 +1195,7 @@ out_free:
osnoise_destroy_tool(record);
osnoise_destroy_tool(top);
free(params);
+ free_cpu_idle_disable_states();
out_exit:
exit(return_value);
}
diff --git a/tools/tracing/rtla/src/trace.c b/tools/tracing/rtla/src/trace.c
index e1ba6d9f4265..728f5029d533 100644
--- a/tools/tracing/rtla/src/trace.c
+++ b/tools/tracing/rtla/src/trace.c
@@ -118,6 +118,8 @@ collect_registered_events(struct tep_event *event, struct tep_record *record,
struct trace_instance *trace = context;
struct trace_seq *s = trace->seq;
+ trace->processed_events++;
+
if (!event->handler)
return 0;
@@ -127,6 +129,31 @@ collect_registered_events(struct tep_event *event, struct tep_record *record,
}
/*
+ * collect_missed_events - record number of missed events
+ *
+ * If rtla cannot keep up with events generated by tracer, events are going
+ * to fall out of the ring buffer.
+ * Collect how many events were missed so it can be reported to the user.
+ */
+static int
+collect_missed_events(struct tep_event *event, struct tep_record *record,
+ int cpu, void *context)
+{
+ struct trace_instance *trace = context;
+
+ if (trace->missed_events == UINT64_MAX)
+ return 0;
+
+ if (record->missed_events > 0)
+ trace->missed_events += record->missed_events;
+ else
+ /* Events missed but no data on how many */
+ trace->missed_events = UINT64_MAX;
+
+ return 0;
+}
+
+/*
* trace_instance_destroy - destroy and free a rtla trace instance
*/
void trace_instance_destroy(struct trace_instance *trace)
@@ -181,6 +208,17 @@ int trace_instance_init(struct trace_instance *trace, char *tool_name)
*/
tracefs_trace_off(trace->inst);
+ /*
+ * Collect the number of events missed due to tracefs buffer
+ * overflow.
+ */
+ trace->missed_events = 0;
+ tracefs_follow_missed_events(trace->inst,
+ collect_missed_events,
+ trace);
+
+ trace->processed_events = 0;
+
return 0;
out_err:
@@ -197,6 +235,14 @@ int trace_instance_start(struct trace_instance *trace)
}
/*
+ * trace_instance_stop - stop tracing a given rtla instance
+ */
+int trace_instance_stop(struct trace_instance *trace)
+{
+ return tracefs_trace_off(trace->inst);
+}
+
+/*
* trace_events_free - free a list of trace events
*/
static void trace_events_free(struct trace_events *events)
@@ -522,21 +568,17 @@ void trace_events_destroy(struct trace_instance *instance,
trace_events_free(events);
}
-int trace_is_off(struct trace_instance *tool, struct trace_instance *trace)
+/*
+ * trace_set_buffer_size - set the per-cpu tracing buffer size.
+ */
+int trace_set_buffer_size(struct trace_instance *trace, int size)
{
- /*
- * The tool instance is always present, it is the one used to collect
- * data.
- */
- if (!tracefs_trace_is_on(tool->inst))
- return 1;
+ int retval;
- /*
- * The trace instance is only enabled when -t is set. IOW, when the system
- * is tracing.
- */
- if (trace && !tracefs_trace_is_on(trace->inst))
- return 1;
+ debug_msg("Setting trace buffer size to %d Kb\n", size);
+ retval = tracefs_instance_set_buffer_size(trace->inst, size, -1);
+ if (retval)
+ err_msg("Error setting trace buffer size\n");
- return 0;
+ return retval;
}
diff --git a/tools/tracing/rtla/src/trace.h b/tools/tracing/rtla/src/trace.h
index 2e9a89a25615..3cd40dd3f06c 100644
--- a/tools/tracing/rtla/src/trace.h
+++ b/tools/tracing/rtla/src/trace.h
@@ -17,10 +17,13 @@ struct trace_instance {
struct tracefs_instance *inst;
struct tep_handle *tep;
struct trace_seq *seq;
+ unsigned long long missed_events;
+ unsigned long long processed_events;
};
int trace_instance_init(struct trace_instance *trace, char *tool_name);
int trace_instance_start(struct trace_instance *trace);
+int trace_instance_stop(struct trace_instance *trace);
void trace_instance_destroy(struct trace_instance *trace);
struct trace_seq *get_trace_seq(void);
@@ -47,4 +50,4 @@ int trace_events_enable(struct trace_instance *instance,
int trace_event_add_filter(struct trace_events *event, char *filter);
int trace_event_add_trigger(struct trace_events *event, char *trigger);
-int trace_is_off(struct trace_instance *tool, struct trace_instance *trace);
+int trace_set_buffer_size(struct trace_instance *trace, int size);
diff --git a/tools/tracing/rtla/src/utils.c b/tools/tracing/rtla/src/utils.c
index 9ac71a66840c..4995d35cf3ec 100644
--- a/tools/tracing/rtla/src/utils.c
+++ b/tools/tracing/rtla/src/utils.c
@@ -4,6 +4,9 @@
*/
#define _GNU_SOURCE
+#ifdef HAVE_LIBCPUPOWER_SUPPORT
+#include <cpuidle.h>
+#endif /* HAVE_LIBCPUPOWER_SUPPORT */
#include <dirent.h>
#include <stdarg.h>
#include <stdlib.h>
@@ -211,29 +214,25 @@ long parse_ns_duration(char *val)
/*
* This is a set of helper functions to use SCHED_DEADLINE.
*/
-#ifdef __x86_64__
-# define __NR_sched_setattr 314
-# define __NR_sched_getattr 315
-#elif __i386__
-# define __NR_sched_setattr 351
-# define __NR_sched_getattr 352
-#elif __arm__
-# define __NR_sched_setattr 380
-# define __NR_sched_getattr 381
-#elif __aarch64__ || __riscv
-# define __NR_sched_setattr 274
-# define __NR_sched_getattr 275
-#elif __powerpc__
-# define __NR_sched_setattr 355
-# define __NR_sched_getattr 356
-#elif __s390x__
-# define __NR_sched_setattr 345
-# define __NR_sched_getattr 346
+#ifndef __NR_sched_setattr
+# ifdef __x86_64__
+# define __NR_sched_setattr 314
+# elif __i386__
+# define __NR_sched_setattr 351
+# elif __arm__
+# define __NR_sched_setattr 380
+# elif __aarch64__ || __riscv
+# define __NR_sched_setattr 274
+# elif __powerpc__
+# define __NR_sched_setattr 355
+# elif __s390x__
+# define __NR_sched_setattr 345
+# endif
#endif
#define SCHED_DEADLINE 6
-static inline int sched_setattr(pid_t pid, const struct sched_attr *attr,
+static inline int syscall_sched_setattr(pid_t pid, const struct sched_attr *attr,
unsigned int flags) {
return syscall(__NR_sched_setattr, pid, attr, flags);
}
@@ -243,7 +242,7 @@ int __set_sched_attr(int pid, struct sched_attr *attr)
int flags = 0;
int retval;
- retval = sched_setattr(pid, attr, flags);
+ retval = syscall_sched_setattr(pid, attr, flags);
if (retval < 0) {
err_msg("Failed to set sched attributes to the pid %d: %s\n",
pid, strerror(errno));
@@ -519,6 +518,153 @@ int set_cpu_dma_latency(int32_t latency)
return fd;
}
+#ifdef HAVE_LIBCPUPOWER_SUPPORT
+static unsigned int **saved_cpu_idle_disable_state;
+static size_t saved_cpu_idle_disable_state_alloc_ctr;
+
+/*
+ * save_cpu_idle_state_disable - save disable for all idle states of a cpu
+ *
+ * Saves the current disable of all idle states of a cpu, to be subsequently
+ * restored via restore_cpu_idle_disable_state.
+ *
+ * Return: idle state count on success, negative on error
+ */
+int save_cpu_idle_disable_state(unsigned int cpu)
+{
+ unsigned int nr_states;
+ unsigned int state;
+ int disabled;
+ int nr_cpus;
+
+ nr_states = cpuidle_state_count(cpu);
+
+ if (nr_states == 0)
+ return 0;
+
+ if (saved_cpu_idle_disable_state == NULL) {
+ nr_cpus = sysconf(_SC_NPROCESSORS_CONF);
+ saved_cpu_idle_disable_state = calloc(nr_cpus, sizeof(unsigned int *));
+ if (!saved_cpu_idle_disable_state)
+ return -1;
+ }
+
+ saved_cpu_idle_disable_state[cpu] = calloc(nr_states, sizeof(unsigned int));
+ if (!saved_cpu_idle_disable_state[cpu])
+ return -1;
+ saved_cpu_idle_disable_state_alloc_ctr++;
+
+ for (state = 0; state < nr_states; state++) {
+ disabled = cpuidle_is_state_disabled(cpu, state);
+ if (disabled < 0)
+ return disabled;
+ saved_cpu_idle_disable_state[cpu][state] = disabled;
+ }
+
+ return nr_states;
+}
+
+/*
+ * restore_cpu_idle_disable_state - restore disable for all idle states of a cpu
+ *
+ * Restores the current disable state of all idle states of a cpu that was
+ * previously saved by save_cpu_idle_disable_state.
+ *
+ * Return: idle state count on success, negative on error
+ */
+int restore_cpu_idle_disable_state(unsigned int cpu)
+{
+ unsigned int nr_states;
+ unsigned int state;
+ int disabled;
+ int result;
+
+ nr_states = cpuidle_state_count(cpu);
+
+ if (nr_states == 0)
+ return 0;
+
+ if (!saved_cpu_idle_disable_state)
+ return -1;
+
+ for (state = 0; state < nr_states; state++) {
+ if (!saved_cpu_idle_disable_state[cpu])
+ return -1;
+ disabled = saved_cpu_idle_disable_state[cpu][state];
+ result = cpuidle_state_disable(cpu, state, disabled);
+ if (result < 0)
+ return result;
+ }
+
+ free(saved_cpu_idle_disable_state[cpu]);
+ saved_cpu_idle_disable_state[cpu] = NULL;
+ saved_cpu_idle_disable_state_alloc_ctr--;
+ if (saved_cpu_idle_disable_state_alloc_ctr == 0) {
+ free(saved_cpu_idle_disable_state);
+ saved_cpu_idle_disable_state = NULL;
+ }
+
+ return nr_states;
+}
+
+/*
+ * free_cpu_idle_disable_states - free saved idle state disable for all cpus
+ *
+ * Frees the memory used for storing cpu idle state disable for all cpus
+ * and states.
+ *
+ * Normally, the memory is freed automatically in
+ * restore_cpu_idle_disable_state; this is mostly for cleaning up after an
+ * error.
+ */
+void free_cpu_idle_disable_states(void)
+{
+ int cpu;
+ int nr_cpus;
+
+ if (!saved_cpu_idle_disable_state)
+ return;
+
+ nr_cpus = sysconf(_SC_NPROCESSORS_CONF);
+
+ for (cpu = 0; cpu < nr_cpus; cpu++) {
+ free(saved_cpu_idle_disable_state[cpu]);
+ saved_cpu_idle_disable_state[cpu] = NULL;
+ }
+
+ free(saved_cpu_idle_disable_state);
+ saved_cpu_idle_disable_state = NULL;
+}
+
+/*
+ * set_deepest_cpu_idle_state - limit idle state of cpu
+ *
+ * Disables all idle states deeper than the one given in
+ * deepest_state (assuming states with higher number are deeper).
+ *
+ * This is used to reduce the exit from idle latency. Unlike
+ * set_cpu_dma_latency, it can disable idle states per cpu.
+ *
+ * Return: idle state count on success, negative on error
+ */
+int set_deepest_cpu_idle_state(unsigned int cpu, unsigned int deepest_state)
+{
+ unsigned int nr_states;
+ unsigned int state;
+ int result;
+
+ nr_states = cpuidle_state_count(cpu);
+
+ for (state = deepest_state + 1; state < nr_states; state++) {
+ result = cpuidle_state_disable(cpu, state, 1);
+ if (result < 0)
+ return result;
+ }
+
+ return nr_states;
+}
+#endif /* HAVE_LIBCPUPOWER_SUPPORT */
+
#define _STR(x) #x
#define STR(x) _STR(x)
diff --git a/tools/tracing/rtla/src/utils.h b/tools/tracing/rtla/src/utils.h
index d44513e6c66a..101d4799a009 100644
--- a/tools/tracing/rtla/src/utils.h
+++ b/tools/tracing/rtla/src/utils.h
@@ -46,6 +46,7 @@ update_sum(unsigned long long *a, unsigned long long *b)
*a += *b;
}
+#ifndef SCHED_ATTR_SIZE_VER0
struct sched_attr {
uint32_t size;
uint32_t sched_policy;
@@ -56,6 +57,7 @@ struct sched_attr {
uint64_t sched_deadline;
uint64_t sched_period;
};
+#endif /* SCHED_ATTR_SIZE_VER0 */
int parse_prio(char *arg, struct sched_attr *sched_param);
int parse_cpu_set(char *cpu_list, cpu_set_t *set);
@@ -64,6 +66,19 @@ int set_comm_sched_attr(const char *comm_prefix, struct sched_attr *attr);
int set_comm_cgroup(const char *comm_prefix, const char *cgroup);
int set_pid_cgroup(pid_t pid, const char *cgroup);
int set_cpu_dma_latency(int32_t latency);
+#ifdef HAVE_LIBCPUPOWER_SUPPORT
+int save_cpu_idle_disable_state(unsigned int cpu);
+int restore_cpu_idle_disable_state(unsigned int cpu);
+void free_cpu_idle_disable_states(void);
+int set_deepest_cpu_idle_state(unsigned int cpu, unsigned int state);
+static inline int have_libcpupower_support(void) { return 1; }
+#else
+static inline int save_cpu_idle_disable_state(unsigned int cpu) { return -1; }
+static inline int restore_cpu_idle_disable_state(unsigned int cpu) { return -1; }
+static inline void free_cpu_idle_disable_states(void) { }
+static inline int set_deepest_cpu_idle_state(unsigned int cpu, unsigned int state) { return -1; }
+static inline int have_libcpupower_support(void) { return 0; }
+#endif /* HAVE_LIBCPUPOWER_SUPPORT */
int auto_house_keeping(cpu_set_t *monitored_cpus);
#define ns_to_usf(x) (((double)x/1000))