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