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 int i; 700 701 char *msg[] = { 702 "", 703 " usage: [rtla] timerlat hist [-h] [-q] [-d s] [-D] [-n] [-a us] [-p us] [-i us] [-T us] [-s us] \\", 704 " [-t [file]] [-e sys[:event]] [--filter <filter>] [--trigger <trigger>] [-c cpu-list] [-H cpu-list]\\", 705 " [-P priority] [-E N] [-b N] [--no-irq] [--no-thread] [--no-header] [--no-summary] \\", 706 " [--no-index] [--with-zeros] [--dma-latency us] [-C [cgroup_name]] [--no-aa] [--dump-task] [-u|-k]", 707 " [--warm-up s] [--deepest-idle-state n]", 708 "", 709 " -h/--help: print this menu", 710 " -a/--auto: set automatic trace mode, stopping the session if argument in us latency is hit", 711 " -p/--period us: timerlat period in us", 712 " -i/--irq us: stop trace if the irq latency is higher than the argument in us", 713 " -T/--thread us: stop trace if the thread latency is higher than the argument in us", 714 " -s/--stack us: save the stack trace at the IRQ if a thread latency is higher than the argument in us", 715 " -c/--cpus cpus: run the tracer only on the given cpus", 716 " -H/--house-keeping cpus: run rtla control threads only on the given cpus", 717 " -C/--cgroup [cgroup_name]: set cgroup, if no cgroup_name is passed, the rtla's cgroup will be inherited", 718 " -d/--duration time[m|h|d]: duration of the session in seconds", 719 " --dump-tasks: prints the task running on all CPUs if stop conditions are met (depends on !--no-aa)", 720 " -D/--debug: print debug info", 721 " -t/--trace [file]: save the stopped trace to [file|timerlat_trace.txt]", 722 " -e/--event <sys:event>: enable the <sys:event> in the trace instance, multiple -e are allowed", 723 " --filter <filter>: enable a trace event filter to the previous -e event", 724 " --trigger <trigger>: enable a trace event trigger to the previous -e event", 725 " -n/--nano: display data in nanoseconds", 726 " --no-aa: disable auto-analysis, reducing rtla timerlat cpu usage", 727 " -b/--bucket-size N: set the histogram bucket size (default 1)", 728 " -E/--entries N: set the number of entries of the histogram (default 256)", 729 " --no-irq: ignore IRQ latencies", 730 " --no-thread: ignore thread latencies", 731 " --no-header: do not print header", 732 " --no-summary: do not print summary", 733 " --no-index: do not print index", 734 " --with-zeros: print zero only entries", 735 " --dma-latency us: set /dev/cpu_dma_latency latency <us> to reduce exit from idle latency", 736 " -P/--priority o:prio|r:prio|f:prio|d:runtime:period : set scheduling parameters", 737 " o:prio - use SCHED_OTHER with prio", 738 " r:prio - use SCHED_RR with prio", 739 " f:prio - use SCHED_FIFO with prio", 740 " d:runtime[us|ms|s]:period[us|ms|s] - use SCHED_DEADLINE with runtime and period", 741 " in nanoseconds", 742 " -u/--user-threads: use rtla user-space threads instead of kernel-space timerlat threads", 743 " -k/--kernel-threads: use timerlat kernel-space threads instead of rtla user-space threads", 744 " -U/--user-load: enable timerlat for user-defined user-space workload", 745 " --warm-up s: let the workload run for s seconds before collecting data", 746 " --trace-buffer-size kB: set the per-cpu trace buffer size in kB", 747 " --deepest-idle-state n: only go down to idle state n on cpus used by timerlat to reduce exit from idle latency", 748 " --on-threshold <action>: define action to be executed at latency threshold, multiple are allowed", 749 " --on-end <action>: define action to be executed at measurement end, multiple are allowed", 750 NULL, 751 }; 752 753 fprintf(stderr, "rtla timerlat hist: a per-cpu histogram of the timer latency (version %s)\n", 754 VERSION); 755 756 for (i = 0; msg[i]; i++) 757 fprintf(stderr, "%s\n", msg[i]); 758 759 exit(EXIT_SUCCESS); 760 } 761 762 /* 763 * timerlat_hist_parse_args - allocs, parse and fill the cmd line parameters 764 */ 765 static struct common_params 766 *timerlat_hist_parse_args(int argc, char *argv[]) 767 { 768 struct timerlat_params *params; 769 struct trace_events *tevent; 770 int auto_thresh; 771 int retval; 772 int c; 773 char *trace_output = NULL; 774 775 params = calloc(1, sizeof(*params)); 776 if (!params) 777 exit(1); 778 779 actions_init(¶ms->common.threshold_actions); 780 actions_init(¶ms->common.end_actions); 781 782 /* disabled by default */ 783 params->dma_latency = -1; 784 785 /* disabled by default */ 786 params->deepest_idle_state = -2; 787 788 /* display data in microseconds */ 789 params->common.output_divisor = 1000; 790 params->common.hist.bucket_size = 1; 791 params->common.hist.entries = 256; 792 793 /* default to BPF mode */ 794 params->mode = TRACING_MODE_BPF; 795 796 while (1) { 797 static struct option long_options[] = { 798 {"auto", required_argument, 0, 'a'}, 799 {"cpus", required_argument, 0, 'c'}, 800 {"cgroup", optional_argument, 0, 'C'}, 801 {"bucket-size", required_argument, 0, 'b'}, 802 {"debug", no_argument, 0, 'D'}, 803 {"entries", required_argument, 0, 'E'}, 804 {"duration", required_argument, 0, 'd'}, 805 {"house-keeping", required_argument, 0, 'H'}, 806 {"help", no_argument, 0, 'h'}, 807 {"irq", required_argument, 0, 'i'}, 808 {"nano", no_argument, 0, 'n'}, 809 {"period", required_argument, 0, 'p'}, 810 {"priority", required_argument, 0, 'P'}, 811 {"stack", required_argument, 0, 's'}, 812 {"thread", required_argument, 0, 'T'}, 813 {"trace", optional_argument, 0, 't'}, 814 {"user-threads", no_argument, 0, 'u'}, 815 {"kernel-threads", no_argument, 0, 'k'}, 816 {"user-load", no_argument, 0, 'U'}, 817 {"event", required_argument, 0, 'e'}, 818 {"no-irq", no_argument, 0, '0'}, 819 {"no-thread", no_argument, 0, '1'}, 820 {"no-header", no_argument, 0, '2'}, 821 {"no-summary", no_argument, 0, '3'}, 822 {"no-index", no_argument, 0, '4'}, 823 {"with-zeros", no_argument, 0, '5'}, 824 {"trigger", required_argument, 0, '6'}, 825 {"filter", required_argument, 0, '7'}, 826 {"dma-latency", required_argument, 0, '8'}, 827 {"no-aa", no_argument, 0, '9'}, 828 {"dump-task", no_argument, 0, '\1'}, 829 {"warm-up", required_argument, 0, '\2'}, 830 {"trace-buffer-size", required_argument, 0, '\3'}, 831 {"deepest-idle-state", required_argument, 0, '\4'}, 832 {"on-threshold", required_argument, 0, '\5'}, 833 {"on-end", required_argument, 0, '\6'}, 834 {0, 0, 0, 0} 835 }; 836 837 c = getopt_long(argc, argv, "a:c:C::b:d:e:E:DhH:i:knp:P:s:t::T:uU0123456:7:8:9\1\2:\3:", 838 long_options, NULL); 839 840 /* detect the end of the options. */ 841 if (c == -1) 842 break; 843 844 switch (c) { 845 case 'a': 846 auto_thresh = get_llong_from_str(optarg); 847 848 /* set thread stop to auto_thresh */ 849 params->common.stop_total_us = auto_thresh; 850 params->common.stop_us = auto_thresh; 851 852 /* get stack trace */ 853 params->print_stack = auto_thresh; 854 855 /* set trace */ 856 trace_output = "timerlat_trace.txt"; 857 858 break; 859 case 'c': 860 retval = parse_cpu_set(optarg, ¶ms->common.monitored_cpus); 861 if (retval) 862 fatal("Invalid -c cpu list"); 863 params->common.cpus = optarg; 864 break; 865 case 'C': 866 params->common.cgroup = 1; 867 params->common.cgroup_name = parse_optional_arg(argc, argv); 868 break; 869 case 'b': 870 params->common.hist.bucket_size = get_llong_from_str(optarg); 871 if (params->common.hist.bucket_size == 0 || 872 params->common.hist.bucket_size >= 1000000) 873 fatal("Bucket size needs to be > 0 and <= 1000000"); 874 break; 875 case 'D': 876 config_debug = 1; 877 break; 878 case 'd': 879 params->common.duration = parse_seconds_duration(optarg); 880 if (!params->common.duration) 881 fatal("Invalid -D duration"); 882 break; 883 case 'e': 884 tevent = trace_event_alloc(optarg); 885 if (!tevent) 886 fatal("Error alloc trace event"); 887 888 if (params->common.events) 889 tevent->next = params->common.events; 890 891 params->common.events = tevent; 892 break; 893 case 'E': 894 params->common.hist.entries = get_llong_from_str(optarg); 895 if (params->common.hist.entries < 10 || 896 params->common.hist.entries > 9999999) 897 fatal("Entries must be > 10 and < 9999999"); 898 break; 899 case 'h': 900 case '?': 901 timerlat_hist_usage(); 902 break; 903 case 'H': 904 params->common.hk_cpus = 1; 905 retval = parse_cpu_set(optarg, ¶ms->common.hk_cpu_set); 906 if (retval) 907 fatal("Error parsing house keeping CPUs"); 908 break; 909 case 'i': 910 params->common.stop_us = get_llong_from_str(optarg); 911 break; 912 case 'k': 913 params->common.kernel_workload = 1; 914 break; 915 case 'n': 916 params->common.output_divisor = 1; 917 break; 918 case 'p': 919 params->timerlat_period_us = get_llong_from_str(optarg); 920 if (params->timerlat_period_us > 1000000) 921 fatal("Period longer than 1 s"); 922 break; 923 case 'P': 924 retval = parse_prio(optarg, ¶ms->common.sched_param); 925 if (retval == -1) 926 fatal("Invalid -P priority"); 927 params->common.set_sched = 1; 928 break; 929 case 's': 930 params->print_stack = get_llong_from_str(optarg); 931 break; 932 case 'T': 933 params->common.stop_total_us = get_llong_from_str(optarg); 934 break; 935 case 't': 936 trace_output = parse_optional_arg(argc, argv); 937 if (!trace_output) 938 trace_output = "timerlat_trace.txt"; 939 break; 940 case 'u': 941 params->common.user_workload = 1; 942 /* fallback: -u implies in -U */ 943 case 'U': 944 params->common.user_data = 1; 945 break; 946 case '0': /* no irq */ 947 params->common.hist.no_irq = 1; 948 break; 949 case '1': /* no thread */ 950 params->common.hist.no_thread = 1; 951 break; 952 case '2': /* no header */ 953 params->common.hist.no_header = 1; 954 break; 955 case '3': /* no summary */ 956 params->common.hist.no_summary = 1; 957 break; 958 case '4': /* no index */ 959 params->common.hist.no_index = 1; 960 break; 961 case '5': /* with zeros */ 962 params->common.hist.with_zeros = 1; 963 break; 964 case '6': /* trigger */ 965 if (params->common.events) { 966 retval = trace_event_add_trigger(params->common.events, optarg); 967 if (retval) 968 fatal("Error adding trigger %s", optarg); 969 } else { 970 fatal("--trigger requires a previous -e"); 971 } 972 break; 973 case '7': /* filter */ 974 if (params->common.events) { 975 retval = trace_event_add_filter(params->common.events, optarg); 976 if (retval) 977 fatal("Error adding filter %s", optarg); 978 } else { 979 fatal("--filter requires a previous -e"); 980 } 981 break; 982 case '8': 983 params->dma_latency = get_llong_from_str(optarg); 984 if (params->dma_latency < 0 || params->dma_latency > 10000) 985 fatal("--dma-latency needs to be >= 0 and < 10000"); 986 break; 987 case '9': 988 params->no_aa = 1; 989 break; 990 case '\1': 991 params->dump_tasks = 1; 992 break; 993 case '\2': 994 params->common.warmup = get_llong_from_str(optarg); 995 break; 996 case '\3': 997 params->common.buffer_size = get_llong_from_str(optarg); 998 break; 999 case '\4': 1000 params->deepest_idle_state = get_llong_from_str(optarg); 1001 break; 1002 case '\5': 1003 retval = actions_parse(¶ms->common.threshold_actions, optarg, 1004 "timerlat_trace.txt"); 1005 if (retval) 1006 fatal("Invalid action %s", optarg); 1007 break; 1008 case '\6': 1009 retval = actions_parse(¶ms->common.end_actions, optarg, 1010 "timerlat_trace.txt"); 1011 if (retval) 1012 fatal("Invalid action %s", optarg); 1013 break; 1014 default: 1015 fatal("Invalid option"); 1016 } 1017 } 1018 1019 if (trace_output) 1020 actions_add_trace_output(¶ms->common.threshold_actions, trace_output); 1021 1022 if (geteuid()) 1023 fatal("rtla needs root permission"); 1024 1025 if (params->common.hist.no_irq && params->common.hist.no_thread) 1026 fatal("no-irq and no-thread set, there is nothing to do here"); 1027 1028 if (params->common.hist.no_index && !params->common.hist.with_zeros) 1029 fatal("no-index set with with-zeros is not set - it does not make sense"); 1030 1031 /* 1032 * Auto analysis only happens if stop tracing, thus: 1033 */ 1034 if (!params->common.stop_us && !params->common.stop_total_us) 1035 params->no_aa = 1; 1036 1037 if (params->common.kernel_workload && params->common.user_workload) 1038 fatal("--kernel-threads and --user-threads are mutually exclusive!"); 1039 1040 /* 1041 * If auto-analysis or trace output is enabled, switch from BPF mode to 1042 * mixed mode 1043 */ 1044 if (params->mode == TRACING_MODE_BPF && 1045 (params->common.threshold_actions.present[ACTION_TRACE_OUTPUT] || 1046 params->common.end_actions.present[ACTION_TRACE_OUTPUT] || 1047 !params->no_aa)) 1048 params->mode = TRACING_MODE_MIXED; 1049 1050 return ¶ms->common; 1051 } 1052 1053 /* 1054 * timerlat_hist_apply_config - apply the hist configs to the initialized tool 1055 */ 1056 static int 1057 timerlat_hist_apply_config(struct osnoise_tool *tool) 1058 { 1059 struct timerlat_params *params = to_timerlat_params(tool->params); 1060 int retval; 1061 1062 retval = timerlat_apply_config(tool, params); 1063 if (retval) 1064 goto out_err; 1065 1066 return 0; 1067 1068 out_err: 1069 return -1; 1070 } 1071 1072 /* 1073 * timerlat_init_hist - initialize a timerlat hist tool with parameters 1074 */ 1075 static struct osnoise_tool 1076 *timerlat_init_hist(struct common_params *params) 1077 { 1078 struct osnoise_tool *tool; 1079 int nr_cpus; 1080 1081 nr_cpus = sysconf(_SC_NPROCESSORS_CONF); 1082 1083 tool = osnoise_init_tool("timerlat_hist"); 1084 if (!tool) 1085 return NULL; 1086 1087 tool->data = timerlat_alloc_histogram(nr_cpus, params->hist.entries, 1088 params->hist.bucket_size); 1089 if (!tool->data) 1090 goto out_err; 1091 1092 tep_register_event_handler(tool->trace.tep, -1, "ftrace", "timerlat", 1093 timerlat_hist_handler, tool); 1094 1095 return tool; 1096 1097 out_err: 1098 osnoise_destroy_tool(tool); 1099 return NULL; 1100 } 1101 1102 static int timerlat_hist_bpf_main_loop(struct osnoise_tool *tool) 1103 { 1104 struct timerlat_params *params = to_timerlat_params(tool->params); 1105 int retval; 1106 1107 while (!stop_tracing) { 1108 timerlat_bpf_wait(-1); 1109 1110 if (!stop_tracing) { 1111 /* Threshold overflow, perform actions on threshold */ 1112 actions_perform(¶ms->common.threshold_actions); 1113 1114 if (!params->common.threshold_actions.continue_flag) 1115 /* continue flag not set, break */ 1116 break; 1117 1118 /* continue action reached, re-enable tracing */ 1119 if (tool->record) 1120 trace_instance_start(&tool->record->trace); 1121 if (tool->aa) 1122 trace_instance_start(&tool->aa->trace); 1123 timerlat_bpf_restart_tracing(); 1124 } 1125 } 1126 timerlat_bpf_detach(); 1127 1128 retval = timerlat_hist_bpf_pull_data(tool); 1129 if (retval) 1130 err_msg("Error pulling BPF data\n"); 1131 1132 return retval; 1133 } 1134 1135 static int timerlat_hist_main(struct osnoise_tool *tool) 1136 { 1137 struct timerlat_params *params = to_timerlat_params(tool->params); 1138 int retval; 1139 1140 if (params->mode == TRACING_MODE_TRACEFS) 1141 retval = hist_main_loop(tool); 1142 else 1143 retval = timerlat_hist_bpf_main_loop(tool); 1144 1145 return retval; 1146 } 1147 1148 struct tool_ops timerlat_hist_ops = { 1149 .tracer = "timerlat", 1150 .comm_prefix = "timerlat/", 1151 .parse_args = timerlat_hist_parse_args, 1152 .init_tool = timerlat_init_hist, 1153 .apply_config = timerlat_hist_apply_config, 1154 .enable = timerlat_enable, 1155 .main = timerlat_hist_main, 1156 .print_stats = timerlat_print_stats, 1157 .analyze = timerlat_analyze, 1158 .free = timerlat_free_histogram_tool, 1159 }; 1160