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