Commit cdca4f4e authored by Daniel Bristot de Oliveira's avatar Daniel Bristot de Oliveira Committed by Steven Rostedt (Google)
Browse files

rtla/timerlat_top: Add timerlat user-space support 

Add the support for running timerlat threads in user-space. In this
mode, enabled with -u/--user-threads, timerlat dispatches user-space
processes that will loop in the timerlat_fd, measuring the overhead
for going to user-space and then returning to the kernel - in addition
to the existing measurements.

Here is one example of the tool's output with -u enabled:

  $ sudo timerlat top -u -d 600 -q
                                       Timer Latency
    0 00:10:01   |          IRQ Timer Latency (us)        |         Thread Timer Latency (us)      |    Ret user Timer Latency (us)
  CPU COUNT      |      cur       min       avg       max |      cur       min       avg       max |      cur       min       avg       max
    0 #600001    |        0         0         0         3 |        2         1         2         9 |        3         2         3        15
    1 #600001    |        0         0         0         2 |        2         1         2        13 |        2         2         3        18
    2 #600001    |        0         0         0        10 |        2         1         2        16 |        3         2         3        20
    3 #600001    |        0         0         0         7 |        2         1         2        10 |        3         2         3        11
    4 #600000    |        0         0         0        16 |        2         1         2        41 |        3         2         3        58
    5 #600000    |        0         0         0         3 |        2         1         2        10 |        3         2         3        13
    6 #600000    |        0         0         0         5 |        2         1         2         7 |        3         2         3        10
    7 #600000    |        0         0         0         1 |        2         1         2         7 |        3         2         3        10

The tuning setup like -p or -C work for the user-space threads as well.

Link: https://lkml.kernel.org/r/758ad2292a0a1d884138d08219e1a0f572d257a2.1686066600.git.bristot@kernel.org



Cc: William White <chwhite@redhat.com>
Cc: Jonathan Corbet <corbet@lwn.net>
Tested-by: default avatarJuri Lelli <juri.lelli@redhat.com>
Signed-off-by: default avatarDaniel Bristot de Oliveira <bristot@kernel.org>
Signed-off-by: default avatarSteven Rostedt (Google) <rostedt@goodmis.org>
parent 7bc4d308

tools/tracing/rtla/src/osnoise.c

+65 −0
Original line number Diff line number Diff line
@@ -841,6 +841,67 @@ static void osnoise_put_irq_disable(struct osnoise_context *context) 
	context->orig_opt_irq_disable = OSNOISE_OPTION_INIT_VAL;

}



static int osnoise_get_workload(struct osnoise_context *context)

{

	if (context->opt_workload != OSNOISE_OPTION_INIT_VAL)

		return context->opt_workload;



	if (context->orig_opt_workload != OSNOISE_OPTION_INIT_VAL)

		return context->orig_opt_workload;



	context->orig_opt_workload = osnoise_options_get_option("OSNOISE_WORKLOAD");



	return context->orig_opt_workload;

}



int osnoise_set_workload(struct osnoise_context *context, bool onoff)

{

	int opt_workload = osnoise_get_workload(context);

	int retval;



	if (opt_workload == OSNOISE_OPTION_INIT_VAL)

		return -1;



	if (opt_workload == onoff)

		return 0;



	retval = osnoise_options_set_option("OSNOISE_WORKLOAD", onoff);

	if (retval < 0)

		return -1;



	context->opt_workload = onoff;



	return 0;

}



static void osnoise_restore_workload(struct osnoise_context *context)

{

	int retval;



	if (context->orig_opt_workload == OSNOISE_OPTION_INIT_VAL)

		return;



	if (context->orig_opt_workload == context->opt_workload)

		goto out_done;



	retval = osnoise_options_set_option("OSNOISE_WORKLOAD", context->orig_opt_workload);

	if (retval < 0)

		err_msg("Could not restore original OSNOISE_WORKLOAD option\n");



out_done:

	context->orig_opt_workload = OSNOISE_OPTION_INIT_VAL;

}



static void osnoise_put_workload(struct osnoise_context *context)

{

	osnoise_restore_workload(context);



	if (context->orig_opt_workload == OSNOISE_OPTION_INIT_VAL)

		return;



	context->orig_opt_workload = OSNOISE_OPTION_INIT_VAL;

}



/*

 * enable_osnoise - enable osnoise tracer in the trace_instance

 */
