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 if (data->bucket_size) 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 /* 405 * timerlat_print_stats - print data for all CPUs 406 */ 407 static void 408 timerlat_print_stats(struct timerlat_hist_params *params, struct osnoise_tool *tool) 409 { 410 struct timerlat_hist_data *data = tool->data; 411 struct trace_instance *trace = &tool->trace; 412 int bucket, cpu; 413 int total; 414 415 timerlat_hist_header(tool); 416 417 for (bucket = 0; bucket < data->entries; bucket++) { 418 total = 0; 419 420 if (!params->no_index) 421 trace_seq_printf(trace->seq, "%-6d", 422 bucket * data->bucket_size); 423 424 for (cpu = 0; cpu < data->nr_cpus; cpu++) { 425 if (params->cpus && !CPU_ISSET(cpu, ¶ms->monitored_cpus)) 426 continue; 427 428 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count) 429 continue; 430 431 if (!params->no_irq) { 432 total += data->hist[cpu].irq[bucket]; 433 trace_seq_printf(trace->seq, "%9d ", 434 data->hist[cpu].irq[bucket]); 435 } 436 437 if (!params->no_thread) { 438 total += data->hist[cpu].thread[bucket]; 439 trace_seq_printf(trace->seq, "%9d ", 440 data->hist[cpu].thread[bucket]); 441 } 442 443 if (params->user_hist) { 444 total += data->hist[cpu].user[bucket]; 445 trace_seq_printf(trace->seq, "%9d ", 446 data->hist[cpu].user[bucket]); 447 } 448 449 } 450 451 if (total == 0 && !params->with_zeros) { 452 trace_seq_reset(trace->seq); 453 continue; 454 } 455 456 trace_seq_printf(trace->seq, "\n"); 457 trace_seq_do_printf(trace->seq); 458 trace_seq_reset(trace->seq); 459 } 460 461 if (!params->no_index) 462 trace_seq_printf(trace->seq, "over: "); 463 464 for (cpu = 0; cpu < data->nr_cpus; cpu++) { 465 if (params->cpus && !CPU_ISSET(cpu, ¶ms->monitored_cpus)) 466 continue; 467 468 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count) 469 continue; 470 471 if (!params->no_irq) 472 trace_seq_printf(trace->seq, "%9d ", 473 data->hist[cpu].irq[data->entries]); 474 475 if (!params->no_thread) 476 trace_seq_printf(trace->seq, "%9d ", 477 data->hist[cpu].thread[data->entries]); 478 479 if (params->user_hist) 480 trace_seq_printf(trace->seq, "%9d ", 481 data->hist[cpu].user[data->entries]); 482 } 483 trace_seq_printf(trace->seq, "\n"); 484 trace_seq_do_printf(trace->seq); 485 trace_seq_reset(trace->seq); 486 487 timerlat_print_summary(params, trace, data); 488 } 489 490 /* 491 * timerlat_hist_usage - prints timerlat top usage message 492 */ 493 static void timerlat_hist_usage(char *usage) 494 { 495 int i; 496 497 char *msg[] = { 498 "", 499 " usage: [rtla] timerlat hist [-h] [-q] [-d s] [-D] [-n] [-a us] [-p us] [-i us] [-T us] [-s us] \\", 500 " [-t[=file]] [-e sys[:event]] [--filter <filter>] [--trigger <trigger>] [-c cpu-list] [-H cpu-list]\\", 501 " [-P priority] [-E N] [-b N] [--no-irq] [--no-thread] [--no-header] [--no-summary] \\", 502 " [--no-index] [--with-zeros] [--dma-latency us] [-C[=cgroup_name]] [--no-aa] [--dump-task] [-u]", 503 "", 504 " -h/--help: print this menu", 505 " -a/--auto: set automatic trace mode, stopping the session if argument in us latency is hit", 506 " -p/--period us: timerlat period in us", 507 " -i/--irq us: stop trace if the irq latency is higher than the argument in us", 508 " -T/--thread us: stop trace if the thread latency is higher than the argument in us", 509 " -s/--stack us: save the stack trace at the IRQ if a thread latency is higher than the argument in us", 510 " -c/--cpus cpus: run the tracer only on the given cpus", 511 " -H/--house-keeping cpus: run rtla control threads only on the given cpus", 512 " -C/--cgroup[=cgroup_name]: set cgroup, if no cgroup_name is passed, the rtla's cgroup will be inherited", 513 " -d/--duration time[m|h|d]: duration of the session in seconds", 514 " --dump-tasks: prints the task running on all CPUs if stop conditions are met (depends on !--no-aa)", 515 " -D/--debug: print debug info", 516 " -t/--trace[=file]: save the stopped trace to [file|timerlat_trace.txt]", 517 " -e/--event <sys:event>: enable the <sys:event> in the trace instance, multiple -e are allowed", 518 " --filter <filter>: enable a trace event filter to the previous -e event", 519 " --trigger <trigger>: enable a trace event trigger to the previous -e event", 520 " -n/--nano: display data in nanoseconds", 521 " --no-aa: disable auto-analysis, reducing rtla timerlat cpu usage", 522 " -b/--bucket-size N: set the histogram bucket size (default 1)", 523 " -E/--entries N: set the number of entries of the histogram (default 256)", 524 " --no-irq: ignore IRQ latencies", 525 " --no-thread: ignore thread latencies", 526 " --no-header: do not print header", 527 " --no-summary: do not print summary", 528 " --no-index: do not print index", 529 " --with-zeros: print zero only entries", 530 " --dma-latency us: set /dev/cpu_dma_latency latency <us> to reduce exit from idle latency", 531 " -P/--priority o:prio|r:prio|f:prio|d:runtime:period : set scheduling parameters", 532 " o:prio - use SCHED_OTHER with prio", 533 " r:prio - use SCHED_RR with prio", 534 " f:prio - use SCHED_FIFO with prio", 535 " d:runtime[us|ms|s]:period[us|ms|s] - use SCHED_DEADLINE with runtime and period", 536 " in nanoseconds", 537 " -u/--user-threads: use rtla user-space threads instead of in-kernel timerlat threads", 538 NULL, 539 }; 540 541 if (usage) 542 fprintf(stderr, "%s\n", usage); 543 544 fprintf(stderr, "rtla timerlat hist: a per-cpu histogram of the timer latency (version %s)\n", 545 VERSION); 546 547 for (i = 0; msg[i]; i++) 548 fprintf(stderr, "%s\n", msg[i]); 549 exit(1); 550 } 551 552 /* 553 * timerlat_hist_parse_args - allocs, parse and fill the cmd line parameters 554 */ 555 static struct timerlat_hist_params 556 *timerlat_hist_parse_args(int argc, char *argv[]) 557 { 558 struct timerlat_hist_params *params; 559 struct trace_events *tevent; 560 int auto_thresh; 561 int retval; 562 int c; 563 564 params = calloc(1, sizeof(*params)); 565 if (!params) 566 exit(1); 567 568 /* disabled by default */ 569 params->dma_latency = -1; 570 571 /* display data in microseconds */ 572 params->output_divisor = 1000; 573 params->bucket_size = 1; 574 params->entries = 256; 575 576 while (1) { 577 static struct option long_options[] = { 578 {"auto", required_argument, 0, 'a'}, 579 {"cpus", required_argument, 0, 'c'}, 580 {"cgroup", optional_argument, 0, 'C'}, 581 {"bucket-size", required_argument, 0, 'b'}, 582 {"debug", no_argument, 0, 'D'}, 583 {"entries", required_argument, 0, 'E'}, 584 {"duration", required_argument, 0, 'd'}, 585 {"house-keeping", required_argument, 0, 'H'}, 586 {"help", no_argument, 0, 'h'}, 587 {"irq", required_argument, 0, 'i'}, 588 {"nano", no_argument, 0, 'n'}, 589 {"period", required_argument, 0, 'p'}, 590 {"priority", required_argument, 0, 'P'}, 591 {"stack", required_argument, 0, 's'}, 592 {"thread", required_argument, 0, 'T'}, 593 {"trace", optional_argument, 0, 't'}, 594 {"user-threads", no_argument, 0, 'u'}, 595 {"event", required_argument, 0, 'e'}, 596 {"no-irq", no_argument, 0, '0'}, 597 {"no-thread", no_argument, 0, '1'}, 598 {"no-header", no_argument, 0, '2'}, 599 {"no-summary", no_argument, 0, '3'}, 600 {"no-index", no_argument, 0, '4'}, 601 {"with-zeros", no_argument, 0, '5'}, 602 {"trigger", required_argument, 0, '6'}, 603 {"filter", required_argument, 0, '7'}, 604 {"dma-latency", required_argument, 0, '8'}, 605 {"no-aa", no_argument, 0, '9'}, 606 {"dump-task", no_argument, 0, '\1'}, 607 {0, 0, 0, 0} 608 }; 609 610 /* getopt_long stores the option index here. */ 611 int option_index = 0; 612 613 c = getopt_long(argc, argv, "a:c:C::b:d:e:E:DhH:i:np:P:s:t::T:u0123456:7:8:9\1", 614 long_options, &option_index); 615 616 /* detect the end of the options. */ 617 if (c == -1) 618 break; 619 620 switch (c) { 621 case 'a': 622 auto_thresh = get_llong_from_str(optarg); 623 624 /* set thread stop to auto_thresh */ 625 params->stop_total_us = auto_thresh; 626 params->stop_us = auto_thresh; 627 628 /* get stack trace */ 629 params->print_stack = auto_thresh; 630 631 /* set trace */ 632 params->trace_output = "timerlat_trace.txt"; 633 634 break; 635 case 'c': 636 retval = parse_cpu_set(optarg, ¶ms->monitored_cpus); 637 if (retval) 638 timerlat_hist_usage("\nInvalid -c cpu list\n"); 639 params->cpus = optarg; 640 break; 641 case 'C': 642 params->cgroup = 1; 643 if (!optarg) { 644 /* will inherit this cgroup */ 645 params->cgroup_name = NULL; 646 } else if (*optarg == '=') { 647 /* skip the = */ 648 params->cgroup_name = ++optarg; 649 } 650 break; 651 case 'b': 652 params->bucket_size = get_llong_from_str(optarg); 653 if ((params->bucket_size == 0) || (params->bucket_size >= 1000000)) 654 timerlat_hist_usage("Bucket size needs to be > 0 and <= 1000000\n"); 655 break; 656 case 'D': 657 config_debug = 1; 658 break; 659 case 'd': 660 params->duration = parse_seconds_duration(optarg); 661 if (!params->duration) 662 timerlat_hist_usage("Invalid -D duration\n"); 663 break; 664 case 'e': 665 tevent = trace_event_alloc(optarg); 666 if (!tevent) { 667 err_msg("Error alloc trace event"); 668 exit(EXIT_FAILURE); 669 } 670 671 if (params->events) 672 tevent->next = params->events; 673 674 params->events = tevent; 675 break; 676 case 'E': 677 params->entries = get_llong_from_str(optarg); 678 if ((params->entries < 10) || (params->entries > 9999999)) 679 timerlat_hist_usage("Entries must be > 10 and < 9999999\n"); 680 break; 681 case 'h': 682 case '?': 683 timerlat_hist_usage(NULL); 684 break; 685 case 'H': 686 params->hk_cpus = 1; 687 retval = parse_cpu_set(optarg, ¶ms->hk_cpu_set); 688 if (retval) { 689 err_msg("Error parsing house keeping CPUs\n"); 690 exit(EXIT_FAILURE); 691 } 692 break; 693 case 'i': 694 params->stop_us = get_llong_from_str(optarg); 695 break; 696 case 'n': 697 params->output_divisor = 1; 698 break; 699 case 'p': 700 params->timerlat_period_us = get_llong_from_str(optarg); 701 if (params->timerlat_period_us > 1000000) 702 timerlat_hist_usage("Period longer than 1 s\n"); 703 break; 704 case 'P': 705 retval = parse_prio(optarg, ¶ms->sched_param); 706 if (retval == -1) 707 timerlat_hist_usage("Invalid -P priority"); 708 params->set_sched = 1; 709 break; 710 case 's': 711 params->print_stack = get_llong_from_str(optarg); 712 break; 713 case 'T': 714 params->stop_total_us = get_llong_from_str(optarg); 715 break; 716 case 't': 717 if (optarg) 718 /* skip = */ 719 params->trace_output = &optarg[1]; 720 else 721 params->trace_output = "timerlat_trace.txt"; 722 break; 723 case 'u': 724 params->user_hist = 1; 725 break; 726 case '0': /* no irq */ 727 params->no_irq = 1; 728 break; 729 case '1': /* no thread */ 730 params->no_thread = 1; 731 break; 732 case '2': /* no header */ 733 params->no_header = 1; 734 break; 735 case '3': /* no summary */ 736 params->no_summary = 1; 737 break; 738 case '4': /* no index */ 739 params->no_index = 1; 740 break; 741 case '5': /* with zeros */ 742 params->with_zeros = 1; 743 break; 744 case '6': /* trigger */ 745 if (params->events) { 746 retval = trace_event_add_trigger(params->events, optarg); 747 if (retval) { 748 err_msg("Error adding trigger %s\n", optarg); 749 exit(EXIT_FAILURE); 750 } 751 } else { 752 timerlat_hist_usage("--trigger requires a previous -e\n"); 753 } 754 break; 755 case '7': /* filter */ 756 if (params->events) { 757 retval = trace_event_add_filter(params->events, optarg); 758 if (retval) { 759 err_msg("Error adding filter %s\n", optarg); 760 exit(EXIT_FAILURE); 761 } 762 } else { 763 timerlat_hist_usage("--filter requires a previous -e\n"); 764 } 765 break; 766 case '8': 767 params->dma_latency = get_llong_from_str(optarg); 768 if (params->dma_latency < 0 || params->dma_latency > 10000) { 769 err_msg("--dma-latency needs to be >= 0 and < 10000"); 770 exit(EXIT_FAILURE); 771 } 772 break; 773 case '9': 774 params->no_aa = 1; 775 break; 776 case '\1': 777 params->dump_tasks = 1; 778 break; 779 default: 780 timerlat_hist_usage("Invalid option"); 781 } 782 } 783 784 if (geteuid()) { 785 err_msg("rtla needs root permission\n"); 786 exit(EXIT_FAILURE); 787 } 788 789 if (params->no_irq && params->no_thread) 790 timerlat_hist_usage("no-irq and no-thread set, there is nothing to do here"); 791 792 if (params->no_index && !params->with_zeros) 793 timerlat_hist_usage("no-index set with with-zeros is not set - it does not make sense"); 794 795 /* 796 * Auto analysis only happens if stop tracing, thus: 797 */ 798 if (!params->stop_us && !params->stop_total_us) 799 params->no_aa = 1; 800 801 return params; 802 } 803 804 /* 805 * timerlat_hist_apply_config - apply the hist configs to the initialized tool 806 */ 807 static int 808 timerlat_hist_apply_config(struct osnoise_tool *tool, struct timerlat_hist_params *params) 809 { 810 int retval, i; 811 812 if (!params->sleep_time) 813 params->sleep_time = 1; 814 815 if (params->cpus) { 816 retval = osnoise_set_cpus(tool->context, params->cpus); 817 if (retval) { 818 err_msg("Failed to apply CPUs config\n"); 819 goto out_err; 820 } 821 } else { 822 for (i = 0; i < sysconf(_SC_NPROCESSORS_CONF); i++) 823 CPU_SET(i, ¶ms->monitored_cpus); 824 } 825 826 if (params->stop_us) { 827 retval = osnoise_set_stop_us(tool->context, params->stop_us); 828 if (retval) { 829 err_msg("Failed to set stop us\n"); 830 goto out_err; 831 } 832 } 833 834 if (params->stop_total_us) { 835 retval = osnoise_set_stop_total_us(tool->context, params->stop_total_us); 836 if (retval) { 837 err_msg("Failed to set stop total us\n"); 838 goto out_err; 839 } 840 } 841 842 if (params->timerlat_period_us) { 843 retval = osnoise_set_timerlat_period_us(tool->context, params->timerlat_period_us); 844 if (retval) { 845 err_msg("Failed to set timerlat period\n"); 846 goto out_err; 847 } 848 } 849 850 if (params->print_stack) { 851 retval = osnoise_set_print_stack(tool->context, params->print_stack); 852 if (retval) { 853 err_msg("Failed to set print stack\n"); 854 goto out_err; 855 } 856 } 857 858 if (params->hk_cpus) { 859 retval = sched_setaffinity(getpid(), sizeof(params->hk_cpu_set), 860 ¶ms->hk_cpu_set); 861 if (retval == -1) { 862 err_msg("Failed to set rtla to the house keeping CPUs\n"); 863 goto out_err; 864 } 865 } else if (params->cpus) { 866 /* 867 * Even if the user do not set a house-keeping CPU, try to 868 * move rtla to a CPU set different to the one where the user 869 * set the workload to run. 870 * 871 * No need to check results as this is an automatic attempt. 872 */ 873 auto_house_keeping(¶ms->monitored_cpus); 874 } 875 876 if (params->user_hist) { 877 retval = osnoise_set_workload(tool->context, 0); 878 if (retval) { 879 err_msg("Failed to set OSNOISE_WORKLOAD option\n"); 880 goto out_err; 881 } 882 } 883 884 return 0; 885 886 out_err: 887 return -1; 888 } 889 890 /* 891 * timerlat_init_hist - initialize a timerlat hist tool with parameters 892 */ 893 static struct osnoise_tool 894 *timerlat_init_hist(struct timerlat_hist_params *params) 895 { 896 struct osnoise_tool *tool; 897 int nr_cpus; 898 899 nr_cpus = sysconf(_SC_NPROCESSORS_CONF); 900 901 tool = osnoise_init_tool("timerlat_hist"); 902 if (!tool) 903 return NULL; 904 905 tool->data = timerlat_alloc_histogram(nr_cpus, params->entries, params->bucket_size); 906 if (!tool->data) 907 goto out_err; 908 909 tool->params = params; 910 911 tep_register_event_handler(tool->trace.tep, -1, "ftrace", "timerlat", 912 timerlat_hist_handler, tool); 913 914 return tool; 915 916 out_err: 917 osnoise_destroy_tool(tool); 918 return NULL; 919 } 920 921 static int stop_tracing; 922 static void stop_hist(int sig) 923 { 924 stop_tracing = 1; 925 } 926 927 /* 928 * timerlat_hist_set_signals - handles the signal to stop the tool 929 */ 930 static void 931 timerlat_hist_set_signals(struct timerlat_hist_params *params) 932 { 933 signal(SIGINT, stop_hist); 934 if (params->duration) { 935 signal(SIGALRM, stop_hist); 936 alarm(params->duration); 937 } 938 } 939 940 int timerlat_hist_main(int argc, char *argv[]) 941 { 942 struct timerlat_hist_params *params; 943 struct osnoise_tool *record = NULL; 944 struct timerlat_u_params params_u; 945 struct osnoise_tool *tool = NULL; 946 struct osnoise_tool *aa = NULL; 947 struct trace_instance *trace; 948 int dma_latency_fd = -1; 949 int return_value = 1; 950 pthread_t timerlat_u; 951 int retval; 952 953 params = timerlat_hist_parse_args(argc, argv); 954 if (!params) 955 exit(1); 956 957 tool = timerlat_init_hist(params); 958 if (!tool) { 959 err_msg("Could not init osnoise hist\n"); 960 goto out_exit; 961 } 962 963 retval = timerlat_hist_apply_config(tool, params); 964 if (retval) { 965 err_msg("Could not apply config\n"); 966 goto out_free; 967 } 968 969 trace = &tool->trace; 970 971 retval = enable_timerlat(trace); 972 if (retval) { 973 err_msg("Failed to enable timerlat tracer\n"); 974 goto out_free; 975 } 976 977 if (params->set_sched) { 978 retval = set_comm_sched_attr("timerlat/", ¶ms->sched_param); 979 if (retval) { 980 err_msg("Failed to set sched parameters\n"); 981 goto out_free; 982 } 983 } 984 985 if (params->cgroup && !params->user_hist) { 986 retval = set_comm_cgroup("timerlat/", params->cgroup_name); 987 if (!retval) { 988 err_msg("Failed to move threads to cgroup\n"); 989 goto out_free; 990 } 991 } 992 993 if (params->dma_latency >= 0) { 994 dma_latency_fd = set_cpu_dma_latency(params->dma_latency); 995 if (dma_latency_fd < 0) { 996 err_msg("Could not set /dev/cpu_dma_latency.\n"); 997 goto out_free; 998 } 999 } 1000 1001 if (params->trace_output) { 1002 record = osnoise_init_trace_tool("timerlat"); 1003 if (!record) { 1004 err_msg("Failed to enable the trace instance\n"); 1005 goto out_free; 1006 } 1007 1008 if (params->events) { 1009 retval = trace_events_enable(&record->trace, params->events); 1010 if (retval) 1011 goto out_hist; 1012 } 1013 } 1014 1015 if (!params->no_aa) { 1016 aa = osnoise_init_tool("timerlat_aa"); 1017 if (!aa) 1018 goto out_hist; 1019 1020 retval = timerlat_aa_init(aa, params->dump_tasks); 1021 if (retval) { 1022 err_msg("Failed to enable the auto analysis instance\n"); 1023 goto out_hist; 1024 } 1025 1026 retval = enable_timerlat(&aa->trace); 1027 if (retval) { 1028 err_msg("Failed to enable timerlat tracer\n"); 1029 goto out_hist; 1030 } 1031 } 1032 1033 /* 1034 * Start the tracers here, after having set all instances. 1035 * 1036 * Let the trace instance start first for the case of hitting a stop 1037 * tracing while enabling other instances. The trace instance is the 1038 * one with most valuable information. 1039 */ 1040 if (params->trace_output) 1041 trace_instance_start(&record->trace); 1042 if (!params->no_aa) 1043 trace_instance_start(&aa->trace); 1044 trace_instance_start(trace); 1045 1046 tool->start_time = time(NULL); 1047 timerlat_hist_set_signals(params); 1048 1049 if (params->user_hist) { 1050 /* rtla asked to stop */ 1051 params_u.should_run = 1; 1052 /* all threads left */ 1053 params_u.stopped_running = 0; 1054 1055 params_u.set = ¶ms->monitored_cpus; 1056 if (params->set_sched) 1057 params_u.sched_param = ¶ms->sched_param; 1058 else 1059 params_u.sched_param = NULL; 1060 1061 params_u.cgroup_name = params->cgroup_name; 1062 1063 retval = pthread_create(&timerlat_u, NULL, timerlat_u_dispatcher, ¶ms_u); 1064 if (retval) 1065 err_msg("Error creating timerlat user-space threads\n"); 1066 } 1067 1068 while (!stop_tracing) { 1069 sleep(params->sleep_time); 1070 1071 retval = tracefs_iterate_raw_events(trace->tep, 1072 trace->inst, 1073 NULL, 1074 0, 1075 collect_registered_events, 1076 trace); 1077 if (retval < 0) { 1078 err_msg("Error iterating on events\n"); 1079 goto out_hist; 1080 } 1081 1082 if (trace_is_off(&tool->trace, &record->trace)) 1083 break; 1084 1085 /* is there still any user-threads ? */ 1086 if (params->user_hist) { 1087 if (params_u.stopped_running) { 1088 debug_msg("timerlat user-space threads stopped!\n"); 1089 break; 1090 } 1091 } 1092 } 1093 if (params->user_hist && !params_u.stopped_running) { 1094 params_u.should_run = 0; 1095 sleep(1); 1096 } 1097 1098 timerlat_print_stats(params, tool); 1099 1100 return_value = 0; 1101 1102 if (trace_is_off(&tool->trace, &record->trace)) { 1103 printf("rtla timerlat hit stop tracing\n"); 1104 1105 if (!params->no_aa) 1106 timerlat_auto_analysis(params->stop_us, params->stop_total_us); 1107 1108 if (params->trace_output) { 1109 printf(" Saving trace to %s\n", params->trace_output); 1110 save_trace_to_file(record->trace.inst, params->trace_output); 1111 } 1112 } 1113 1114 out_hist: 1115 timerlat_aa_destroy(); 1116 if (dma_latency_fd >= 0) 1117 close(dma_latency_fd); 1118 trace_events_destroy(&record->trace, params->events); 1119 params->events = NULL; 1120 out_free: 1121 timerlat_free_histogram(tool->data); 1122 osnoise_destroy_tool(aa); 1123 osnoise_destroy_tool(record); 1124 osnoise_destroy_tool(tool); 1125 free(params); 1126 out_exit: 1127 exit(return_value); 1128 } 1129