tools/tracing/rtla/src/timerlat_hist.c

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