@@ -908,6 +969,9 @@ struct osnoise_context *osnoise_context_alloc(void) 
	context->orig_opt_irq_disable	= OSNOISE_OPTION_INIT_VAL;

	context->opt_irq_disable	= OSNOISE_OPTION_INIT_VAL;



	context->orig_opt_workload	= OSNOISE_OPTION_INIT_VAL;

	context->opt_workload		= OSNOISE_OPTION_INIT_VAL;



	osnoise_get_context(context);



	return context;
@@ -935,6 +999,7 @@ void osnoise_put_context(struct osnoise_context *context) 
	osnoise_put_print_stack(context);

	osnoise_put_tracing_thresh(context);

	osnoise_put_irq_disable(context);

	osnoise_put_workload(context);



	free(context);

}

tools/tracing/rtla/src/osnoise.h

+5 −0
Original line number Diff line number Diff line
@@ -42,6 +42,10 @@ struct osnoise_context { 
	/* -1 as init value because 0 is off */

	int			orig_opt_irq_disable;

	int			opt_irq_disable;



	/* -1 as init value because 0 is off */

	int			orig_opt_workload;

	int			opt_workload;

};



/*
@@ -84,6 +88,7 @@ int osnoise_set_print_stack(struct osnoise_context *context, 
			    long long print_stack);



int osnoise_set_irq_disable(struct osnoise_context *context, bool onoff);

int osnoise_set_workload(struct osnoise_context *context, bool onoff);



/*

 * osnoise_tool -  osnoise based tool definition.

tools/tracing/rtla/src/timerlat_top.c

+102 −6
Original line number Diff line number Diff line
@@ -13,11 +13,13 @@ 
#include <time.h>

#include <errno.h>

#include <sched.h>

#include <pthread.h>



#include "utils.h"

#include "osnoise.h"

#include "timerlat.h"

#include "timerlat_aa.h"

#include "timerlat_u.h"



struct timerlat_top_params {

	char			*cpus;
@@ -40,6 +42,7 @@ struct timerlat_top_params { 
	int			dump_tasks;

	int			cgroup;

	int			hk_cpus;

	int			user_top;

	cpu_set_t		hk_cpu_set;

	struct sched_attr	sched_param;

	struct trace_events	*events;
@@ -48,6 +51,7 @@ struct timerlat_top_params { 
struct timerlat_top_cpu {

	int			irq_count;

	int			thread_count;

	int			user_count;



	unsigned long long	cur_irq;

	unsigned long long	min_irq;
@@ -58,6 +62,11 @@ struct timerlat_top_cpu { 
	unsigned long long	min_thread;

	unsigned long long	sum_thread;

	unsigned long long	max_thread;



	unsigned long long	cur_user;

	unsigned long long	min_user;

	unsigned long long	sum_user;

	unsigned long long	max_user;

};



struct timerlat_top_data {
@@ -98,6 +107,7 @@ static struct timerlat_top_data *timerlat_alloc_top(int nr_cpus) 
	for (cpu = 0; cpu < nr_cpus; cpu++) {

		data->cpu_data[cpu].min_irq = ~0;

		data->cpu_data[cpu].min_thread = ~0;

		data->cpu_data[cpu].min_user = ~0;

	}



	return data;
@@ -124,12 +134,18 @@ timerlat_top_update(struct osnoise_tool *tool, int cpu, 
		update_min(&cpu_data->min_irq, &latency);

		update_sum(&cpu_data->sum_irq, &latency);

		update_max(&cpu_data->max_irq, &latency);

	} else {

	} else if (thread == 1) {

		cpu_data->thread_count++;

		cpu_data->cur_thread = latency;

		update_min(&cpu_data->min_thread, &latency);

		update_sum(&cpu_data->sum_thread, &latency);

		update_max(&cpu_data->max_thread, &latency);

	} else {

		cpu_data->user_count++;

		cpu_data->cur_user = latency;

		update_min(&cpu_data->min_user, &latency);

		update_sum(&cpu_data->sum_user, &latency);

		update_max(&cpu_data->max_user, &latency);

	}

}
@@ -172,15 +188,25 @@ static void timerlat_top_header(struct osnoise_tool *top) 


	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");

	trace_seq_printf(s, "\n");



	trace_seq_printf(s, "%-6s   |          IRQ Timer Latency (%s)        |         Thread Timer Latency (%s)\n", duration,

	trace_seq_printf(s, "%-6s   |          IRQ Timer Latency (%s)        |         Thread Timer Latency (%s)", duration,

			params->output_divisor == 1 ? "ns" : "us",

			params->output_divisor == 1 ? "ns" : "us");



	if (params->user_top) {

		trace_seq_printf(s, "      |    Ret user Timer Latency (%s)",

				params->output_divisor == 1 ? "ns" : "us");

	}



	trace_seq_printf(s, "\n");

	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");

	trace_seq_printf(s, "\n");

}
@@ -233,7 +259,27 @@ static void timerlat_top_print(struct osnoise_tool *top, int cpu) 
		trace_seq_printf(s, "%9llu ", cpu_data->min_thread / divisor);

		trace_seq_printf(s, "%9llu ",

				(cpu_data->sum_thread / cpu_data->thread_count) / divisor);

		trace_seq_printf(s, "%9llu\n", cpu_data->max_thread / divisor);

		trace_seq_printf(s, "%9llu", cpu_data->max_thread / divisor);

	}



	if (!params->user_top) {

		trace_seq_printf(s, "\n");

		return;

	}



	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");

	} else {

		trace_seq_printf(s, "%9llu ", cpu_data->cur_user / divisor);

		trace_seq_printf(s, "%9llu ", cpu_data->min_user / divisor);

		trace_seq_printf(s, "%9llu ",

				(cpu_data->sum_user / cpu_data->user_count) / divisor);

		trace_seq_printf(s, "%9llu\n", cpu_data->max_user / divisor);

	}

}
@@ -288,7 +334,7 @@ static void timerlat_top_usage(char *usage) 
		"",

		"  usage: rtla timerlat [top] [-h] [-q] [-a us] [-d s] [-D] [-n] [-p us] [-i us] [-T us] [-s us] \\",

		"	  [[-t[=file]] [-e sys[:event]] [--filter <filter>] [--trigger <trigger>] [-c cpu-list] [-H cpu-list]\\",

		"	  [-P priority] [--dma-latency us] [--aa-only us] [-C[=cgroup_name]]",

		"	  [-P priority] [--dma-latency us] [--aa-only us] [-C[=cgroup_name]] [-u]",

		"",

		"	  -h/--help: print this menu",

		"	  -a/--auto: set automatic trace mode, stopping the session if argument in us latency is hit",
@@ -317,6 +363,7 @@ 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",

		NULL,

	};
@@ -371,6 +418,7 @@ static struct timerlat_top_params 
			{"stack",		required_argument,	0, 's'},

			{"thread",		required_argument,	0, 'T'},

			{"trace",		optional_argument,	0, 't'},

			{"user-threads",	no_argument,		0, 'u'},

			{"trigger",		required_argument,	0, '0'},

			{"filter",		required_argument,	0, '1'},

			{"dma-latency",		required_argument,	0, '2'},
@@ -383,7 +431,7 @@ static struct timerlat_top_params 
		/* 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:0:1:2:345:",

		c = getopt_long(argc, argv, "a:c:C::d:De:hH:i:np:P:qs:t::T:u0:1:2:345:",

				 long_options, &option_index);



		/* detect the end of the options. */
