2
0
mirror of git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git synced 2025-09-04 20:19:47 +08:00

tracing tools changes for 6.17:

- Introduce enum timerlat_tracing_mode
 
   Now that BPF based sampling has been added to timerlat, add an enum to
   represent which mode timerlat is running in.
 
 - Add action on timelat threshold feature
 
   A new option, --on-threshold, is added, taking an argument
   that further specifies the action. Actions added in this patch are:
 
   - trace[,file=<filename>]: Saves tracefs buffer, optionally taking a
           filename.
   - signal,num=<sig>,pid=<pid>: Sends signal to process. "parent" might
           be specified instead of number to send signal to parent process.
   - shell,command=<command>: Execute shell command.
 
 - Allow resuming tracing in timerlat bpf
 
   rtla-timerlat BPF program uses a global variable stored in a .bss section to
   store whether tracing has been stopped. Map it to allow it to resume tracing
   after it has been stopped.
 
 - Add continue action to timerlat
 
   Introduce option to resume tracing after a latency threshold overflow.  The
   option is implemented as an action named "continue".
 
 - Add action on end feature to timerlat
 
   Implement actions on end next to actions on threshold. A new option,
   --on-end is added, parallel to --on-threshold. Instead of being executed
   whenever a latency threshold is reached, it is executed at the end of the
   measurement.
 
 - Have rtla tests check output with grep
 
   Add argument to the check command in the test suite that takes a regular
   expression that the output of rtla command is checked against. This allows
   testing for specific information in rtla output in addition to checking the
   return value.
 
 - Add tests for timerlat actions
 
 - Update the documentation for the new features
 -----BEGIN PGP SIGNATURE-----
 
 iIoEABYKADIWIQRRSw7ePDh/lE+zeZMp5XQQmuv6qgUCaIuAtBQccm9zdGVkdEBn
 b29kbWlzLm9yZwAKCRAp5XQQmuv6qk1uAQCzkGc7IUqp8038HU0aZoOwSxS04ma3
 NvrF0Vuw8wvVqgD+Pogi1M7fr3LyXHzW4k3Vx7Ot3YSy52T6aCohjcKQ0wo=
 =P46B
 -----END PGP SIGNATURE-----

Merge tag 'trace-tools-v6.17' of git://git.kernel.org/pub/scm/linux/kernel/git/trace/linux-trace

Pull tracing tools updates from Steven Rostedt:

 - Introduce enum timerlat_tracing_mode

   Now that BPF based sampling has been added to timerlat, add an enum
   to represent which mode timerlat is running in

 - Add action on timelat threshold feature

   A new option, --on-threshold, is added, taking an argument that
   further specifies the action. Actions added in this patch are:

     - trace[,file=<filename>]: Saves tracefs buffer, optionally taking a
             filename
     - signal,num=<sig>,pid=<pid>: Sends signal to process. "parent" might
             be specified instead of number to send signal to parent process
     - shell,command=<command>: Execute shell command

 - Allow resuming tracing in timerlat bpf

   rtla-timerlat BPF program uses a global variable stored in a .bss
   section to store whether tracing has been stopped. Map it to allow it
   to resume tracing after it has been stopped

 - Add continue action to timerlat

   Introduce option to resume tracing after a latency threshold
   overflow. The option is implemented as an action named "continue"

 - Add action on end feature to timerlat

   Implement actions on end next to actions on threshold. A new option,
   --on-end is added, parallel to --on-threshold. Instead of being
   executed whenever a latency threshold is reached, it is executed at
   the end of the measurement

 - Have rtla tests check output with grep

   Add argument to the check command in the test suite that takes a
   regular expression that the output of rtla command is checked
   against. This allows testing for specific information in rtla output
   in addition to checking the return value

 - Add tests for timerlat actions

 - Update the documentation for the new features

* tag 'trace-tools-v6.17' of git://git.kernel.org/pub/scm/linux/kernel/git/trace/linux-trace:
  rtla/tests: Test timerlat -P option using actions
  rtla/tests: Add grep checks for base test cases
  Documentation/rtla: Add actions feature
  rtla/tests: Limit duration to maximum of 10s
  rtla/tests: Add tests for actions
  rtla/tests: Check rtla output with grep
  rtla/timerlat: Add action on end feature
  rtla/timerlat: Add continue action
  rtla/timerlat_bpf: Allow resuming tracing
  rtla/timerlat: Add action on threshold feature
  rtla/timerlat: Introduce enum timerlat_tracing_mode
This commit is contained in:
Linus Torvalds 2025-08-01 10:23:13 -07:00
commit 5172a77724
16 changed files with 739 additions and 131 deletions

View File

@ -55,3 +55,67 @@
Set timerlat to run without workload, waiting for the user to dispatch a per-cpu
task that waits for a new period on the tracing/osnoise/per_cpu/cpu$ID/timerlat_fd.
See linux/tools/rtla/sample/timerlat_load.py for an example of user-load code.
**--on-threshold** *action*
Defines an action to be executed when tracing is stopped on a latency threshold
specified by **-i/--irq** or **-T/--thread**.
Multiple --on-threshold actions may be specified, and they will be executed in
the order they are provided. If any action fails, subsequent actions in the list
will not be executed.
Supported actions are:
- *trace[,file=<filename>]*
Saves trace output, optionally taking a filename. Alternative to -t/--trace.
Note that nlike -t/--trace, specifying this multiple times will result in
the trace being saved multiple times.
- *signal,num=<sig>,pid=<pid>*
Sends signal to process. "parent" might be specified in place of pid to target
the parent process of rtla.
- *shell,command=<command>*
Execute shell command.
- *continue*
Continue tracing after actions are executed instead of stopping.
Example:
$ rtla timerlat -T 20 --on-threshold trace
--on-threshold shell,command="grep ipi_send timerlat_trace.txt"
--on-threshold signal,num=2,pid=parent
This will save a trace with the default filename "timerlat_trace.txt", print its
lines that contain the text "ipi_send" on standard output, and send signal 2
(SIGINT) to the parent process.
Performance Considerations:
For time-sensitive actions, it is recommended to run **rtla timerlat** with BPF
support and RT priority. Note that due to implementational limitations, actions
might be delayed up to one second after tracing is stopped if BPF mode is not
available or disabled.
**--on-end** *action*
Defines an action to be executed at the end of **rtla timerlat** tracing.
Multiple --on-end actions can be specified, and they will be executed in the order
they are provided. If any action fails, subsequent actions in the list will not be
executed.
See the documentation for **--on-threshold** for the list of supported actions, with
the exception that *continue* has no effect.
Example:
$ rtla timerlat -d 5s --on-end trace
This runs rtla timerlat with default options and save trace output at the end.

