Path: blob/master/tools/tracing/rtla/src/timerlat_hist.c
29524 views
// SPDX-License-Identifier: GPL-2.01/*2* Copyright (C) 2021 Red Hat Inc, Daniel Bristot de Oliveira <[email protected]>3*/45#define _GNU_SOURCE6#include <getopt.h>7#include <stdlib.h>8#include <string.h>9#include <signal.h>10#include <unistd.h>11#include <stdio.h>12#include <time.h>13#include <sched.h>14#include <pthread.h>1516#include "timerlat.h"17#include "timerlat_aa.h"18#include "timerlat_bpf.h"1920struct timerlat_hist_cpu {21int *irq;22int *thread;23int *user;2425unsigned long long irq_count;26unsigned long long thread_count;27unsigned long long user_count;2829unsigned long long min_irq;30unsigned long long sum_irq;31unsigned long long max_irq;3233unsigned long long min_thread;34unsigned long long sum_thread;35unsigned long long max_thread;3637unsigned long long min_user;38unsigned long long sum_user;39unsigned long long max_user;40};4142struct timerlat_hist_data {43struct timerlat_hist_cpu *hist;44int entries;45int bucket_size;46int nr_cpus;47};4849/*50* timerlat_free_histogram - free runtime data51*/52static void53timerlat_free_histogram(struct timerlat_hist_data *data)54{55int cpu;5657/* one histogram for IRQ and one for thread, per CPU */58for (cpu = 0; cpu < data->nr_cpus; cpu++) {59if (data->hist[cpu].irq)60free(data->hist[cpu].irq);6162if (data->hist[cpu].thread)63free(data->hist[cpu].thread);6465if (data->hist[cpu].user)66free(data->hist[cpu].user);6768}6970/* one set of histograms per CPU */71if (data->hist)72free(data->hist);73}7475static void timerlat_free_histogram_tool(struct osnoise_tool *tool)76{77timerlat_free_histogram(tool->data);78timerlat_free(tool);79}8081/*82* timerlat_alloc_histogram - alloc runtime data83*/84static struct timerlat_hist_data85*timerlat_alloc_histogram(int nr_cpus, int entries, int bucket_size)86{87struct timerlat_hist_data *data;88int cpu;8990data = calloc(1, sizeof(*data));91if (!data)92return NULL;9394data->entries = entries;95data->bucket_size = bucket_size;96data->nr_cpus = nr_cpus;9798/* one set of histograms per CPU */99data->hist = calloc(1, sizeof(*data->hist) * nr_cpus);100if (!data->hist)101goto cleanup;102103/* one histogram for IRQ and one for thread, per cpu */104for (cpu = 0; cpu < nr_cpus; cpu++) {105data->hist[cpu].irq = calloc(1, sizeof(*data->hist->irq) * (entries + 1));106if (!data->hist[cpu].irq)107goto cleanup;108109data->hist[cpu].thread = calloc(1, sizeof(*data->hist->thread) * (entries + 1));110if (!data->hist[cpu].thread)111goto cleanup;112113data->hist[cpu].user = calloc(1, sizeof(*data->hist->user) * (entries + 1));114if (!data->hist[cpu].user)115goto cleanup;116}117118/* set the min to max */119for (cpu = 0; cpu < nr_cpus; cpu++) {120data->hist[cpu].min_irq = ~0;121data->hist[cpu].min_thread = ~0;122data->hist[cpu].min_user = ~0;123}124125return data;126127cleanup:128timerlat_free_histogram(data);129return NULL;130}131132/*133* timerlat_hist_update - record a new timerlat occurent on cpu, updating data134*/135static void136timerlat_hist_update(struct osnoise_tool *tool, int cpu,137unsigned long long context,138unsigned long long latency)139{140struct timerlat_params *params = to_timerlat_params(tool->params);141struct timerlat_hist_data *data = tool->data;142int entries = data->entries;143int bucket;144int *hist;145146if (params->common.output_divisor)147latency = latency / params->common.output_divisor;148149bucket = latency / data->bucket_size;150151if (!context) {152hist = data->hist[cpu].irq;153data->hist[cpu].irq_count++;154update_min(&data->hist[cpu].min_irq, &latency);155update_sum(&data->hist[cpu].sum_irq, &latency);156update_max(&data->hist[cpu].max_irq, &latency);157} else if (context == 1) {158hist = data->hist[cpu].thread;159data->hist[cpu].thread_count++;160update_min(&data->hist[cpu].min_thread, &latency);161update_sum(&data->hist[cpu].sum_thread, &latency);162update_max(&data->hist[cpu].max_thread, &latency);163} else { /* user */164hist = data->hist[cpu].user;165data->hist[cpu].user_count++;166update_min(&data->hist[cpu].min_user, &latency);167update_sum(&data->hist[cpu].sum_user, &latency);168update_max(&data->hist[cpu].max_user, &latency);169}170171if (bucket < entries)172hist[bucket]++;173else174hist[entries]++;175}176177/*178* timerlat_hist_handler - this is the handler for timerlat tracer events179*/180static int181timerlat_hist_handler(struct trace_seq *s, struct tep_record *record,182struct tep_event *event, void *data)183{184struct trace_instance *trace = data;185unsigned long long context, latency;186struct osnoise_tool *tool;187int cpu = record->cpu;188189tool = container_of(trace, struct osnoise_tool, trace);190191tep_get_field_val(s, event, "context", record, &context, 1);192tep_get_field_val(s, event, "timer_latency", record, &latency, 1);193194timerlat_hist_update(tool, cpu, context, latency);195196return 0;197}198199/*200* timerlat_hist_bpf_pull_data - copy data from BPF maps into userspace201*/202static int timerlat_hist_bpf_pull_data(struct osnoise_tool *tool)203{204struct timerlat_hist_data *data = tool->data;205int i, j, err;206long long value_irq[data->nr_cpus],207value_thread[data->nr_cpus],208value_user[data->nr_cpus];209210/* Pull histogram */211for (i = 0; i < data->entries; i++) {212err = timerlat_bpf_get_hist_value(i, value_irq, value_thread,213value_user, data->nr_cpus);214if (err)215return err;216for (j = 0; j < data->nr_cpus; j++) {217data->hist[j].irq[i] = value_irq[j];218data->hist[j].thread[i] = value_thread[j];219data->hist[j].user[i] = value_user[j];220}221}222223/* Pull summary */224err = timerlat_bpf_get_summary_value(SUMMARY_COUNT,225value_irq, value_thread, value_user,226data->nr_cpus);227if (err)228return err;229for (i = 0; i < data->nr_cpus; i++) {230data->hist[i].irq_count = value_irq[i];231data->hist[i].thread_count = value_thread[i];232data->hist[i].user_count = value_user[i];233}234235err = timerlat_bpf_get_summary_value(SUMMARY_MIN,236value_irq, value_thread, value_user,237data->nr_cpus);238if (err)239return err;240for (i = 0; i < data->nr_cpus; i++) {241data->hist[i].min_irq = value_irq[i];242data->hist[i].min_thread = value_thread[i];243data->hist[i].min_user = value_user[i];244}245246err = timerlat_bpf_get_summary_value(SUMMARY_MAX,247value_irq, value_thread, value_user,248data->nr_cpus);249if (err)250return err;251for (i = 0; i < data->nr_cpus; i++) {252data->hist[i].max_irq = value_irq[i];253data->hist[i].max_thread = value_thread[i];254data->hist[i].max_user = value_user[i];255}256257err = timerlat_bpf_get_summary_value(SUMMARY_SUM,258value_irq, value_thread, value_user,259data->nr_cpus);260if (err)261return err;262for (i = 0; i < data->nr_cpus; i++) {263data->hist[i].sum_irq = value_irq[i];264data->hist[i].sum_thread = value_thread[i];265data->hist[i].sum_user = value_user[i];266}267268err = timerlat_bpf_get_summary_value(SUMMARY_OVERFLOW,269value_irq, value_thread, value_user,270data->nr_cpus);271if (err)272return err;273for (i = 0; i < data->nr_cpus; i++) {274data->hist[i].irq[data->entries] = value_irq[i];275data->hist[i].thread[data->entries] = value_thread[i];276data->hist[i].user[data->entries] = value_user[i];277}278279return 0;280}281282/*283* timerlat_hist_header - print the header of the tracer to the output284*/285static void timerlat_hist_header(struct osnoise_tool *tool)286{287struct timerlat_params *params = to_timerlat_params(tool->params);288struct timerlat_hist_data *data = tool->data;289struct trace_seq *s = tool->trace.seq;290char duration[26];291int cpu;292293if (params->common.hist.no_header)294return;295296get_duration(tool->start_time, duration, sizeof(duration));297trace_seq_printf(s, "# RTLA timerlat histogram\n");298trace_seq_printf(s, "# Time unit is %s (%s)\n",299params->common.output_divisor == 1 ? "nanoseconds" : "microseconds",300params->common.output_divisor == 1 ? "ns" : "us");301302trace_seq_printf(s, "# Duration: %s\n", duration);303304if (!params->common.hist.no_index)305trace_seq_printf(s, "Index");306307for (cpu = 0; cpu < data->nr_cpus; cpu++) {308if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus))309continue;310311if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)312continue;313314if (!params->common.hist.no_irq)315trace_seq_printf(s, " IRQ-%03d", cpu);316317if (!params->common.hist.no_thread)318trace_seq_printf(s, " Thr-%03d", cpu);319320if (params->common.user_data)321trace_seq_printf(s, " Usr-%03d", cpu);322}323trace_seq_printf(s, "\n");324325326trace_seq_do_printf(s);327trace_seq_reset(s);328}329330/*331* format_summary_value - format a line of summary value (min, max or avg)332* of hist data333*/334static void format_summary_value(struct trace_seq *seq,335int count,336unsigned long long val,337bool avg)338{339if (count)340trace_seq_printf(seq, "%9llu ", avg ? val / count : val);341else342trace_seq_printf(seq, "%9c ", '-');343}344345/*346* timerlat_print_summary - print the summary of the hist data to the output347*/348static void349timerlat_print_summary(struct timerlat_params *params,350struct trace_instance *trace,351struct timerlat_hist_data *data)352{353int cpu;354355if (params->common.hist.no_summary)356return;357358if (!params->common.hist.no_index)359trace_seq_printf(trace->seq, "count:");360361for (cpu = 0; cpu < data->nr_cpus; cpu++) {362if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus))363continue;364365if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)366continue;367368if (!params->common.hist.no_irq)369trace_seq_printf(trace->seq, "%9llu ",370data->hist[cpu].irq_count);371372if (!params->common.hist.no_thread)373trace_seq_printf(trace->seq, "%9llu ",374data->hist[cpu].thread_count);375376if (params->common.user_data)377trace_seq_printf(trace->seq, "%9llu ",378data->hist[cpu].user_count);379}380trace_seq_printf(trace->seq, "\n");381382if (!params->common.hist.no_index)383trace_seq_printf(trace->seq, "min: ");384385for (cpu = 0; cpu < data->nr_cpus; cpu++) {386if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus))387continue;388389if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)390continue;391392if (!params->common.hist.no_irq)393format_summary_value(trace->seq,394data->hist[cpu].irq_count,395data->hist[cpu].min_irq,396false);397398if (!params->common.hist.no_thread)399format_summary_value(trace->seq,400data->hist[cpu].thread_count,401data->hist[cpu].min_thread,402false);403404if (params->common.user_data)405format_summary_value(trace->seq,406data->hist[cpu].user_count,407data->hist[cpu].min_user,408false);409}410trace_seq_printf(trace->seq, "\n");411412if (!params->common.hist.no_index)413trace_seq_printf(trace->seq, "avg: ");414415for (cpu = 0; cpu < data->nr_cpus; cpu++) {416if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus))417continue;418419if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)420continue;421422if (!params->common.hist.no_irq)423format_summary_value(trace->seq,424data->hist[cpu].irq_count,425data->hist[cpu].sum_irq,426true);427428if (!params->common.hist.no_thread)429format_summary_value(trace->seq,430data->hist[cpu].thread_count,431data->hist[cpu].sum_thread,432true);433434if (params->common.user_data)435format_summary_value(trace->seq,436data->hist[cpu].user_count,437data->hist[cpu].sum_user,438true);439}440trace_seq_printf(trace->seq, "\n");441442if (!params->common.hist.no_index)443trace_seq_printf(trace->seq, "max: ");444445for (cpu = 0; cpu < data->nr_cpus; cpu++) {446if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus))447continue;448449if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)450continue;451452if (!params->common.hist.no_irq)453format_summary_value(trace->seq,454data->hist[cpu].irq_count,455data->hist[cpu].max_irq,456false);457458if (!params->common.hist.no_thread)459format_summary_value(trace->seq,460data->hist[cpu].thread_count,461data->hist[cpu].max_thread,462false);463464if (params->common.user_data)465format_summary_value(trace->seq,466data->hist[cpu].user_count,467data->hist[cpu].max_user,468false);469}470trace_seq_printf(trace->seq, "\n");471trace_seq_do_printf(trace->seq);472trace_seq_reset(trace->seq);473}474475static void476timerlat_print_stats_all(struct timerlat_params *params,477struct trace_instance *trace,478struct timerlat_hist_data *data)479{480struct timerlat_hist_cpu *cpu_data;481struct timerlat_hist_cpu sum;482int cpu;483484if (params->common.hist.no_summary)485return;486487memset(&sum, 0, sizeof(sum));488sum.min_irq = ~0;489sum.min_thread = ~0;490sum.min_user = ~0;491492for (cpu = 0; cpu < data->nr_cpus; cpu++) {493if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus))494continue;495496if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)497continue;498499cpu_data = &data->hist[cpu];500501sum.irq_count += cpu_data->irq_count;502update_min(&sum.min_irq, &cpu_data->min_irq);503update_sum(&sum.sum_irq, &cpu_data->sum_irq);504update_max(&sum.max_irq, &cpu_data->max_irq);505506sum.thread_count += cpu_data->thread_count;507update_min(&sum.min_thread, &cpu_data->min_thread);508update_sum(&sum.sum_thread, &cpu_data->sum_thread);509update_max(&sum.max_thread, &cpu_data->max_thread);510511sum.user_count += cpu_data->user_count;512update_min(&sum.min_user, &cpu_data->min_user);513update_sum(&sum.sum_user, &cpu_data->sum_user);514update_max(&sum.max_user, &cpu_data->max_user);515}516517if (!params->common.hist.no_index)518trace_seq_printf(trace->seq, "ALL: ");519520if (!params->common.hist.no_irq)521trace_seq_printf(trace->seq, " IRQ");522523if (!params->common.hist.no_thread)524trace_seq_printf(trace->seq, " Thr");525526if (params->common.user_data)527trace_seq_printf(trace->seq, " Usr");528529trace_seq_printf(trace->seq, "\n");530531if (!params->common.hist.no_index)532trace_seq_printf(trace->seq, "count:");533534if (!params->common.hist.no_irq)535trace_seq_printf(trace->seq, "%9llu ",536sum.irq_count);537538if (!params->common.hist.no_thread)539trace_seq_printf(trace->seq, "%9llu ",540sum.thread_count);541542if (params->common.user_data)543trace_seq_printf(trace->seq, "%9llu ",544sum.user_count);545546trace_seq_printf(trace->seq, "\n");547548if (!params->common.hist.no_index)549trace_seq_printf(trace->seq, "min: ");550551if (!params->common.hist.no_irq)552format_summary_value(trace->seq,553sum.irq_count,554sum.min_irq,555false);556557if (!params->common.hist.no_thread)558format_summary_value(trace->seq,559sum.thread_count,560sum.min_thread,561false);562563if (params->common.user_data)564format_summary_value(trace->seq,565sum.user_count,566sum.min_user,567false);568569trace_seq_printf(trace->seq, "\n");570571if (!params->common.hist.no_index)572trace_seq_printf(trace->seq, "avg: ");573574if (!params->common.hist.no_irq)575format_summary_value(trace->seq,576sum.irq_count,577sum.sum_irq,578true);579580if (!params->common.hist.no_thread)581format_summary_value(trace->seq,582sum.thread_count,583sum.sum_thread,584true);585586if (params->common.user_data)587format_summary_value(trace->seq,588sum.user_count,589sum.sum_user,590true);591592trace_seq_printf(trace->seq, "\n");593594if (!params->common.hist.no_index)595trace_seq_printf(trace->seq, "max: ");596597if (!params->common.hist.no_irq)598format_summary_value(trace->seq,599sum.irq_count,600sum.max_irq,601false);602603if (!params->common.hist.no_thread)604format_summary_value(trace->seq,605sum.thread_count,606sum.max_thread,607false);608609if (params->common.user_data)610format_summary_value(trace->seq,611sum.user_count,612sum.max_user,613false);614615trace_seq_printf(trace->seq, "\n");616trace_seq_do_printf(trace->seq);617trace_seq_reset(trace->seq);618}619620/*621* timerlat_print_stats - print data for each CPUs622*/623static void624timerlat_print_stats(struct osnoise_tool *tool)625{626struct timerlat_params *params = to_timerlat_params(tool->params);627struct timerlat_hist_data *data = tool->data;628struct trace_instance *trace = &tool->trace;629int bucket, cpu;630int total;631632timerlat_hist_header(tool);633634for (bucket = 0; bucket < data->entries; bucket++) {635total = 0;636637if (!params->common.hist.no_index)638trace_seq_printf(trace->seq, "%-6d",639bucket * data->bucket_size);640641for (cpu = 0; cpu < data->nr_cpus; cpu++) {642if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus))643continue;644645if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)646continue;647648if (!params->common.hist.no_irq) {649total += data->hist[cpu].irq[bucket];650trace_seq_printf(trace->seq, "%9d ",651data->hist[cpu].irq[bucket]);652}653654if (!params->common.hist.no_thread) {655total += data->hist[cpu].thread[bucket];656trace_seq_printf(trace->seq, "%9d ",657data->hist[cpu].thread[bucket]);658}659660if (params->common.user_data) {661total += data->hist[cpu].user[bucket];662trace_seq_printf(trace->seq, "%9d ",663data->hist[cpu].user[bucket]);664}665666}667668if (total == 0 && !params->common.hist.with_zeros) {669trace_seq_reset(trace->seq);670continue;671}672673trace_seq_printf(trace->seq, "\n");674trace_seq_do_printf(trace->seq);675trace_seq_reset(trace->seq);676}677678if (!params->common.hist.no_index)679trace_seq_printf(trace->seq, "over: ");680681for (cpu = 0; cpu < data->nr_cpus; cpu++) {682if (params->common.cpus && !CPU_ISSET(cpu, ¶ms->common.monitored_cpus))683continue;684685if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)686continue;687688if (!params->common.hist.no_irq)689trace_seq_printf(trace->seq, "%9d ",690data->hist[cpu].irq[data->entries]);691692if (!params->common.hist.no_thread)693trace_seq_printf(trace->seq, "%9d ",694data->hist[cpu].thread[data->entries]);695696if (params->common.user_data)697trace_seq_printf(trace->seq, "%9d ",698data->hist[cpu].user[data->entries]);699}700trace_seq_printf(trace->seq, "\n");701trace_seq_do_printf(trace->seq);702trace_seq_reset(trace->seq);703704timerlat_print_summary(params, trace, data);705timerlat_print_stats_all(params, trace, data);706osnoise_report_missed_events(tool);707}708709/*710* timerlat_hist_usage - prints timerlat top usage message711*/712static void timerlat_hist_usage(char *usage)713{714int i;715716char *msg[] = {717"",718" usage: [rtla] timerlat hist [-h] [-q] [-d s] [-D] [-n] [-a us] [-p us] [-i us] [-T us] [-s us] \\",719" [-t[file]] [-e sys[:event]] [--filter <filter>] [--trigger <trigger>] [-c cpu-list] [-H cpu-list]\\",720" [-P priority] [-E N] [-b N] [--no-irq] [--no-thread] [--no-header] [--no-summary] \\",721" [--no-index] [--with-zeros] [--dma-latency us] [-C[=cgroup_name]] [--no-aa] [--dump-task] [-u|-k]",722" [--warm-up s] [--deepest-idle-state n]",723"",724" -h/--help: print this menu",725" -a/--auto: set automatic trace mode, stopping the session if argument in us latency is hit",726" -p/--period us: timerlat period in us",727" -i/--irq us: stop trace if the irq latency is higher than the argument in us",728" -T/--thread us: stop trace if the thread latency is higher than the argument in us",729" -s/--stack us: save the stack trace at the IRQ if a thread latency is higher than the argument in us",730" -c/--cpus cpus: run the tracer only on the given cpus",731" -H/--house-keeping cpus: run rtla control threads only on the given cpus",732" -C/--cgroup[=cgroup_name]: set cgroup, if no cgroup_name is passed, the rtla's cgroup will be inherited",733" -d/--duration time[m|h|d]: duration of the session in seconds",734" --dump-tasks: prints the task running on all CPUs if stop conditions are met (depends on !--no-aa)",735" -D/--debug: print debug info",736" -t/--trace[file]: save the stopped trace to [file|timerlat_trace.txt]",737" -e/--event <sys:event>: enable the <sys:event> in the trace instance, multiple -e are allowed",738" --filter <filter>: enable a trace event filter to the previous -e event",739" --trigger <trigger>: enable a trace event trigger to the previous -e event",740" -n/--nano: display data in nanoseconds",741" --no-aa: disable auto-analysis, reducing rtla timerlat cpu usage",742" -b/--bucket-size N: set the histogram bucket size (default 1)",743" -E/--entries N: set the number of entries of the histogram (default 256)",744" --no-irq: ignore IRQ latencies",745" --no-thread: ignore thread latencies",746" --no-header: do not print header",747" --no-summary: do not print summary",748" --no-index: do not print index",749" --with-zeros: print zero only entries",750" --dma-latency us: set /dev/cpu_dma_latency latency <us> to reduce exit from idle latency",751" -P/--priority o:prio|r:prio|f:prio|d:runtime:period : set scheduling parameters",752" o:prio - use SCHED_OTHER with prio",753" r:prio - use SCHED_RR with prio",754" f:prio - use SCHED_FIFO with prio",755" d:runtime[us|ms|s]:period[us|ms|s] - use SCHED_DEADLINE with runtime and period",756" in nanoseconds",757" -u/--user-threads: use rtla user-space threads instead of kernel-space timerlat threads",758" -k/--kernel-threads: use timerlat kernel-space threads instead of rtla user-space threads",759" -U/--user-load: enable timerlat for user-defined user-space workload",760" --warm-up s: let the workload run for s seconds before collecting data",761" --trace-buffer-size kB: set the per-cpu trace buffer size in kB",762" --deepest-idle-state n: only go down to idle state n on cpus used by timerlat to reduce exit from idle latency",763" --on-threshold <action>: define action to be executed at latency threshold, multiple are allowed",764" --on-end <action>: define action to be executed at measurement end, multiple are allowed",765NULL,766};767768if (usage)769fprintf(stderr, "%s\n", usage);770771fprintf(stderr, "rtla timerlat hist: a per-cpu histogram of the timer latency (version %s)\n",772VERSION);773774for (i = 0; msg[i]; i++)775fprintf(stderr, "%s\n", msg[i]);776777if (usage)778exit(EXIT_FAILURE);779780exit(EXIT_SUCCESS);781}782783/*784* timerlat_hist_parse_args - allocs, parse and fill the cmd line parameters785*/786static struct common_params787*timerlat_hist_parse_args(int argc, char *argv[])788{789struct timerlat_params *params;790struct trace_events *tevent;791int auto_thresh;792int retval;793int c;794char *trace_output = NULL;795796params = calloc(1, sizeof(*params));797if (!params)798exit(1);799800actions_init(¶ms->common.threshold_actions);801actions_init(¶ms->common.end_actions);802803/* disabled by default */804params->dma_latency = -1;805806/* disabled by default */807params->deepest_idle_state = -2;808809/* display data in microseconds */810params->common.output_divisor = 1000;811params->common.hist.bucket_size = 1;812params->common.hist.entries = 256;813814/* default to BPF mode */815params->mode = TRACING_MODE_BPF;816817while (1) {818static struct option long_options[] = {819{"auto", required_argument, 0, 'a'},820{"cpus", required_argument, 0, 'c'},821{"cgroup", optional_argument, 0, 'C'},822{"bucket-size", required_argument, 0, 'b'},823{"debug", no_argument, 0, 'D'},824{"entries", required_argument, 0, 'E'},825{"duration", required_argument, 0, 'd'},826{"house-keeping", required_argument, 0, 'H'},827{"help", no_argument, 0, 'h'},828{"irq", required_argument, 0, 'i'},829{"nano", no_argument, 0, 'n'},830{"period", required_argument, 0, 'p'},831{"priority", required_argument, 0, 'P'},832{"stack", required_argument, 0, 's'},833{"thread", required_argument, 0, 'T'},834{"trace", optional_argument, 0, 't'},835{"user-threads", no_argument, 0, 'u'},836{"kernel-threads", no_argument, 0, 'k'},837{"user-load", no_argument, 0, 'U'},838{"event", required_argument, 0, 'e'},839{"no-irq", no_argument, 0, '0'},840{"no-thread", no_argument, 0, '1'},841{"no-header", no_argument, 0, '2'},842{"no-summary", no_argument, 0, '3'},843{"no-index", no_argument, 0, '4'},844{"with-zeros", no_argument, 0, '5'},845{"trigger", required_argument, 0, '6'},846{"filter", required_argument, 0, '7'},847{"dma-latency", required_argument, 0, '8'},848{"no-aa", no_argument, 0, '9'},849{"dump-task", no_argument, 0, '\1'},850{"warm-up", required_argument, 0, '\2'},851{"trace-buffer-size", required_argument, 0, '\3'},852{"deepest-idle-state", required_argument, 0, '\4'},853{"on-threshold", required_argument, 0, '\5'},854{"on-end", required_argument, 0, '\6'},855{0, 0, 0, 0}856};857858/* getopt_long stores the option index here. */859int option_index = 0;860861c = getopt_long(argc, argv, "a:c:C::b:d:e:E:DhH:i:knp:P:s:t::T:uU0123456:7:8:9\1\2:\3:",862long_options, &option_index);863864/* detect the end of the options. */865if (c == -1)866break;867868switch (c) {869case 'a':870auto_thresh = get_llong_from_str(optarg);871872/* set thread stop to auto_thresh */873params->common.stop_total_us = auto_thresh;874params->common.stop_us = auto_thresh;875876/* get stack trace */877params->print_stack = auto_thresh;878879/* set trace */880trace_output = "timerlat_trace.txt";881882break;883case 'c':884retval = parse_cpu_set(optarg, ¶ms->common.monitored_cpus);885if (retval)886timerlat_hist_usage("\nInvalid -c cpu list\n");887params->common.cpus = optarg;888break;889case 'C':890params->common.cgroup = 1;891if (!optarg) {892/* will inherit this cgroup */893params->common.cgroup_name = NULL;894} else if (*optarg == '=') {895/* skip the = */896params->common.cgroup_name = ++optarg;897}898break;899case 'b':900params->common.hist.bucket_size = get_llong_from_str(optarg);901if (params->common.hist.bucket_size == 0 ||902params->common.hist.bucket_size >= 1000000)903timerlat_hist_usage("Bucket size needs to be > 0 and <= 1000000\n");904break;905case 'D':906config_debug = 1;907break;908case 'd':909params->common.duration = parse_seconds_duration(optarg);910if (!params->common.duration)911timerlat_hist_usage("Invalid -D duration\n");912break;913case 'e':914tevent = trace_event_alloc(optarg);915if (!tevent) {916err_msg("Error alloc trace event");917exit(EXIT_FAILURE);918}919920if (params->common.events)921tevent->next = params->common.events;922923params->common.events = tevent;924break;925case 'E':926params->common.hist.entries = get_llong_from_str(optarg);927if (params->common.hist.entries < 10 ||928params->common.hist.entries > 9999999)929timerlat_hist_usage("Entries must be > 10 and < 9999999\n");930break;931case 'h':932case '?':933timerlat_hist_usage(NULL);934break;935case 'H':936params->common.hk_cpus = 1;937retval = parse_cpu_set(optarg, ¶ms->common.hk_cpu_set);938if (retval) {939err_msg("Error parsing house keeping CPUs\n");940exit(EXIT_FAILURE);941}942break;943case 'i':944params->common.stop_us = get_llong_from_str(optarg);945break;946case 'k':947params->common.kernel_workload = 1;948break;949case 'n':950params->common.output_divisor = 1;951break;952case 'p':953params->timerlat_period_us = get_llong_from_str(optarg);954if (params->timerlat_period_us > 1000000)955timerlat_hist_usage("Period longer than 1 s\n");956break;957case 'P':958retval = parse_prio(optarg, ¶ms->common.sched_param);959if (retval == -1)960timerlat_hist_usage("Invalid -P priority");961params->common.set_sched = 1;962break;963case 's':964params->print_stack = get_llong_from_str(optarg);965break;966case 'T':967params->common.stop_total_us = get_llong_from_str(optarg);968break;969case 't':970if (optarg) {971if (optarg[0] == '=')972trace_output = &optarg[1];973else974trace_output = &optarg[0];975} else if (optind < argc && argv[optind][0] != '-')976trace_output = argv[optind];977else978trace_output = "timerlat_trace.txt";979break;980case 'u':981params->common.user_workload = 1;982/* fallback: -u implies in -U */983case 'U':984params->common.user_data = 1;985break;986case '0': /* no irq */987params->common.hist.no_irq = 1;988break;989case '1': /* no thread */990params->common.hist.no_thread = 1;991break;992case '2': /* no header */993params->common.hist.no_header = 1;994break;995case '3': /* no summary */996params->common.hist.no_summary = 1;997break;998case '4': /* no index */999params->common.hist.no_index = 1;1000break;1001case '5': /* with zeros */1002params->common.hist.with_zeros = 1;1003break;1004case '6': /* trigger */1005if (params->common.events) {1006retval = trace_event_add_trigger(params->common.events, optarg);1007if (retval) {1008err_msg("Error adding trigger %s\n", optarg);1009exit(EXIT_FAILURE);1010}1011} else {1012timerlat_hist_usage("--trigger requires a previous -e\n");1013}1014break;1015case '7': /* filter */1016if (params->common.events) {1017retval = trace_event_add_filter(params->common.events, optarg);1018if (retval) {1019err_msg("Error adding filter %s\n", optarg);1020exit(EXIT_FAILURE);1021}1022} else {1023timerlat_hist_usage("--filter requires a previous -e\n");1024}1025break;1026case '8':1027params->dma_latency = get_llong_from_str(optarg);1028if (params->dma_latency < 0 || params->dma_latency > 10000) {1029err_msg("--dma-latency needs to be >= 0 and < 10000");1030exit(EXIT_FAILURE);1031}1032break;1033case '9':1034params->no_aa = 1;1035break;1036case '\1':1037params->dump_tasks = 1;1038break;1039case '\2':1040params->common.warmup = get_llong_from_str(optarg);1041break;1042case '\3':1043params->common.buffer_size = get_llong_from_str(optarg);1044break;1045case '\4':1046params->deepest_idle_state = get_llong_from_str(optarg);1047break;1048case '\5':1049retval = actions_parse(¶ms->common.threshold_actions, optarg,1050"timerlat_trace.txt");1051if (retval) {1052err_msg("Invalid action %s\n", optarg);1053exit(EXIT_FAILURE);1054}1055break;1056case '\6':1057retval = actions_parse(¶ms->common.end_actions, optarg,1058"timerlat_trace.txt");1059if (retval) {1060err_msg("Invalid action %s\n", optarg);1061exit(EXIT_FAILURE);1062}1063break;1064default:1065timerlat_hist_usage("Invalid option");1066}1067}10681069if (trace_output)1070actions_add_trace_output(¶ms->common.threshold_actions, trace_output);10711072if (geteuid()) {1073err_msg("rtla needs root permission\n");1074exit(EXIT_FAILURE);1075}10761077if (params->common.hist.no_irq && params->common.hist.no_thread)1078timerlat_hist_usage("no-irq and no-thread set, there is nothing to do here");10791080if (params->common.hist.no_index && !params->common.hist.with_zeros)1081timerlat_hist_usage("no-index set with with-zeros is not set - it does not make sense");10821083/*1084* Auto analysis only happens if stop tracing, thus:1085*/1086if (!params->common.stop_us && !params->common.stop_total_us)1087params->no_aa = 1;10881089if (params->common.kernel_workload && params->common.user_workload)1090timerlat_hist_usage("--kernel-threads and --user-threads are mutually exclusive!");10911092/*1093* If auto-analysis or trace output is enabled, switch from BPF mode to1094* mixed mode1095*/1096if (params->mode == TRACING_MODE_BPF &&1097(params->common.threshold_actions.present[ACTION_TRACE_OUTPUT] ||1098params->common.end_actions.present[ACTION_TRACE_OUTPUT] ||1099!params->no_aa))1100params->mode = TRACING_MODE_MIXED;11011102return ¶ms->common;1103}11041105/*1106* timerlat_hist_apply_config - apply the hist configs to the initialized tool1107*/1108static int1109timerlat_hist_apply_config(struct osnoise_tool *tool)1110{1111struct timerlat_params *params = to_timerlat_params(tool->params);1112int retval;11131114retval = timerlat_apply_config(tool, params);1115if (retval)1116goto out_err;11171118return 0;11191120out_err:1121return -1;1122}11231124/*1125* timerlat_init_hist - initialize a timerlat hist tool with parameters1126*/1127static struct osnoise_tool1128*timerlat_init_hist(struct common_params *params)1129{1130struct osnoise_tool *tool;1131int nr_cpus;11321133nr_cpus = sysconf(_SC_NPROCESSORS_CONF);11341135tool = osnoise_init_tool("timerlat_hist");1136if (!tool)1137return NULL;11381139tool->data = timerlat_alloc_histogram(nr_cpus, params->hist.entries,1140params->hist.bucket_size);1141if (!tool->data)1142goto out_err;11431144tep_register_event_handler(tool->trace.tep, -1, "ftrace", "timerlat",1145timerlat_hist_handler, tool);11461147return tool;11481149out_err:1150osnoise_destroy_tool(tool);1151return NULL;1152}11531154static int timerlat_hist_bpf_main_loop(struct osnoise_tool *tool)1155{1156struct timerlat_params *params = to_timerlat_params(tool->params);1157int retval;11581159while (!stop_tracing) {1160timerlat_bpf_wait(-1);11611162if (!stop_tracing) {1163/* Threshold overflow, perform actions on threshold */1164actions_perform(¶ms->common.threshold_actions);11651166if (!params->common.threshold_actions.continue_flag)1167/* continue flag not set, break */1168break;11691170/* continue action reached, re-enable tracing */1171if (tool->record)1172trace_instance_start(&tool->record->trace);1173if (tool->aa)1174trace_instance_start(&tool->aa->trace);1175timerlat_bpf_restart_tracing();1176}1177}1178timerlat_bpf_detach();11791180retval = timerlat_hist_bpf_pull_data(tool);1181if (retval)1182err_msg("Error pulling BPF data\n");11831184return retval;1185}11861187static int timerlat_hist_main(struct osnoise_tool *tool)1188{1189struct timerlat_params *params = to_timerlat_params(tool->params);1190int retval;11911192if (params->mode == TRACING_MODE_TRACEFS)1193retval = hist_main_loop(tool);1194else1195retval = timerlat_hist_bpf_main_loop(tool);11961197return retval;1198}11991200struct tool_ops timerlat_hist_ops = {1201.tracer = "timerlat",1202.comm_prefix = "timerlat/",1203.parse_args = timerlat_hist_parse_args,1204.init_tool = timerlat_init_hist,1205.apply_config = timerlat_hist_apply_config,1206.enable = timerlat_enable,1207.main = timerlat_hist_main,1208.print_stats = timerlat_print_stats,1209.analyze = timerlat_analyze,1210.free = timerlat_free_histogram_tool,1211};121212131214