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