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