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