View File

@ -1,5 +1,6 @@
rtla-y += trace.o
rtla-y += utils.o
rtla-y += actions.o
rtla-y += osnoise.o
rtla-y += osnoise_top.o
rtla-y += osnoise_hist.o

View File

@ -0,0 +1,260 @@
// SPDX-License-Identifier: GPL-2.0
#include <stdlib.h>
#include <string.h>
#include <signal.h>
#include <unistd.h>
#include "actions.h"
#include "trace.h"
#include "utils.h"
/*
* actions_init - initialize struct actions
*/
void
actions_init(struct actions *self)
{
self->size = action_default_size;
self->list = calloc(self->size, sizeof(struct action));
self->len = 0;
self->continue_flag = false;
memset(&self->present, 0, sizeof(self->present));
/* This has to be set by the user */
self->trace_output_inst = NULL;
}
/*
* actions_destroy - destroy struct actions
*/
void
actions_destroy(struct actions *self)
{
/* Free any action-specific data */
for (struct action *action = self->list; action < self->list + self->len; action++) {
if (action->type == ACTION_SHELL)
free(action->command);
if (action->type == ACTION_TRACE_OUTPUT)
free(action->trace_output);
}
/* Free action list */
free(self->list);
}
/*
* actions_new - Get pointer to new action
*/
static struct action *
actions_new(struct actions *self)
{
if (self->size >= self->len) {
self->size *= 2;
self->list = realloc(self->list, self->size * sizeof(struct action));
}
return &self->list[self->len++];
}
/*
* actions_add_trace_output - add an action to output trace
*/
int
actions_add_trace_output(struct actions *self, const char *trace_output)
{
struct action *action = actions_new(self);
self->present[ACTION_TRACE_OUTPUT] = true;
action->type = ACTION_TRACE_OUTPUT;
action->trace_output = calloc(strlen(trace_output) + 1, sizeof(char));
if (!action->trace_output)
return -1;
strcpy(action->trace_output, trace_output);
return 0;
}
/*
* actions_add_trace_output - add an action to send signal to a process
*/
int
actions_add_signal(struct actions *self, int signal, int pid)
{
struct action *action = actions_new(self);
self->present[ACTION_SIGNAL] = true;
action->type = ACTION_SIGNAL;
action->signal = signal;
action->pid = pid;
return 0;
}
/*
* actions_add_shell - add an action to execute a shell command
*/
int
actions_add_shell(struct actions *self, const char *command)
{
struct action *action = actions_new(self);
self->present[ACTION_SHELL] = true;
action->type = ACTION_SHELL;
action->command = calloc(strlen(command) + 1, sizeof(char));
if (!action->command)
return -1;
strcpy(action->command, command);
return 0;
}
/*
* actions_add_continue - add an action to resume measurement
*/
int
actions_add_continue(struct actions *self)
{
struct action *action = actions_new(self);
self->present[ACTION_CONTINUE] = true;
action->type = ACTION_CONTINUE;
return 0;
}
/*
* actions_parse - add an action based on text specification
*/
int
actions_parse(struct actions *self, const char *trigger)
{
enum action_type type = ACTION_NONE;
char *token;
char trigger_c[strlen(trigger)];
/* For ACTION_SIGNAL */
int signal = 0, pid = 0;
/* For ACTION_TRACE_OUTPUT */
char *trace_output;
strcpy(trigger_c, trigger);
token = strtok(trigger_c, ",");
if (strcmp(token, "trace") == 0)
type = ACTION_TRACE_OUTPUT;
else if (strcmp(token, "signal") == 0)
type = ACTION_SIGNAL;
else if (strcmp(token, "shell") == 0)
type = ACTION_SHELL;
else if (strcmp(token, "continue") == 0)
type = ACTION_CONTINUE;
else
/* Invalid trigger type */
return -1;
token = strtok(NULL, ",");
switch (type) {
case ACTION_TRACE_OUTPUT:
/* Takes no argument */
if (token == NULL)
trace_output = "timerlat_trace.txt";
else {
if (strlen(token) > 5 && strncmp(token, "file=", 5) == 0) {
trace_output = token + 5;
} else {
/* Invalid argument */
return -1;
}
token = strtok(NULL, ",");
if (token != NULL)
/* Only one argument allowed */
return -1;
}
return actions_add_trace_output(self, trace_output);
case ACTION_SIGNAL:
/* Takes two arguments, num (signal) and pid */
while (token != NULL) {
if (strlen(token) > 4 && strncmp(token, "num=", 4) == 0) {
signal = atoi(token + 4);
} else if (strlen(token) > 4 && strncmp(token, "pid=", 4) == 0) {
if (strncmp(token + 4, "parent", 7) == 0)
pid = -1;
else
pid = atoi(token + 4);
} else {
/* Invalid argument */
return -1;
}
token = strtok(NULL, ",");
}
if (!signal || !pid)
/* Missing argument */
return -1;
return actions_add_signal(self, signal, pid);
case ACTION_SHELL:
if (token == NULL)
return -1;
if (strlen(token) > 8 && strncmp(token, "command=", 8) == 0)
return actions_add_shell(self, token + 8);
return -1;
case ACTION_CONTINUE:
/* Takes no argument */
if (token != NULL)
return -1;
return actions_add_continue(self);
default:
return -1;
}
}
/*
* actions_perform - perform all actions
*/
int
actions_perform(struct actions *self)
{
int pid, retval;
const struct action *action;
for (action = self->list; action < self->list + self->len; action++) {
switch (action->type) {
case ACTION_TRACE_OUTPUT:
retval = save_trace_to_file(self->trace_output_inst, action->trace_output);
if (retval) {
err_msg("Error saving trace\n");
return retval;
}
break;
case ACTION_SIGNAL:
if (action->pid == -1)
pid = getppid();
else
pid = action->pid;
retval = kill(pid, action->signal);
if (retval) {
err_msg("Error sending signal\n");
return retval;
}
break;
case ACTION_SHELL:
retval = system(action->command);
if (retval)
return retval;
break;
case ACTION_CONTINUE:
self->continue_flag = true;
return 0;
default:
break;
}
}
return 0;
}

