Commit 20f463fb authored by Linus Torvalds's avatar Linus Torvalds

Merge tag 'trace-rtla-v5.18' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace

Pull RTLA tracing tool updates from Steven Rostedt:
 "Real Time Analysis Tool updatesfor 5.18:

   - Support for adjusting tracing_threashold

   - Add -a (auto) option to make it easier for users to debug in the field

   - Add -e option to add more events to the trace

   - Add --trigger option to add triggers to events

   - Add --filter option to filter events

   - Add support to save histograms to the file

   - Add --dma-latency to set /dev/cpu_dma_latency

   - Other fixes and cleanups"

* tag 'trace-rtla-v5.18' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace:
  rtla: Tools main loop cleanup
  rtla/timerlat: Add --dma-latency option
  rtla/osnoise: Fix osnoise hist stop tracing message
  rtla: Check for trace off also in the trace instance
  rtla/trace: Save event histogram output to a file
  rtla: Add --filter support
  rtla/trace: Add trace event filter helpers
  rtla: Add --trigger support
  rtla/trace: Add trace event trigger helpers
  rtla: Add -e/--event support
  rtla/trace: Add trace events helpers
  rtla/timerlat: Add the automatic trace option
  rtla/osnoise: Add the automatic trace option
  rtla/osnoise: Add an option to set the threshold
  rtla/osnoise: Add support to adjust the tracing_thresh
