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