View File

@ -0,0 +1,52 @@
/* SPDX-License-Identifier: GPL-2.0 */
#include <tracefs.h>
#include <stdbool.h>
enum action_type {
ACTION_NONE = 0,
ACTION_TRACE_OUTPUT,
ACTION_SIGNAL,
ACTION_SHELL,
ACTION_CONTINUE,
ACTION_FIELD_N
};
struct action {
enum action_type type;
union {
struct {
/* For ACTION_TRACE_OUTPUT */
char *trace_output;
};
struct {
/* For ACTION_SIGNAL */
int signal;
int pid;
};
struct {
/* For ACTION_SHELL */
char *command;
};
};
};
static const int action_default_size = 8;
struct actions {
struct action *list;
int len, size;
bool present[ACTION_FIELD_N];
bool continue_flag;
/* External dependencies */
struct tracefs_instance *trace_output_inst;
};
void actions_init(struct actions *self);
void actions_destroy(struct actions *self);
int actions_add_trace_output(struct actions *self, const char *trace_output);
int actions_add_signal(struct actions *self, int signal, int pid);
int actions_add_shell(struct actions *self, const char *command);
int actions_add_continue(struct actions *self);
int actions_parse(struct actions *self, const char *trigger);
int actions_perform(struct actions *self);

View File

