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