@@ -498,6 +546,9 @@ static struct timerlat_top_params 
			else

				params->trace_output = "timerlat_trace.txt";



			break;

		case 'u':

			params->user_top = true;

			break;

		case '0': /* trigger */

			if (params->events) {
@@ -563,6 +614,7 @@ static int 
timerlat_top_apply_config(struct osnoise_tool *top, struct timerlat_top_params *params)

{

	int retval;

	int i;



	if (!params->sleep_time)

		params->sleep_time = 1;
@@ -573,6 +625,9 @@ timerlat_top_apply_config(struct osnoise_tool *top, struct timerlat_top_params * 
			err_msg("Failed to apply CPUs config\n");

			goto out_err;

		}

	} else {

		for (i = 0; i < sysconf(_SC_NPROCESSORS_CONF); i++)

			CPU_SET(i, &params->monitored_cpus);

	}



	if (params->stop_us) {
@@ -627,6 +682,14 @@ 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 (retval) {

			err_msg("Failed to set OSNOISE_WORKLOAD option\n");

			goto out_err;

		}

	}



	return 0;



out_err:
@@ -687,10 +750,12 @@ int timerlat_top_main(int argc, char *argv[]) 
{

	struct timerlat_top_params *params;

	struct osnoise_tool *record = NULL;

	struct timerlat_u_params params_u;

	struct osnoise_tool *top = NULL;

	struct osnoise_tool *aa = NULL;

	struct trace_instance *trace;

	int dma_latency_fd = -1;

	pthread_t timerlat_u;

	int return_value = 1;

	char *max_lat;

	int retval;
@@ -727,7 +792,7 @@ int timerlat_top_main(int argc, char *argv[]) 
		}

	}



	if (params->cgroup) {

	if (params->cgroup && !params->user_top) {

		retval = set_comm_cgroup("timerlat/", params->cgroup_name);

		if (!retval) {

			err_msg("Failed to move threads to cgroup\n");
@@ -800,6 +865,25 @@ int timerlat_top_main(int argc, char *argv[]) 
	top->start_time = time(NULL);

	timerlat_top_set_signals(params);



	if (params->user_top) {

		/* rtla asked to stop */

		params_u.should_run = 1;

		/* all threads left */

		params_u.stopped_running = 0;



		params_u.set = &params->monitored_cpus;

		if (params->set_sched)

			params_u.sched_param = &params->sched_param;

		else

			params_u.sched_param = NULL;



		params_u.cgroup_name = params->cgroup_name;



		retval = pthread_create(&timerlat_u, NULL, timerlat_u_dispatcher, &params_u);

		if (retval)

			err_msg("Error creating timerlat user-space threads\n");

	}



	while (!stop_tracing) {

		sleep(params->sleep_time);
@@ -823,6 +907,18 @@ int timerlat_top_main(int argc, char *argv[]) 
		if (trace_is_off(&top->trace, &record->trace))

			break;



		/* is there still any user-threads ? */

		if (params->user_top) {

			if (params_u.stopped_running) {

				debug_msg("timerlat user space threads stopped!\n");

				break;

			}

		}

	}



	if (params->user_top && !params_u.stopped_running) {

		params_u.should_run = 0;

		sleep(1);

	}



	timerlat_print_stats(params, top);

tools/tracing/rtla/src/timerlat_u.c

0 → 100644
+224 −0
Original line number Diff line number Diff line 
// SPDX-License-Identifier: GPL-2.0

/*

 * Copyright (C) 2023 Red Hat Inc, Daniel Bristot de Oliveira <bristot@kernel.org>

 */



#define _GNU_SOURCE

#include <sched.h>

#include <fcntl.h>

#include <stdlib.h>

#include <unistd.h>

#include <stdio.h>

#include <errno.h>

#include <string.h>

#include <tracefs.h>

#include <pthread.h>

#include <sys/wait.h>

#include <sys/prctl.h>



#include "utils.h"

#include "timerlat_u.h"



/*

 * This is the user-space main for the tool timerlatu/ threads.

 *

 * It is as simple as this:

 *  - set affinity

 *  - set priority

 *  - open tracer fd

 *  - spin

 *  - close

 */

static int timerlat_u_main(int cpu, struct timerlat_u_params *params)

{

	struct sched_param sp = { .sched_priority = 95 };

	char buffer[1024];

	int timerlat_fd;

	cpu_set_t set;

	int retval;



	/*

	 * This all is only setting up the tool.

	 */

	CPU_ZERO(&set);

	CPU_SET(cpu, &set);



	retval = sched_setaffinity(gettid(), sizeof(set), &set);

	if (retval == -1) {

		err_msg("Error setting user thread affinity\n");

		exit(1);

	}



	if (!params->sched_param) {

		retval = sched_setscheduler(0, SCHED_FIFO, &sp);

		if (retval < 0) {

			err_msg("Error setting timerlat u default priority: %s\n", strerror(errno));

			exit(1);

		}

	} else {

		retval = __set_sched_attr(getpid(), params->sched_param);

		if (retval) {

			/* __set_sched_attr prints an error message, so */

			exit(0);

		}

	}



	if (params->cgroup_name) {

		retval = set_pid_cgroup(gettid(), params->cgroup_name);

		if (!retval) {

			err_msg("Error setting timerlat u cgroup pid\n");

			pthread_exit(&retval);

		}

	}



	/*

	 * This is the tool's loop. If you want to use as base for your own tool...

	 * go ahead.

	 */

	snprintf(buffer, sizeof(buffer), "osnoise/per_cpu/cpu%d/timerlat_fd", cpu);



	timerlat_fd = tracefs_instance_file_open(NULL, buffer, O_RDONLY);

	if (timerlat_fd < 0) {

		err_msg("Error opening %s:%s\n", buffer, strerror(errno));

		exit(1);

	}



	debug_msg("User-space timerlat pid %d on cpu %d\n", gettid(), cpu);



	/* add should continue with a signal handler */

	while (true) {

		retval = read(timerlat_fd, buffer, 1024);

		if (retval < 0)

			break;

	}



	close(timerlat_fd);



	debug_msg("Leaving timerlat pid %d on cpu %d\n", gettid(), cpu);

	exit(0);

}



/*

 * timerlat_u_send_kill - send a kill signal for all processes

 *

 * Return the number of processes that received the kill.

 */

static int timerlat_u_send_kill(pid_t *procs, int nr_cpus)

{

	int killed = 0;

	int i, retval;



	for (i = 0; i < nr_cpus; i++) {

		if (!procs[i])

			continue;

		retval = kill(procs[i], SIGKILL);

		if (!retval)

			killed++;

		else

			err_msg("Error killing child process %d\n", procs[i]);

	}



	return killed;

}



/**

 * timerlat_u_dispatcher - dispatch one timerlatu/ process per monitored CPU

 *

 * This is a thread main that will fork one new process for each monitored

 * CPU. It will wait for:

 *

 *  - rtla to tell to kill the child processes

 *  - some child process to die, and the cleanup all the processes

 *

 * whichever comes first.

 *

 */

void *timerlat_u_dispatcher(void *data)

{

	int nr_cpus = sysconf(_SC_NPROCESSORS_CONF);

	struct timerlat_u_params *params = data;

	char proc_name[128];

	int procs_count = 0;

	int retval = 1;

	pid_t *procs;

	int wstatus;

	pid_t pid;

	int i;



	debug_msg("Dispatching timerlat u procs\n");



	procs = calloc(nr_cpus, sizeof(pid_t));

	if (!procs)

		pthread_exit(&retval);



	for (i = 0; i < nr_cpus; i++) {

		if (params->set && !CPU_ISSET(i, params->set))

			continue;



		pid = fork();



		/* child */

		if (!pid) {



			/*

			 * rename the process

			 */

			snprintf(proc_name, sizeof(proc_name), "timerlatu/%d", i);

			pthread_setname_np(pthread_self(), proc_name);

			prctl(PR_SET_NAME, (unsigned long)proc_name, 0, 0, 0);



			timerlat_u_main(i, params);

			/* timerlat_u_main should exit()! Anyways... */

			pthread_exit(&retval);

		}



		/* parent */

		if (pid == -1) {

			timerlat_u_send_kill(procs, nr_cpus);

			debug_msg("Failed to create child processes");

			pthread_exit(&retval);

		}



		procs_count++;

		procs[i] = pid;

	}



	while (params->should_run) {

		/* check if processes died */

		pid = waitpid(-1, &wstatus, WNOHANG);

		if (pid != 0) {

			for (i = 0; i < nr_cpus; i++) {

				if (procs[i] == pid) {

					procs[i] = 0;

					procs_count--;

				}

			}

			break;

		}



		sleep(1);

	}



	timerlat_u_send_kill(procs, nr_cpus);



	while (procs_count) {

		pid = waitpid(-1, &wstatus, 0);

		if (pid == -1) {

			err_msg("Failed to monitor child processes");

			pthread_exit(&retval);

		}

		for (i = 0; i < nr_cpus; i++) {

			if (procs[i] == pid) {

				procs[i] = 0;

				procs_count--;

			}

		}

	}



	params->stopped_running = 1;



	free(procs);

	retval = 0;

	pthread_exit(&retval);



}

tools/tracing/rtla/src/timerlat_u.h

0 → 100644
+18 −0
Original line number Diff line number Diff line 
// SPDX-License-Identifier: GPL-2.0

/*

 * Copyright (C) 2023 Red Hat Inc, Daniel Bristot de Oliveira <bristot@kernel.org>

 */



struct timerlat_u_params {

	/* timerlat -> timerlat_u: user-space threads can keep running */

	int should_run;

	/* timerlat_u -> timerlat: all timerlat_u threads left, no reason to continue */

	int stopped_running;



	/* threads config */

	cpu_set_t *set;

	char *cgroup_name;

	struct sched_attr *sched_param;

};



void *timerlat_u_dispatcher(void *data);