@ -28,6 +28,13 @@ struct {
__type(value, unsigned long long);
} summary_irq SEC(".maps"), summary_thread SEC(".maps"), summary_user SEC(".maps");
struct {
__uint(type, BPF_MAP_TYPE_ARRAY);
__uint(max_entries, 1);
__type(key, unsigned int);
__type(value, unsigned long long);
} stop_tracing SEC(".maps");
struct {
__uint(type, BPF_MAP_TYPE_RINGBUF);
__uint(max_entries, 1);
@ -41,8 +48,6 @@ const volatile int irq_threshold;
const volatile int thread_threshold;
const volatile bool aa_only;
int stop_tracing;
nosubprog unsigned long long map_get(void *map,
unsigned int key)
{
@ -109,7 +114,7 @@ nosubprog void set_stop_tracing(void)
int value = 0;
/* Suppress further sample processing */
stop_tracing = 1;
map_set(&stop_tracing, 0, 1);
/* Signal to userspace */
bpf_ringbuf_output(&signal_stop_tracing, &value, sizeof(value), 0);
@ -121,7 +126,7 @@ int handle_timerlat_sample(struct trace_event_raw_timerlat_sample *tp_args)
unsigned long long latency, latency_us;
int bucket;
if (stop_tracing)
if (map_get(&stop_tracing, 0))
return 0;
latency = tp_args->timer_latency / output_divisor;

View File

@ -40,16 +40,22 @@ timerlat_apply_config(struct osnoise_tool *tool, struct timerlat_params *params)
CPU_SET(i, &params->monitored_cpus);
}
retval = osnoise_set_stop_us(tool->context, params->stop_us);
if (retval) {
err_msg("Failed to set stop us\n");
goto out_err;
}
if (params->mode != TRACING_MODE_BPF) {
/*
* In tracefs and mixed mode, timerlat tracer handles stopping
* on threshold
*/
retval = osnoise_set_stop_us(tool->context, params->stop_us);
if (retval) {
err_msg("Failed to set stop us\n");
goto out_err;
}
retval = osnoise_set_stop_total_us(tool->context, params->stop_total_us);
if (retval) {
err_msg("Failed to set stop total us\n");
goto out_err;
retval = osnoise_set_stop_total_us(tool->context, params->stop_total_us);
if (retval) {
err_msg("Failed to set stop total us\n");
goto out_err;
}
}

View File

@ -1,11 +1,28 @@
// SPDX-License-Identifier: GPL-2.0
#include "actions.h"
#include "osnoise.h"
/*
* Define timerlat tracing mode.
*
* There are three tracing modes:
* - tracefs-only, used when BPF is unavailable.
* - BPF-only, used when BPF is available and neither trace saving nor
* auto-analysis are enabled.
* - mixed mode, used when BPF is available and either trace saving or
* auto-analysis is enabled (which rely on sample collection through
* tracefs).
*/
enum timerlat_tracing_mode {
TRACING_MODE_BPF,
TRACING_MODE_TRACEFS,
TRACING_MODE_MIXED,
};
struct timerlat_params {
/* Common params */
char *cpus;
cpu_set_t monitored_cpus;
char *trace_output;
char *cgroup_name;
unsigned long long runtime;
long long stop_us;
@ -30,6 +47,11 @@ struct timerlat_params {
cpu_set_t hk_cpu_set;
struct sched_attr sched_param;
struct trace_events *events;
enum timerlat_tracing_mode mode;
struct actions threshold_actions;
struct actions end_actions;
union {
struct {
/* top only */

View File

@ -106,6 +106,19 @@ int timerlat_bpf_wait(int timeout)
return retval;
}
/*
* timerlat_bpf_restart_tracing - restart stopped tracing
*/
int timerlat_bpf_restart_tracing(void)
{
unsigned int key = 0;
unsigned long long value = 0;
return bpf_map__update_elem(bpf->maps.stop_tracing,
&key, sizeof(key),
&value, sizeof(value), BPF_ANY);
}
static int get_value(struct bpf_map *map_irq,
struct bpf_map *map_thread,
struct bpf_map *map_user,

View File

@ -18,6 +18,7 @@ int timerlat_bpf_attach(void);
void timerlat_bpf_detach(void);
void timerlat_bpf_destroy(void);
int timerlat_bpf_wait(int timeout);
int timerlat_bpf_restart_tracing(void);
int timerlat_bpf_get_hist_value(int key,
long long *value_irq,
long long *value_thread,
@ -28,6 +29,7 @@ int timerlat_bpf_get_summary_value(enum summary_field key,
long long *value_thread,
long long *value_user,
int cpus);
static inline int have_libbpf_support(void) { return 1; }
#else
static inline int timerlat_bpf_init(struct timerlat_params *params)
@ -38,6 +40,7 @@ static inline int timerlat_bpf_attach(void) { return -1; }
static inline void timerlat_bpf_detach(void) { };
static inline void timerlat_bpf_destroy(void) { };
static inline int timerlat_bpf_wait(int timeout) { return -1; }
static inline int timerlat_bpf_restart_tracing(void) { return -1; };
static inline int timerlat_bpf_get_hist_value(int key,
long long *value_irq,
long long *value_thread,

View File

@ -757,6 +757,8 @@ static void timerlat_hist_usage(char *usage)
" --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",
" --on-threshold <action>: define action to be executed at latency threshold, multiple are allowed",
" --on-end <action>: define action to be executed at measurement end, multiple are allowed",
NULL,
};
@ -786,11 +788,15 @@ static struct timerlat_params
int auto_thresh;
int retval;
int c;
char *trace_output = NULL;
params = calloc(1, sizeof(*params));
if (!params)
exit(1);
actions_init(&params->threshold_actions);
actions_init(&params->end_actions);
/* disabled by default */
params->dma_latency = -1;
@ -802,6 +808,9 @@ static struct timerlat_params
params->bucket_size = 1;
params->entries = 256;
/* default to BPF mode */
params->mode = TRACING_MODE_BPF;
while (1) {
static struct option long_options[] = {
{"auto", required_argument, 0, 'a'},
@ -838,6 +847,8 @@ static struct timerlat_params
{"warm-up", required_argument, 0, '\2'},
{"trace-buffer-size", required_argument, 0, '\3'},
{"deepest-idle-state", required_argument, 0, '\4'},
{"on-threshold", required_argument, 0, '\5'},
{"on-end", required_argument, 0, '\6'},
{0, 0, 0, 0}
};
@ -863,7 +874,7 @@ static struct timerlat_params
params->print_stack = auto_thresh;
/* set trace */
params->trace_output = "timerlat_trace.txt";
trace_output = "timerlat_trace.txt";
break;
case 'c':
@ -953,13 +964,13 @@ static struct timerlat_params
case 't':
if (optarg) {
if (optarg[0] == '=')
params->trace_output = &optarg[1];
trace_output = &optarg[1];
else
params->trace_output = &optarg[0];
trace_output = &optarg[0];
} else if (optind < argc && argv[optind][0] != '-')
params->trace_output = argv[optind];
trace_output = argv[optind];
else
params->trace_output = "timerlat_trace.txt";
trace_output = "timerlat_trace.txt";
break;
case 'u':
params->user_workload = 1;
@ -1029,11 +1040,28 @@ static struct timerlat_params
case '\4':
params->deepest_idle_state = get_llong_from_str(optarg);
break;
case '\5':
retval = actions_parse(&params->threshold_actions, optarg);
if (retval) {
err_msg("Invalid action %s\n", optarg);
exit(EXIT_FAILURE);
}
break;
case '\6':
retval = actions_parse(&params->end_actions, optarg);
if (retval) {
err_msg("Invalid action %s\n", optarg);
exit(EXIT_FAILURE);
}
break;
default:
timerlat_hist_usage("Invalid option");
}
}
if (trace_output)
actions_add_trace_output(&params->threshold_actions, trace_output);
if (geteuid()) {
err_msg("rtla needs root permission\n");
exit(EXIT_FAILURE);
@ -1054,6 +1082,15 @@ static struct timerlat_params
if (params->kernel_workload && params->user_workload)
timerlat_hist_usage("--kernel-threads and --user-threads are mutually exclusive!");
/*
* If auto-analysis or trace output is enabled, switch from BPF mode to
* mixed mode
*/
if (params->mode == TRACING_MODE_BPF &&
(params->threshold_actions.present[ACTION_TRACE_OUTPUT] ||
params->end_actions.present[ACTION_TRACE_OUTPUT] || !params->no_aa))
params->mode = TRACING_MODE_MIXED;
return params;
}
@ -1149,7 +1186,6 @@ int timerlat_hist_main(int argc, char *argv[])
pthread_t timerlat_u;
int retval;
int nr_cpus, i;
bool no_bpf = false;
params = timerlat_hist_parse_args(argc, argv);
if (!params)
@ -1161,12 +1197,6 @@ int timerlat_hist_main(int argc, char *argv[])
goto out_exit;
}
retval = timerlat_hist_apply_config(tool, params);
if (retval) {
err_msg("Could not apply config\n");
goto out_free;
}
trace = &tool->trace;
/*
* Save trace instance into global variable so that SIGINT can stop
@ -1175,24 +1205,30 @@ int timerlat_hist_main(int argc, char *argv[])
*/
hist_inst = trace;
/*
* Try to enable BPF, unless disabled explicitly.
* If BPF enablement fails, fall back to tracefs mode.
*/
if (getenv("RTLA_NO_BPF") && strncmp(getenv("RTLA_NO_BPF"), "1", 2) == 0) {
debug_msg("RTLA_NO_BPF set, disabling BPF\n");
no_bpf = true;
}
if (!no_bpf && !tep_find_event_by_name(trace->tep, "osnoise", "timerlat_sample")) {
params->mode = TRACING_MODE_TRACEFS;
} else if (!tep_find_event_by_name(trace->tep, "osnoise", "timerlat_sample")) {
debug_msg("osnoise:timerlat_sample missing, disabling BPF\n");
no_bpf = true;
}
if (!no_bpf) {
params->mode = TRACING_MODE_TRACEFS;
} else {
retval = timerlat_bpf_init(params);
if (retval) {
debug_msg("Could not enable BPF\n");
no_bpf = true;
params->mode = TRACING_MODE_TRACEFS;
}
}
retval = timerlat_hist_apply_config(tool, params);
if (retval) {
err_msg("Could not apply config\n");
goto out_free;
}
retval = enable_timerlat(trace);
if (retval) {
err_msg("Failed to enable timerlat tracer\n");
@ -1245,12 +1281,15 @@ int timerlat_hist_main(int argc, char *argv[])
}
}
if (params->trace_output) {
if (params->threshold_actions.present[ACTION_TRACE_OUTPUT] ||
params->end_actions.present[ACTION_TRACE_OUTPUT]) {
record = osnoise_init_trace_tool("timerlat");
if (!record) {
err_msg("Failed to enable the trace instance\n");
goto out_free;
}
params->threshold_actions.trace_output_inst = record->trace.inst;
params->end_actions.trace_output_inst = record->trace.inst;
if (params->events) {
retval = trace_events_enable(&record->trace, params->events);
@ -1316,11 +1355,11 @@ int timerlat_hist_main(int argc, char *argv[])
* tracing while enabling other instances. The trace instance is the
* one with most valuable information.
*/
if (params->trace_output)
if (record)
trace_instance_start(&record->trace);
if (!params->no_aa)
trace_instance_start(&aa->trace);
if (no_bpf) {
if (params->mode == TRACING_MODE_TRACEFS) {
trace_instance_start(trace);
} else {
retval = timerlat_bpf_attach();
@ -1333,7 +1372,7 @@ int timerlat_hist_main(int argc, char *argv[])
tool->start_time = time(NULL);
timerlat_hist_set_signals(params);
if (no_bpf) {
if (params->mode == TRACING_MODE_TRACEFS) {
while (!stop_tracing) {
sleep(params->sleep_time);
@ -1348,8 +1387,20 @@ int timerlat_hist_main(int argc, char *argv[])
goto out_hist;
}
if (osnoise_trace_is_off(tool, record))
break;
if (osnoise_trace_is_off(tool, record)) {
actions_perform(&params->threshold_actions);
if (!params->threshold_actions.continue_flag)
/* continue flag not set, break */
break;
/* continue action reached, re-enable tracing */
if (record)
trace_instance_start(&record->trace);
if (!params->no_aa)
trace_instance_start(&aa->trace);
trace_instance_start(trace);
}
/* is there still any user-threads ? */
if (params->user_workload) {
@ -1359,10 +1410,29 @@ int timerlat_hist_main(int argc, char *argv[])
}
}
}
} else
timerlat_bpf_wait(-1);
} else {
while (!stop_tracing) {
timerlat_bpf_wait(-1);
if (!no_bpf) {
if (!stop_tracing) {
/* Threshold overflow, perform actions on threshold */
actions_perform(&params->threshold_actions);
if (!params->threshold_actions.continue_flag)
/* continue flag not set, break */
break;
/* continue action reached, re-enable tracing */
if (record)
trace_instance_start(&record->trace);
if (!params->no_aa)
trace_instance_start(&aa->trace);
timerlat_bpf_restart_tracing();
}
}
}
if (params->mode != TRACING_MODE_TRACEFS) {
timerlat_bpf_detach();
retval = timerlat_hist_bpf_pull_data(tool);
if (retval) {
@ -1378,6 +1448,8 @@ int timerlat_hist_main(int argc, char *argv[])
timerlat_print_stats(params, tool);
actions_perform(&params->end_actions);
return_value = PASSED;
if (osnoise_trace_is_off(tool, record) && !stop_tracing) {
@ -1386,8 +1458,6 @@ int timerlat_hist_main(int argc, char *argv[])
if (!params->no_aa)
timerlat_auto_analysis(params->stop_us, params->stop_total_us);
save_trace_to_file(record ? record->trace.inst : NULL,
params->trace_output);
return_value = FAILED;
}
@ -1409,10 +1479,12 @@ out_free:
osnoise_destroy_tool(aa);
osnoise_destroy_tool(record);
osnoise_destroy_tool(tool);
actions_destroy(&params->threshold_actions);
actions_destroy(&params->end_actions);
if (params->mode != TRACING_MODE_TRACEFS)
timerlat_bpf_destroy();
free(params);
free_cpu_idle_disable_states();
if (!no_bpf)
timerlat_bpf_destroy();
out_exit:
exit(return_value);
}

View File

@ -516,6 +516,8 @@ static void timerlat_top_usage(char *usage)
" --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",
" --on-threshold <action>: define action to be executed at latency threshold, multiple are allowed",
" --on-end: define action to be executed at measurement end, multiple are allowed",
NULL,
};
@ -545,11 +547,15 @@ static struct timerlat_params
long long auto_thresh;
int retval;
int c;
char *trace_output = NULL;
params = calloc(1, sizeof(*params));
if (!params)
exit(1);
actions_init(&params->threshold_actions);
actions_init(&params->end_actions);
/* disabled by default */
params->dma_latency = -1;
@ -559,6 +565,9 @@ static struct timerlat_params
/* display data in microseconds */
params->output_divisor = 1000;
/* default to BPF mode */
params->mode = TRACING_MODE_BPF;
while (1) {
static struct option long_options[] = {
{"auto", required_argument, 0, 'a'},
@ -589,6 +598,8 @@ static struct timerlat_params
{"warm-up", required_argument, 0, '6'},
{"trace-buffer-size", required_argument, 0, '7'},
{"deepest-idle-state", required_argument, 0, '8'},
{"on-threshold", required_argument, 0, '9'},
{"on-end", required_argument, 0, '\1'},
{0, 0, 0, 0}
};
@ -614,7 +625,8 @@ static struct timerlat_params
params->print_stack = auto_thresh;
/* set trace */
params->trace_output = "timerlat_trace.txt";
trace_output = "timerlat_trace.txt";
break;
case '5':
/* it is here because it is similar to -a */
@ -709,14 +721,13 @@ static struct timerlat_params
case 't':
if (optarg) {
if (optarg[0] == '=')
params->trace_output = &optarg[1];
trace_output = &optarg[1];
else
params->trace_output = &optarg[0];
trace_output = &optarg[0];
} else if (optind < argc && argv[optind][0] != '-')
params->trace_output = argv[optind];
trace_output = argv[optind];
else
params->trace_output = "timerlat_trace.txt";
trace_output = "timerlat_trace.txt";
break;
case 'u':
params->user_workload = true;
@ -768,11 +779,28 @@ static struct timerlat_params
case '8':
params->deepest_idle_state = get_llong_from_str(optarg);
break;
case '9':
retval = actions_parse(&params->threshold_actions, optarg);
if (retval) {
err_msg("Invalid action %s\n", optarg);
exit(EXIT_FAILURE);
}
break;
case '\1':
retval = actions_parse(&params->end_actions, optarg);
if (retval) {
err_msg("Invalid action %s\n", optarg);
exit(EXIT_FAILURE);
}
break;
default:
timerlat_top_usage("Invalid option");
}
}
if (trace_output)
actions_add_trace_output(&params->threshold_actions, trace_output);
if (geteuid()) {
err_msg("rtla needs root permission\n");
exit(EXIT_FAILURE);
@ -790,6 +818,15 @@ static struct timerlat_params
if (params->kernel_workload && params->user_workload)
timerlat_top_usage("--kernel-threads and --user-threads are mutually exclusive!");
/*
* If auto-analysis or trace output is enabled, switch from BPF mode to
* mixed mode
*/
if (params->mode == TRACING_MODE_BPF &&
(params->threshold_actions.present[ACTION_TRACE_OUTPUT] ||
params->end_actions.present[ACTION_TRACE_OUTPUT] || !params->no_aa))
params->mode = TRACING_MODE_MIXED;
return params;
}
@ -881,6 +918,7 @@ timerlat_top_set_signals(struct timerlat_params *params)
static int
timerlat_top_main_loop(struct osnoise_tool *top,
struct osnoise_tool *record,
struct osnoise_tool *aa,
struct timerlat_params *params,
struct timerlat_u_params *params_u)
{
@ -907,8 +945,20 @@ timerlat_top_main_loop(struct osnoise_tool *top,
if (!params->quiet)
timerlat_print_stats(params, top);
if (osnoise_trace_is_off(top, record))
break;
if (osnoise_trace_is_off(top, record)) {
actions_perform(&params->threshold_actions);
if (!params->threshold_actions.continue_flag)
/* continue flag not set, break */
break;
/* continue action reached, re-enable tracing */
if (record)
trace_instance_start(&record->trace);
if (!params->no_aa)
trace_instance_start(&aa->trace);
trace_instance_start(trace);
}
/* is there still any user-threads ? */
if (params->user_workload) {
@ -928,6 +978,7 @@ timerlat_top_main_loop(struct osnoise_tool *top,
static int
timerlat_top_bpf_main_loop(struct osnoise_tool *top,
struct osnoise_tool *record,
struct osnoise_tool *aa,
struct timerlat_params *params,
struct timerlat_u_params *params_u)
{
@ -939,22 +990,9 @@ timerlat_top_bpf_main_loop(struct osnoise_tool *top,
return 0;
}
if (params->quiet) {
/* Quiet mode: wait for stop and then, print results */
timerlat_bpf_wait(-1);
retval = timerlat_top_bpf_pull_data(top);
if (retval) {
err_msg("Error pulling BPF data\n");
return retval;
}
return 0;
}
/* Pull and display data in a loop */
while (!stop_tracing) {
wait_retval = timerlat_bpf_wait(params->sleep_time);
wait_retval = timerlat_bpf_wait(params->quiet ? -1 : params->sleep_time);
retval = timerlat_top_bpf_pull_data(top);
if (retval) {
@ -962,11 +1000,24 @@ timerlat_top_bpf_main_loop(struct osnoise_tool *top,
return retval;
}
timerlat_print_stats(params, top);
if (!params->quiet)
timerlat_print_stats(params, top);
if (wait_retval == 1)
if (wait_retval == 1) {
/* Stopping requested by tracer */
break;
actions_perform(&params->threshold_actions);
if (!params->threshold_actions.continue_flag)
/* continue flag not set, break */
break;
/* continue action reached, re-enable tracing */
if (record)
trace_instance_start(&record->trace);
if (!params->no_aa)
trace_instance_start(&aa->trace);
timerlat_bpf_restart_tracing();
}
/* is there still any user-threads ? */
if (params->user_workload) {
@ -994,7 +1045,6 @@ int timerlat_top_main(int argc, char *argv[])
char *max_lat;
int retval;
int nr_cpus, i;
bool no_bpf = false;
params = timerlat_top_parse_args(argc, argv);
if (!params)
@ -1006,38 +1056,38 @@ int timerlat_top_main(int argc, char *argv[])
goto out_exit;
}
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;
/*
* Try to enable BPF, unless disabled explicitly.
* If BPF enablement fails, fall back to tracefs mode.
*/
if (getenv("RTLA_NO_BPF") && strncmp(getenv("RTLA_NO_BPF"), "1", 2) == 0) {
debug_msg("RTLA_NO_BPF set, disabling BPF\n");
params->mode = TRACING_MODE_TRACEFS;
} else if (!tep_find_event_by_name(trace->tep, "osnoise", "timerlat_sample")) {
debug_msg("osnoise:timerlat_sample missing, disabling BPF\n");
params->mode = TRACING_MODE_TRACEFS;
} else {
retval = timerlat_bpf_init(params);
if (retval) {
debug_msg("Could not enable BPF\n");
params->mode = TRACING_MODE_TRACEFS;
}
}
retval = timerlat_top_apply_config(top, params);
if (retval) {
err_msg("Could not apply config\n");
goto out_free;
}
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;
if (getenv("RTLA_NO_BPF") && strncmp(getenv("RTLA_NO_BPF"), "1", 2) == 0) {
debug_msg("RTLA_NO_BPF set, disabling BPF\n");
no_bpf = true;
}
if (!no_bpf && !tep_find_event_by_name(trace->tep, "osnoise", "timerlat_sample")) {
debug_msg("osnoise:timerlat_sample missing, disabling BPF\n");
no_bpf = true;
}
if (!no_bpf) {
retval = timerlat_bpf_init(params);
if (retval) {
debug_msg("Could not enable BPF\n");
no_bpf = true;
}
}
retval = enable_timerlat(trace);
if (retval) {
err_msg("Failed to enable timerlat tracer\n");
@ -1090,12 +1140,15 @@ int timerlat_top_main(int argc, char *argv[])
}
}
if (params->trace_output) {
if (params->threshold_actions.present[ACTION_TRACE_OUTPUT] ||
params->end_actions.present[ACTION_TRACE_OUTPUT]) {
record = osnoise_init_trace_tool("timerlat");
if (!record) {
err_msg("Failed to enable the trace instance\n");
goto out_free;
}
params->threshold_actions.trace_output_inst = record->trace.inst;
params->end_actions.trace_output_inst = record->trace.inst;
if (params->events) {
retval = trace_events_enable(&record->trace, params->events);
@ -1162,11 +1215,11 @@ int timerlat_top_main(int argc, char *argv[])
* tracing while enabling other instances. The trace instance is the
* one with most valuable information.
*/
if (params->trace_output)
if (record)
trace_instance_start(&record->trace);
if (!params->no_aa)
trace_instance_start(&aa->trace);
if (no_bpf) {
if (params->mode == TRACING_MODE_TRACEFS) {
trace_instance_start(trace);
} else {
retval = timerlat_bpf_attach();
@ -1179,15 +1232,15 @@ int timerlat_top_main(int argc, char *argv[])
top->start_time = time(NULL);
timerlat_top_set_signals(params);
if (no_bpf)
retval = timerlat_top_main_loop(top, record, params, &params_u);
if (params->mode == TRACING_MODE_TRACEFS)
retval = timerlat_top_main_loop(top, record, aa, params, &params_u);
else
retval = timerlat_top_bpf_main_loop(top, record, params, &params_u);
retval = timerlat_top_bpf_main_loop(top, record, aa, params, &params_u);
if (retval)
goto out_top;
if (!no_bpf)
if (params->mode != TRACING_MODE_TRACEFS)
timerlat_bpf_detach();
if (params->user_workload && !params_u.stopped_running) {
@ -1197,6 +1250,8 @@ int timerlat_top_main(int argc, char *argv[])
timerlat_print_stats(params, top);
actions_perform(&params->end_actions);
return_value = PASSED;
if (osnoise_trace_is_off(top, record) && !stop_tracing) {
@ -1205,8 +1260,6 @@ int timerlat_top_main(int argc, char *argv[])
if (!params->no_aa)
timerlat_auto_analysis(params->stop_us, params->stop_total_us);
save_trace_to_file(record ? record->trace.inst : NULL,
params->trace_output);
return_value = FAILED;
} else if (params->aa_only) {
/*
@ -1239,6 +1292,10 @@ out_free:
osnoise_destroy_tool(aa);
osnoise_destroy_tool(record);
osnoise_destroy_tool(top);
actions_destroy(&params->threshold_actions);
actions_destroy(&params->end_actions);
if (params->mode != TRACING_MODE_TRACEFS)
timerlat_bpf_destroy();
free(params);
free_cpu_idle_disable_states();
out_exit:

View File

@ -11,7 +11,7 @@ test_begin() {
reset_osnoise() {
# Reset osnoise options to default and remove any dangling instances created
# by improperly exited rtla runs.
pushd /sys/kernel/tracing || return 1
pushd /sys/kernel/tracing >/dev/null || return 1
# Remove dangling instances created by previous rtla run
echo 0 > tracing_thresh
@ -35,11 +35,14 @@ reset_osnoise() {
echo 0 > stop_tracing_us
echo 1000 > timerlat_period_us
popd
popd >/dev/null
}
check() {
test_name=$0
tested_command=$1
expected_exitcode=${3:-0}
expected_output=$4
# Simple check: run rtla with given arguments and test exit code.
# If TEST_COUNT is set, run the test. Otherwise, just count.
ctr=$(($ctr + 1))
@ -49,8 +52,16 @@ check() {
[ "$NO_RESET_OSNOISE" == 1 ] || reset_osnoise
# Run rtla; in case of failure, include its output as comment
# in the test results.
result=$(stdbuf -oL $TIMEOUT "$RTLA" $2 2>&1); exitcode=$?
if [ $exitcode -eq $expected_exitcode ]
result=$(eval stdbuf -oL $TIMEOUT "$RTLA" $2 2>&1); exitcode=$?
# Test if the results matches if requested
if [ -n "$expected_output" ]
then
grep -E "$expected_output" <<< "$result" > /dev/null; grep_result=$?
else
grep_result=0
fi
if [ $exitcode -eq $expected_exitcode ] && [ $grep_result -eq 0 ]
then
echo "ok $ctr - $1"
else
@ -58,6 +69,8 @@ check() {
# Add rtla output and exit code as comments in case of failure
echo "$result" | col -b | while read line; do echo "# $line"; done
printf "#\n# exit code %s\n" $exitcode
[ -n "$expected_output" ] && [ $grep_result -ne 0 ] && \
printf "# Output match failed: \"%s\"\n" "$expected_output"
fi
fi
}

View File

@ -6,16 +6,17 @@ test_begin
set_timeout 2m
check "verify help page" \
"hwnoise --help"
"hwnoise --help" 0 "summary of hardware-related noise"
check "detect noise higher than one microsecond" \
"hwnoise -c 0 -T 1 -d 5s -q"
"hwnoise -c 0 -T 1 -d 5s -q" 0
check "set the automatic trace mode" \
"hwnoise -a 5 -d 30s" 2
"hwnoise -a 5 -d 10s" 2 "osnoise hit stop tracing"
check "set scheduling param to the osnoise tracer threads" \
"hwnoise -P F:1 -c 0 -r 900000 -d 1M -q"
"hwnoise -P F:1 -c 0 -r 900000 -d 10s -q"
check "stop the trace if a single sample is higher than 1 us" \
"hwnoise -s 1 -T 1 -t -d 30s" 2
"hwnoise -s 1 -T 1 -t -d 10s" 2 "Saving trace to osnoise_trace.txt"
check "enable a trace event trigger" \
"hwnoise -t -e osnoise:irq_noise trigger=\"hist:key=desc,duration:sort=desc,duration:vals=hitcount\" -d 1m"
"hwnoise -t -e osnoise:irq_noise --trigger=\"hist:key=desc,duration:sort=desc,duration:vals=hitcount\" -d 10s" \
0 "Saving event osnoise:irq_noise hist to osnoise_irq_noise_hist.txt"
test_end

View File

@ -6,15 +6,15 @@ test_begin
set_timeout 2m
check "verify help page" \
"osnoise --help"
"osnoise --help" 0 "osnoise version"
check "verify the --priority/-P param" \
"osnoise top -P F:1 -c 0 -r 900000 -d 1M -q"
"osnoise top -P F:1 -c 0 -r 900000 -d 10s -q"
check "verify the --stop/-s param" \
"osnoise top -s 30 -T 1 -t" 2
"osnoise top -s 30 -T 1" 2 "osnoise hit stop tracing"
check "verify the --trace param" \
"osnoise hist -s 30 -T 1 -t" 2
"osnoise hist -s 30 -T 1 -t" 2 "Saving trace to osnoise_trace.txt"
check "verify the --entries/-E param" \
"osnoise hist -P F:1 -c 0 -r 900000 -d 1M -b 10 -E 25"
"osnoise hist -P F:1 -c 0 -r 900000 -d 10s -b 10 -E 25"
# Test setting default period by putting an absurdly high period
# and stopping on threshold.

View File

@ -0,0 +1,8 @@
#!/bin/bash
# SPDX-License-Identifier: GPL-2.0
pids="$(pgrep ^$1)" || exit 1
for pid in $pids
do
chrt -p $pid | cut -d ':' -f 2 | head -n1 | grep "^ $2\$" >/dev/null
chrt -p $pid | cut -d ':' -f 2 | tail -n1 | grep "^ $3\$" >/dev/null
done && echo "Priorities are set correctly"

View File

@ -18,24 +18,55 @@ fi
for option in $no_bpf_options
do
export RTLA_NO_BPF=$option
# Basic tests
check "verify help page" \
"timerlat --help"
"timerlat --help" 0 "timerlat version"
check "verify -s/--stack" \
"timerlat top -s 3 -T 10 -t" 2
"timerlat top -s 3 -T 10 -t" 2 "Blocking thread stack trace"
check "verify -P/--priority" \
"timerlat top -P F:1 -c 0 -d 1M -q"
"timerlat top -P F:1 -c 0 -d 10s -q -T 1 --on-threshold shell,command=\"tests/scripts/check-priority.sh timerlatu/ SCHED_FIFO 1\"" \
2 "Priorities are set correctly"
check "test in nanoseconds" \
"timerlat top -i 2 -c 0 -n -d 30s" 2
"timerlat top -i 2 -c 0 -n -d 10s" 2 "ns"
check "set the automatic trace mode" \
"timerlat top -a 5 --dump-tasks" 2
"timerlat top -a 5" 2 "analyzing it"
check "dump tasks" \
"timerlat top -a 5 --dump-tasks" 2 "Printing CPU tasks"
check "print the auto-analysis if hits the stop tracing condition" \
"timerlat top --aa-only 5" 2
check "disable auto-analysis" \
"timerlat top -s 3 -T 10 -t --no-aa" 2
check "verify -c/--cpus" \
"timerlat hist -c 0 -d 30s"
"timerlat hist -c 0 -d 10s"
check "hist test in nanoseconds" \
"timerlat hist -i 2 -c 0 -n -d 30s" 2
"timerlat hist -i 2 -c 0 -n -d 10s" 2 "ns"
# Actions tests
check "trace output through -t" \
"timerlat hist -T 2 -t" 2 "^ Saving trace to timerlat_trace.txt$"
check "trace output through -t with custom filename" \
"timerlat hist -T 2 -t custom_filename.txt" 2 "^ Saving trace to custom_filename.txt$"
check "trace output through -A trace" \
"timerlat hist -T 2 --on-threshold trace" 2 "^ Saving trace to timerlat_trace.txt$"
check "trace output through -A trace with custom filename" \
"timerlat hist -T 2 --on-threshold trace,file=custom_filename.txt" 2 "^ Saving trace to custom_filename.txt$"
check "exec command" \
"timerlat hist -T 2 --on-threshold shell,command='echo TestOutput'" 2 "^TestOutput$"
check "multiple actions" \
"timerlat hist -T 2 --on-threshold shell,command='echo -n 1' --on-threshold shell,command='echo 2'" 2 "^12$"
check "hist stop at failed action" \
"timerlat hist -T 2 --on-threshold shell,command='echo -n 1; false' --on-threshold shell,command='echo -n 2'" 2 "^1# RTLA timerlat histogram$"
check "top stop at failed action" \
"timerlat top -T 2 --on-threshold shell,command='echo -n 1; false' --on-threshold shell,command='echo -n 2'" 2 "^1ALL"
check "hist with continue" \
"timerlat hist -T 2 -d 1s --on-threshold shell,command='echo TestOutput' --on-threshold continue" 0 "^TestOutput$"
check "top with continue" \
"timerlat top -q -T 2 -d 1s --on-threshold shell,command='echo TestOutput' --on-threshold continue" 0 "^TestOutput$"
check "hist with trace output at end" \
"timerlat hist -d 1s --on-end trace" 0 "^ Saving trace to timerlat_trace.txt$"
check "top with trace output at end" \
"timerlat top -d 1s --on-end trace" 0 "^ Saving trace to timerlat_trace.txt$"
done
test_end