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