parents 3ef4ea3d 75016ca3
......@@ -14,6 +14,25 @@
Save the stopped trace to [*file|osnoise_trace.txt*].
**-e**, **--event** *sys:event*
Enable an event in the trace (**-t**) session. The argument can be a specific event, e.g., **-e** *sched:sched_switch*, or all events of a system group, e.g., **-e** *sched*. Multiple **-e** are allowed. It is only active when **-t** or **-a** are set.
**--filter** *<filter>*
Filter the previous **-e** *sys:event* event with *<filter>*. For further information about event filtering see https://www.kernel.org/doc/html/latest/trace/events.html#event-filtering.
**--trigger** *<trigger>*
Enable a trace event trigger to the previous **-e** *sys:event*.
If the *hist:* trigger is activated, the output histogram will be automatically saved to a file named *system_event_hist.txt*.
For example, the command:
rtla <command> <mode> -t -e osnoise:irq_noise --trigger="hist:key=desc,duration/1000:sort=desc,duration/1000:vals=hitcount"
Will automatically save the content of the histogram associated to *osnoise:irq_noise* event in *osnoise_irq_noise_hist.txt*.
For further information about event trigger see https://www.kernel.org/doc/html/latest/trace/events.html#event-triggers.
**-P**, **--priority** *o:prio|r:prio|f:prio|d:runtime:period*
Set scheduling parameters to the osnoise tracer threads, the format to set the priority are:
......
**-a**, **--auto** *us*
Set the automatic trace mode. This mode sets some commonly used options
while debugging the system. It is equivalent to use **-s** *us* **-T 1 -t**.
**-p**, **--period** *us*
Set the *osnoise* tracer period in microseconds.
......@@ -15,3 +20,8 @@
Stop the trace if the total sample is higher than the argument in microseconds.
If **-T** is set, it will also save the trace to the output.
**-T**, **--threshold** *us*
Specify the minimum delta between two time reads to be considered noise.
The default threshold is *5 us*.
**-a**, **--auto** *us*
Set the automatic trace mode. This mode sets some commonly used options
while debugging the system. It is equivalent to use **-T** *us* **-s** *us*
**-t**. By default, *timerlat* tracer uses FIFO:95 for *timerlat* threads,
thus equilavent to **-P** *f:95*.
**-p**, **--period** *us*
Set the *timerlat* tracer period in microseconds.
......@@ -14,3 +21,8 @@
Save the stack trace at the *IRQ* if a *Thread* latency is higher than the
argument in us.
**--dma-latency** *us*
Set the /dev/cpu_dma_latency to *us*, aiming to bound exit from idle latencies.
*cyclictest* sets this value to *0* by default, use **--dma-latency** *0* to have
similar results.
......@@ -655,6 +655,85 @@ void osnoise_put_print_stack(struct osnoise_context *context)
context->orig_print_stack = OSNOISE_OPTION_INIT_VAL;
}
/*
* osnoise_get_tracing_thresh - read and save the original "tracing_thresh"
*/
static long long
osnoise_get_tracing_thresh(struct osnoise_context *context)
{
long long tracing_thresh;
if (context->tracing_thresh != OSNOISE_OPTION_INIT_VAL)
return context->tracing_thresh;
if (context->orig_tracing_thresh != OSNOISE_OPTION_INIT_VAL)
return context->orig_tracing_thresh;
tracing_thresh = osnoise_read_ll_config("tracing_thresh");
if (tracing_thresh < 0)
goto out_err;
context->orig_tracing_thresh = tracing_thresh;
return tracing_thresh;
out_err:
return OSNOISE_OPTION_INIT_VAL;
}
/*
* osnoise_set_tracing_thresh - set "tracing_thresh"
*/
int osnoise_set_tracing_thresh(struct osnoise_context *context, long long tracing_thresh)
{
long long curr_tracing_thresh = osnoise_get_tracing_thresh(context);
int retval;
if (curr_tracing_thresh == OSNOISE_OPTION_INIT_VAL)
return -1;
retval = osnoise_write_ll_config("tracing_thresh", tracing_thresh);
if (retval < 0)
return -1;
context->tracing_thresh = tracing_thresh;
return 0;
}
/*
* osnoise_restore_tracing_thresh - restore the original "tracing_thresh"
*/
void osnoise_restore_tracing_thresh(struct osnoise_context *context)
{
int retval;
if (context->orig_tracing_thresh == OSNOISE_OPTION_INIT_VAL)
return;
if (context->orig_tracing_thresh == context->tracing_thresh)
goto out_done;
retval = osnoise_write_ll_config("tracing_thresh", context->orig_tracing_thresh);
if (retval < 0)
err_msg("Could not restore original tracing_thresh\n");
out_done:
context->tracing_thresh = OSNOISE_OPTION_INIT_VAL;
}
/*
* osnoise_put_tracing_thresh - restore original values and cleanup data
*/
void osnoise_put_tracing_thresh(struct osnoise_context *context)
{
osnoise_restore_tracing_thresh(context);
if (context->orig_tracing_thresh == OSNOISE_OPTION_INIT_VAL)
return;
context->orig_tracing_thresh = OSNOISE_OPTION_INIT_VAL;
}
/*
* enable_osnoise - enable osnoise tracer in the trace_instance
*/
......@@ -716,6 +795,9 @@ struct osnoise_context *osnoise_context_alloc(void)
context->orig_print_stack = OSNOISE_OPTION_INIT_VAL;
context->print_stack = OSNOISE_OPTION_INIT_VAL;
context->orig_tracing_thresh = OSNOISE_OPTION_INIT_VAL;
context->tracing_thresh = OSNOISE_OPTION_INIT_VAL;
osnoise_get_context(context);
return context;
......@@ -741,6 +823,7 @@ void osnoise_put_context(struct osnoise_context *context)
osnoise_put_stop_total_us(context);
osnoise_put_timerlat_period_us(context);
osnoise_put_print_stack(context);
osnoise_put_tracing_thresh(context);
free(context);
}
......
......@@ -23,6 +23,10 @@ struct osnoise_context {
long long orig_timerlat_period_us;
long long timerlat_period_us;
/* 0 as init value */
long long orig_tracing_thresh;
long long tracing_thresh;
/* -1 as init value because 0 is disabled */
long long orig_stop_us;
long long stop_us;
......@@ -67,6 +71,10 @@ int osnoise_set_timerlat_period_us(struct osnoise_context *context,
long long timerlat_period_us);
void osnoise_restore_timerlat_period_us(struct osnoise_context *context);
int osnoise_set_tracing_thresh(struct osnoise_context *context,
long long tracing_thresh);
void osnoise_restore_tracing_thresh(struct osnoise_context *context);
void osnoise_restore_print_stack(struct osnoise_context *context);
int osnoise_set_print_stack(struct osnoise_context *context,
long long print_stack);
......
......@@ -21,6 +21,7 @@ struct osnoise_hist_params {
char *trace_output;
unsigned long long runtime;
unsigned long long period;
long long threshold;
long long stop_us;
long long stop_total_us;
int sleep_time;
......@@ -28,6 +29,7 @@ struct osnoise_hist_params {
int set_sched;
int output_divisor;
struct sched_attr sched_param;
struct trace_events *events;
char no_header;
char no_summary;
......@@ -425,19 +427,25 @@ static void osnoise_hist_usage(char *usage)
static const char * const msg[] = {
"",
" usage: rtla osnoise hist [-h] [-D] [-d s] [-p us] [-r us] [-s us] [-S us] [-t[=file]] \\",
" [-c cpu-list] [-P priority] [-b N] [-E N] [--no-header] [--no-summary] \\",
" [--no-index] [--with-zeros]",
" 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>] \\",
" [-c cpu-list] [-P priority] [-b N] [-E N] [--no-header] [--no-summary] [--no-index] \\",
" [--with-zeros]",
"",
" -h/--help: print this menu",
" -a/--auto: set automatic trace mode, stopping the session if argument in us sample is hit",
" -p/--period us: osnoise period in us",
" -r/--runtime us: osnoise runtime in us",
" -s/--stop us: stop trace if a single sample is higher than the argument in us",
" -S/--stop-total us: stop trace if the total sample is higher than the argument in us",
" -T/--threshold us: the minimum delta to be considered a noise",
" -c/--cpus cpu-list: list of cpus to run osnoise threads",
" -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]",
" -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",
" -b/--bucket-size N: set the histogram bucket size (default 1)",
" -E/--entries N: set the number of entries of the histogram (default 256)",
" --no-header: do not print header",
......@@ -471,6 +479,7 @@ static struct osnoise_hist_params
*osnoise_hist_parse_args(int argc, char *argv[])
{
struct osnoise_hist_params *params;
struct trace_events *tevent;
int retval;
int c;
......@@ -485,6 +494,7 @@ static struct osnoise_hist_params
while (1) {
static struct option long_options[] = {
{"auto", required_argument, 0, 'a'},
{"bucket-size", required_argument, 0, 'b'},
{"entries", required_argument, 0, 'E'},
{"cpus", required_argument, 0, 'c'},
......@@ -497,17 +507,21 @@ static struct osnoise_hist_params
{"stop", required_argument, 0, 's'},
{"stop-total", required_argument, 0, 'S'},
{"trace", optional_argument, 0, 't'},
{"event", required_argument, 0, 'e'},
{"threshold", required_argument, 0, 'T'},
{"no-header", no_argument, 0, '0'},
{"no-summary", no_argument, 0, '1'},
{"no-index", no_argument, 0, '2'},
{"with-zeros", no_argument, 0, '3'},
{"trigger", required_argument, 0, '4'},
{"filter", required_argument, 0, '5'},
{0, 0, 0, 0}
};
/* getopt_long stores the option index here. */
int option_index = 0;
c = getopt_long(argc, argv, "c:b:d:E:Dhp:P:r:s:S:t::0123",
c = getopt_long(argc, argv, "a:c:b:d:e:E:Dhp:P:r:s:S:t::T:01234:5:",
long_options, &option_index);
/* detect the end of the options. */
......@@ -515,6 +529,17 @@ static struct osnoise_hist_params
break;
switch (c) {
case 'a':
/* set sample stop to auto_thresh */
params->stop_us = get_llong_from_str(optarg);
/* set sample threshold to 1 */
params->threshold = 1;
/* set trace */
params->trace_output = "osnoise_trace.txt";
break;
case 'b':
params->bucket_size = get_llong_from_str(optarg);
if ((params->bucket_size == 0) || (params->bucket_size >= 1000000))
......@@ -534,6 +559,18 @@ static struct osnoise_hist_params
if (!params->duration)
osnoise_hist_usage("Invalid -D duration\n");
break;
case 'e':
tevent = trace_event_alloc(optarg);
if (!tevent) {
err_msg("Error alloc trace event");
exit(EXIT_FAILURE);
}
if (params->events)
tevent->next = params->events;
params->events = tevent;
break;
case 'E':
params->entries = get_llong_from_str(optarg);
if ((params->entries < 10) || (params->entries > 9999999))
......@@ -565,6 +602,9 @@ static struct osnoise_hist_params
case 'S':
params->stop_total_us = get_llong_from_str(optarg);
break;
case 'T':
params->threshold = get_llong_from_str(optarg);
break;
case 't':
if (optarg)
/* skip = */
......@@ -584,6 +624,28 @@ static struct osnoise_hist_params
case '3': /* with zeros */
params->with_zeros = 1;
break;
case '4': /* trigger */
if (params->events) {
retval = trace_event_add_trigger(params->events, optarg);
if (retval) {
err_msg("Error adding trigger %s\n", optarg);
exit(EXIT_FAILURE);
}
} else {
osnoise_hist_usage("--trigger requires a previous -e\n");
}
break;
case '5': /* filter */
if (params->events) {
retval = trace_event_add_filter(params->events, optarg);
if (retval) {
err_msg("Error adding filter %s\n", optarg);
exit(EXIT_FAILURE);
}
} else {
osnoise_hist_usage("--filter requires a previous -e\n");
}
break;
default:
osnoise_hist_usage("Invalid option");
}
......@@ -645,6 +707,14 @@ osnoise_hist_apply_config(struct osnoise_tool *tool, struct osnoise_hist_params
}
}
if (params->threshold) {
retval = osnoise_set_tracing_thresh(tool->context, params->threshold);
if (retval) {
err_msg("Failed to set tracing_thresh\n");
goto out_err;
}
}
return 0;
out_err:
......@@ -751,6 +821,13 @@ int osnoise_hist_main(int argc, char *argv[])
err_msg("Failed to enable the trace instance\n");
goto out_hist;
}
if (params->events) {
retval = trace_events_enable(&record->trace, params->events);
if (retval)
goto out_hist;
}
trace_instance_start(&record->trace);
}
......@@ -771,9 +848,9 @@ int osnoise_hist_main(int argc, char *argv[])
goto out_hist;
}
if (!tracefs_trace_is_on(trace->inst))
if (trace_is_off(&tool->trace, &record->trace))
break;
};
}
osnoise_read_trace_hist(tool);
......@@ -781,8 +858,8 @@ int osnoise_hist_main(int argc, char *argv[])
return_value = 0;
if (!tracefs_trace_is_on(trace->inst)) {
printf("rtla timelat hit stop tracing\n");
if (trace_is_off(&tool->trace, &record->trace)) {
printf("rtla osnoise hit stop tracing\n");
if (params->trace_output) {
printf(" Saving trace to %s\n", params->trace_output);
save_trace_to_file(record->trace.inst, params->trace_output);
......@@ -790,6 +867,8 @@ int osnoise_hist_main(int argc, char *argv[])
}
out_hist:
trace_events_destroy(&record->trace, params->events);
params->events = NULL;
osnoise_free_histogram(tool->data);
out_destroy:
osnoise_destroy_tool(record);
......
......@@ -23,6 +23,7 @@ struct osnoise_top_params {
char *trace_output;
unsigned long long runtime;
unsigned long long period;
long long threshold;
long long stop_us;
long long stop_total_us;
int sleep_time;
......@@ -30,6 +31,7 @@ struct osnoise_top_params {
int quiet;
int set_sched;
struct sched_attr sched_param;
struct trace_events *events;
};
struct osnoise_top_cpu {
......@@ -244,18 +246,24 @@ void osnoise_top_usage(char *usage)
int i;
static const char * const msg[] = {
" usage: rtla osnoise [top] [-h] [-q] [-D] [-d s] [-p us] [-r us] [-s us] [-S us] [-t[=file]] \\",
" usage: rtla osnoise [top] [-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] [-P priority]",
"",
" -h/--help: print this menu",
" -a/--auto: set automatic trace mode, stopping the session if argument in us sample is hit",
" -p/--period us: osnoise period in us",
" -r/--runtime us: osnoise runtime in us",
" -s/--stop us: stop trace if a single sample is higher than the argument in us",
" -S/--stop-total us: stop trace if the total sample is higher than the argument in us",
" -T/--threshold us: the minimum delta to be considered a noise",
" -c/--cpus cpu-list: list of cpus to run osnoise threads",
" -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]",
" -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",
" -q/--quiet print only a summary at the end",
" -P/--priority o:prio|r:prio|f:prio|d:runtime:period : set scheduling parameters",
" o:prio - use SCHED_OTHER with prio",
......@@ -283,6 +291,7 @@ void osnoise_top_usage(char *usage)
struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
{
struct osnoise_top_params *params;
struct trace_events *tevent;
int retval;
int c;
......@@ -292,9 +301,11 @@ struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
while (1) {
static struct option long_options[] = {
{"auto", required_argument, 0, 'a'},
{"cpus", required_argument, 0, 'c'},
{"debug", no_argument, 0, 'D'},
{"duration", required_argument, 0, 'd'},
{"event", required_argument, 0, 'e'},
{"help", no_argument, 0, 'h'},
{"period", required_argument, 0, 'p'},
{"priority", required_argument, 0, 'P'},
......@@ -302,14 +313,17 @@ struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
{"runtime", required_argument, 0, 'r'},
{"stop", required_argument, 0, 's'},
{"stop-total", required_argument, 0, 'S'},
{"threshold", required_argument, 0, 'T'},
{"trace", optional_argument, 0, 't'},
{"trigger", required_argument, 0, '0'},
{"filter", required_argument, 0, '1'},
{0, 0, 0, 0}
};
/* getopt_long stores the option index here. */
int option_index = 0;
c = getopt_long(argc, argv, "c:d:Dhp:P:qr:s:S:t::",
c = getopt_long(argc, argv, "a:c:d:De:hp:P:qr:s:S:t::T:0:1:",
long_options, &option_index);
/* Detect the end of the options. */
......@@ -317,6 +331,17 @@ struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
break;
switch (c) {
case 'a':
/* set sample stop to auto_thresh */
params->stop_us = get_llong_from_str(optarg);
/* set sample threshold to 1 */
params->threshold = 1;
/* set trace */
params->trace_output = "osnoise_trace.txt";
break;
case 'c':
retval = parse_cpu_list(optarg, &params->monitored_cpus);
if (retval)
......@@ -331,6 +356,18 @@ struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
if (!params->duration)
osnoise_top_usage("Invalid -D duration\n");
break;
case 'e':
tevent = trace_event_alloc(optarg);
if (!tevent) {
err_msg("Error alloc trace event");
exit(EXIT_FAILURE);
}
if (params->events)
tevent->next = params->events;
params->events = tevent;
break;
case 'h':
case '?':
osnoise_top_usage(NULL);
......@@ -367,6 +404,31 @@ struct osnoise_top_params *osnoise_top_parse_args(int argc, char **argv)
else
params->trace_output = "osnoise_trace.txt";
break;
case 'T':
params->threshold = get_llong_from_str(optarg);
break;
case '0': /* trigger */
if (params->events) {
retval = trace_event_add_trigger(params->events, optarg);
if (retval) {
err_msg("Error adding trigger %s\n", optarg);
exit(EXIT_FAILURE);
}
} else {
osnoise_top_usage("--trigger requires a previous -e\n");
}
break;
case '1': /* filter */
if (params->events) {
retval = trace_event_add_filter(params->events, optarg);
if (retval) {
err_msg("Error adding filter %s\n", optarg);
exit(EXIT_FAILURE);
}
} else {
osnoise_top_usage("--filter requires a previous -e\n");
}
break;
default:
osnoise_top_usage("Invalid option");
}
......@@ -425,6 +487,14 @@ osnoise_top_apply_config(struct osnoise_tool *tool, struct osnoise_top_params *p
}
}
if (params->threshold) {
retval = osnoise_set_tracing_thresh(tool->context, params->threshold);
if (retval) {
err_msg("Failed to set tracing_thresh\n");
goto out_err;
}
}
return 0;
out_err:
......@@ -529,13 +599,20 @@ int osnoise_top_main(int argc, char **argv)
err_msg("Failed to enable the trace instance\n");
goto out_top;
}
if (params->events) {
retval = trace_events_enable(&record->trace, params->events);
if (retval)
goto out_top;
}
trace_instance_start(&record->trace);
}
tool->start_time = time(NULL);
osnoise_top_set_signals(params);
do {
while (!stop_tracing) {
sleep(params->sleep_time);
retval = tracefs_iterate_raw_events(trace->tep,
......@@ -552,16 +629,16 @@ int osnoise_top_main(int argc, char **argv)
if (!params->quiet)
osnoise_print_stats(params, tool);
if (!tracefs_trace_is_on(trace->inst))
if (trace_is_off(&tool->trace, &record->trace))
break;
} while (!stop_tracing);
}
osnoise_print_stats(params, tool);
return_value = 0;
if (!tracefs_trace_is_on(trace->inst)) {
if (trace_is_off(&tool->trace, &record->trace)) {
printf("osnoise hit stop tracing\n");
if (params->trace_output) {
printf(" Saving trace to %s\n", params->trace_output);
......@@ -570,6 +647,8 @@ int osnoise_top_main(int argc, char **argv)
}
out_top:
trace_events_destroy(&record->trace, params->events);
params->events = NULL;
osnoise_free_top(tool->data);
osnoise_destroy_tool(record);
osnoise_destroy_tool(tool);
......
......@@ -28,7 +28,9 @@ struct timerlat_hist_params {
int output_divisor;
int duration;
int set_sched;
int dma_latency;
struct sched_attr sched_param;
struct trace_events *events;
char no_irq;
char no_thread;
......@@ -428,11 +430,13 @@ static void timerlat_hist_usage(char *usage)
char *msg[] = {
"",
" usage: [rtla] timerlat hist [-h] [-q] [-d s] [-D] [-n] [-p us] [-i us] [-T us] [-s us] [-t[=file]] \\",
" [-c cpu-list] [-P priority] [-E N] [-b N] [--no-irq] [--no-thread] [--no-header] [--no-summary] \\",
" [--no-index] [--with-zeros]",
" 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] \\",
" [-P priority] [-E N] [-b N] [--no-irq] [--no-thread] [--no-header] [--no-summary] \\",
" [--no-index] [--with-zeros] [--dma-latency us]",
"",
" -h/--help: print this menu",
" -a/--auto: set automatic trace mode, stopping the session if argument in us latency is hit",
" -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",
......@@ -440,7 +444,10 @@ static void timerlat_hist_usage(char *usage)
" -c/--cpus cpus: run the tracer only on the given cpus",
" -d/--duration time[m|h|d]: duration of the session in seconds",
" -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",
" -n/--nano: display data in nanoseconds",
" -b/--bucket-size N: set the histogram bucket size (default 1)",
" -E/--entries N: set the number of entries of the histogram (default 256)",
......@@ -450,6 +457,7 @@ static void timerlat_hist_usage(char *usage)
" --no-summary: do not print summary",
" --no-index: do not print index",
" --with-zeros: print zero only entries",
" --dma-latency us: set /dev/cpu_dma_latency latency <us> to reduce exit from idle latency",
" -P/--priority o:prio|r:prio|f:prio|d:runtime:period : set scheduling parameters",
" o:prio - use SCHED_OTHER with prio",
" r:prio - use SCHED_RR with prio",
......@@ -477,6 +485,8 @@ static struct timerlat_hist_params
*timerlat_hist_parse_args(int argc, char *argv[])
{
struct timerlat_hist_params *params;
struct trace_events *tevent;
int auto_thresh;
int retval;
int c;
......@@ -484,6 +494,9 @@ static struct timerlat_hist_params
if (!params)
exit(1);
/* disabled by default */
params->dma_latency = -1;
/* display data in microseconds */
params->output_divisor = 1000;
params->bucket_size = 1;
......@@ -491,6 +504,7 @@ static struct timerlat_hist_params
while (1) {
static struct option long_options[] = {
{"auto", required_argument, 0, 'a'},
{"cpus", required_argument, 0, 'c'},
{"bucket-size", required_argument, 0, 'b'},
{"debug", no_argument, 0, 'D'},
......@@ -504,19 +518,23 @@ static struct timerlat_hist_params
{"stack", required_argument, 0, 's'},
{"thread", required_argument, 0, 'T'},
{"trace", optional_argument, 0, 't'},
{"event", required_argument, 0, 'e'},
{"no-irq", no_argument, 0, '0'},
{"no-thread", no_argument, 0, '1'},
{"no-header", no_argument, 0, '2'},
{"no-summary", no_argument, 0, '3'},
{"no-index", no_argument, 0, '4'},
{"with-zeros", no_argument, 0, '5'},
{"trigger", required_argument, 0, '6'},
{"filter", required_argument, 0, '7'},
{"dma-latency", required_argument, 0, '8'},
{0, 0, 0, 0}
};
/* getopt_long stores the option index here. */
int option_index = 0;
c = getopt_long(argc, argv, "c:b:d:E:Dhi:np:P:s:t::T:012345",
c = getopt_long(argc, argv, "a:c:b:d:e:E:Dhi:np:P:s:t::T:0123456:7:8:",
long_options, &option_index);
/* detect the end of the options. */
......@@ -524,6 +542,19 @@ static struct timerlat_hist_params
break;
switch (c) {
case 'a':
auto_thresh = get_llong_from_str(optarg);
/* set thread stop to auto_thresh */
params->stop_total_us = auto_thresh;
/* get stack trace */
params->print_stack = auto_thresh;
/* set trace */
params->trace_output = "timerlat_trace.txt";
break;
case 'c':
retval = parse_cpu_list(optarg, &params->monitored_cpus);
if (retval)
......@@ -543,6 +574,18 @@ static struct timerlat_hist_params
if (!params->duration)
timerlat_hist_usage("Invalid -D duration\n");
break;
case 'e':
tevent = trace_event_alloc(optarg);
if (!tevent) {
err_msg("Error alloc trace event");
exit(EXIT_FAILURE);
}
if (params->events)
tevent->next = params->events;
params->events = tevent;
break;
case 'E':
params->entries = get_llong_from_str(optarg);
if ((params->entries < 10) || (params->entries > 9999999))
......@@ -600,6 +643,35 @@ static struct timerlat_hist_params
case '5': /* with zeros */
params->with_zeros = 1;
break;
case '6': /* trigger */
if (params->events) {
retval = trace_event_add_trigger(params->events, optarg);
if (retval) {
err_msg("Error adding trigger %s\n", optarg);
exit(EXIT_FAILURE);
}
} else {
timerlat_hist_usage("--trigger requires a previous -e\n");
}
break;
case '7': /* filter */
if (params->events) {
retval = trace_event_add_filter(params->events, optarg);
if (retval) {
err_msg("Error adding filter %s\n", optarg);
exit(EXIT_FAILURE);
}
} else {
timerlat_hist_usage("--filter requires a previous -e\n");
}
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);
}
break;
default:
timerlat_hist_usage("Invalid option");
}
......@@ -732,6 +804,7 @@ int timerlat_hist_main(int argc, char *argv[])
struct osnoise_tool *record = NULL;
struct osnoise_tool *tool = NULL;
struct trace_instance *trace;
int dma_latency_fd = -1;
int return_value = 1;
int retval;
......@@ -767,6 +840,14 @@ int timerlat_hist_main(int argc, char *argv[])
}
}
if (params->dma_latency >= 0) {
dma_latency_fd = set_cpu_dma_latency(params->dma_latency);
if (dma_latency_fd < 0) {
err_msg("Could not set /dev/cpu_dma_latency.\n");
goto out_hist;
}
}
trace_instance_start(trace);
if (params->trace_output) {
......@@ -775,6 +856,13 @@ int timerlat_hist_main(int argc, char *argv[])
err_msg("Failed to enable the trace instance\n");
goto out_hist;
}
if (params->events) {
retval = trace_events_enable(&record->trace, params->events);
if (retval)
goto out_hist;
}
trace_instance_start(&record->trace);
}
......@@ -795,15 +883,15 @@ int timerlat_hist_main(int argc, char *argv[])
goto out_hist;
}
if (!tracefs_trace_is_on(trace->inst))
if (trace_is_off(&tool->trace, &record->trace))
break;
};
}
timerlat_print_stats(params, tool);
return_value = 0;
if (!tracefs_trace_is_on(trace->inst)) {
if (trace_is_off(&tool->trace, &record->trace)) {
printf("rtla timelat hit stop tracing\n");
if (params->trace_output) {
printf(" Saving trace to %s\n", params->trace_output);
......@@ -812,6 +900,10 @@ int timerlat_hist_main(int argc, char *argv[])
}
out_hist:
if (dma_latency_fd >= 0)
close(dma_latency_fd);
trace_events_destroy(&record->trace, params->events);
params->events = NULL;
timerlat_free_histogram(tool->data);
osnoise_destroy_tool(record);
osnoise_destroy_tool(tool);
......
......@@ -29,7 +29,9 @@ struct timerlat_top_params {
int duration;
int quiet;
int set_sched;
int dma_latency;
struct sched_attr sched_param;
struct trace_events *events;
};
struct timerlat_top_cpu {
......@@ -266,10 +268,12 @@ static void timerlat_top_usage(char *usage)
static const char *const msg[] = {
"",
" usage: rtla timerlat [top] [-h] [-q] [-d s] [-D] [-n] [-p us] [-i us] [-T us] [-s us] [-t[=file]] \\",
" [-c cpu-list] [-P priority]",
" 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]",
"",
" -h/--help: print this menu",
" -a/--auto: set automatic trace mode, stopping the session if argument in us latency is hit",
" -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",
......@@ -278,8 +282,12 @@ static void timerlat_top_usage(char *usage)
" -d/--duration time[m|h|d]: duration of the session in seconds",
" -D/--debug: print debug info",
" -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",
" -n/--nano: display data in nanoseconds",
" -q/--quiet print only a summary at the end",
" --dma-latency us: set /dev/cpu_dma_latency latency <us> to reduce exit from idle latency",
" -P/--priority o:prio|r:prio|f:prio|d:runtime:period : set scheduling parameters",
" o:prio - use SCHED_OTHER with prio",
" r:prio - use SCHED_RR with prio",
......@@ -307,6 +315,8 @@ static struct timerlat_top_params
*timerlat_top_parse_args(int argc, char **argv)
{
struct timerlat_top_params *params;
struct trace_events *tevent;
long long auto_thresh;
int retval;
int c;
......@@ -314,14 +324,19 @@ static struct timerlat_top_params
if (!params)
exit(1);
/* disabled by default */
params->dma_latency = -1;
/* display data in microseconds */
params->output_divisor = 1000;
while (1) {
static struct option long_options[] = {
{"auto", required_argument, 0, 'a'},
{"cpus", required_argument, 0, 'c'},
{"debug", no_argument, 0, 'D'},
{"duration", required_argument, 0, 'd'},
{"event", required_argument, 0, 'e'},
{"help", no_argument, 0, 'h'},
{"irq", required_argument, 0, 'i'},
{"nano", no_argument, 0, 'n'},
......@@ -331,13 +346,16 @@ static struct timerlat_top_params
{"stack", required_argument, 0, 's'},
{"thread", required_argument, 0, 'T'},
{"trace", optional_argument, 0, 't'},
{"trigger", required_argument, 0, '0'},
{"filter", required_argument, 0, '1'},
{"dma-latency", required_argument, 0, '2'},
{0, 0, 0, 0}
};
/* getopt_long stores the option index here. */
int option_index = 0;
c = getopt_long(argc, argv, "c:d:Dhi:np:P:qs:t::T:",
c = getopt_long(argc, argv, "a:c:d:De:hi:np:P:qs:t::T:0:1:2:",
long_options, &option_index);
/* detect the end of the options. */
......@@ -345,6 +363,19 @@ static struct timerlat_top_params
break;
switch (c) {
case 'a':
auto_thresh = get_llong_from_str(optarg);
/* set thread stop to auto_thresh */
params->stop_total_us = auto_thresh;
/* get stack trace */
params->print_stack = auto_thresh;
/* set trace */
params->trace_output = "timerlat_trace.txt";
break;
case 'c':
retval = parse_cpu_list(optarg, &params->monitored_cpus);
if (retval)
......@@ -359,6 +390,17 @@ static struct timerlat_top_params
if (!params->duration)
timerlat_top_usage("Invalid -D duration\n");
break;
case 'e':
tevent = trace_event_alloc(optarg);
if (!tevent) {
err_msg("Error alloc trace event");
exit(EXIT_FAILURE);
}
if (params->events)
tevent->next = params->events;
params->events = tevent;
break;
case 'h':
case '?':
timerlat_top_usage(NULL);
......@@ -396,6 +438,35 @@ static struct timerlat_top_params
else
params->trace_output = "timerlat_trace.txt";
break;
case '0': /* trigger */
if (params->events) {
retval = trace_event_add_trigger(params->events, optarg);
if (retval) {
err_msg("Error adding trigger %s\n", optarg);
exit(EXIT_FAILURE);
}
} else {
timerlat_top_usage("--trigger requires a previous -e\n");
}
break;
case '1': /* filter */
if (params->events) {
retval = trace_event_add_filter(params->events, optarg);
if (retval) {
err_msg("Error adding filter %s\n", optarg);
exit(EXIT_FAILURE);
}
} else {
timerlat_top_usage("--filter requires a previous -e\n");
}
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);
}
break;
default:
timerlat_top_usage("Invalid option");
}
......@@ -524,6 +595,7 @@ int timerlat_top_main(int argc, char *argv[])
struct osnoise_tool *record = NULL;
struct osnoise_tool *top = NULL;
struct trace_instance *trace;
int dma_latency_fd = -1;
int return_value = 1;
int retval;
......@@ -559,6 +631,14 @@ int timerlat_top_main(int argc, char *argv[])
}
}
if (params->dma_latency >= 0) {
dma_latency_fd = set_cpu_dma_latency(params->dma_latency);
if (dma_latency_fd < 0) {
err_msg("Could not set /dev/cpu_dma_latency.\n");
goto out_top;
}
}
trace_instance_start(trace);
if (params->trace_output) {
......@@ -567,6 +647,13 @@ int timerlat_top_main(int argc, char *argv[])
err_msg("Failed to enable the trace instance\n");
goto out_top;
}
if (params->events) {
retval = trace_events_enable(&record->trace, params->events);
if (retval)
goto out_top;
}
trace_instance_start(&record->trace);
}
......@@ -590,16 +677,16 @@ int timerlat_top_main(int argc, char *argv[])
if (!params->quiet)
timerlat_print_stats(params, top);
if (!tracefs_trace_is_on(trace->inst))
if (trace_is_off(&top->trace, &record->trace))
break;
};
}
timerlat_print_stats(params, top);
return_value = 0;
if (!tracefs_trace_is_on(trace->inst)) {
if (trace_is_off(&top->trace, &record->trace)) {
printf("rtla timelat hit stop tracing\n");
if (params->trace_output) {
printf(" Saving trace to %s\n", params->trace_output);
......@@ -608,6 +695,10 @@ int timerlat_top_main(int argc, char *argv[])
}
out_top:
if (dma_latency_fd >= 0)
close(dma_latency_fd);
trace_events_destroy(&record->trace, params->events);
params->events = NULL;
timerlat_free_top(top->data);
osnoise_destroy_tool(record);
osnoise_destroy_tool(top);
......
......@@ -190,3 +190,348 @@ int trace_instance_start(struct trace_instance *trace)
{
return tracefs_trace_on(trace->inst);
}
/*
* trace_events_free - free a list of trace events
*/
static void trace_events_free(struct trace_events *events)
{
struct trace_events *tevent = events;
struct trace_events *free_event;
while (tevent) {
free_event = tevent;
tevent = tevent->next;
if (free_event->filter)
free(free_event->filter);
if (free_event->trigger)
free(free_event->trigger);
free(free_event->system);
free(free_event);
}
}
/*
* trace_event_alloc - alloc and parse a single trace event
*/
struct trace_events *trace_event_alloc(const char *event_string)
{
struct trace_events *tevent;
tevent = calloc(1, sizeof(*tevent));
if (!tevent)
return NULL;
tevent->system = strdup(event_string);
if (!tevent->system) {
free(tevent);
return NULL;
}
tevent->event = strstr(tevent->system, ":");
if (tevent->event) {
*tevent->event = '\0';
tevent->event = &tevent->event[1];
}
return tevent;
}
/*
* trace_event_add_filter - record an event filter
*/
int trace_event_add_filter(struct trace_events *event, char *filter)
{
if (event->filter)
free(event->filter);
event->filter = strdup(filter);
if (!event->filter)
return 1;
return 0;
}
/*
* trace_event_add_trigger - record an event trigger action
*/
int trace_event_add_trigger(struct trace_events *event, char *trigger)
{
if (event->trigger)
free(event->trigger);
event->trigger = strdup(trigger);
if (!event->trigger)
return 1;
return 0;
}
/*
* trace_event_disable_filter - disable an event filter
*/
static void trace_event_disable_filter(struct trace_instance *instance,
struct trace_events *tevent)
{
char filter[1024];
int retval;
if (!tevent->filter)
return;
if (!tevent->filter_enabled)
return;
debug_msg("Disabling %s:%s filter %s\n", tevent->system,
tevent->event ? : "*", tevent->filter);
snprintf(filter, 1024, "!%s\n", tevent->filter);
retval = tracefs_event_file_write(instance->inst, tevent->system,
tevent->event, "filter", filter);
if (retval < 0)
err_msg("Error disabling %s:%s filter %s\n", tevent->system,
tevent->event ? : "*", tevent->filter);
}
/*
* trace_event_save_hist - save the content of an event hist
*
* If the trigger is a hist: one, save the content of the hist file.
*/
static void trace_event_save_hist(struct trace_instance *instance,
struct trace_events *tevent)
{
int retval, index, out_fd;
mode_t mode = 0644;
char path[1024];
char *hist;
if (!tevent)
return;
/* trigger enables hist */
if (!tevent->trigger)
return;
/* is this a hist: trigger? */
retval = strncmp(tevent->trigger, "hist:", strlen("hist:"));
if (retval)
return;
snprintf(path, 1024, "%s_%s_hist.txt", tevent->system, tevent->event);
printf(" Saving event %s:%s hist to %s\n", tevent->system, tevent->event, path);
out_fd = creat(path, mode);
if (out_fd < 0) {
err_msg(" Failed to create %s output file\n", path);
return;
}
hist = tracefs_event_file_read(instance->inst, tevent->system, tevent->event, "hist", 0);
if (!hist) {
err_msg(" Failed to read %s:%s hist file\n", tevent->system, tevent->event);
goto out_close;
}
index = 0;
do {
index += write(out_fd, &hist[index], strlen(hist) - index);
} while (index < strlen(hist));
free(hist);
out_close:
close(out_fd);
}
/*
* trace_event_disable_trigger - disable an event trigger
*/
static void trace_event_disable_trigger(struct trace_instance *instance,
struct trace_events *tevent)
{
char trigger[1024];
int retval;
if (!tevent->trigger)
return;
if (!tevent->trigger_enabled)
return;
debug_msg("Disabling %s:%s trigger %s\n", tevent->system,
tevent->event ? : "*", tevent->trigger);
trace_event_save_hist(instance, tevent);
snprintf(trigger, 1024, "!%s\n", tevent->trigger);
retval = tracefs_event_file_write(instance->inst, tevent->system,
tevent->event, "trigger", trigger);
if (retval < 0)
err_msg("Error disabling %s:%s trigger %s\n", tevent->system,
tevent->event ? : "*", tevent->trigger);
}
/*
* trace_events_disable - disable all trace events
*/
void trace_events_disable(struct trace_instance *instance,
struct trace_events *events)
{
struct trace_events *tevent = events;
if (!events)
return;
while (tevent) {
debug_msg("Disabling event %s:%s\n", tevent->system, tevent->event ? : "*");
if (tevent->enabled) {
trace_event_disable_filter(instance, tevent);
trace_event_disable_trigger(instance, tevent);
tracefs_event_disable(instance->inst, tevent->system, tevent->event);
}
tevent->enabled = 0;
tevent = tevent->next;
}
}
/*
* trace_event_enable_filter - enable an event filter associated with an event
*/
static int trace_event_enable_filter(struct trace_instance *instance,
struct trace_events *tevent)
{
char filter[1024];
int retval;
if (!tevent->filter)
return 0;
if (!tevent->event) {
err_msg("Filter %s applies only for single events, not for all %s:* events\n",
tevent->filter, tevent->system);
return 1;
}
snprintf(filter, 1024, "%s\n", tevent->filter);
debug_msg("Enabling %s:%s filter %s\n", tevent->system,
tevent->event ? : "*", tevent->filter);
retval = tracefs_event_file_write(instance->inst, tevent->system,
tevent->event, "filter", filter);
if (retval < 0) {
err_msg("Error enabling %s:%s filter %s\n", tevent->system,
tevent->event ? : "*", tevent->filter);
return 1;
}
tevent->filter_enabled = 1;
return 0;
}
/*
* trace_event_enable_trigger - enable an event trigger associated with an event
*/
static int trace_event_enable_trigger(struct trace_instance *instance,
struct trace_events *tevent)
{
char trigger[1024];
int retval;
if (!tevent->trigger)
return 0;
if (!tevent->event) {
err_msg("Trigger %s applies only for single events, not for all %s:* events\n",
tevent->trigger, tevent->system);
return 1;
}
snprintf(trigger, 1024, "%s\n", tevent->trigger);
debug_msg("Enabling %s:%s trigger %s\n", tevent->system,
tevent->event ? : "*", tevent->trigger);
retval = tracefs_event_file_write(instance->inst, tevent->system,
tevent->event, "trigger", trigger);
if (retval < 0) {
err_msg("Error enabling %s:%s trigger %s\n", tevent->system,
tevent->event ? : "*", tevent->trigger);
return 1;
}
tevent->trigger_enabled = 1;
return 0;
}
/*
* trace_events_enable - enable all events
*/
int trace_events_enable(struct trace_instance *instance,
struct trace_events *events)
{
struct trace_events *tevent = events;
int retval;
while (tevent) {
debug_msg("Enabling event %s:%s\n", tevent->system, tevent->event ? : "*");
retval = tracefs_event_enable(instance->inst, tevent->system, tevent->event);
if (retval < 0) {
err_msg("Error enabling event %s:%s\n", tevent->system,
tevent->event ? : "*");
return 1;
}
retval = trace_event_enable_filter(instance, tevent);
if (retval)
return 1;
retval = trace_event_enable_trigger(instance, tevent);
if (retval)
return 1;
tevent->enabled = 1;
tevent = tevent->next;
}
return 0;
}
/*
* trace_events_destroy - disable and free all trace events
*/
void trace_events_destroy(struct trace_instance *instance,
struct trace_events *events)
{
if (!events)
return;
trace_events_disable(instance, events);
trace_events_free(events);
}
int trace_is_off(struct trace_instance *tool, struct trace_instance *trace)
{
/*
* The tool instance is always present, it is the one used to collect
* data.
*/
if (!tracefs_trace_is_on(tool->inst))
return 1;
/*
* 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;
return 0;
}
......@@ -2,6 +2,17 @@
#include <tracefs.h>
#include <stddef.h>
struct trace_events {
struct trace_events *next;
char *system;
char *event;
char *filter;
char *trigger;
char enabled;
char filter_enabled;
char trigger_enabled;
};
struct trace_instance {
struct tracefs_instance *inst;
struct tep_handle *tep;
......@@ -25,3 +36,15 @@ void destroy_instance(struct tracefs_instance *inst);
int save_trace_to_file(struct tracefs_instance *inst, const char *filename);
int collect_registered_events(struct tep_event *tep, struct tep_record *record,
int cpu, void *context);
struct trace_events *trace_event_alloc(const char *event_string);
void trace_events_disable(struct trace_instance *instance,
struct trace_events *events);
void trace_events_destroy(struct trace_instance *instance,
struct trace_events *events);
int trace_events_enable(struct trace_instance *instance,
struct trace_events *events);
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);
......@@ -10,6 +10,7 @@
#include <unistd.h>
#include <ctype.h>
#include <errno.h>
#include <fcntl.h>
#include <sched.h>
#include <stdio.h>
......@@ -431,3 +432,35 @@ int parse_prio(char *arg, struct sched_attr *sched_param)
}
return 0;
}
/*
* set_cpu_dma_latency - set the /dev/cpu_dma_latecy
*
* This is used to reduce the exit from idle latency. The value
* will be reset once the file descriptor of /dev/cpu_dma_latecy
* is closed.
*
* Return: the /dev/cpu_dma_latecy file descriptor
*/
int set_cpu_dma_latency(int32_t latency)
{
int retval;
int fd;
fd = open("/dev/cpu_dma_latency", O_RDWR);
if (fd < 0) {
err_msg("Error opening /dev/cpu_dma_latency\n");
return -1;
}
retval = write(fd, &latency, 4);
if (retval < 1) {
err_msg("Error setting /dev/cpu_dma_latency\n");
close(fd);
return -1;
}
debug_msg("Set /dev/cpu_dma_latency to %d\n", latency);
return fd;
}
......@@ -54,3 +54,4 @@ struct sched_attr {
int parse_prio(char *arg, struct sched_attr *sched_param);
int set_comm_sched_attr(const char *comm, struct sched_attr *attr);
int set_cpu_dma_latency(int32_t latency);
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment