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 " --on-threshold <action>: define action to be executed at latency threshold, multiple are allowed", 520 " --on-end: define action to be executed at measurement end, multiple are allowed", 521 NULL, 522 }; 523 524 if (usage) 525 fprintf(stderr, "%s\n", usage); 526 527 fprintf(stderr, "rtla timerlat top: a per-cpu summary of the timer latency (version %s)\n", 528 VERSION); 529 530 for (i = 0; msg[i]; i++) 531 fprintf(stderr, "%s\n", msg[i]); 532 533 if (usage) 534 exit(EXIT_FAILURE); 535 536 exit(EXIT_SUCCESS); 537 } 538 539 /* 540 * timerlat_top_parse_args - allocs, parse and fill the cmd line parameters 541 */ 542 static struct timerlat_params 543 *timerlat_top_parse_args(int argc, char **argv) 544 { 545 struct timerlat_params *params; 546 struct trace_events *tevent; 547 long long auto_thresh; 548 int retval; 549 int c; 550 char *trace_output = NULL; 551 552 params = calloc(1, sizeof(*params)); 553 if (!params) 554 exit(1); 555 556 actions_init(¶ms->threshold_actions); 557 actions_init(¶ms->end_actions); 558 559 /* disabled by default */ 560 params->dma_latency = -1; 561 562 /* disabled by default */ 563 params->deepest_idle_state = -2; 564 565 /* display data in microseconds */ 566 params->output_divisor = 1000; 567 568 /* default to BPF mode */ 569 params->mode = TRACING_MODE_BPF; 570 571 while (1) { 572 static struct option long_options[] = { 573 {"auto", required_argument, 0, 'a'}, 574 {"cpus", required_argument, 0, 'c'}, 575 {"cgroup", optional_argument, 0, 'C'}, 576 {"debug", no_argument, 0, 'D'}, 577 {"duration", required_argument, 0, 'd'}, 578 {"event", required_argument, 0, 'e'}, 579 {"help", no_argument, 0, 'h'}, 580 {"house-keeping", required_argument, 0, 'H'}, 581 {"irq", required_argument, 0, 'i'}, 582 {"nano", no_argument, 0, 'n'}, 583 {"period", required_argument, 0, 'p'}, 584 {"priority", required_argument, 0, 'P'}, 585 {"quiet", no_argument, 0, 'q'}, 586 {"stack", required_argument, 0, 's'}, 587 {"thread", required_argument, 0, 'T'}, 588 {"trace", optional_argument, 0, 't'}, 589 {"user-threads", no_argument, 0, 'u'}, 590 {"kernel-threads", no_argument, 0, 'k'}, 591 {"user-load", no_argument, 0, 'U'}, 592 {"trigger", required_argument, 0, '0'}, 593 {"filter", required_argument, 0, '1'}, 594 {"dma-latency", required_argument, 0, '2'}, 595 {"no-aa", no_argument, 0, '3'}, 596 {"dump-tasks", no_argument, 0, '4'}, 597 {"aa-only", required_argument, 0, '5'}, 598 {"warm-up", required_argument, 0, '6'}, 599 {"trace-buffer-size", required_argument, 0, '7'}, 600 {"deepest-idle-state", required_argument, 0, '8'}, 601 {"on-threshold", required_argument, 0, '9'}, 602 {"on-end", required_argument, 0, '\1'}, 603 {0, 0, 0, 0} 604 }; 605 606 /* getopt_long stores the option index here. */ 607 int option_index = 0; 608 609 c = getopt_long(argc, argv, "a:c:C::d:De:hH:i:knp:P:qs:t::T:uU0:1:2:345:6:7:", 610 long_options, &option_index); 611 612 /* detect the end of the options. */ 613 if (c == -1) 614 break; 615 616 switch (c) { 617 case 'a': 618 auto_thresh = get_llong_from_str(optarg); 619 620 /* set thread stop to auto_thresh */ 621 params->stop_total_us = auto_thresh; 622 params->stop_us = auto_thresh; 623 624 /* get stack trace */ 625 params->print_stack = auto_thresh; 626 627 /* set trace */ 628 trace_output = "timerlat_trace.txt"; 629 630 break; 631 case '5': 632 /* it is here because it is similar to -a */ 633 auto_thresh = get_llong_from_str(optarg); 634 635 /* set thread stop to auto_thresh */ 636 params->stop_total_us = auto_thresh; 637 params->stop_us = auto_thresh; 638 639 /* get stack trace */ 640 params->print_stack = auto_thresh; 641 642 /* set aa_only to avoid parsing the trace */ 643 params->aa_only = 1; 644 break; 645 case 'c': 646 retval = parse_cpu_set(optarg, ¶ms->monitored_cpus); 647 if (retval) 648 timerlat_top_usage("\nInvalid -c cpu list\n"); 649 params->cpus = optarg; 650 break; 651 case 'C': 652 params->cgroup = 1; 653 if (!optarg) { 654 /* will inherit this cgroup */ 655 params->cgroup_name = NULL; 656 } else if (*optarg == '=') { 657 /* skip the = */ 658 params->cgroup_name = ++optarg; 659 } 660 break; 661 case 'D': 662 config_debug = 1; 663 break; 664 case 'd': 665 params->duration = parse_seconds_duration(optarg); 666 if (!params->duration) 667 timerlat_top_usage("Invalid -d duration\n"); 668 break; 669 case 'e': 670 tevent = trace_event_alloc(optarg); 671 if (!tevent) { 672 err_msg("Error alloc trace event"); 673 exit(EXIT_FAILURE); 674 } 675 676 if (params->events) 677 tevent->next = params->events; 678 params->events = tevent; 679 break; 680 case 'h': 681 case '?': 682 timerlat_top_usage(NULL); 683 break; 684 case 'H': 685 params->hk_cpus = 1; 686 retval = parse_cpu_set(optarg, ¶ms->hk_cpu_set); 687 if (retval) { 688 err_msg("Error parsing house keeping CPUs\n"); 689 exit(EXIT_FAILURE); 690 } 691 break; 692 case 'i': 693 params->stop_us = get_llong_from_str(optarg); 694 break; 695 case 'k': 696 params->kernel_workload = true; 697 break; 698 case 'n': 699 params->output_divisor = 1; 700 break; 701 case 'p': 702 params->timerlat_period_us = get_llong_from_str(optarg); 703 if (params->timerlat_period_us > 1000000) 704 timerlat_top_usage("Period longer than 1 s\n"); 705 break; 706 case 'P': 707 retval = parse_prio(optarg, ¶ms->sched_param); 708 if (retval == -1) 709 timerlat_top_usage("Invalid -P priority"); 710 params->set_sched = 1; 711 break; 712 case 'q': 713 params->quiet = 1; 714 break; 715 case 's': 716 params->print_stack = get_llong_from_str(optarg); 717 break; 718 case 'T': 719 params->stop_total_us = get_llong_from_str(optarg); 720 break; 721 case 't': 722 if (optarg) { 723 if (optarg[0] == '=') 724 trace_output = &optarg[1]; 725 else 726 trace_output = &optarg[0]; 727 } else if (optind < argc && argv[optind][0] != '-') 728 trace_output = argv[optind]; 729 else 730 trace_output = "timerlat_trace.txt"; 731 break; 732 case 'u': 733 params->user_workload = true; 734 /* fallback: -u implies -U */ 735 case 'U': 736 params->user_data = true; 737 break; 738 case '0': /* trigger */ 739 if (params->events) { 740 retval = trace_event_add_trigger(params->events, optarg); 741 if (retval) { 742 err_msg("Error adding trigger %s\n", optarg); 743 exit(EXIT_FAILURE); 744 } 745 } else { 746 timerlat_top_usage("--trigger requires a previous -e\n"); 747 } 748 break; 749 case '1': /* filter */ 750 if (params->events) { 751 retval = trace_event_add_filter(params->events, optarg); 752 if (retval) { 753 err_msg("Error adding filter %s\n", optarg); 754 exit(EXIT_FAILURE); 755 } 756 } else { 757 timerlat_top_usage("--filter requires a previous -e\n"); 758 } 759 break; 760 case '2': /* dma-latency */ 761 params->dma_latency = get_llong_from_str(optarg); 762 if (params->dma_latency < 0 || params->dma_latency > 10000) { 763 err_msg("--dma-latency needs to be >= 0 and < 10000"); 764 exit(EXIT_FAILURE); 765 } 766 break; 767 case '3': /* no-aa */ 768 params->no_aa = 1; 769 break; 770 case '4': 771 params->dump_tasks = 1; 772 break; 773 case '6': 774 params->warmup = get_llong_from_str(optarg); 775 break; 776 case '7': 777 params->buffer_size = get_llong_from_str(optarg); 778 break; 779 case '8': 780 params->deepest_idle_state = get_llong_from_str(optarg); 781 break; 782 case '9': 783 retval = actions_parse(¶ms->threshold_actions, optarg); 784 if (retval) { 785 err_msg("Invalid action %s\n", optarg); 786 exit(EXIT_FAILURE); 787 } 788 break; 789 case '\1': 790 retval = actions_parse(¶ms->end_actions, optarg); 791 if (retval) { 792 err_msg("Invalid action %s\n", optarg); 793 exit(EXIT_FAILURE); 794 } 795 break; 796 default: 797 timerlat_top_usage("Invalid option"); 798 } 799 } 800 801 if (trace_output) 802 actions_add_trace_output(¶ms->threshold_actions, trace_output); 803 804 if (geteuid()) { 805 err_msg("rtla needs root permission\n"); 806 exit(EXIT_FAILURE); 807 } 808 809 /* 810 * Auto analysis only happens if stop tracing, thus: 811 */ 812 if (!params->stop_us && !params->stop_total_us) 813 params->no_aa = 1; 814 815 if (params->no_aa && params->aa_only) 816 timerlat_top_usage("--no-aa and --aa-only are mutually exclusive!"); 817 818 if (params->kernel_workload && params->user_workload) 819 timerlat_top_usage("--kernel-threads and --user-threads are mutually exclusive!"); 820 821 /* 822 * If auto-analysis or trace output is enabled, switch from BPF mode to 823 * mixed mode 824 */ 825 if (params->mode == TRACING_MODE_BPF && 826 (params->threshold_actions.present[ACTION_TRACE_OUTPUT] || 827 params->end_actions.present[ACTION_TRACE_OUTPUT] || !params->no_aa)) 828 params->mode = TRACING_MODE_MIXED; 829 830 return params; 831 } 832 833 /* 834 * timerlat_top_apply_config - apply the top configs to the initialized tool 835 */ 836 static int 837 timerlat_top_apply_config(struct osnoise_tool *top, struct timerlat_params *params) 838 { 839 int retval; 840 841 retval = timerlat_apply_config(top, params); 842 if (retval) 843 goto out_err; 844 845 if (isatty(STDOUT_FILENO) && !params->quiet) 846 params->pretty_output = 1; 847 848 return 0; 849 850 out_err: 851 return -1; 852 } 853 854 /* 855 * timerlat_init_top - initialize a timerlat top tool with parameters 856 */ 857 static struct osnoise_tool 858 *timerlat_init_top(struct timerlat_params *params) 859 { 860 struct osnoise_tool *top; 861 int nr_cpus; 862 863 nr_cpus = sysconf(_SC_NPROCESSORS_CONF); 864 865 top = osnoise_init_tool("timerlat_top"); 866 if (!top) 867 return NULL; 868 869 top->data = timerlat_alloc_top(nr_cpus); 870 if (!top->data) 871 goto out_err; 872 873 top->params = params; 874 875 tep_register_event_handler(top->trace.tep, -1, "ftrace", "timerlat", 876 timerlat_top_handler, top); 877 878 return top; 879 880 out_err: 881 osnoise_destroy_tool(top); 882 return NULL; 883 } 884 885 static int stop_tracing; 886 static struct trace_instance *top_inst = NULL; 887 static void stop_top(int sig) 888 { 889 if (stop_tracing) { 890 /* 891 * Stop requested twice in a row; abort event processing and 892 * exit immediately 893 */ 894 tracefs_iterate_stop(top_inst->inst); 895 return; 896 } 897 stop_tracing = 1; 898 if (top_inst) 899 trace_instance_stop(top_inst); 900 } 901 902 /* 903 * timerlat_top_set_signals - handles the signal to stop the tool 904 */ 905 static void 906 timerlat_top_set_signals(struct timerlat_params *params) 907 { 908 signal(SIGINT, stop_top); 909 if (params->duration) { 910 signal(SIGALRM, stop_top); 911 alarm(params->duration); 912 } 913 } 914 915 /* 916 * timerlat_top_main_loop - main loop to process events 917 */ 918 static int 919 timerlat_top_main_loop(struct osnoise_tool *top, 920 struct osnoise_tool *record, 921 struct osnoise_tool *aa, 922 struct timerlat_params *params, 923 struct timerlat_u_params *params_u) 924 { 925 struct trace_instance *trace = &top->trace; 926 int retval; 927 928 while (!stop_tracing) { 929 sleep(params->sleep_time); 930 931 if (params->aa_only && !osnoise_trace_is_off(top, record)) 932 continue; 933 934 retval = tracefs_iterate_raw_events(trace->tep, 935 trace->inst, 936 NULL, 937 0, 938 collect_registered_events, 939 trace); 940 if (retval < 0) { 941 err_msg("Error iterating on events\n"); 942 return retval; 943 } 944 945 if (!params->quiet) 946 timerlat_print_stats(params, top); 947 948 if (osnoise_trace_is_off(top, record)) { 949 actions_perform(¶ms->threshold_actions); 950 951 if (!params->threshold_actions.continue_flag) 952 /* continue flag not set, break */ 953 break; 954 955 /* continue action reached, re-enable tracing */ 956 if (record) 957 trace_instance_start(&record->trace); 958 if (!params->no_aa) 959 trace_instance_start(&aa->trace); 960 trace_instance_start(trace); 961 } 962 963 /* is there still any user-threads ? */ 964 if (params->user_workload) { 965 if (params_u->stopped_running) { 966 debug_msg("timerlat user space threads stopped!\n"); 967 break; 968 } 969 } 970 } 971 972 return 0; 973 } 974 975 /* 976 * timerlat_top_bpf_main_loop - main loop to process events (BPF variant) 977 */ 978 static int 979 timerlat_top_bpf_main_loop(struct osnoise_tool *top, 980 struct osnoise_tool *record, 981 struct osnoise_tool *aa, 982 struct timerlat_params *params, 983 struct timerlat_u_params *params_u) 984 { 985 int retval, wait_retval; 986 987 if (params->aa_only) { 988 /* Auto-analysis only, just wait for stop tracing */ 989 timerlat_bpf_wait(-1); 990 return 0; 991 } 992 993 /* Pull and display data in a loop */ 994 while (!stop_tracing) { 995 wait_retval = timerlat_bpf_wait(params->quiet ? -1 : params->sleep_time); 996 997 retval = timerlat_top_bpf_pull_data(top); 998 if (retval) { 999 err_msg("Error pulling BPF data\n"); 1000 return retval; 1001 } 1002 1003 if (!params->quiet) 1004 timerlat_print_stats(params, top); 1005 1006 if (wait_retval == 1) { 1007 /* Stopping requested by tracer */ 1008 actions_perform(¶ms->threshold_actions); 1009 1010 if (!params->threshold_actions.continue_flag) 1011 /* continue flag not set, break */ 1012 break; 1013 1014 /* continue action reached, re-enable tracing */ 1015 if (record) 1016 trace_instance_start(&record->trace); 1017 if (!params->no_aa) 1018 trace_instance_start(&aa->trace); 1019 timerlat_bpf_restart_tracing(); 1020 } 1021 1022 /* is there still any user-threads ? */ 1023 if (params->user_workload) { 1024 if (params_u->stopped_running) { 1025 debug_msg("timerlat user space threads stopped!\n"); 1026 break; 1027 } 1028 } 1029 } 1030 1031 return 0; 1032 } 1033 1034 int timerlat_top_main(int argc, char *argv[]) 1035 { 1036 struct timerlat_params *params; 1037 struct osnoise_tool *record = NULL; 1038 struct timerlat_u_params params_u; 1039 enum result return_value = ERROR; 1040 struct osnoise_tool *top = NULL; 1041 struct osnoise_tool *aa = NULL; 1042 struct trace_instance *trace; 1043 int dma_latency_fd = -1; 1044 pthread_t timerlat_u; 1045 char *max_lat; 1046 int retval; 1047 int nr_cpus, i; 1048 1049 params = timerlat_top_parse_args(argc, argv); 1050 if (!params) 1051 exit(1); 1052 1053 top = timerlat_init_top(params); 1054 if (!top) { 1055 err_msg("Could not init osnoise top\n"); 1056 goto out_exit; 1057 } 1058 1059 trace = &top->trace; 1060 /* 1061 * Save trace instance into global variable so that SIGINT can stop 1062 * the timerlat tracer. 1063 * Otherwise, rtla could loop indefinitely when overloaded. 1064 */ 1065 top_inst = trace; 1066 1067 /* 1068 * Try to enable BPF, unless disabled explicitly. 1069 * If BPF enablement fails, fall back to tracefs mode. 1070 */ 1071 if (getenv("RTLA_NO_BPF") && strncmp(getenv("RTLA_NO_BPF"), "1", 2) == 0) { 1072 debug_msg("RTLA_NO_BPF set, disabling BPF\n"); 1073 params->mode = TRACING_MODE_TRACEFS; 1074 } else if (!tep_find_event_by_name(trace->tep, "osnoise", "timerlat_sample")) { 1075 debug_msg("osnoise:timerlat_sample missing, disabling BPF\n"); 1076 params->mode = TRACING_MODE_TRACEFS; 1077 } else { 1078 retval = timerlat_bpf_init(params); 1079 if (retval) { 1080 debug_msg("Could not enable BPF\n"); 1081 params->mode = TRACING_MODE_TRACEFS; 1082 } 1083 } 1084 1085 retval = timerlat_top_apply_config(top, params); 1086 if (retval) { 1087 err_msg("Could not apply config\n"); 1088 goto out_free; 1089 } 1090 1091 retval = enable_timerlat(trace); 1092 if (retval) { 1093 err_msg("Failed to enable timerlat tracer\n"); 1094 goto out_free; 1095 } 1096 1097 if (params->set_sched) { 1098 retval = set_comm_sched_attr("timerlat/", ¶ms->sched_param); 1099 if (retval) { 1100 err_msg("Failed to set sched parameters\n"); 1101 goto out_free; 1102 } 1103 } 1104 1105 if (params->cgroup && !params->user_data) { 1106 retval = set_comm_cgroup("timerlat/", params->cgroup_name); 1107 if (!retval) { 1108 err_msg("Failed to move threads to cgroup\n"); 1109 goto out_free; 1110 } 1111 } 1112 1113 if (params->dma_latency >= 0) { 1114 dma_latency_fd = set_cpu_dma_latency(params->dma_latency); 1115 if (dma_latency_fd < 0) { 1116 err_msg("Could not set /dev/cpu_dma_latency.\n"); 1117 goto out_free; 1118 } 1119 } 1120 1121 if (params->deepest_idle_state >= -1) { 1122 if (!have_libcpupower_support()) { 1123 err_msg("rtla built without libcpupower, --deepest-idle-state is not supported\n"); 1124 goto out_free; 1125 } 1126 1127 nr_cpus = sysconf(_SC_NPROCESSORS_CONF); 1128 1129 for (i = 0; i < nr_cpus; i++) { 1130 if (params->cpus && !CPU_ISSET(i, ¶ms->monitored_cpus)) 1131 continue; 1132 if (save_cpu_idle_disable_state(i) < 0) { 1133 err_msg("Could not save cpu idle state.\n"); 1134 goto out_free; 1135 } 1136 if (set_deepest_cpu_idle_state(i, params->deepest_idle_state) < 0) { 1137 err_msg("Could not set deepest cpu idle state.\n"); 1138 goto out_free; 1139 } 1140 } 1141 } 1142 1143 if (params->threshold_actions.present[ACTION_TRACE_OUTPUT] || 1144 params->end_actions.present[ACTION_TRACE_OUTPUT]) { 1145 record = osnoise_init_trace_tool("timerlat"); 1146 if (!record) { 1147 err_msg("Failed to enable the trace instance\n"); 1148 goto out_free; 1149 } 1150 params->threshold_actions.trace_output_inst = record->trace.inst; 1151 params->end_actions.trace_output_inst = record->trace.inst; 1152 1153 if (params->events) { 1154 retval = trace_events_enable(&record->trace, params->events); 1155 if (retval) 1156 goto out_top; 1157 } 1158 1159 if (params->buffer_size > 0) { 1160 retval = trace_set_buffer_size(&record->trace, params->buffer_size); 1161 if (retval) 1162 goto out_top; 1163 } 1164 } 1165 1166 if (!params->no_aa) { 1167 aa = osnoise_init_tool("timerlat_aa"); 1168 if (!aa) 1169 goto out_top; 1170 1171 retval = timerlat_aa_init(aa, params->dump_tasks); 1172 if (retval) { 1173 err_msg("Failed to enable the auto analysis instance\n"); 1174 goto out_top; 1175 } 1176 1177 /* if it is re-using the main instance, there is no need to start it */ 1178 if (aa != top) { 1179 retval = enable_timerlat(&aa->trace); 1180 if (retval) { 1181 err_msg("Failed to enable timerlat tracer\n"); 1182 goto out_top; 1183 } 1184 } 1185 } 1186 1187 if (params->user_workload) { 1188 /* rtla asked to stop */ 1189 params_u.should_run = 1; 1190 /* all threads left */ 1191 params_u.stopped_running = 0; 1192 1193 params_u.set = ¶ms->monitored_cpus; 1194 if (params->set_sched) 1195 params_u.sched_param = ¶ms->sched_param; 1196 else 1197 params_u.sched_param = NULL; 1198 1199 params_u.cgroup_name = params->cgroup_name; 1200 1201 retval = pthread_create(&timerlat_u, NULL, timerlat_u_dispatcher, ¶ms_u); 1202 if (retval) 1203 err_msg("Error creating timerlat user-space threads\n"); 1204 } 1205 1206 if (params->warmup > 0) { 1207 debug_msg("Warming up for %d seconds\n", params->warmup); 1208 sleep(params->warmup); 1209 } 1210 1211 /* 1212 * Start the tracers here, after having set all instances. 1213 * 1214 * Let the trace instance start first for the case of hitting a stop 1215 * tracing while enabling other instances. The trace instance is the 1216 * one with most valuable information. 1217 */ 1218 if (record) 1219 trace_instance_start(&record->trace); 1220 if (!params->no_aa) 1221 trace_instance_start(&aa->trace); 1222 if (params->mode == TRACING_MODE_TRACEFS) { 1223 trace_instance_start(trace); 1224 } else { 1225 retval = timerlat_bpf_attach(); 1226 if (retval) { 1227 err_msg("Error attaching BPF program\n"); 1228 goto out_top; 1229 } 1230 } 1231 1232 top->start_time = time(NULL); 1233 timerlat_top_set_signals(params); 1234 1235 if (params->mode == TRACING_MODE_TRACEFS) 1236 retval = timerlat_top_main_loop(top, record, aa, params, ¶ms_u); 1237 else 1238 retval = timerlat_top_bpf_main_loop(top, record, aa, params, ¶ms_u); 1239 1240 if (retval) 1241 goto out_top; 1242 1243 if (params->mode != TRACING_MODE_TRACEFS) 1244 timerlat_bpf_detach(); 1245 1246 if (params->user_workload && !params_u.stopped_running) { 1247 params_u.should_run = 0; 1248 sleep(1); 1249 } 1250 1251 timerlat_print_stats(params, top); 1252 1253 actions_perform(¶ms->end_actions); 1254 1255 return_value = PASSED; 1256 1257 if (osnoise_trace_is_off(top, record) && !stop_tracing) { 1258 printf("rtla timerlat hit stop tracing\n"); 1259 1260 if (!params->no_aa) 1261 timerlat_auto_analysis(params->stop_us, params->stop_total_us); 1262 1263 return_value = FAILED; 1264 } else if (params->aa_only) { 1265 /* 1266 * If the trace did not stop with --aa-only, at least print the 1267 * max known latency. 1268 */ 1269 max_lat = tracefs_instance_file_read(trace->inst, "tracing_max_latency", NULL); 1270 if (max_lat) { 1271 printf(" Max latency was %s\n", max_lat); 1272 free(max_lat); 1273 } 1274 } 1275 1276 out_top: 1277 timerlat_aa_destroy(); 1278 if (dma_latency_fd >= 0) 1279 close(dma_latency_fd); 1280 if (params->deepest_idle_state >= -1) { 1281 for (i = 0; i < nr_cpus; i++) { 1282 if (params->cpus && !CPU_ISSET(i, ¶ms->monitored_cpus)) 1283 continue; 1284 restore_cpu_idle_disable_state(i); 1285 } 1286 } 1287 trace_events_destroy(&record->trace, params->events); 1288 params->events = NULL; 1289 out_free: 1290 timerlat_free_top(top->data); 1291 if (aa && aa != top) 1292 osnoise_destroy_tool(aa); 1293 osnoise_destroy_tool(record); 1294 osnoise_destroy_tool(top); 1295 actions_destroy(¶ms->threshold_actions); 1296 actions_destroy(¶ms->end_actions); 1297 if (params->mode != TRACING_MODE_TRACEFS) 1298 timerlat_bpf_destroy(); 1299 free(params); 1300 free_cpu_idle_disable_states(); 1301 out_exit: 1302 exit(return_value); 1303 } 1304