1346 lines · c
1// SPDX-License-Identifier: GPL-2.02/*3 * Copyright (C) 2021 Red Hat Inc, Daniel Bristot de Oliveira <bristot@kernel.org>4 */5 6#define _GNU_SOURCE7#include <getopt.h>8#include <stdlib.h>9#include <string.h>10#include <signal.h>11#include <unistd.h>12#include <stdio.h>13#include <time.h>14#include <sched.h>15#include <pthread.h>16 17#include "utils.h"18#include "osnoise.h"19#include "timerlat.h"20#include "timerlat_aa.h"21#include "timerlat_u.h"22 23struct timerlat_hist_params {24 char *cpus;25 cpu_set_t monitored_cpus;26 char *trace_output;27 char *cgroup_name;28 unsigned long long runtime;29 long long stop_us;30 long long stop_total_us;31 long long timerlat_period_us;32 long long print_stack;33 int sleep_time;34 int output_divisor;35 int duration;36 int set_sched;37 int dma_latency;38 int cgroup;39 int hk_cpus;40 int no_aa;41 int dump_tasks;42 int user_workload;43 int kernel_workload;44 int user_hist;45 cpu_set_t hk_cpu_set;46 struct sched_attr sched_param;47 struct trace_events *events;48 char no_irq;49 char no_thread;50 char no_header;51 char no_summary;52 char no_index;53 char with_zeros;54 int bucket_size;55 int entries;56 int warmup;57 int buffer_size;58};59 60struct timerlat_hist_cpu {61 int *irq;62 int *thread;63 int *user;64 65 int irq_count;66 int thread_count;67 int user_count;68 69 unsigned long long min_irq;70 unsigned long long sum_irq;71 unsigned long long max_irq;72 73 unsigned long long min_thread;74 unsigned long long sum_thread;75 unsigned long long max_thread;76 77 unsigned long long min_user;78 unsigned long long sum_user;79 unsigned long long max_user;80};81 82struct timerlat_hist_data {83 struct timerlat_hist_cpu *hist;84 int entries;85 int bucket_size;86 int nr_cpus;87};88 89/*90 * timerlat_free_histogram - free runtime data91 */92static void93timerlat_free_histogram(struct timerlat_hist_data *data)94{95 int cpu;96 97 /* one histogram for IRQ and one for thread, per CPU */98 for (cpu = 0; cpu < data->nr_cpus; cpu++) {99 if (data->hist[cpu].irq)100 free(data->hist[cpu].irq);101 102 if (data->hist[cpu].thread)103 free(data->hist[cpu].thread);104 105 if (data->hist[cpu].user)106 free(data->hist[cpu].user);107 108 }109 110 /* one set of histograms per CPU */111 if (data->hist)112 free(data->hist);113 114 free(data);115}116 117/*118 * timerlat_alloc_histogram - alloc runtime data119 */120static struct timerlat_hist_data121*timerlat_alloc_histogram(int nr_cpus, int entries, int bucket_size)122{123 struct timerlat_hist_data *data;124 int cpu;125 126 data = calloc(1, sizeof(*data));127 if (!data)128 return NULL;129 130 data->entries = entries;131 data->bucket_size = bucket_size;132 data->nr_cpus = nr_cpus;133 134 /* one set of histograms per CPU */135 data->hist = calloc(1, sizeof(*data->hist) * nr_cpus);136 if (!data->hist)137 goto cleanup;138 139 /* one histogram for IRQ and one for thread, per cpu */140 for (cpu = 0; cpu < nr_cpus; cpu++) {141 data->hist[cpu].irq = calloc(1, sizeof(*data->hist->irq) * (entries + 1));142 if (!data->hist[cpu].irq)143 goto cleanup;144 145 data->hist[cpu].thread = calloc(1, sizeof(*data->hist->thread) * (entries + 1));146 if (!data->hist[cpu].thread)147 goto cleanup;148 149 data->hist[cpu].user = calloc(1, sizeof(*data->hist->user) * (entries + 1));150 if (!data->hist[cpu].user)151 goto cleanup;152 }153 154 /* set the min to max */155 for (cpu = 0; cpu < nr_cpus; cpu++) {156 data->hist[cpu].min_irq = ~0;157 data->hist[cpu].min_thread = ~0;158 data->hist[cpu].min_user = ~0;159 }160 161 return data;162 163cleanup:164 timerlat_free_histogram(data);165 return NULL;166}167 168/*169 * timerlat_hist_update - record a new timerlat occurent on cpu, updating data170 */171static void172timerlat_hist_update(struct osnoise_tool *tool, int cpu,173 unsigned long long context,174 unsigned long long latency)175{176 struct timerlat_hist_params *params = tool->params;177 struct timerlat_hist_data *data = tool->data;178 int entries = data->entries;179 int bucket;180 int *hist;181 182 if (params->output_divisor)183 latency = latency / params->output_divisor;184 185 bucket = latency / data->bucket_size;186 187 if (!context) {188 hist = data->hist[cpu].irq;189 data->hist[cpu].irq_count++;190 update_min(&data->hist[cpu].min_irq, &latency);191 update_sum(&data->hist[cpu].sum_irq, &latency);192 update_max(&data->hist[cpu].max_irq, &latency);193 } else if (context == 1) {194 hist = data->hist[cpu].thread;195 data->hist[cpu].thread_count++;196 update_min(&data->hist[cpu].min_thread, &latency);197 update_sum(&data->hist[cpu].sum_thread, &latency);198 update_max(&data->hist[cpu].max_thread, &latency);199 } else { /* user */200 hist = data->hist[cpu].user;201 data->hist[cpu].user_count++;202 update_min(&data->hist[cpu].min_user, &latency);203 update_sum(&data->hist[cpu].sum_user, &latency);204 update_max(&data->hist[cpu].max_user, &latency);205 }206 207 if (bucket < entries)208 hist[bucket]++;209 else210 hist[entries]++;211}212 213/*214 * timerlat_hist_handler - this is the handler for timerlat tracer events215 */216static int217timerlat_hist_handler(struct trace_seq *s, struct tep_record *record,218 struct tep_event *event, void *data)219{220 struct trace_instance *trace = data;221 unsigned long long context, latency;222 struct osnoise_tool *tool;223 int cpu = record->cpu;224 225 tool = container_of(trace, struct osnoise_tool, trace);226 227 tep_get_field_val(s, event, "context", record, &context, 1);228 tep_get_field_val(s, event, "timer_latency", record, &latency, 1);229 230 timerlat_hist_update(tool, cpu, context, latency);231 232 return 0;233}234 235/*236 * timerlat_hist_header - print the header of the tracer to the output237 */238static void timerlat_hist_header(struct osnoise_tool *tool)239{240 struct timerlat_hist_params *params = tool->params;241 struct timerlat_hist_data *data = tool->data;242 struct trace_seq *s = tool->trace.seq;243 char duration[26];244 int cpu;245 246 if (params->no_header)247 return;248 249 get_duration(tool->start_time, duration, sizeof(duration));250 trace_seq_printf(s, "# RTLA timerlat histogram\n");251 trace_seq_printf(s, "# Time unit is %s (%s)\n",252 params->output_divisor == 1 ? "nanoseconds" : "microseconds",253 params->output_divisor == 1 ? "ns" : "us");254 255 trace_seq_printf(s, "# Duration: %s\n", duration);256 257 if (!params->no_index)258 trace_seq_printf(s, "Index");259 260 for (cpu = 0; cpu < data->nr_cpus; cpu++) {261 if (params->cpus && !CPU_ISSET(cpu, ¶ms->monitored_cpus))262 continue;263 264 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)265 continue;266 267 if (!params->no_irq)268 trace_seq_printf(s, " IRQ-%03d", cpu);269 270 if (!params->no_thread)271 trace_seq_printf(s, " Thr-%03d", cpu);272 273 if (params->user_hist)274 trace_seq_printf(s, " Usr-%03d", cpu);275 }276 trace_seq_printf(s, "\n");277 278 279 trace_seq_do_printf(s);280 trace_seq_reset(s);281}282 283/*284 * timerlat_print_summary - print the summary of the hist data to the output285 */286static void287timerlat_print_summary(struct timerlat_hist_params *params,288 struct trace_instance *trace,289 struct timerlat_hist_data *data)290{291 int cpu;292 293 if (params->no_summary)294 return;295 296 if (!params->no_index)297 trace_seq_printf(trace->seq, "count:");298 299 for (cpu = 0; cpu < data->nr_cpus; cpu++) {300 if (params->cpus && !CPU_ISSET(cpu, ¶ms->monitored_cpus))301 continue;302 303 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)304 continue;305 306 if (!params->no_irq)307 trace_seq_printf(trace->seq, "%9d ",308 data->hist[cpu].irq_count);309 310 if (!params->no_thread)311 trace_seq_printf(trace->seq, "%9d ",312 data->hist[cpu].thread_count);313 314 if (params->user_hist)315 trace_seq_printf(trace->seq, "%9d ",316 data->hist[cpu].user_count);317 }318 trace_seq_printf(trace->seq, "\n");319 320 if (!params->no_index)321 trace_seq_printf(trace->seq, "min: ");322 323 for (cpu = 0; cpu < data->nr_cpus; cpu++) {324 if (params->cpus && !CPU_ISSET(cpu, ¶ms->monitored_cpus))325 continue;326 327 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)328 continue;329 330 if (!params->no_irq) {331 if (data->hist[cpu].irq_count)332 trace_seq_printf(trace->seq, "%9llu ",333 data->hist[cpu].min_irq);334 else335 trace_seq_printf(trace->seq, " - ");336 }337 338 if (!params->no_thread) {339 if (data->hist[cpu].thread_count)340 trace_seq_printf(trace->seq, "%9llu ",341 data->hist[cpu].min_thread);342 else343 trace_seq_printf(trace->seq, " - ");344 }345 346 if (params->user_hist) {347 if (data->hist[cpu].user_count)348 trace_seq_printf(trace->seq, "%9llu ",349 data->hist[cpu].min_user);350 else351 trace_seq_printf(trace->seq, " - ");352 }353 }354 trace_seq_printf(trace->seq, "\n");355 356 if (!params->no_index)357 trace_seq_printf(trace->seq, "avg: ");358 359 for (cpu = 0; cpu < data->nr_cpus; cpu++) {360 if (params->cpus && !CPU_ISSET(cpu, ¶ms->monitored_cpus))361 continue;362 363 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)364 continue;365 366 if (!params->no_irq) {367 if (data->hist[cpu].irq_count)368 trace_seq_printf(trace->seq, "%9llu ",369 data->hist[cpu].sum_irq / data->hist[cpu].irq_count);370 else371 trace_seq_printf(trace->seq, " - ");372 }373 374 if (!params->no_thread) {375 if (data->hist[cpu].thread_count)376 trace_seq_printf(trace->seq, "%9llu ",377 data->hist[cpu].sum_thread / data->hist[cpu].thread_count);378 else379 trace_seq_printf(trace->seq, " - ");380 }381 382 if (params->user_hist) {383 if (data->hist[cpu].user_count)384 trace_seq_printf(trace->seq, "%9llu ",385 data->hist[cpu].sum_user / data->hist[cpu].user_count);386 else387 trace_seq_printf(trace->seq, " - ");388 }389 }390 trace_seq_printf(trace->seq, "\n");391 392 if (!params->no_index)393 trace_seq_printf(trace->seq, "max: ");394 395 for (cpu = 0; cpu < data->nr_cpus; cpu++) {396 if (params->cpus && !CPU_ISSET(cpu, ¶ms->monitored_cpus))397 continue;398 399 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)400 continue;401 402 if (!params->no_irq) {403 if (data->hist[cpu].irq_count)404 trace_seq_printf(trace->seq, "%9llu ",405 data->hist[cpu].max_irq);406 else407 trace_seq_printf(trace->seq, " - ");408 }409 410 if (!params->no_thread) {411 if (data->hist[cpu].thread_count)412 trace_seq_printf(trace->seq, "%9llu ",413 data->hist[cpu].max_thread);414 else415 trace_seq_printf(trace->seq, " - ");416 }417 418 if (params->user_hist) {419 if (data->hist[cpu].user_count)420 trace_seq_printf(trace->seq, "%9llu ",421 data->hist[cpu].max_user);422 else423 trace_seq_printf(trace->seq, " - ");424 }425 }426 trace_seq_printf(trace->seq, "\n");427 trace_seq_do_printf(trace->seq);428 trace_seq_reset(trace->seq);429}430 431static void432timerlat_print_stats_all(struct timerlat_hist_params *params,433 struct trace_instance *trace,434 struct timerlat_hist_data *data)435{436 struct timerlat_hist_cpu *cpu_data;437 struct timerlat_hist_cpu sum;438 int cpu;439 440 if (params->no_summary)441 return;442 443 memset(&sum, 0, sizeof(sum));444 sum.min_irq = ~0;445 sum.min_thread = ~0;446 sum.min_user = ~0;447 448 for (cpu = 0; cpu < data->nr_cpus; cpu++) {449 if (params->cpus && !CPU_ISSET(cpu, ¶ms->monitored_cpus))450 continue;451 452 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)453 continue;454 455 cpu_data = &data->hist[cpu];456 457 sum.irq_count += cpu_data->irq_count;458 update_min(&sum.min_irq, &cpu_data->min_irq);459 update_sum(&sum.sum_irq, &cpu_data->sum_irq);460 update_max(&sum.max_irq, &cpu_data->max_irq);461 462 sum.thread_count += cpu_data->thread_count;463 update_min(&sum.min_thread, &cpu_data->min_thread);464 update_sum(&sum.sum_thread, &cpu_data->sum_thread);465 update_max(&sum.max_thread, &cpu_data->max_thread);466 467 sum.user_count += cpu_data->user_count;468 update_min(&sum.min_user, &cpu_data->min_user);469 update_sum(&sum.sum_user, &cpu_data->sum_user);470 update_max(&sum.max_user, &cpu_data->max_user);471 }472 473 if (!params->no_index)474 trace_seq_printf(trace->seq, "ALL: ");475 476 if (!params->no_irq)477 trace_seq_printf(trace->seq, " IRQ");478 479 if (!params->no_thread)480 trace_seq_printf(trace->seq, " Thr");481 482 if (params->user_hist)483 trace_seq_printf(trace->seq, " Usr");484 485 trace_seq_printf(trace->seq, "\n");486 487 if (!params->no_index)488 trace_seq_printf(trace->seq, "count:");489 490 if (!params->no_irq)491 trace_seq_printf(trace->seq, "%9d ",492 sum.irq_count);493 494 if (!params->no_thread)495 trace_seq_printf(trace->seq, "%9d ",496 sum.thread_count);497 498 if (params->user_hist)499 trace_seq_printf(trace->seq, "%9d ",500 sum.user_count);501 502 trace_seq_printf(trace->seq, "\n");503 504 if (!params->no_index)505 trace_seq_printf(trace->seq, "min: ");506 507 if (!params->no_irq)508 trace_seq_printf(trace->seq, "%9llu ",509 sum.min_irq);510 511 if (!params->no_thread)512 trace_seq_printf(trace->seq, "%9llu ",513 sum.min_thread);514 515 if (params->user_hist)516 trace_seq_printf(trace->seq, "%9llu ",517 sum.min_user);518 519 trace_seq_printf(trace->seq, "\n");520 521 if (!params->no_index)522 trace_seq_printf(trace->seq, "avg: ");523 524 if (!params->no_irq)525 trace_seq_printf(trace->seq, "%9llu ",526 sum.sum_irq / sum.irq_count);527 528 if (!params->no_thread)529 trace_seq_printf(trace->seq, "%9llu ",530 sum.sum_thread / sum.thread_count);531 532 if (params->user_hist)533 trace_seq_printf(trace->seq, "%9llu ",534 sum.sum_user / sum.user_count);535 536 trace_seq_printf(trace->seq, "\n");537 538 if (!params->no_index)539 trace_seq_printf(trace->seq, "max: ");540 541 if (!params->no_irq)542 trace_seq_printf(trace->seq, "%9llu ",543 sum.max_irq);544 545 if (!params->no_thread)546 trace_seq_printf(trace->seq, "%9llu ",547 sum.max_thread);548 549 if (params->user_hist)550 trace_seq_printf(trace->seq, "%9llu ",551 sum.max_user);552 553 trace_seq_printf(trace->seq, "\n");554 trace_seq_do_printf(trace->seq);555 trace_seq_reset(trace->seq);556}557 558/*559 * timerlat_print_stats - print data for each CPUs560 */561static void562timerlat_print_stats(struct timerlat_hist_params *params, struct osnoise_tool *tool)563{564 struct timerlat_hist_data *data = tool->data;565 struct trace_instance *trace = &tool->trace;566 int bucket, cpu;567 int total;568 569 timerlat_hist_header(tool);570 571 for (bucket = 0; bucket < data->entries; bucket++) {572 total = 0;573 574 if (!params->no_index)575 trace_seq_printf(trace->seq, "%-6d",576 bucket * data->bucket_size);577 578 for (cpu = 0; cpu < data->nr_cpus; cpu++) {579 if (params->cpus && !CPU_ISSET(cpu, ¶ms->monitored_cpus))580 continue;581 582 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)583 continue;584 585 if (!params->no_irq) {586 total += data->hist[cpu].irq[bucket];587 trace_seq_printf(trace->seq, "%9d ",588 data->hist[cpu].irq[bucket]);589 }590 591 if (!params->no_thread) {592 total += data->hist[cpu].thread[bucket];593 trace_seq_printf(trace->seq, "%9d ",594 data->hist[cpu].thread[bucket]);595 }596 597 if (params->user_hist) {598 total += data->hist[cpu].user[bucket];599 trace_seq_printf(trace->seq, "%9d ",600 data->hist[cpu].user[bucket]);601 }602 603 }604 605 if (total == 0 && !params->with_zeros) {606 trace_seq_reset(trace->seq);607 continue;608 }609 610 trace_seq_printf(trace->seq, "\n");611 trace_seq_do_printf(trace->seq);612 trace_seq_reset(trace->seq);613 }614 615 if (!params->no_index)616 trace_seq_printf(trace->seq, "over: ");617 618 for (cpu = 0; cpu < data->nr_cpus; cpu++) {619 if (params->cpus && !CPU_ISSET(cpu, ¶ms->monitored_cpus))620 continue;621 622 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)623 continue;624 625 if (!params->no_irq)626 trace_seq_printf(trace->seq, "%9d ",627 data->hist[cpu].irq[data->entries]);628 629 if (!params->no_thread)630 trace_seq_printf(trace->seq, "%9d ",631 data->hist[cpu].thread[data->entries]);632 633 if (params->user_hist)634 trace_seq_printf(trace->seq, "%9d ",635 data->hist[cpu].user[data->entries]);636 }637 trace_seq_printf(trace->seq, "\n");638 trace_seq_do_printf(trace->seq);639 trace_seq_reset(trace->seq);640 641 timerlat_print_summary(params, trace, data);642 timerlat_print_stats_all(params, trace, data);643}644 645/*646 * timerlat_hist_usage - prints timerlat top usage message647 */648static void timerlat_hist_usage(char *usage)649{650 int i;651 652 char *msg[] = {653 "",654 " usage: [rtla] timerlat hist [-h] [-q] [-d s] [-D] [-n] [-a us] [-p us] [-i us] [-T us] [-s us] \\",655 " [-t[file]] [-e sys[:event]] [--filter <filter>] [--trigger <trigger>] [-c cpu-list] [-H cpu-list]\\",656 " [-P priority] [-E N] [-b N] [--no-irq] [--no-thread] [--no-header] [--no-summary] \\",657 " [--no-index] [--with-zeros] [--dma-latency us] [-C[=cgroup_name]] [--no-aa] [--dump-task] [-u|-k]",658 " [--warm-up s]",659 "",660 " -h/--help: print this menu",661 " -a/--auto: set automatic trace mode, stopping the session if argument in us latency is hit",662 " -p/--period us: timerlat period in us",663 " -i/--irq us: stop trace if the irq latency is higher than the argument in us",664 " -T/--thread us: stop trace if the thread latency is higher than the argument in us",665 " -s/--stack us: save the stack trace at the IRQ if a thread latency is higher than the argument in us",666 " -c/--cpus cpus: run the tracer only on the given cpus",667 " -H/--house-keeping cpus: run rtla control threads only on the given cpus",668 " -C/--cgroup[=cgroup_name]: set cgroup, if no cgroup_name is passed, the rtla's cgroup will be inherited",669 " -d/--duration time[m|h|d]: duration of the session in seconds",670 " --dump-tasks: prints the task running on all CPUs if stop conditions are met (depends on !--no-aa)",671 " -D/--debug: print debug info",672 " -t/--trace[file]: save the stopped trace to [file|timerlat_trace.txt]",673 " -e/--event <sys:event>: enable the <sys:event> in the trace instance, multiple -e are allowed",674 " --filter <filter>: enable a trace event filter to the previous -e event",675 " --trigger <trigger>: enable a trace event trigger to the previous -e event",676 " -n/--nano: display data in nanoseconds",677 " --no-aa: disable auto-analysis, reducing rtla timerlat cpu usage",678 " -b/--bucket-size N: set the histogram bucket size (default 1)",679 " -E/--entries N: set the number of entries of the histogram (default 256)",680 " --no-irq: ignore IRQ latencies",681 " --no-thread: ignore thread latencies",682 " --no-header: do not print header",683 " --no-summary: do not print summary",684 " --no-index: do not print index",685 " --with-zeros: print zero only entries",686 " --dma-latency us: set /dev/cpu_dma_latency latency <us> to reduce exit from idle latency",687 " -P/--priority o:prio|r:prio|f:prio|d:runtime:period : set scheduling parameters",688 " o:prio - use SCHED_OTHER with prio",689 " r:prio - use SCHED_RR with prio",690 " f:prio - use SCHED_FIFO with prio",691 " d:runtime[us|ms|s]:period[us|ms|s] - use SCHED_DEADLINE with runtime and period",692 " in nanoseconds",693 " -u/--user-threads: use rtla user-space threads instead of kernel-space timerlat threads",694 " -k/--kernel-threads: use timerlat kernel-space threads instead of rtla user-space threads",695 " -U/--user-load: enable timerlat for user-defined user-space workload",696 " --warm-up s: let the workload run for s seconds before collecting data",697 " --trace-buffer-size kB: set the per-cpu trace buffer size in kB",698 NULL,699 };700 701 if (usage)702 fprintf(stderr, "%s\n", usage);703 704 fprintf(stderr, "rtla timerlat hist: a per-cpu histogram of the timer latency (version %s)\n",705 VERSION);706 707 for (i = 0; msg[i]; i++)708 fprintf(stderr, "%s\n", msg[i]);709 710 if (usage)711 exit(EXIT_FAILURE);712 713 exit(EXIT_SUCCESS);714}715 716/*717 * timerlat_hist_parse_args - allocs, parse and fill the cmd line parameters718 */719static struct timerlat_hist_params720*timerlat_hist_parse_args(int argc, char *argv[])721{722 struct timerlat_hist_params *params;723 struct trace_events *tevent;724 int auto_thresh;725 int retval;726 int c;727 728 params = calloc(1, sizeof(*params));729 if (!params)730 exit(1);731 732 /* disabled by default */733 params->dma_latency = -1;734 735 /* display data in microseconds */736 params->output_divisor = 1000;737 params->bucket_size = 1;738 params->entries = 256;739 740 while (1) {741 static struct option long_options[] = {742 {"auto", required_argument, 0, 'a'},743 {"cpus", required_argument, 0, 'c'},744 {"cgroup", optional_argument, 0, 'C'},745 {"bucket-size", required_argument, 0, 'b'},746 {"debug", no_argument, 0, 'D'},747 {"entries", required_argument, 0, 'E'},748 {"duration", required_argument, 0, 'd'},749 {"house-keeping", required_argument, 0, 'H'},750 {"help", no_argument, 0, 'h'},751 {"irq", required_argument, 0, 'i'},752 {"nano", no_argument, 0, 'n'},753 {"period", required_argument, 0, 'p'},754 {"priority", required_argument, 0, 'P'},755 {"stack", required_argument, 0, 's'},756 {"thread", required_argument, 0, 'T'},757 {"trace", optional_argument, 0, 't'},758 {"user-threads", no_argument, 0, 'u'},759 {"kernel-threads", no_argument, 0, 'k'},760 {"user-load", no_argument, 0, 'U'},761 {"event", required_argument, 0, 'e'},762 {"no-irq", no_argument, 0, '0'},763 {"no-thread", no_argument, 0, '1'},764 {"no-header", no_argument, 0, '2'},765 {"no-summary", no_argument, 0, '3'},766 {"no-index", no_argument, 0, '4'},767 {"with-zeros", no_argument, 0, '5'},768 {"trigger", required_argument, 0, '6'},769 {"filter", required_argument, 0, '7'},770 {"dma-latency", required_argument, 0, '8'},771 {"no-aa", no_argument, 0, '9'},772 {"dump-task", no_argument, 0, '\1'},773 {"warm-up", required_argument, 0, '\2'},774 {"trace-buffer-size", required_argument, 0, '\3'},775 {0, 0, 0, 0}776 };777 778 /* getopt_long stores the option index here. */779 int option_index = 0;780 781 c = getopt_long(argc, argv, "a:c:C::b:d:e:E:DhH:i:knp:P:s:t::T:uU0123456:7:8:9\1\2:\3",782 long_options, &option_index);783 784 /* detect the end of the options. */785 if (c == -1)786 break;787 788 switch (c) {789 case 'a':790 auto_thresh = get_llong_from_str(optarg);791 792 /* set thread stop to auto_thresh */793 params->stop_total_us = auto_thresh;794 params->stop_us = auto_thresh;795 796 /* get stack trace */797 params->print_stack = auto_thresh;798 799 /* set trace */800 params->trace_output = "timerlat_trace.txt";801 802 break;803 case 'c':804 retval = parse_cpu_set(optarg, ¶ms->monitored_cpus);805 if (retval)806 timerlat_hist_usage("\nInvalid -c cpu list\n");807 params->cpus = optarg;808 break;809 case 'C':810 params->cgroup = 1;811 if (!optarg) {812 /* will inherit this cgroup */813 params->cgroup_name = NULL;814 } else if (*optarg == '=') {815 /* skip the = */816 params->cgroup_name = ++optarg;817 }818 break;819 case 'b':820 params->bucket_size = get_llong_from_str(optarg);821 if ((params->bucket_size == 0) || (params->bucket_size >= 1000000))822 timerlat_hist_usage("Bucket size needs to be > 0 and <= 1000000\n");823 break;824 case 'D':825 config_debug = 1;826 break;827 case 'd':828 params->duration = parse_seconds_duration(optarg);829 if (!params->duration)830 timerlat_hist_usage("Invalid -D duration\n");831 break;832 case 'e':833 tevent = trace_event_alloc(optarg);834 if (!tevent) {835 err_msg("Error alloc trace event");836 exit(EXIT_FAILURE);837 }838 839 if (params->events)840 tevent->next = params->events;841 842 params->events = tevent;843 break;844 case 'E':845 params->entries = get_llong_from_str(optarg);846 if ((params->entries < 10) || (params->entries > 9999999))847 timerlat_hist_usage("Entries must be > 10 and < 9999999\n");848 break;849 case 'h':850 case '?':851 timerlat_hist_usage(NULL);852 break;853 case 'H':854 params->hk_cpus = 1;855 retval = parse_cpu_set(optarg, ¶ms->hk_cpu_set);856 if (retval) {857 err_msg("Error parsing house keeping CPUs\n");858 exit(EXIT_FAILURE);859 }860 break;861 case 'i':862 params->stop_us = get_llong_from_str(optarg);863 break;864 case 'k':865 params->kernel_workload = 1;866 break;867 case 'n':868 params->output_divisor = 1;869 break;870 case 'p':871 params->timerlat_period_us = get_llong_from_str(optarg);872 if (params->timerlat_period_us > 1000000)873 timerlat_hist_usage("Period longer than 1 s\n");874 break;875 case 'P':876 retval = parse_prio(optarg, ¶ms->sched_param);877 if (retval == -1)878 timerlat_hist_usage("Invalid -P priority");879 params->set_sched = 1;880 break;881 case 's':882 params->print_stack = get_llong_from_str(optarg);883 break;884 case 'T':885 params->stop_total_us = get_llong_from_str(optarg);886 break;887 case 't':888 if (optarg) {889 if (optarg[0] == '=')890 params->trace_output = &optarg[1];891 else892 params->trace_output = &optarg[0];893 } else if (optind < argc && argv[optind][0] != '-')894 params->trace_output = argv[optind];895 else896 params->trace_output = "timerlat_trace.txt";897 break;898 case 'u':899 params->user_workload = 1;900 /* fallback: -u implies in -U */901 case 'U':902 params->user_hist = 1;903 break;904 case '0': /* no irq */905 params->no_irq = 1;906 break;907 case '1': /* no thread */908 params->no_thread = 1;909 break;910 case '2': /* no header */911 params->no_header = 1;912 break;913 case '3': /* no summary */914 params->no_summary = 1;915 break;916 case '4': /* no index */917 params->no_index = 1;918 break;919 case '5': /* with zeros */920 params->with_zeros = 1;921 break;922 case '6': /* trigger */923 if (params->events) {924 retval = trace_event_add_trigger(params->events, optarg);925 if (retval) {926 err_msg("Error adding trigger %s\n", optarg);927 exit(EXIT_FAILURE);928 }929 } else {930 timerlat_hist_usage("--trigger requires a previous -e\n");931 }932 break;933 case '7': /* filter */934 if (params->events) {935 retval = trace_event_add_filter(params->events, optarg);936 if (retval) {937 err_msg("Error adding filter %s\n", optarg);938 exit(EXIT_FAILURE);939 }940 } else {941 timerlat_hist_usage("--filter requires a previous -e\n");942 }943 break;944 case '8':945 params->dma_latency = get_llong_from_str(optarg);946 if (params->dma_latency < 0 || params->dma_latency > 10000) {947 err_msg("--dma-latency needs to be >= 0 and < 10000");948 exit(EXIT_FAILURE);949 }950 break;951 case '9':952 params->no_aa = 1;953 break;954 case '\1':955 params->dump_tasks = 1;956 break;957 case '\2':958 params->warmup = get_llong_from_str(optarg);959 break;960 case '\3':961 params->buffer_size = get_llong_from_str(optarg);962 break;963 default:964 timerlat_hist_usage("Invalid option");965 }966 }967 968 if (geteuid()) {969 err_msg("rtla needs root permission\n");970 exit(EXIT_FAILURE);971 }972 973 if (params->no_irq && params->no_thread)974 timerlat_hist_usage("no-irq and no-thread set, there is nothing to do here");975 976 if (params->no_index && !params->with_zeros)977 timerlat_hist_usage("no-index set with with-zeros is not set - it does not make sense");978 979 /*980 * Auto analysis only happens if stop tracing, thus:981 */982 if (!params->stop_us && !params->stop_total_us)983 params->no_aa = 1;984 985 if (params->kernel_workload && params->user_workload)986 timerlat_hist_usage("--kernel-threads and --user-threads are mutually exclusive!");987 988 return params;989}990 991/*992 * timerlat_hist_apply_config - apply the hist configs to the initialized tool993 */994static int995timerlat_hist_apply_config(struct osnoise_tool *tool, struct timerlat_hist_params *params)996{997 int retval, i;998 999 if (!params->sleep_time)1000 params->sleep_time = 1;1001 1002 if (params->cpus) {1003 retval = osnoise_set_cpus(tool->context, params->cpus);1004 if (retval) {1005 err_msg("Failed to apply CPUs config\n");1006 goto out_err;1007 }1008 } else {1009 for (i = 0; i < sysconf(_SC_NPROCESSORS_CONF); i++)1010 CPU_SET(i, ¶ms->monitored_cpus);1011 }1012 1013 if (params->stop_us) {1014 retval = osnoise_set_stop_us(tool->context, params->stop_us);1015 if (retval) {1016 err_msg("Failed to set stop us\n");1017 goto out_err;1018 }1019 }1020 1021 if (params->stop_total_us) {1022 retval = osnoise_set_stop_total_us(tool->context, params->stop_total_us);1023 if (retval) {1024 err_msg("Failed to set stop total us\n");1025 goto out_err;1026 }1027 }1028 1029 if (params->timerlat_period_us) {1030 retval = osnoise_set_timerlat_period_us(tool->context, params->timerlat_period_us);1031 if (retval) {1032 err_msg("Failed to set timerlat period\n");1033 goto out_err;1034 }1035 }1036 1037 if (params->print_stack) {1038 retval = osnoise_set_print_stack(tool->context, params->print_stack);1039 if (retval) {1040 err_msg("Failed to set print stack\n");1041 goto out_err;1042 }1043 }1044 1045 if (params->hk_cpus) {1046 retval = sched_setaffinity(getpid(), sizeof(params->hk_cpu_set),1047 ¶ms->hk_cpu_set);1048 if (retval == -1) {1049 err_msg("Failed to set rtla to the house keeping CPUs\n");1050 goto out_err;1051 }1052 } else if (params->cpus) {1053 /*1054 * Even if the user do not set a house-keeping CPU, try to1055 * move rtla to a CPU set different to the one where the user1056 * set the workload to run.1057 *1058 * No need to check results as this is an automatic attempt.1059 */1060 auto_house_keeping(¶ms->monitored_cpus);1061 }1062 1063 /*1064 * If the user did not specify a type of thread, try user-threads first.1065 * Fall back to kernel threads otherwise.1066 */1067 if (!params->kernel_workload && !params->user_workload) {1068 retval = tracefs_file_exists(NULL, "osnoise/per_cpu/cpu0/timerlat_fd");1069 if (retval) {1070 debug_msg("User-space interface detected, setting user-threads\n");1071 params->user_workload = 1;1072 params->user_hist = 1;1073 } else {1074 debug_msg("User-space interface not detected, setting kernel-threads\n");1075 params->kernel_workload = 1;1076 }1077 }1078 1079 if (params->user_hist) {1080 retval = osnoise_set_workload(tool->context, 0);1081 if (retval) {1082 err_msg("Failed to set OSNOISE_WORKLOAD option\n");1083 goto out_err;1084 }1085 }1086 1087 return 0;1088 1089out_err:1090 return -1;1091}1092 1093/*1094 * timerlat_init_hist - initialize a timerlat hist tool with parameters1095 */1096static struct osnoise_tool1097*timerlat_init_hist(struct timerlat_hist_params *params)1098{1099 struct osnoise_tool *tool;1100 int nr_cpus;1101 1102 nr_cpus = sysconf(_SC_NPROCESSORS_CONF);1103 1104 tool = osnoise_init_tool("timerlat_hist");1105 if (!tool)1106 return NULL;1107 1108 tool->data = timerlat_alloc_histogram(nr_cpus, params->entries, params->bucket_size);1109 if (!tool->data)1110 goto out_err;1111 1112 tool->params = params;1113 1114 tep_register_event_handler(tool->trace.tep, -1, "ftrace", "timerlat",1115 timerlat_hist_handler, tool);1116 1117 return tool;1118 1119out_err:1120 osnoise_destroy_tool(tool);1121 return NULL;1122}1123 1124static int stop_tracing;1125static void stop_hist(int sig)1126{1127 stop_tracing = 1;1128}1129 1130/*1131 * timerlat_hist_set_signals - handles the signal to stop the tool1132 */1133static void1134timerlat_hist_set_signals(struct timerlat_hist_params *params)1135{1136 signal(SIGINT, stop_hist);1137 if (params->duration) {1138 signal(SIGALRM, stop_hist);1139 alarm(params->duration);1140 }1141}1142 1143int timerlat_hist_main(int argc, char *argv[])1144{1145 struct timerlat_hist_params *params;1146 struct osnoise_tool *record = NULL;1147 struct timerlat_u_params params_u;1148 struct osnoise_tool *tool = NULL;1149 struct osnoise_tool *aa = NULL;1150 struct trace_instance *trace;1151 int dma_latency_fd = -1;1152 int return_value = 1;1153 pthread_t timerlat_u;1154 int retval;1155 1156 params = timerlat_hist_parse_args(argc, argv);1157 if (!params)1158 exit(1);1159 1160 tool = timerlat_init_hist(params);1161 if (!tool) {1162 err_msg("Could not init osnoise hist\n");1163 goto out_exit;1164 }1165 1166 retval = timerlat_hist_apply_config(tool, params);1167 if (retval) {1168 err_msg("Could not apply config\n");1169 goto out_free;1170 }1171 1172 trace = &tool->trace;1173 1174 retval = enable_timerlat(trace);1175 if (retval) {1176 err_msg("Failed to enable timerlat tracer\n");1177 goto out_free;1178 }1179 1180 if (params->set_sched) {1181 retval = set_comm_sched_attr("timerlat/", ¶ms->sched_param);1182 if (retval) {1183 err_msg("Failed to set sched parameters\n");1184 goto out_free;1185 }1186 }1187 1188 if (params->cgroup && !params->user_workload) {1189 retval = set_comm_cgroup("timerlat/", params->cgroup_name);1190 if (!retval) {1191 err_msg("Failed to move threads to cgroup\n");1192 goto out_free;1193 }1194 }1195 1196 if (params->dma_latency >= 0) {1197 dma_latency_fd = set_cpu_dma_latency(params->dma_latency);1198 if (dma_latency_fd < 0) {1199 err_msg("Could not set /dev/cpu_dma_latency.\n");1200 goto out_free;1201 }1202 }1203 1204 if (params->trace_output) {1205 record = osnoise_init_trace_tool("timerlat");1206 if (!record) {1207 err_msg("Failed to enable the trace instance\n");1208 goto out_free;1209 }1210 1211 if (params->events) {1212 retval = trace_events_enable(&record->trace, params->events);1213 if (retval)1214 goto out_hist;1215 }1216 1217 if (params->buffer_size > 0) {1218 retval = trace_set_buffer_size(&record->trace, params->buffer_size);1219 if (retval)1220 goto out_hist;1221 }1222 }1223 1224 if (!params->no_aa) {1225 aa = osnoise_init_tool("timerlat_aa");1226 if (!aa)1227 goto out_hist;1228 1229 retval = timerlat_aa_init(aa, params->dump_tasks);1230 if (retval) {1231 err_msg("Failed to enable the auto analysis instance\n");1232 goto out_hist;1233 }1234 1235 retval = enable_timerlat(&aa->trace);1236 if (retval) {1237 err_msg("Failed to enable timerlat tracer\n");1238 goto out_hist;1239 }1240 }1241 1242 if (params->user_workload) {1243 /* rtla asked to stop */1244 params_u.should_run = 1;1245 /* all threads left */1246 params_u.stopped_running = 0;1247 1248 params_u.set = ¶ms->monitored_cpus;1249 if (params->set_sched)1250 params_u.sched_param = ¶ms->sched_param;1251 else1252 params_u.sched_param = NULL;1253 1254 params_u.cgroup_name = params->cgroup_name;1255 1256 retval = pthread_create(&timerlat_u, NULL, timerlat_u_dispatcher, ¶ms_u);1257 if (retval)1258 err_msg("Error creating timerlat user-space threads\n");1259 }1260 1261 if (params->warmup > 0) {1262 debug_msg("Warming up for %d seconds\n", params->warmup);1263 sleep(params->warmup);1264 if (stop_tracing)1265 goto out_hist;1266 }1267 1268 /*1269 * Start the tracers here, after having set all instances.1270 *1271 * Let the trace instance start first for the case of hitting a stop1272 * tracing while enabling other instances. The trace instance is the1273 * one with most valuable information.1274 */1275 if (params->trace_output)1276 trace_instance_start(&record->trace);1277 if (!params->no_aa)1278 trace_instance_start(&aa->trace);1279 trace_instance_start(trace);1280 1281 tool->start_time = time(NULL);1282 timerlat_hist_set_signals(params);1283 1284 while (!stop_tracing) {1285 sleep(params->sleep_time);1286 1287 retval = tracefs_iterate_raw_events(trace->tep,1288 trace->inst,1289 NULL,1290 0,1291 collect_registered_events,1292 trace);1293 if (retval < 0) {1294 err_msg("Error iterating on events\n");1295 goto out_hist;1296 }1297 1298 if (trace_is_off(&tool->trace, &record->trace))1299 break;1300 1301 /* is there still any user-threads ? */1302 if (params->user_workload) {1303 if (params_u.stopped_running) {1304 debug_msg("timerlat user-space threads stopped!\n");1305 break;1306 }1307 }1308 }1309 1310 if (params->user_workload && !params_u.stopped_running) {1311 params_u.should_run = 0;1312 sleep(1);1313 }1314 1315 timerlat_print_stats(params, tool);1316 1317 return_value = 0;1318 1319 if (trace_is_off(&tool->trace, &record->trace)) {1320 printf("rtla timerlat hit stop tracing\n");1321 1322 if (!params->no_aa)1323 timerlat_auto_analysis(params->stop_us, params->stop_total_us);1324 1325 if (params->trace_output) {1326 printf(" Saving trace to %s\n", params->trace_output);1327 save_trace_to_file(record->trace.inst, params->trace_output);1328 }1329 }1330 1331out_hist:1332 timerlat_aa_destroy();1333 if (dma_latency_fd >= 0)1334 close(dma_latency_fd);1335 trace_events_destroy(&record->trace, params->events);1336 params->events = NULL;1337out_free:1338 timerlat_free_histogram(tool->data);1339 osnoise_destroy_tool(aa);1340 osnoise_destroy_tool(record);1341 osnoise_destroy_tool(tool);1342 free(params);1343out_exit:1344 exit(return_value);1345}1346