1 // SPDX-License-Identifier: GPL-2.0 2 /* 3 * builtin-kwork.c 4 * 5 * Copyright (c) 2022 Huawei Inc, Yang Jihong <yangjihong1@huawei.com> 6 */ 7 8 #include "builtin.h" 9 #include "perf.h" 10 11 #include "util/data.h" 12 #include "util/event.h" 13 #include "util/evlist.h" 14 #include "util/evsel.h" 15 #include "util/header.h" 16 #include "util/kwork.h" 17 #include "util/debug.h" 18 #include "util/session.h" 19 #include "util/symbol.h" 20 #include "util/thread.h" 21 #include "util/string2.h" 22 #include "util/callchain.h" 23 #include "util/evsel_fprintf.h" 24 #include "util/util.h" 25 26 #include <subcmd/pager.h> 27 #include <subcmd/parse-options.h> 28 #include <event-parse.h> 29 30 #include <errno.h> 31 #include <inttypes.h> 32 #include <signal.h> 33 #include <linux/err.h> 34 #include <linux/time64.h> 35 #include <linux/zalloc.h> 36 37 /* 38 * report header elements width 39 */ 40 #define PRINT_CPU_WIDTH 4 41 #define PRINT_COUNT_WIDTH 9 42 #define PRINT_RUNTIME_WIDTH 10 43 #define PRINT_LATENCY_WIDTH 10 44 #define PRINT_TIMESTAMP_WIDTH 17 45 #define PRINT_KWORK_NAME_WIDTH 30 46 #define RPINT_DECIMAL_WIDTH 3 47 #define PRINT_BRACKETPAIR_WIDTH 2 48 #define PRINT_TIME_UNIT_SEC_WIDTH 2 49 #define PRINT_TIME_UNIT_MESC_WIDTH 3 50 #define PRINT_PID_WIDTH 7 51 #define PRINT_TASK_NAME_WIDTH 16 52 #define PRINT_CPU_USAGE_WIDTH 6 53 #define PRINT_CPU_USAGE_DECIMAL_WIDTH 2 54 #define PRINT_CPU_USAGE_HIST_WIDTH 30 55 #define PRINT_RUNTIME_HEADER_WIDTH (PRINT_RUNTIME_WIDTH + PRINT_TIME_UNIT_MESC_WIDTH) 56 #define PRINT_LATENCY_HEADER_WIDTH (PRINT_LATENCY_WIDTH + PRINT_TIME_UNIT_MESC_WIDTH) 57 #define PRINT_TIMEHIST_CPU_WIDTH (PRINT_CPU_WIDTH + PRINT_BRACKETPAIR_WIDTH) 58 #define PRINT_TIMESTAMP_HEADER_WIDTH (PRINT_TIMESTAMP_WIDTH + PRINT_TIME_UNIT_SEC_WIDTH) 59 60 struct sort_dimension { 61 const char *name; 62 int (*cmp)(struct kwork_work *l, struct kwork_work *r); 63 struct list_head list; 64 }; 65 66 static int id_cmp(struct kwork_work *l, struct kwork_work *r) 67 { 68 if (l->cpu > r->cpu) 69 return 1; 70 if (l->cpu < r->cpu) 71 return -1; 72 73 if (l->id > r->id) 74 return 1; 75 if (l->id < r->id) 76 return -1; 77 78 return 0; 79 } 80 81 static int count_cmp(struct kwork_work *l, struct kwork_work *r) 82 { 83 if (l->nr_atoms > r->nr_atoms) 84 return 1; 85 if (l->nr_atoms < r->nr_atoms) 86 return -1; 87 88 return 0; 89 } 90 91 static int runtime_cmp(struct kwork_work *l, struct kwork_work *r) 92 { 93 if (l->total_runtime > r->total_runtime) 94 return 1; 95 if (l->total_runtime < r->total_runtime) 96 return -1; 97 98 return 0; 99 } 100 101 static int max_runtime_cmp(struct kwork_work *l, struct kwork_work *r) 102 { 103 if (l->max_runtime > r->max_runtime) 104 return 1; 105 if (l->max_runtime < r->max_runtime) 106 return -1; 107 108 return 0; 109 } 110 111 static int avg_latency_cmp(struct kwork_work *l, struct kwork_work *r) 112 { 113 u64 avgl, avgr; 114 115 if (!r->nr_atoms) 116 return 1; 117 if (!l->nr_atoms) 118 return -1; 119 120 avgl = l->total_latency / l->nr_atoms; 121 avgr = r->total_latency / r->nr_atoms; 122 123 if (avgl > avgr) 124 return 1; 125 if (avgl < avgr) 126 return -1; 127 128 return 0; 129 } 130 131 static int max_latency_cmp(struct kwork_work *l, struct kwork_work *r) 132 { 133 if (l->max_latency > r->max_latency) 134 return 1; 135 if (l->max_latency < r->max_latency) 136 return -1; 137 138 return 0; 139 } 140 141 static int cpu_usage_cmp(struct kwork_work *l, struct kwork_work *r) 142 { 143 if (l->cpu_usage > r->cpu_usage) 144 return 1; 145 if (l->cpu_usage < r->cpu_usage) 146 return -1; 147 148 return 0; 149 } 150 151 static int id_or_cpu_r_cmp(struct kwork_work *l, struct kwork_work *r) 152 { 153 if (l->id < r->id) 154 return 1; 155 if (l->id > r->id) 156 return -1; 157 158 if (l->id != 0) 159 return 0; 160 161 if (l->cpu < r->cpu) 162 return 1; 163 if (l->cpu > r->cpu) 164 return -1; 165 166 return 0; 167 } 168 169 static int sort_dimension__add(struct perf_kwork *kwork __maybe_unused, 170 const char *tok, struct list_head *list) 171 { 172 size_t i; 173 static struct sort_dimension max_sort_dimension = { 174 .name = "max", 175 .cmp = max_runtime_cmp, 176 }; 177 static struct sort_dimension id_sort_dimension = { 178 .name = "id", 179 .cmp = id_cmp, 180 }; 181 static struct sort_dimension runtime_sort_dimension = { 182 .name = "runtime", 183 .cmp = runtime_cmp, 184 }; 185 static struct sort_dimension count_sort_dimension = { 186 .name = "count", 187 .cmp = count_cmp, 188 }; 189 static struct sort_dimension avg_sort_dimension = { 190 .name = "avg", 191 .cmp = avg_latency_cmp, 192 }; 193 static struct sort_dimension rate_sort_dimension = { 194 .name = "rate", 195 .cmp = cpu_usage_cmp, 196 }; 197 static struct sort_dimension tid_sort_dimension = { 198 .name = "tid", 199 .cmp = id_or_cpu_r_cmp, 200 }; 201 struct sort_dimension *available_sorts[] = { 202 &id_sort_dimension, 203 &max_sort_dimension, 204 &count_sort_dimension, 205 &runtime_sort_dimension, 206 &avg_sort_dimension, 207 &rate_sort_dimension, 208 &tid_sort_dimension, 209 }; 210 211 if (kwork->report == KWORK_REPORT_LATENCY) 212 max_sort_dimension.cmp = max_latency_cmp; 213 214 for (i = 0; i < ARRAY_SIZE(available_sorts); i++) { 215 if (!strcmp(available_sorts[i]->name, tok)) { 216 list_add_tail(&available_sorts[i]->list, list); 217 return 0; 218 } 219 } 220 221 return -1; 222 } 223 224 static void setup_sorting(struct perf_kwork *kwork, 225 const struct option *options, 226 const char * const usage_msg[]) 227 { 228 char *tmp, *tok, *str = strdup(kwork->sort_order); 229 230 for (tok = strtok_r(str, ", ", &tmp); 231 tok; tok = strtok_r(NULL, ", ", &tmp)) { 232 if (sort_dimension__add(kwork, tok, &kwork->sort_list) < 0) 233 usage_with_options_msg(usage_msg, options, 234 "Unknown --sort key: `%s'", tok); 235 } 236 237 pr_debug("Sort order: %s\n", kwork->sort_order); 238 free(str); 239 } 240 241 static struct kwork_atom *atom_new(struct perf_kwork *kwork, 242 struct perf_sample *sample) 243 { 244 unsigned long i; 245 struct kwork_atom_page *page; 246 struct kwork_atom *atom = NULL; 247 248 list_for_each_entry(page, &kwork->atom_page_list, list) { 249 if (!bitmap_full(page->bitmap, NR_ATOM_PER_PAGE)) { 250 i = find_first_zero_bit(page->bitmap, NR_ATOM_PER_PAGE); 251 BUG_ON(i >= NR_ATOM_PER_PAGE); 252 atom = &page->atoms[i]; 253 goto found_atom; 254 } 255 } 256 257 /* 258 * new page 259 */ 260 page = zalloc(sizeof(*page)); 261 if (page == NULL) { 262 pr_err("Failed to zalloc kwork atom page\n"); 263 return NULL; 264 } 265 266 i = 0; 267 atom = &page->atoms[0]; 268 list_add_tail(&page->list, &kwork->atom_page_list); 269 270 found_atom: 271 __set_bit(i, page->bitmap); 272 atom->time = sample->time; 273 atom->prev = NULL; 274 atom->page_addr = page; 275 atom->bit_inpage = i; 276 return atom; 277 } 278 279 static void atom_free(struct kwork_atom *atom) 280 { 281 if (atom->prev != NULL) 282 atom_free(atom->prev); 283 284 __clear_bit(atom->bit_inpage, 285 ((struct kwork_atom_page *)atom->page_addr)->bitmap); 286 } 287 288 static void atom_del(struct kwork_atom *atom) 289 { 290 list_del(&atom->list); 291 atom_free(atom); 292 } 293 294 static int work_cmp(struct list_head *list, 295 struct kwork_work *l, struct kwork_work *r) 296 { 297 int ret = 0; 298 struct sort_dimension *sort; 299 300 BUG_ON(list_empty(list)); 301 302 list_for_each_entry(sort, list, list) { 303 ret = sort->cmp(l, r); 304 if (ret) 305 return ret; 306 } 307 308 return ret; 309 } 310 311 static struct kwork_work *work_search(struct rb_root_cached *root, 312 struct kwork_work *key, 313 struct list_head *sort_list) 314 { 315 int cmp; 316 struct kwork_work *work; 317 struct rb_node *node = root->rb_root.rb_node; 318 319 while (node) { 320 work = container_of(node, struct kwork_work, node); 321 cmp = work_cmp(sort_list, key, work); 322 if (cmp > 0) 323 node = node->rb_left; 324 else if (cmp < 0) 325 node = node->rb_right; 326 else { 327 if (work->name == NULL && key->name != NULL) 328 work->name = strdup(key->name); 329 return work; 330 } 331 } 332 return NULL; 333 } 334 335 static void work_insert(struct rb_root_cached *root, 336 struct kwork_work *key, struct list_head *sort_list) 337 { 338 int cmp; 339 bool leftmost = true; 340 struct kwork_work *cur; 341 struct rb_node **new = &(root->rb_root.rb_node), *parent = NULL; 342 343 while (*new) { 344 cur = container_of(*new, struct kwork_work, node); 345 parent = *new; 346 cmp = work_cmp(sort_list, key, cur); 347 348 if (cmp > 0) 349 new = &((*new)->rb_left); 350 else { 351 new = &((*new)->rb_right); 352 leftmost = false; 353 } 354 } 355 356 rb_link_node(&key->node, parent, new); 357 rb_insert_color_cached(&key->node, root, leftmost); 358 } 359 360 static struct kwork_work *work_new(struct kwork_work *key) 361 { 362 int i; 363 struct kwork_work *work = zalloc(sizeof(*work)); 364 365 if (work == NULL) { 366 pr_err("Failed to zalloc kwork work\n"); 367 return NULL; 368 } 369 370 for (i = 0; i < KWORK_TRACE_MAX; i++) 371 INIT_LIST_HEAD(&work->atom_list[i]); 372 373 work->id = key->id; 374 work->cpu = key->cpu; 375 work->name = key->name ? strdup(key->name) : NULL; 376 work->class = key->class; 377 return work; 378 } 379 380 381 static void work_delete(struct kwork_work *work) 382 { 383 if (work) { 384 work_exit(work); 385 free(work); 386 } 387 } 388 389 static void kwork_work__free_root(struct rb_root_cached *root) 390 { 391 struct rb_node *next; 392 struct kwork_work *work; 393 394 while ((next = rb_first_cached(root))) { 395 work = rb_entry(next, struct kwork_work, node); 396 rb_erase_cached(next, root); 397 work_delete(work); 398 } 399 } 400 401 static void perf_kwork__exit(struct perf_kwork *kwork) 402 { 403 struct kwork_class *class; 404 struct kwork_atom_page *page, *tmp_page; 405 406 list_for_each_entry(class, &kwork->class_list, list) { 407 kwork_work__free_root(&class->work_root); 408 } 409 410 kwork_work__free_root(&kwork->sorted_work_root); 411 412 list_for_each_entry_safe(page, tmp_page, &kwork->atom_page_list, list) { 413 list_del_init(&page->list); 414 free(page); 415 } 416 417 INIT_LIST_HEAD(&kwork->class_list); 418 INIT_LIST_HEAD(&kwork->atom_page_list); 419 INIT_LIST_HEAD(&kwork->sort_list); 420 INIT_LIST_HEAD(&kwork->cmp_id); 421 } 422 423 static struct kwork_work *work_findnew(struct rb_root_cached *root, 424 struct kwork_work *key, 425 struct list_head *sort_list) 426 { 427 struct kwork_work *work = work_search(root, key, sort_list); 428 429 if (work != NULL) 430 return work; 431 432 work = work_new(key); 433 if (work) 434 work_insert(root, work, sort_list); 435 436 return work; 437 } 438 439 static void profile_update_timespan(struct perf_kwork *kwork, 440 struct perf_sample *sample) 441 { 442 if (!kwork->summary) 443 return; 444 445 if ((kwork->timestart == 0) || (kwork->timestart > sample->time)) 446 kwork->timestart = sample->time; 447 448 if (kwork->timeend < sample->time) 449 kwork->timeend = sample->time; 450 } 451 452 static bool profile_name_match(struct perf_kwork *kwork, 453 struct kwork_work *work) 454 { 455 if (kwork->profile_name && work->name && 456 (strcmp(work->name, kwork->profile_name) != 0)) { 457 return false; 458 } 459 460 return true; 461 } 462 463 static bool profile_event_match(struct perf_kwork *kwork, 464 struct kwork_work *work, 465 struct perf_sample *sample) 466 { 467 int cpu = work->cpu; 468 u64 time = sample->time; 469 struct perf_time_interval *ptime = &kwork->ptime; 470 471 /* Guard test_bit: cpu == -1 (absent PERF_SAMPLE_CPU) would index past the bitmap */ 472 if ((kwork->cpu_list != NULL) && 473 ((unsigned int)cpu >= MAX_NR_CPUS || !test_bit(cpu, kwork->cpu_bitmap))) 474 return false; 475 476 if (((ptime->start != 0) && (ptime->start > time)) || 477 ((ptime->end != 0) && (ptime->end < time))) 478 return false; 479 480 /* 481 * report top needs to collect the runtime of all tasks to 482 * calculate the load of each core. 483 */ 484 if ((kwork->report != KWORK_REPORT_TOP) && 485 !profile_name_match(kwork, work)) { 486 return false; 487 } 488 489 profile_update_timespan(kwork, sample); 490 return true; 491 } 492 493 static int work_push_atom(struct perf_kwork *kwork, 494 struct kwork_class *class, 495 enum kwork_trace_type src_type, 496 enum kwork_trace_type dst_type, 497 struct perf_sample *sample, 498 struct machine *machine, 499 struct kwork_work **ret_work, 500 bool overwrite) 501 { 502 struct kwork_atom *atom = NULL, *dst_atom, *last_atom; 503 struct kwork_work *work, key; 504 int ret = 0; 505 506 BUG_ON(class->work_init == NULL); 507 class->work_init(kwork, class, &key, src_type, sample, machine); 508 509 atom = atom_new(kwork, sample); 510 if (atom == NULL) { 511 ret = -1; 512 goto out; 513 } 514 515 work = work_findnew(&class->work_root, &key, &kwork->cmp_id); 516 if (work == NULL) { 517 atom_free(atom); 518 ret = -1; 519 goto out; 520 } 521 522 if (!profile_event_match(kwork, work, sample)) { 523 atom_free(atom); 524 goto out; 525 } 526 527 if (dst_type < KWORK_TRACE_MAX) { 528 dst_atom = list_last_entry_or_null(&work->atom_list[dst_type], 529 struct kwork_atom, list); 530 if (dst_atom != NULL) { 531 atom->prev = dst_atom; 532 list_del(&dst_atom->list); 533 } 534 } 535 536 if (ret_work != NULL) 537 *ret_work = work; 538 539 if (overwrite) { 540 last_atom = list_last_entry_or_null(&work->atom_list[src_type], 541 struct kwork_atom, list); 542 if (last_atom) { 543 atom_del(last_atom); 544 545 kwork->nr_skipped_events[src_type]++; 546 kwork->nr_skipped_events[KWORK_TRACE_MAX]++; 547 } 548 } 549 550 list_add_tail(&atom->list, &work->atom_list[src_type]); 551 out: 552 work_exit(&key); 553 return ret; 554 } 555 556 static struct kwork_atom *work_pop_atom(struct perf_kwork *kwork, 557 struct kwork_class *class, 558 enum kwork_trace_type src_type, 559 enum kwork_trace_type dst_type, 560 struct perf_sample *sample, 561 struct machine *machine, 562 struct kwork_work **ret_work) 563 { 564 struct kwork_atom *atom = NULL, *src_atom; 565 struct kwork_work *work, key; 566 567 BUG_ON(class->work_init == NULL); 568 class->work_init(kwork, class, &key, src_type, sample, machine); 569 570 work = work_findnew(&class->work_root, &key, &kwork->cmp_id); 571 if (ret_work != NULL) 572 *ret_work = work; 573 574 if (work == NULL) 575 goto out; 576 577 if (!profile_event_match(kwork, work, sample)) 578 goto out; 579 580 atom = list_last_entry_or_null(&work->atom_list[dst_type], 581 struct kwork_atom, list); 582 if (atom != NULL) 583 goto out; 584 585 src_atom = atom_new(kwork, sample); 586 if (src_atom != NULL) 587 list_add_tail(&src_atom->list, &work->atom_list[src_type]); 588 else { 589 if (ret_work != NULL) 590 *ret_work = NULL; 591 } 592 out: 593 work_exit(&key); 594 return atom; 595 } 596 597 static struct kwork_work *find_work_by_id(struct rb_root_cached *root, 598 u64 id, int cpu) 599 { 600 struct rb_node *next; 601 struct kwork_work *work; 602 603 next = rb_first_cached(root); 604 while (next) { 605 work = rb_entry(next, struct kwork_work, node); 606 if ((cpu != -1 && work->id == id && work->cpu == cpu) || 607 (cpu == -1 && work->id == id)) 608 return work; 609 610 next = rb_next(next); 611 } 612 613 return NULL; 614 } 615 616 static struct kwork_class *get_kwork_class(struct perf_kwork *kwork, 617 enum kwork_class_type type) 618 { 619 struct kwork_class *class; 620 621 list_for_each_entry(class, &kwork->class_list, list) { 622 if (class->type == type) 623 return class; 624 } 625 626 return NULL; 627 } 628 629 static void report_update_exit_event(struct kwork_work *work, 630 struct kwork_atom *atom, 631 struct perf_sample *sample) 632 { 633 u64 delta; 634 u64 exit_time = sample->time; 635 u64 entry_time = atom->time; 636 637 if ((entry_time != 0) && (exit_time >= entry_time)) { 638 delta = exit_time - entry_time; 639 if ((delta > work->max_runtime) || 640 (work->max_runtime == 0)) { 641 work->max_runtime = delta; 642 work->max_runtime_start = entry_time; 643 work->max_runtime_end = exit_time; 644 } 645 work->total_runtime += delta; 646 work->nr_atoms++; 647 } 648 } 649 650 static int report_entry_event(struct perf_kwork *kwork, 651 struct kwork_class *class, 652 struct perf_sample *sample, 653 struct machine *machine) 654 { 655 return work_push_atom(kwork, class, KWORK_TRACE_ENTRY, 656 KWORK_TRACE_MAX, sample, 657 machine, NULL, true); 658 } 659 660 static int report_exit_event(struct perf_kwork *kwork, 661 struct kwork_class *class, 662 struct perf_sample *sample, 663 struct machine *machine) 664 { 665 struct kwork_atom *atom = NULL; 666 struct kwork_work *work = NULL; 667 668 atom = work_pop_atom(kwork, class, KWORK_TRACE_EXIT, 669 KWORK_TRACE_ENTRY, sample, 670 machine, &work); 671 if (work == NULL) 672 return -1; 673 674 if (atom != NULL) { 675 report_update_exit_event(work, atom, sample); 676 atom_del(atom); 677 } 678 679 return 0; 680 } 681 682 static void latency_update_entry_event(struct kwork_work *work, 683 struct kwork_atom *atom, 684 struct perf_sample *sample) 685 { 686 u64 delta; 687 u64 entry_time = sample->time; 688 u64 raise_time = atom->time; 689 690 if ((raise_time != 0) && (entry_time >= raise_time)) { 691 delta = entry_time - raise_time; 692 if ((delta > work->max_latency) || 693 (work->max_latency == 0)) { 694 work->max_latency = delta; 695 work->max_latency_start = raise_time; 696 work->max_latency_end = entry_time; 697 } 698 work->total_latency += delta; 699 work->nr_atoms++; 700 } 701 } 702 703 static int latency_raise_event(struct perf_kwork *kwork, 704 struct kwork_class *class, 705 struct perf_sample *sample, 706 struct machine *machine) 707 { 708 return work_push_atom(kwork, class, KWORK_TRACE_RAISE, 709 KWORK_TRACE_MAX, sample, 710 machine, NULL, true); 711 } 712 713 static int latency_entry_event(struct perf_kwork *kwork, 714 struct kwork_class *class, 715 struct perf_sample *sample, 716 struct machine *machine) 717 { 718 struct kwork_atom *atom = NULL; 719 struct kwork_work *work = NULL; 720 721 atom = work_pop_atom(kwork, class, KWORK_TRACE_ENTRY, 722 KWORK_TRACE_RAISE, sample, 723 machine, &work); 724 if (work == NULL) 725 return -1; 726 727 if (atom != NULL) { 728 latency_update_entry_event(work, atom, sample); 729 atom_del(atom); 730 } 731 732 return 0; 733 } 734 735 static void timehist_save_callchain(struct perf_kwork *kwork, 736 struct perf_sample *sample, 737 struct machine *machine) 738 { 739 struct symbol *sym; 740 struct thread *thread; 741 struct callchain_cursor_node *node; 742 struct callchain_cursor *cursor; 743 744 if (!kwork->show_callchain || sample->callchain == NULL) 745 return; 746 747 /* want main thread for process - has maps */ 748 thread = machine__findnew_thread(machine, sample->pid, sample->pid); 749 if (thread == NULL) { 750 pr_debug("Failed to get thread for pid %d\n", sample->pid); 751 return; 752 } 753 754 cursor = get_tls_callchain_cursor(); 755 756 if (thread__resolve_callchain(thread, cursor, sample, 757 NULL, NULL, kwork->max_stack + 2) != 0) { 758 pr_debug("Failed to resolve callchain, skipping\n"); 759 goto out_put; 760 } 761 762 callchain_cursor_commit(cursor); 763 764 while (true) { 765 node = callchain_cursor_current(cursor); 766 if (node == NULL) 767 break; 768 769 sym = node->ms.sym; 770 if (sym) { 771 if (!strcmp(sym->name, "__softirqentry_text_start") || 772 !strcmp(sym->name, "__do_softirq")) 773 symbol__set_ignore(sym, true); 774 } 775 776 callchain_cursor_advance(cursor); 777 } 778 779 out_put: 780 thread__put(thread); 781 } 782 783 static void timehist_print_event(struct perf_kwork *kwork, 784 struct kwork_work *work, 785 struct kwork_atom *atom, 786 struct perf_sample *sample, 787 struct addr_location *al) 788 { 789 char entrytime[32], exittime[32]; 790 char kwork_name[PRINT_KWORK_NAME_WIDTH]; 791 792 /* 793 * runtime start 794 */ 795 timestamp__scnprintf_usec(atom->time, 796 entrytime, sizeof(entrytime)); 797 printf(" %*s ", PRINT_TIMESTAMP_WIDTH, entrytime); 798 799 /* 800 * runtime end 801 */ 802 timestamp__scnprintf_usec(sample->time, 803 exittime, sizeof(exittime)); 804 printf(" %*s ", PRINT_TIMESTAMP_WIDTH, exittime); 805 806 /* 807 * cpu 808 */ 809 printf(" [%0*d] ", PRINT_CPU_WIDTH, work->cpu); 810 811 /* 812 * kwork name 813 */ 814 if (work->class && work->class->work_name) { 815 work->class->work_name(work, kwork_name, 816 PRINT_KWORK_NAME_WIDTH); 817 printf(" %-*s ", PRINT_KWORK_NAME_WIDTH, kwork_name); 818 } else 819 printf(" %-*s ", PRINT_KWORK_NAME_WIDTH, ""); 820 821 /* 822 *runtime 823 */ 824 printf(" %*.*f ", 825 PRINT_RUNTIME_WIDTH, RPINT_DECIMAL_WIDTH, 826 (double)(sample->time - atom->time) / NSEC_PER_MSEC); 827 828 /* 829 * delaytime 830 */ 831 if (atom->prev != NULL) 832 printf(" %*.*f ", PRINT_LATENCY_WIDTH, RPINT_DECIMAL_WIDTH, 833 (double)(atom->time - atom->prev->time) / NSEC_PER_MSEC); 834 else 835 printf(" %*s ", PRINT_LATENCY_WIDTH, " "); 836 837 /* 838 * callchain 839 */ 840 if (kwork->show_callchain) { 841 struct callchain_cursor *cursor = get_tls_callchain_cursor(); 842 843 if (cursor == NULL) 844 return; 845 846 printf(" "); 847 848 sample__fprintf_sym(sample, al, 0, 849 EVSEL__PRINT_SYM | EVSEL__PRINT_ONELINE | 850 EVSEL__PRINT_CALLCHAIN_ARROW | 851 EVSEL__PRINT_SKIP_IGNORED, 852 cursor, symbol_conf.bt_stop_list, 853 stdout); 854 } 855 856 printf("\n"); 857 } 858 859 static int timehist_raise_event(struct perf_kwork *kwork, 860 struct kwork_class *class, 861 struct perf_sample *sample, 862 struct machine *machine) 863 { 864 return work_push_atom(kwork, class, KWORK_TRACE_RAISE, 865 KWORK_TRACE_MAX, sample, 866 machine, NULL, true); 867 } 868 869 static int timehist_entry_event(struct perf_kwork *kwork, 870 struct kwork_class *class, 871 struct perf_sample *sample, 872 struct machine *machine) 873 { 874 int ret; 875 struct kwork_work *work = NULL; 876 877 ret = work_push_atom(kwork, class, KWORK_TRACE_ENTRY, 878 KWORK_TRACE_RAISE, sample, 879 machine, &work, true); 880 if (ret) 881 return ret; 882 883 if (work != NULL) 884 timehist_save_callchain(kwork, sample, machine); 885 886 return 0; 887 } 888 889 static int timehist_exit_event(struct perf_kwork *kwork, 890 struct kwork_class *class, 891 struct perf_sample *sample, 892 struct machine *machine) 893 { 894 struct kwork_atom *atom = NULL; 895 struct kwork_work *work = NULL; 896 struct addr_location al; 897 int ret = 0; 898 899 addr_location__init(&al); 900 if (machine__resolve(machine, &al, sample) < 0) { 901 pr_debug("problem processing event at offset %#" PRIx64 ", skipping it\n", 902 sample->file_offset); 903 ret = -1; 904 goto out; 905 } 906 907 atom = work_pop_atom(kwork, class, KWORK_TRACE_EXIT, 908 KWORK_TRACE_ENTRY, sample, 909 machine, &work); 910 if (work == NULL) { 911 ret = -1; 912 goto out; 913 } 914 915 if (atom != NULL) { 916 work->nr_atoms++; 917 timehist_print_event(kwork, work, atom, sample, &al); 918 atom_del(atom); 919 } 920 921 out: 922 addr_location__exit(&al); 923 return ret; 924 } 925 926 static void top_update_runtime(struct kwork_work *work, 927 struct kwork_atom *atom, 928 struct perf_sample *sample) 929 { 930 u64 delta; 931 u64 exit_time = sample->time; 932 u64 entry_time = atom->time; 933 934 if ((entry_time != 0) && (exit_time >= entry_time)) { 935 delta = exit_time - entry_time; 936 work->total_runtime += delta; 937 } 938 } 939 940 static int top_entry_event(struct perf_kwork *kwork, 941 struct kwork_class *class, 942 struct perf_sample *sample, 943 struct machine *machine) 944 { 945 return work_push_atom(kwork, class, KWORK_TRACE_ENTRY, 946 KWORK_TRACE_MAX, sample, 947 machine, NULL, true); 948 } 949 950 static int top_exit_event(struct perf_kwork *kwork, 951 struct kwork_class *class, 952 struct perf_sample *sample, 953 struct machine *machine) 954 { 955 struct kwork_work *work, *sched_work; 956 struct kwork_class *sched_class; 957 struct kwork_atom *atom; 958 959 atom = work_pop_atom(kwork, class, KWORK_TRACE_EXIT, 960 KWORK_TRACE_ENTRY, sample, 961 machine, &work); 962 if (!work) 963 return -1; 964 965 if (atom) { 966 sched_class = get_kwork_class(kwork, KWORK_CLASS_SCHED); 967 if (sched_class) { 968 sched_work = find_work_by_id(&sched_class->work_root, 969 work->id, work->cpu); 970 if (sched_work) 971 top_update_runtime(work, atom, sample); 972 } 973 atom_del(atom); 974 } 975 976 return 0; 977 } 978 979 static int top_sched_switch_event(struct perf_kwork *kwork, 980 struct kwork_class *class, 981 struct perf_sample *sample, 982 struct machine *machine) 983 { 984 struct kwork_atom *atom; 985 struct kwork_work *work; 986 987 atom = work_pop_atom(kwork, class, KWORK_TRACE_EXIT, 988 KWORK_TRACE_ENTRY, sample, 989 machine, &work); 990 if (!work) 991 return -1; 992 993 if (atom) { 994 top_update_runtime(work, atom, sample); 995 atom_del(atom); 996 } 997 998 return top_entry_event(kwork, class, sample, machine); 999 } 1000 1001 static struct kwork_class kwork_irq; 1002 static int process_irq_handler_entry_event(const struct perf_tool *tool, 1003 struct perf_sample *sample, 1004 struct machine *machine) 1005 { 1006 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 1007 1008 if (kwork->tp_handler->entry_event) 1009 return kwork->tp_handler->entry_event(kwork, &kwork_irq, 1010 sample, machine); 1011 return 0; 1012 } 1013 1014 static int process_irq_handler_exit_event(const struct perf_tool *tool, 1015 struct perf_sample *sample, 1016 struct machine *machine) 1017 { 1018 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 1019 1020 if (kwork->tp_handler->exit_event) 1021 return kwork->tp_handler->exit_event(kwork, &kwork_irq, 1022 sample, machine); 1023 return 0; 1024 } 1025 1026 static const struct evsel_str_handler irq_tp_handlers[] = { 1027 { "irq:irq_handler_entry", process_irq_handler_entry_event, }, 1028 { "irq:irq_handler_exit", process_irq_handler_exit_event, }, 1029 }; 1030 1031 static int irq_class_init(struct kwork_class *class, 1032 struct perf_session *session) 1033 { 1034 if (perf_session__set_tracepoints_handlers(session, irq_tp_handlers)) { 1035 pr_err("Failed to set irq tracepoints handlers\n"); 1036 return -1; 1037 } 1038 1039 class->work_root = RB_ROOT_CACHED; 1040 return 0; 1041 } 1042 1043 static void irq_work_init(struct perf_kwork *kwork, 1044 struct kwork_class *class, 1045 struct kwork_work *work, 1046 enum kwork_trace_type src_type __maybe_unused, 1047 struct perf_sample *sample, 1048 struct machine *machine __maybe_unused) 1049 { 1050 work->class = class; 1051 work->cpu = sample->cpu; 1052 1053 if (kwork->report == KWORK_REPORT_TOP) { 1054 work->id = perf_sample__intval_common(sample, "common_pid"); 1055 work->name = NULL; 1056 } else { 1057 work->id = perf_sample__intval(sample, "irq"); 1058 work->name = strdup(perf_sample__strval(sample, "name") ?: "<unknown>"); 1059 } 1060 } 1061 1062 static void irq_work_name(struct kwork_work *work, char *buf, int len) 1063 { 1064 if (work->name != NULL) 1065 snprintf(buf, len, "%s:%" PRIu64 "", work->name, work->id); 1066 else 1067 snprintf(buf, len, "%" PRIu64 "", work->id); 1068 } 1069 1070 static struct kwork_class kwork_irq = { 1071 .name = "irq", 1072 .type = KWORK_CLASS_IRQ, 1073 .nr_tracepoints = 2, 1074 .tp_handlers = irq_tp_handlers, 1075 .class_init = irq_class_init, 1076 .work_init = irq_work_init, 1077 .work_name = irq_work_name, 1078 }; 1079 1080 static struct kwork_class kwork_softirq; 1081 static int process_softirq_raise_event(const struct perf_tool *tool, 1082 struct perf_sample *sample, 1083 struct machine *machine) 1084 { 1085 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 1086 1087 if (kwork->tp_handler->raise_event) 1088 return kwork->tp_handler->raise_event(kwork, &kwork_softirq, 1089 sample, machine); 1090 1091 return 0; 1092 } 1093 1094 static int process_softirq_entry_event(const struct perf_tool *tool, 1095 struct perf_sample *sample, 1096 struct machine *machine) 1097 { 1098 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 1099 1100 if (kwork->tp_handler->entry_event) 1101 return kwork->tp_handler->entry_event(kwork, &kwork_softirq, 1102 sample, machine); 1103 1104 return 0; 1105 } 1106 1107 static int process_softirq_exit_event(const struct perf_tool *tool, 1108 struct perf_sample *sample, 1109 struct machine *machine) 1110 { 1111 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 1112 1113 if (kwork->tp_handler->exit_event) 1114 return kwork->tp_handler->exit_event(kwork, &kwork_softirq, 1115 sample, machine); 1116 1117 return 0; 1118 } 1119 1120 static const struct evsel_str_handler softirq_tp_handlers[] = { 1121 { "irq:softirq_raise", process_softirq_raise_event, }, 1122 { "irq:softirq_entry", process_softirq_entry_event, }, 1123 { "irq:softirq_exit", process_softirq_exit_event, }, 1124 }; 1125 1126 static int softirq_class_init(struct kwork_class *class, 1127 struct perf_session *session) 1128 { 1129 if (perf_session__set_tracepoints_handlers(session, 1130 softirq_tp_handlers)) { 1131 pr_err("Failed to set softirq tracepoints handlers\n"); 1132 return -1; 1133 } 1134 1135 class->work_root = RB_ROOT_CACHED; 1136 return 0; 1137 } 1138 1139 static char *evsel__softirq_name(struct evsel *evsel, u64 num) 1140 { 1141 char *name = NULL; 1142 bool found = false; 1143 struct tep_print_flag_sym *sym = NULL; 1144 const struct tep_event *tp_format = evsel__tp_format(evsel); 1145 struct tep_print_arg *args = tp_format ? tp_format->print_fmt.args : NULL; 1146 1147 if ((args == NULL) || (args->next == NULL)) 1148 return NULL; 1149 1150 /* skip softirq field: "REC->vec" */ 1151 for (sym = args->next->symbol.symbols; sym != NULL; sym = sym->next) { 1152 if ((eval_flag(sym->value) == (unsigned long long)num) && 1153 (strlen(sym->str) != 0)) { 1154 found = true; 1155 break; 1156 } 1157 } 1158 1159 if (!found) 1160 return NULL; 1161 1162 name = strdup(sym->str); 1163 if (name == NULL) { 1164 pr_err("Failed to copy symbol name\n"); 1165 return NULL; 1166 } 1167 return name; 1168 } 1169 1170 static void softirq_work_init(struct perf_kwork *kwork, 1171 struct kwork_class *class, 1172 struct kwork_work *work, 1173 enum kwork_trace_type src_type __maybe_unused, 1174 struct perf_sample *sample, 1175 struct machine *machine __maybe_unused) 1176 { 1177 u64 num; 1178 1179 work->class = class; 1180 work->cpu = sample->cpu; 1181 1182 if (kwork->report == KWORK_REPORT_TOP) { 1183 work->id = perf_sample__intval_common(sample, "common_pid"); 1184 work->name = NULL; 1185 } else { 1186 num = perf_sample__intval(sample, "vec"); 1187 work->id = num; 1188 work->name = evsel__softirq_name(sample->evsel, num); 1189 } 1190 } 1191 1192 static void softirq_work_name(struct kwork_work *work, char *buf, int len) 1193 { 1194 if (work->name != NULL) 1195 snprintf(buf, len, "(s)%s:%" PRIu64 "", work->name, work->id); 1196 else 1197 snprintf(buf, len, "(s)%" PRIu64 "", work->id); 1198 } 1199 1200 static struct kwork_class kwork_softirq = { 1201 .name = "softirq", 1202 .type = KWORK_CLASS_SOFTIRQ, 1203 .nr_tracepoints = 3, 1204 .tp_handlers = softirq_tp_handlers, 1205 .class_init = softirq_class_init, 1206 .work_init = softirq_work_init, 1207 .work_name = softirq_work_name, 1208 }; 1209 1210 static struct kwork_class kwork_workqueue; 1211 static int process_workqueue_activate_work_event(const struct perf_tool *tool, 1212 struct perf_sample *sample, 1213 struct machine *machine) 1214 { 1215 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 1216 1217 if (kwork->tp_handler->raise_event) 1218 return kwork->tp_handler->raise_event(kwork, &kwork_workqueue, 1219 sample, machine); 1220 1221 return 0; 1222 } 1223 1224 static int process_workqueue_execute_start_event(const struct perf_tool *tool, 1225 struct perf_sample *sample, 1226 struct machine *machine) 1227 { 1228 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 1229 1230 if (kwork->tp_handler->entry_event) 1231 return kwork->tp_handler->entry_event(kwork, &kwork_workqueue, 1232 sample, machine); 1233 1234 return 0; 1235 } 1236 1237 static int process_workqueue_execute_end_event(const struct perf_tool *tool, 1238 struct perf_sample *sample, 1239 struct machine *machine) 1240 { 1241 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 1242 1243 if (kwork->tp_handler->exit_event) 1244 return kwork->tp_handler->exit_event(kwork, &kwork_workqueue, 1245 sample, machine); 1246 1247 return 0; 1248 } 1249 1250 static const struct evsel_str_handler workqueue_tp_handlers[] = { 1251 { "workqueue:workqueue_activate_work", process_workqueue_activate_work_event, }, 1252 { "workqueue:workqueue_execute_start", process_workqueue_execute_start_event, }, 1253 { "workqueue:workqueue_execute_end", process_workqueue_execute_end_event, }, 1254 }; 1255 1256 static int workqueue_class_init(struct kwork_class *class, 1257 struct perf_session *session) 1258 { 1259 if (perf_session__set_tracepoints_handlers(session, 1260 workqueue_tp_handlers)) { 1261 pr_err("Failed to set workqueue tracepoints handlers\n"); 1262 return -1; 1263 } 1264 1265 class->work_root = RB_ROOT_CACHED; 1266 return 0; 1267 } 1268 1269 static void workqueue_work_init(struct perf_kwork *kwork __maybe_unused, 1270 struct kwork_class *class, 1271 struct kwork_work *work, 1272 enum kwork_trace_type src_type __maybe_unused, 1273 struct perf_sample *sample, 1274 struct machine *machine) 1275 { 1276 char *modp = NULL; 1277 unsigned long long function_addr = perf_sample__intval(sample, "function"); 1278 1279 work->class = class; 1280 work->cpu = sample->cpu; 1281 work->id = perf_sample__intval(sample, "work"); 1282 work->name = NULL; 1283 1284 if (function_addr != 0) { 1285 const char *name = machine__resolve_kernel_addr(machine, &function_addr, &modp); 1286 1287 if (name) 1288 work->name = strdup(name); 1289 } 1290 } 1291 1292 static void workqueue_work_name(struct kwork_work *work, char *buf, int len) 1293 { 1294 if (work->name != NULL) 1295 snprintf(buf, len, "(w)%s", work->name); 1296 else 1297 snprintf(buf, len, "(w)0x%" PRIx64, work->id); 1298 } 1299 1300 static struct kwork_class kwork_workqueue = { 1301 .name = "workqueue", 1302 .type = KWORK_CLASS_WORKQUEUE, 1303 .nr_tracepoints = 3, 1304 .tp_handlers = workqueue_tp_handlers, 1305 .class_init = workqueue_class_init, 1306 .work_init = workqueue_work_init, 1307 .work_name = workqueue_work_name, 1308 }; 1309 1310 static struct kwork_class kwork_sched; 1311 static int process_sched_switch_event(const struct perf_tool *tool, 1312 struct perf_sample *sample, 1313 struct machine *machine) 1314 { 1315 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 1316 1317 if (kwork->tp_handler->sched_switch_event) 1318 return kwork->tp_handler->sched_switch_event(kwork, &kwork_sched, 1319 sample, machine); 1320 return 0; 1321 } 1322 1323 static const struct evsel_str_handler sched_tp_handlers[] = { 1324 { "sched:sched_switch", process_sched_switch_event, }, 1325 }; 1326 1327 static int sched_class_init(struct kwork_class *class, 1328 struct perf_session *session) 1329 { 1330 if (perf_session__set_tracepoints_handlers(session, 1331 sched_tp_handlers)) { 1332 pr_err("Failed to set sched tracepoints handlers\n"); 1333 return -1; 1334 } 1335 1336 class->work_root = RB_ROOT_CACHED; 1337 return 0; 1338 } 1339 1340 static void sched_work_init(struct perf_kwork *kwork __maybe_unused, 1341 struct kwork_class *class, 1342 struct kwork_work *work, 1343 enum kwork_trace_type src_type, 1344 struct perf_sample *sample, 1345 struct machine *machine __maybe_unused) 1346 { 1347 work->class = class; 1348 work->cpu = sample->cpu; 1349 1350 if (src_type == KWORK_TRACE_EXIT) { 1351 work->id = perf_sample__intval(sample, "prev_pid"); 1352 work->name = strdup(perf_sample__strval(sample, "prev_comm") ?: "<unknown>"); 1353 } else if (src_type == KWORK_TRACE_ENTRY) { 1354 work->id = perf_sample__intval(sample, "next_pid"); 1355 work->name = strdup(perf_sample__strval(sample, "next_comm") ?: "<unknown>"); 1356 } 1357 } 1358 1359 static void sched_work_name(struct kwork_work *work, char *buf, int len) 1360 { 1361 snprintf(buf, len, "%s", work->name ?: ""); 1362 } 1363 1364 static struct kwork_class kwork_sched = { 1365 .name = "sched", 1366 .type = KWORK_CLASS_SCHED, 1367 .nr_tracepoints = ARRAY_SIZE(sched_tp_handlers), 1368 .tp_handlers = sched_tp_handlers, 1369 .class_init = sched_class_init, 1370 .work_init = sched_work_init, 1371 .work_name = sched_work_name, 1372 }; 1373 1374 static struct kwork_class *kwork_class_supported_list[KWORK_CLASS_MAX] = { 1375 [KWORK_CLASS_IRQ] = &kwork_irq, 1376 [KWORK_CLASS_SOFTIRQ] = &kwork_softirq, 1377 [KWORK_CLASS_WORKQUEUE] = &kwork_workqueue, 1378 [KWORK_CLASS_SCHED] = &kwork_sched, 1379 }; 1380 1381 static void print_separator(int len) 1382 { 1383 printf(" %.*s\n", len, graph_dotted_line); 1384 } 1385 1386 static int report_print_work(struct perf_kwork *kwork, struct kwork_work *work) 1387 { 1388 int ret = 0; 1389 char kwork_name[PRINT_KWORK_NAME_WIDTH]; 1390 char max_runtime_start[32], max_runtime_end[32]; 1391 char max_latency_start[32], max_latency_end[32]; 1392 1393 printf(" "); 1394 1395 /* 1396 * kwork name 1397 */ 1398 if (work->class && work->class->work_name) { 1399 work->class->work_name(work, kwork_name, 1400 PRINT_KWORK_NAME_WIDTH); 1401 ret += printf(" %-*s |", PRINT_KWORK_NAME_WIDTH, kwork_name); 1402 } else { 1403 ret += printf(" %-*s |", PRINT_KWORK_NAME_WIDTH, ""); 1404 } 1405 1406 /* 1407 * cpu 1408 */ 1409 ret += printf(" %0*d |", PRINT_CPU_WIDTH, work->cpu); 1410 1411 /* 1412 * total runtime 1413 */ 1414 if (kwork->report == KWORK_REPORT_RUNTIME) { 1415 ret += printf(" %*.*f ms |", 1416 PRINT_RUNTIME_WIDTH, RPINT_DECIMAL_WIDTH, 1417 (double)work->total_runtime / NSEC_PER_MSEC); 1418 } else if (kwork->report == KWORK_REPORT_LATENCY) { // avg delay 1419 ret += printf(" %*.*f ms |", 1420 PRINT_LATENCY_WIDTH, RPINT_DECIMAL_WIDTH, 1421 (double)work->total_latency / 1422 work->nr_atoms / NSEC_PER_MSEC); 1423 } 1424 1425 /* 1426 * count 1427 */ 1428 ret += printf(" %*" PRIu64 " |", PRINT_COUNT_WIDTH, work->nr_atoms); 1429 1430 /* 1431 * max runtime, max runtime start, max runtime end 1432 */ 1433 if (kwork->report == KWORK_REPORT_RUNTIME) { 1434 timestamp__scnprintf_usec(work->max_runtime_start, 1435 max_runtime_start, 1436 sizeof(max_runtime_start)); 1437 timestamp__scnprintf_usec(work->max_runtime_end, 1438 max_runtime_end, 1439 sizeof(max_runtime_end)); 1440 ret += printf(" %*.*f ms | %*s s | %*s s |", 1441 PRINT_RUNTIME_WIDTH, RPINT_DECIMAL_WIDTH, 1442 (double)work->max_runtime / NSEC_PER_MSEC, 1443 PRINT_TIMESTAMP_WIDTH, max_runtime_start, 1444 PRINT_TIMESTAMP_WIDTH, max_runtime_end); 1445 } 1446 /* 1447 * max delay, max delay start, max delay end 1448 */ 1449 else if (kwork->report == KWORK_REPORT_LATENCY) { 1450 timestamp__scnprintf_usec(work->max_latency_start, 1451 max_latency_start, 1452 sizeof(max_latency_start)); 1453 timestamp__scnprintf_usec(work->max_latency_end, 1454 max_latency_end, 1455 sizeof(max_latency_end)); 1456 ret += printf(" %*.*f ms | %*s s | %*s s |", 1457 PRINT_LATENCY_WIDTH, RPINT_DECIMAL_WIDTH, 1458 (double)work->max_latency / NSEC_PER_MSEC, 1459 PRINT_TIMESTAMP_WIDTH, max_latency_start, 1460 PRINT_TIMESTAMP_WIDTH, max_latency_end); 1461 } 1462 1463 printf("\n"); 1464 return ret; 1465 } 1466 1467 static int report_print_header(struct perf_kwork *kwork) 1468 { 1469 int ret; 1470 1471 printf("\n "); 1472 ret = printf(" %-*s | %-*s |", 1473 PRINT_KWORK_NAME_WIDTH, "Kwork Name", 1474 PRINT_CPU_WIDTH, "Cpu"); 1475 1476 if (kwork->report == KWORK_REPORT_RUNTIME) { 1477 ret += printf(" %-*s |", 1478 PRINT_RUNTIME_HEADER_WIDTH, "Total Runtime"); 1479 } else if (kwork->report == KWORK_REPORT_LATENCY) { 1480 ret += printf(" %-*s |", 1481 PRINT_LATENCY_HEADER_WIDTH, "Avg delay"); 1482 } 1483 1484 ret += printf(" %-*s |", PRINT_COUNT_WIDTH, "Count"); 1485 1486 if (kwork->report == KWORK_REPORT_RUNTIME) { 1487 ret += printf(" %-*s | %-*s | %-*s |", 1488 PRINT_RUNTIME_HEADER_WIDTH, "Max runtime", 1489 PRINT_TIMESTAMP_HEADER_WIDTH, "Max runtime start", 1490 PRINT_TIMESTAMP_HEADER_WIDTH, "Max runtime end"); 1491 } else if (kwork->report == KWORK_REPORT_LATENCY) { 1492 ret += printf(" %-*s | %-*s | %-*s |", 1493 PRINT_LATENCY_HEADER_WIDTH, "Max delay", 1494 PRINT_TIMESTAMP_HEADER_WIDTH, "Max delay start", 1495 PRINT_TIMESTAMP_HEADER_WIDTH, "Max delay end"); 1496 } 1497 1498 printf("\n"); 1499 print_separator(ret); 1500 return ret; 1501 } 1502 1503 static void timehist_print_header(void) 1504 { 1505 /* 1506 * header row 1507 */ 1508 printf(" %-*s %-*s %-*s %-*s %-*s %-*s\n", 1509 PRINT_TIMESTAMP_WIDTH, "Runtime start", 1510 PRINT_TIMESTAMP_WIDTH, "Runtime end", 1511 PRINT_TIMEHIST_CPU_WIDTH, "Cpu", 1512 PRINT_KWORK_NAME_WIDTH, "Kwork name", 1513 PRINT_RUNTIME_WIDTH, "Runtime", 1514 PRINT_RUNTIME_WIDTH, "Delaytime"); 1515 1516 /* 1517 * units row 1518 */ 1519 printf(" %-*s %-*s %-*s %-*s %-*s %-*s\n", 1520 PRINT_TIMESTAMP_WIDTH, "", 1521 PRINT_TIMESTAMP_WIDTH, "", 1522 PRINT_TIMEHIST_CPU_WIDTH, "", 1523 PRINT_KWORK_NAME_WIDTH, "(TYPE)NAME:NUM", 1524 PRINT_RUNTIME_WIDTH, "(msec)", 1525 PRINT_RUNTIME_WIDTH, "(msec)"); 1526 1527 /* 1528 * separator 1529 */ 1530 printf(" %.*s %.*s %.*s %.*s %.*s %.*s\n", 1531 PRINT_TIMESTAMP_WIDTH, graph_dotted_line, 1532 PRINT_TIMESTAMP_WIDTH, graph_dotted_line, 1533 PRINT_TIMEHIST_CPU_WIDTH, graph_dotted_line, 1534 PRINT_KWORK_NAME_WIDTH, graph_dotted_line, 1535 PRINT_RUNTIME_WIDTH, graph_dotted_line, 1536 PRINT_RUNTIME_WIDTH, graph_dotted_line); 1537 } 1538 1539 static void print_summary(struct perf_kwork *kwork) 1540 { 1541 u64 time = kwork->timeend - kwork->timestart; 1542 1543 printf(" Total count : %9" PRIu64 "\n", kwork->all_count); 1544 printf(" Total runtime (msec) : %9.3f (%.3f%% load average)\n", 1545 (double)kwork->all_runtime / NSEC_PER_MSEC, 1546 time == 0 ? 0 : (double)kwork->all_runtime / time); 1547 printf(" Total time span (msec) : %9.3f\n", 1548 (double)time / NSEC_PER_MSEC); 1549 } 1550 1551 static unsigned long long nr_list_entry(struct list_head *head) 1552 { 1553 struct list_head *pos; 1554 unsigned long long n = 0; 1555 1556 list_for_each(pos, head) 1557 n++; 1558 1559 return n; 1560 } 1561 1562 static void print_skipped_events(struct perf_kwork *kwork) 1563 { 1564 int i; 1565 const char *const kwork_event_str[] = { 1566 [KWORK_TRACE_RAISE] = "raise", 1567 [KWORK_TRACE_ENTRY] = "entry", 1568 [KWORK_TRACE_EXIT] = "exit", 1569 }; 1570 1571 if ((kwork->nr_skipped_events[KWORK_TRACE_MAX] != 0) && 1572 (kwork->nr_events != 0)) { 1573 printf(" INFO: %.3f%% skipped events (%" PRIu64 " including ", 1574 (double)kwork->nr_skipped_events[KWORK_TRACE_MAX] / 1575 (double)kwork->nr_events * 100.0, 1576 kwork->nr_skipped_events[KWORK_TRACE_MAX]); 1577 1578 for (i = 0; i < KWORK_TRACE_MAX; i++) { 1579 printf("%" PRIu64 " %s%s", 1580 kwork->nr_skipped_events[i], 1581 kwork_event_str[i], 1582 (i == KWORK_TRACE_MAX - 1) ? ")\n" : ", "); 1583 } 1584 } 1585 1586 if (verbose > 0) 1587 printf(" INFO: use %lld atom pages\n", 1588 nr_list_entry(&kwork->atom_page_list)); 1589 } 1590 1591 static void print_bad_events(struct perf_kwork *kwork) 1592 { 1593 if ((kwork->nr_lost_events != 0) && (kwork->nr_events != 0)) { 1594 printf(" INFO: %.3f%% lost events (%ld out of %ld, in %ld chunks)\n", 1595 (double)kwork->nr_lost_events / 1596 (double)kwork->nr_events * 100.0, 1597 kwork->nr_lost_events, kwork->nr_events, 1598 kwork->nr_lost_chunks); 1599 } 1600 } 1601 1602 static void top_print_per_cpu_load(struct perf_kwork *kwork) 1603 { 1604 int i, load_width; 1605 u64 total, load, load_ratio; 1606 struct kwork_top_stat *stat = &kwork->top_stat; 1607 const char *graph_load = "||||||||||||||||||||||||||||||||||||||||||||||||"; 1608 const char *graph_idle = " "; 1609 1610 for (i = 0; i < MAX_NR_CPUS; i++) { 1611 total = stat->cpus_runtime[i].total; 1612 load = stat->cpus_runtime[i].load; 1613 if (test_bit(i, stat->all_cpus_bitmap) && total) { 1614 load_ratio = load * 10000 / total; 1615 load_width = PRINT_CPU_USAGE_HIST_WIDTH * 1616 load_ratio / 10000; 1617 1618 printf("%%Cpu%-*d[%.*s%.*s %*.*f%%]\n", 1619 PRINT_CPU_WIDTH, i, 1620 load_width, graph_load, 1621 PRINT_CPU_USAGE_HIST_WIDTH - load_width, 1622 graph_idle, 1623 PRINT_CPU_USAGE_WIDTH, 1624 PRINT_CPU_USAGE_DECIMAL_WIDTH, 1625 (double)load_ratio / 100); 1626 } 1627 } 1628 } 1629 1630 static void top_print_cpu_usage(struct perf_kwork *kwork) 1631 { 1632 struct kwork_top_stat *stat = &kwork->top_stat; 1633 u64 idle_time = stat->cpus_runtime[MAX_NR_CPUS].idle; 1634 u64 hardirq_time = stat->cpus_runtime[MAX_NR_CPUS].irq; 1635 u64 softirq_time = stat->cpus_runtime[MAX_NR_CPUS].softirq; 1636 int cpus_nr = bitmap_weight(stat->all_cpus_bitmap, MAX_NR_CPUS); 1637 u64 cpus_total_time = stat->cpus_runtime[MAX_NR_CPUS].total; 1638 1639 printf("Total : %*.*f ms, %d cpus\n", 1640 PRINT_RUNTIME_WIDTH, RPINT_DECIMAL_WIDTH, 1641 (double)cpus_total_time / NSEC_PER_MSEC, 1642 cpus_nr); 1643 1644 printf("%%Cpu(s): %*.*f%% id, %*.*f%% hi, %*.*f%% si\n", 1645 PRINT_CPU_USAGE_WIDTH, PRINT_CPU_USAGE_DECIMAL_WIDTH, 1646 cpus_total_time ? (double)idle_time * 100 / cpus_total_time : 0, 1647 1648 PRINT_CPU_USAGE_WIDTH, PRINT_CPU_USAGE_DECIMAL_WIDTH, 1649 cpus_total_time ? (double)hardirq_time * 100 / cpus_total_time : 0, 1650 1651 PRINT_CPU_USAGE_WIDTH, PRINT_CPU_USAGE_DECIMAL_WIDTH, 1652 cpus_total_time ? (double)softirq_time * 100 / cpus_total_time : 0); 1653 1654 top_print_per_cpu_load(kwork); 1655 } 1656 1657 static void top_print_header(struct perf_kwork *kwork __maybe_unused) 1658 { 1659 int ret; 1660 1661 printf("\n "); 1662 ret = printf(" %*s %s%*s%s %*s %*s %-*s", 1663 PRINT_PID_WIDTH, "PID", 1664 1665 kwork->use_bpf ? " " : "", 1666 kwork->use_bpf ? PRINT_PID_WIDTH : 0, 1667 kwork->use_bpf ? "SPID" : "", 1668 kwork->use_bpf ? " " : "", 1669 1670 PRINT_CPU_USAGE_WIDTH, "%CPU", 1671 PRINT_RUNTIME_HEADER_WIDTH + RPINT_DECIMAL_WIDTH, "RUNTIME", 1672 PRINT_TASK_NAME_WIDTH, "COMMAND"); 1673 printf("\n "); 1674 print_separator(ret); 1675 } 1676 1677 static int top_print_work(struct perf_kwork *kwork __maybe_unused, struct kwork_work *work) 1678 { 1679 int ret = 0; 1680 1681 printf(" "); 1682 1683 /* 1684 * pid 1685 */ 1686 ret += printf(" %*" PRIu64 " ", PRINT_PID_WIDTH, work->id); 1687 1688 /* 1689 * tgid 1690 */ 1691 if (kwork->use_bpf) 1692 ret += printf(" %*d ", PRINT_PID_WIDTH, work->tgid); 1693 1694 /* 1695 * cpu usage 1696 */ 1697 ret += printf(" %*.*f ", 1698 PRINT_CPU_USAGE_WIDTH, PRINT_CPU_USAGE_DECIMAL_WIDTH, 1699 (double)work->cpu_usage / 100); 1700 1701 /* 1702 * total runtime 1703 */ 1704 ret += printf(" %*.*f ms ", 1705 PRINT_RUNTIME_WIDTH + RPINT_DECIMAL_WIDTH, RPINT_DECIMAL_WIDTH, 1706 (double)work->total_runtime / NSEC_PER_MSEC); 1707 1708 /* 1709 * command 1710 */ 1711 if (kwork->use_bpf) 1712 ret += printf(" %s%s%s", 1713 work->is_kthread ? "[" : "", 1714 work->name, 1715 work->is_kthread ? "]" : ""); 1716 else 1717 ret += printf(" %-*s", PRINT_TASK_NAME_WIDTH, work->name); 1718 1719 printf("\n"); 1720 return ret; 1721 } 1722 1723 static void work_sort(struct perf_kwork *kwork, 1724 struct kwork_class *class, struct rb_root_cached *root) 1725 { 1726 struct rb_node *node; 1727 struct kwork_work *data; 1728 1729 pr_debug("Sorting %s ...\n", class->name); 1730 for (;;) { 1731 node = rb_first_cached(root); 1732 if (!node) 1733 break; 1734 1735 rb_erase_cached(node, root); 1736 data = rb_entry(node, struct kwork_work, node); 1737 work_insert(&kwork->sorted_work_root, 1738 data, &kwork->sort_list); 1739 } 1740 } 1741 1742 static void perf_kwork__sort(struct perf_kwork *kwork) 1743 { 1744 struct kwork_class *class; 1745 1746 list_for_each_entry(class, &kwork->class_list, list) 1747 work_sort(kwork, class, &class->work_root); 1748 } 1749 1750 static int perf_kwork__check_config(struct perf_kwork *kwork, 1751 struct perf_session *session) 1752 { 1753 int ret; 1754 struct evsel *evsel; 1755 struct kwork_class *class; 1756 1757 static struct trace_kwork_handler report_ops = { 1758 .entry_event = report_entry_event, 1759 .exit_event = report_exit_event, 1760 }; 1761 static struct trace_kwork_handler latency_ops = { 1762 .raise_event = latency_raise_event, 1763 .entry_event = latency_entry_event, 1764 }; 1765 static struct trace_kwork_handler timehist_ops = { 1766 .raise_event = timehist_raise_event, 1767 .entry_event = timehist_entry_event, 1768 .exit_event = timehist_exit_event, 1769 }; 1770 static struct trace_kwork_handler top_ops = { 1771 .entry_event = timehist_entry_event, 1772 .exit_event = top_exit_event, 1773 .sched_switch_event = top_sched_switch_event, 1774 }; 1775 1776 switch (kwork->report) { 1777 case KWORK_REPORT_RUNTIME: 1778 kwork->tp_handler = &report_ops; 1779 break; 1780 case KWORK_REPORT_LATENCY: 1781 kwork->tp_handler = &latency_ops; 1782 break; 1783 case KWORK_REPORT_TIMEHIST: 1784 kwork->tp_handler = &timehist_ops; 1785 break; 1786 case KWORK_REPORT_TOP: 1787 kwork->tp_handler = &top_ops; 1788 break; 1789 default: 1790 pr_debug("Invalid report type %d\n", kwork->report); 1791 return -1; 1792 } 1793 1794 list_for_each_entry(class, &kwork->class_list, list) 1795 if ((class->class_init != NULL) && 1796 (class->class_init(class, session) != 0)) 1797 return -1; 1798 1799 if (kwork->cpu_list != NULL) { 1800 ret = perf_session__cpu_bitmap(session, 1801 kwork->cpu_list, 1802 kwork->cpu_bitmap); 1803 if (ret < 0) { 1804 pr_err("Invalid cpu bitmap\n"); 1805 return -1; 1806 } 1807 } 1808 1809 if (kwork->time_str != NULL) { 1810 ret = perf_time__parse_str(&kwork->ptime, kwork->time_str); 1811 if (ret != 0) { 1812 pr_err("Invalid time span\n"); 1813 return -1; 1814 } 1815 } 1816 1817 list_for_each_entry(evsel, &session->evlist->core.entries, core.node) { 1818 if (kwork->show_callchain && !evsel__has_callchain(evsel)) { 1819 pr_debug("Samples do not have callchains\n"); 1820 kwork->show_callchain = 0; 1821 symbol_conf.use_callchain = 0; 1822 } 1823 } 1824 1825 return 0; 1826 } 1827 1828 static int perf_kwork__read_events(struct perf_kwork *kwork) 1829 { 1830 int ret = -1; 1831 struct perf_session *session = NULL; 1832 1833 struct perf_data data = { 1834 .path = input_name, 1835 .mode = PERF_DATA_MODE_READ, 1836 .force = kwork->force, 1837 }; 1838 1839 session = perf_session__new(&data, &kwork->tool); 1840 if (IS_ERR(session)) { 1841 pr_debug("Error creating perf session\n"); 1842 return PTR_ERR(session); 1843 } 1844 1845 symbol__init(perf_session__env(session)); 1846 1847 if (perf_kwork__check_config(kwork, session) != 0) 1848 goto out_delete; 1849 1850 if (session->tevent.pevent && 1851 tep_set_function_resolver(session->tevent.pevent, 1852 machine__resolve_kernel_addr, 1853 &session->machines.host) < 0) { 1854 pr_err("Failed to set libtraceevent function resolver\n"); 1855 goto out_delete; 1856 } 1857 1858 if (kwork->report == KWORK_REPORT_TIMEHIST) 1859 timehist_print_header(); 1860 1861 ret = perf_session__process_events(session); 1862 if (ret) { 1863 pr_debug("Failed to process events, error %d\n", ret); 1864 goto out_delete; 1865 } 1866 1867 kwork->nr_events = session->evlist->stats.nr_events[0]; 1868 kwork->nr_lost_events = session->evlist->stats.total_lost; 1869 kwork->nr_lost_chunks = session->evlist->stats.nr_events[PERF_RECORD_LOST]; 1870 1871 out_delete: 1872 perf_session__delete(session); 1873 return ret; 1874 } 1875 1876 static void process_skipped_events(struct perf_kwork *kwork, 1877 struct kwork_work *work) 1878 { 1879 int i; 1880 unsigned long long count; 1881 1882 for (i = 0; i < KWORK_TRACE_MAX; i++) { 1883 count = nr_list_entry(&work->atom_list[i]); 1884 kwork->nr_skipped_events[i] += count; 1885 kwork->nr_skipped_events[KWORK_TRACE_MAX] += count; 1886 } 1887 } 1888 1889 static struct kwork_work *perf_kwork_add_work(struct perf_kwork *kwork, 1890 struct kwork_class *class, 1891 struct kwork_work *key) 1892 { 1893 struct kwork_work *work = NULL; 1894 1895 work = work_new(key); 1896 if (work == NULL) 1897 return NULL; 1898 1899 work_insert(&class->work_root, work, &kwork->cmp_id); 1900 return work; 1901 } 1902 1903 static void sig_handler(int sig) 1904 { 1905 /* 1906 * Simply capture termination signal so that 1907 * the program can continue after pause returns 1908 */ 1909 pr_debug("Capture signal %d\n", sig); 1910 } 1911 1912 static int perf_kwork__report_bpf(struct perf_kwork *kwork) 1913 { 1914 int ret; 1915 1916 signal(SIGINT, sig_handler); 1917 signal(SIGTERM, sig_handler); 1918 1919 ret = perf_kwork__trace_prepare_bpf(kwork); 1920 if (ret) 1921 return -1; 1922 1923 printf("Starting trace, Hit <Ctrl+C> to stop and report\n"); 1924 1925 perf_kwork__trace_start(); 1926 1927 /* 1928 * a simple pause, wait here for stop signal 1929 */ 1930 pause(); 1931 1932 perf_kwork__trace_finish(); 1933 1934 perf_kwork__report_read_bpf(kwork); 1935 1936 perf_kwork__report_cleanup_bpf(); 1937 1938 return 0; 1939 } 1940 1941 static int perf_kwork__report(struct perf_kwork *kwork) 1942 { 1943 int ret; 1944 struct rb_node *next; 1945 struct kwork_work *work; 1946 1947 if (kwork->use_bpf) 1948 ret = perf_kwork__report_bpf(kwork); 1949 else 1950 ret = perf_kwork__read_events(kwork); 1951 1952 if (ret != 0) 1953 return -1; 1954 1955 perf_kwork__sort(kwork); 1956 1957 setup_pager(); 1958 1959 ret = report_print_header(kwork); 1960 next = rb_first_cached(&kwork->sorted_work_root); 1961 while (next) { 1962 work = rb_entry(next, struct kwork_work, node); 1963 process_skipped_events(kwork, work); 1964 1965 if (work->nr_atoms != 0) { 1966 report_print_work(kwork, work); 1967 if (kwork->summary) { 1968 kwork->all_runtime += work->total_runtime; 1969 kwork->all_count += work->nr_atoms; 1970 } 1971 } 1972 next = rb_next(next); 1973 } 1974 print_separator(ret); 1975 1976 if (kwork->summary) { 1977 print_summary(kwork); 1978 print_separator(ret); 1979 } 1980 1981 print_bad_events(kwork); 1982 print_skipped_events(kwork); 1983 printf("\n"); 1984 1985 return 0; 1986 } 1987 1988 typedef int (*tracepoint_handler)(const struct perf_tool *tool, 1989 struct perf_sample *sample, 1990 struct machine *machine); 1991 1992 static int perf_kwork__process_tracepoint_sample(const struct perf_tool *tool, 1993 union perf_event *event __maybe_unused, 1994 struct perf_sample *sample, 1995 struct machine *machine) 1996 { 1997 struct evsel *evsel = sample->evsel; 1998 int err = 0; 1999 2000 if (evsel->handler != NULL) { 2001 tracepoint_handler f = evsel->handler; 2002 2003 err = f(tool, sample, machine); 2004 } 2005 2006 return err; 2007 } 2008 2009 static int perf_kwork__timehist(struct perf_kwork *kwork) 2010 { 2011 /* 2012 * event handlers for timehist option 2013 */ 2014 kwork->tool.comm = perf_event__process_comm; 2015 kwork->tool.exit = perf_event__process_exit; 2016 kwork->tool.fork = perf_event__process_fork; 2017 kwork->tool.attr = perf_event__process_attr; 2018 kwork->tool.tracing_data = perf_event__process_tracing_data; 2019 kwork->tool.build_id = perf_event__process_build_id; 2020 kwork->tool.ordered_events = true; 2021 kwork->tool.ordering_requires_timestamps = true; 2022 symbol_conf.use_callchain = kwork->show_callchain; 2023 2024 if (symbol__validate_sym_arguments()) { 2025 pr_err("Failed to validate sym arguments\n"); 2026 return -1; 2027 } 2028 2029 setup_pager(); 2030 2031 return perf_kwork__read_events(kwork); 2032 } 2033 2034 static void top_calc_total_runtime(struct perf_kwork *kwork) 2035 { 2036 struct kwork_class *class; 2037 struct kwork_work *work; 2038 struct rb_node *next; 2039 struct kwork_top_stat *stat = &kwork->top_stat; 2040 2041 class = get_kwork_class(kwork, KWORK_CLASS_SCHED); 2042 if (!class) 2043 return; 2044 2045 next = rb_first_cached(&class->work_root); 2046 while (next) { 2047 work = rb_entry(next, struct kwork_work, node); 2048 /* 2049 * work->cpu comes from sample->cpu which is -1 when 2050 * PERF_SAMPLE_CPU is absent. As int that's -1, but as 2051 * unsigned it exceeds MAX_NR_CPUS — skip to avoid OOB 2052 * on cpus_runtime[]. 2053 */ 2054 /* Counted and reported in perf_kwork__top_report() */ 2055 if ((unsigned int)work->cpu >= MAX_NR_CPUS) { 2056 stat->nr_skipped_cpu++; 2057 next = rb_next(next); 2058 continue; 2059 } 2060 stat->cpus_runtime[work->cpu].total += work->total_runtime; 2061 stat->cpus_runtime[MAX_NR_CPUS].total += work->total_runtime; 2062 next = rb_next(next); 2063 } 2064 } 2065 2066 static void top_calc_idle_time(struct perf_kwork *kwork, 2067 struct kwork_work *work) 2068 { 2069 struct kwork_top_stat *stat = &kwork->top_stat; 2070 2071 /* See comment in top_calc_total_runtime() */ 2072 if (work->id == 0 && (unsigned int)work->cpu < MAX_NR_CPUS) { 2073 stat->cpus_runtime[work->cpu].idle += work->total_runtime; 2074 stat->cpus_runtime[MAX_NR_CPUS].idle += work->total_runtime; 2075 } 2076 } 2077 2078 static void top_calc_irq_runtime(struct perf_kwork *kwork, 2079 enum kwork_class_type type, 2080 struct kwork_work *work) 2081 { 2082 struct kwork_top_stat *stat = &kwork->top_stat; 2083 2084 /* See comment in top_calc_total_runtime() */ 2085 if ((unsigned int)work->cpu >= MAX_NR_CPUS) 2086 return; 2087 2088 if (type == KWORK_CLASS_IRQ) { 2089 stat->cpus_runtime[work->cpu].irq += work->total_runtime; 2090 stat->cpus_runtime[MAX_NR_CPUS].irq += work->total_runtime; 2091 } else if (type == KWORK_CLASS_SOFTIRQ) { 2092 stat->cpus_runtime[work->cpu].softirq += work->total_runtime; 2093 stat->cpus_runtime[MAX_NR_CPUS].softirq += work->total_runtime; 2094 } 2095 } 2096 2097 static void top_subtract_irq_runtime(struct perf_kwork *kwork, 2098 struct kwork_work *work) 2099 { 2100 struct kwork_class *class; 2101 struct kwork_work *data; 2102 unsigned int i; 2103 int irq_class_list[] = {KWORK_CLASS_IRQ, KWORK_CLASS_SOFTIRQ}; 2104 2105 for (i = 0; i < ARRAY_SIZE(irq_class_list); i++) { 2106 class = get_kwork_class(kwork, irq_class_list[i]); 2107 if (!class) 2108 continue; 2109 2110 data = find_work_by_id(&class->work_root, 2111 work->id, work->cpu); 2112 if (!data) 2113 continue; 2114 2115 if (work->total_runtime > data->total_runtime) { 2116 work->total_runtime -= data->total_runtime; 2117 top_calc_irq_runtime(kwork, irq_class_list[i], data); 2118 } 2119 } 2120 } 2121 2122 static void top_calc_cpu_usage(struct perf_kwork *kwork) 2123 { 2124 struct kwork_class *class; 2125 struct kwork_work *work; 2126 struct rb_node *next; 2127 struct kwork_top_stat *stat = &kwork->top_stat; 2128 2129 class = get_kwork_class(kwork, KWORK_CLASS_SCHED); 2130 if (!class) 2131 return; 2132 2133 next = rb_first_cached(&class->work_root); 2134 while (next) { 2135 work = rb_entry(next, struct kwork_work, node); 2136 2137 if (work->total_runtime == 0) 2138 goto next; 2139 2140 /* See comment in top_calc_total_runtime() */ 2141 if ((unsigned int)work->cpu >= MAX_NR_CPUS) 2142 goto next; 2143 2144 __set_bit(work->cpu, stat->all_cpus_bitmap); 2145 2146 top_subtract_irq_runtime(kwork, work); 2147 2148 /* Guard against division by zero if no runtime was accumulated */ 2149 if (stat->cpus_runtime[work->cpu].total) { 2150 work->cpu_usage = work->total_runtime * 10000 / 2151 stat->cpus_runtime[work->cpu].total; 2152 } 2153 2154 top_calc_idle_time(kwork, work); 2155 next: 2156 next = rb_next(next); 2157 } 2158 } 2159 2160 static void top_calc_load_runtime(struct perf_kwork *kwork, 2161 struct kwork_work *work) 2162 { 2163 struct kwork_top_stat *stat = &kwork->top_stat; 2164 2165 /* See comment in top_calc_total_runtime() */ 2166 if (work->id != 0 && (unsigned int)work->cpu < MAX_NR_CPUS) { 2167 stat->cpus_runtime[work->cpu].load += work->total_runtime; 2168 stat->cpus_runtime[MAX_NR_CPUS].load += work->total_runtime; 2169 } 2170 } 2171 2172 static void top_merge_tasks(struct perf_kwork *kwork) 2173 { 2174 struct kwork_work *merged_work, *data; 2175 struct kwork_class *class; 2176 struct rb_node *node; 2177 int cpu; 2178 struct rb_root_cached merged_root = RB_ROOT_CACHED; 2179 2180 class = get_kwork_class(kwork, KWORK_CLASS_SCHED); 2181 if (!class) 2182 return; 2183 2184 for (;;) { 2185 node = rb_first_cached(&class->work_root); 2186 if (!node) 2187 break; 2188 2189 rb_erase_cached(node, &class->work_root); 2190 data = rb_entry(node, struct kwork_work, node); 2191 2192 if (!profile_name_match(kwork, data)) { 2193 work_delete(data); 2194 continue; 2195 } 2196 2197 cpu = data->cpu; 2198 merged_work = find_work_by_id(&merged_root, data->id, 2199 data->id == 0 ? cpu : -1); 2200 if (!merged_work) { 2201 work_insert(&merged_root, data, &kwork->cmp_id); 2202 } else { 2203 if (merged_work->name == NULL && data->name != NULL) 2204 merged_work->name = strdup(data->name); 2205 2206 merged_work->total_runtime += data->total_runtime; 2207 merged_work->cpu_usage += data->cpu_usage; 2208 } 2209 2210 top_calc_load_runtime(kwork, data); 2211 2212 if (merged_work) 2213 work_delete(data); 2214 } 2215 2216 work_sort(kwork, class, &merged_root); 2217 } 2218 2219 static void perf_kwork__top_report(struct perf_kwork *kwork) 2220 { 2221 struct kwork_work *work; 2222 struct rb_node *next; 2223 2224 printf("\n"); 2225 2226 top_print_cpu_usage(kwork); 2227 top_print_header(kwork); 2228 next = rb_first_cached(&kwork->sorted_work_root); 2229 while (next) { 2230 work = rb_entry(next, struct kwork_work, node); 2231 process_skipped_events(kwork, work); 2232 2233 if (work->total_runtime == 0) 2234 goto next; 2235 2236 top_print_work(kwork, work); 2237 2238 next: 2239 next = rb_next(next); 2240 } 2241 2242 if (kwork->top_stat.nr_skipped_cpu) { 2243 printf(" Warning: %u work entries with invalid CPU were excluded from totals.\n" 2244 " Task runtimes may appear inflated (IRQ time not subtracted).\n" 2245 " Consider re-recording with PERF_SAMPLE_CPU enabled.\n", 2246 kwork->top_stat.nr_skipped_cpu); 2247 } 2248 2249 printf("\n"); 2250 } 2251 2252 static int perf_kwork__top_bpf(struct perf_kwork *kwork) 2253 { 2254 int ret; 2255 2256 signal(SIGINT, sig_handler); 2257 signal(SIGTERM, sig_handler); 2258 2259 ret = perf_kwork__top_prepare_bpf(kwork); 2260 if (ret) 2261 return -1; 2262 2263 printf("Starting trace, Hit <Ctrl+C> to stop and report\n"); 2264 2265 perf_kwork__top_start(); 2266 2267 /* 2268 * a simple pause, wait here for stop signal 2269 */ 2270 pause(); 2271 2272 perf_kwork__top_finish(); 2273 2274 perf_kwork__top_read_bpf(kwork); 2275 2276 perf_kwork__top_cleanup_bpf(); 2277 2278 return 0; 2279 2280 } 2281 2282 static int perf_kwork__top(struct perf_kwork *kwork) 2283 { 2284 struct __top_cpus_runtime *cpus_runtime; 2285 int ret = 0; 2286 2287 cpus_runtime = calloc(MAX_NR_CPUS + 1, sizeof(struct __top_cpus_runtime)); 2288 if (!cpus_runtime) 2289 return -1; 2290 2291 kwork->top_stat.cpus_runtime = cpus_runtime; 2292 bitmap_zero(kwork->top_stat.all_cpus_bitmap, MAX_NR_CPUS); 2293 2294 if (kwork->use_bpf) 2295 ret = perf_kwork__top_bpf(kwork); 2296 else 2297 ret = perf_kwork__read_events(kwork); 2298 2299 if (ret) 2300 goto out; 2301 2302 top_calc_total_runtime(kwork); 2303 top_calc_cpu_usage(kwork); 2304 top_merge_tasks(kwork); 2305 2306 setup_pager(); 2307 2308 perf_kwork__top_report(kwork); 2309 2310 out: 2311 zfree(&kwork->top_stat.cpus_runtime); 2312 return ret; 2313 } 2314 2315 static void setup_event_list(struct perf_kwork *kwork, 2316 const struct option *options, 2317 const char * const usage_msg[]) 2318 { 2319 int i; 2320 struct kwork_class *class; 2321 char *tmp, *tok, *str; 2322 2323 /* 2324 * set default events list if not specified 2325 */ 2326 if (kwork->event_list_str == NULL) 2327 kwork->event_list_str = "irq, softirq, workqueue"; 2328 2329 str = strdup(kwork->event_list_str); 2330 for (tok = strtok_r(str, ", ", &tmp); 2331 tok; tok = strtok_r(NULL, ", ", &tmp)) { 2332 for (i = 0; i < KWORK_CLASS_MAX; i++) { 2333 class = kwork_class_supported_list[i]; 2334 if (strcmp(tok, class->name) == 0) { 2335 list_add_tail(&class->list, &kwork->class_list); 2336 break; 2337 } 2338 } 2339 if (i == KWORK_CLASS_MAX) { 2340 usage_with_options_msg(usage_msg, options, 2341 "Unknown --event key: `%s'", tok); 2342 } 2343 } 2344 free(str); 2345 2346 pr_debug("Config event list:"); 2347 list_for_each_entry(class, &kwork->class_list, list) 2348 pr_debug(" %s", class->name); 2349 pr_debug("\n"); 2350 } 2351 2352 #define STRDUP_FAIL_EXIT(s) \ 2353 ({ char *_p; \ 2354 _p = strdup(s); \ 2355 if (!_p) { \ 2356 ret = -ENOMEM; \ 2357 goto EXIT; \ 2358 } \ 2359 _p; \ 2360 }) 2361 2362 static int perf_kwork__record(struct perf_kwork *kwork, 2363 int argc, const char **argv) 2364 { 2365 const char **rec_argv, **to_free = NULL; 2366 unsigned int rec_argc, i, j; 2367 struct kwork_class *class; 2368 int ret; 2369 2370 const char *const record_args[] = { 2371 "record", 2372 "-a", 2373 "-R", 2374 "-m", "1024", 2375 "-c", "1", 2376 }; 2377 2378 rec_argc = ARRAY_SIZE(record_args) + argc - 1; 2379 2380 list_for_each_entry(class, &kwork->class_list, list) 2381 rec_argc += 2 * class->nr_tracepoints; 2382 2383 rec_argv = calloc(rec_argc + 1, sizeof(char *)); 2384 if (rec_argv == NULL) 2385 return -ENOMEM; 2386 2387 for (i = 0; i < ARRAY_SIZE(record_args); i++) 2388 rec_argv[i] = STRDUP_FAIL_EXIT(record_args[i]); 2389 2390 list_for_each_entry(class, &kwork->class_list, list) { 2391 for (j = 0; j < class->nr_tracepoints; j++) { 2392 rec_argv[i++] = STRDUP_FAIL_EXIT("-e"); 2393 rec_argv[i++] = STRDUP_FAIL_EXIT(class->tp_handlers[j].name); 2394 } 2395 } 2396 2397 for (j = 1; j < (unsigned int)argc; j++, i++) 2398 rec_argv[i] = STRDUP_FAIL_EXIT(argv[j]); 2399 2400 BUG_ON(i != rec_argc); 2401 2402 /* Save the pointers as the array will be mutated by cmd_record. */ 2403 to_free = calloc(rec_argc + 1, sizeof(char *)); 2404 if (to_free == NULL) { 2405 ret = -ENOMEM; 2406 goto EXIT; 2407 } 2408 2409 pr_debug("record comm: "); 2410 for (j = 0; j < rec_argc; j++) { 2411 pr_debug("%s ", rec_argv[j]); 2412 to_free[j] = rec_argv[j]; 2413 } 2414 pr_debug("\n"); 2415 2416 ret = cmd_record(i, rec_argv); 2417 2418 EXIT: 2419 for (i = 0; i < rec_argc; i++) 2420 free((void *)(to_free ? to_free[i] : rec_argv[i])); 2421 2422 free(to_free); 2423 free(rec_argv); 2424 return ret; 2425 } 2426 2427 int cmd_kwork(int argc, const char **argv) 2428 { 2429 static struct perf_kwork kwork = { 2430 .class_list = LIST_HEAD_INIT(kwork.class_list), 2431 .atom_page_list = LIST_HEAD_INIT(kwork.atom_page_list), 2432 .sort_list = LIST_HEAD_INIT(kwork.sort_list), 2433 .cmp_id = LIST_HEAD_INIT(kwork.cmp_id), 2434 .sorted_work_root = RB_ROOT_CACHED, 2435 .tp_handler = NULL, 2436 .profile_name = NULL, 2437 .cpu_list = NULL, 2438 .time_str = NULL, 2439 .force = false, 2440 .event_list_str = NULL, 2441 .summary = false, 2442 .sort_order = NULL, 2443 .show_callchain = false, 2444 .max_stack = 5, 2445 .timestart = 0, 2446 .timeend = 0, 2447 .nr_events = 0, 2448 .nr_lost_chunks = 0, 2449 .nr_lost_events = 0, 2450 .all_runtime = 0, 2451 .all_count = 0, 2452 .nr_skipped_events = { 0 }, 2453 .add_work = perf_kwork_add_work, 2454 }; 2455 static const char default_report_sort_order[] = "runtime, max, count"; 2456 static const char default_latency_sort_order[] = "avg, max, count"; 2457 static const char default_top_sort_order[] = "rate, runtime"; 2458 const struct option kwork_options[] = { 2459 OPT_INCR('v', "verbose", &verbose, 2460 "be more verbose (show symbol address, etc)"), 2461 OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace, 2462 "dump raw trace in ASCII"), 2463 OPT_STRING('k', "kwork", &kwork.event_list_str, "kwork", 2464 "list of kwork to profile (irq, softirq, workqueue, sched, etc)"), 2465 OPT_BOOLEAN('f', "force", &kwork.force, "don't complain, do it"), 2466 OPT_END() 2467 }; 2468 const struct option report_options[] = { 2469 OPT_STRING('s', "sort", &kwork.sort_order, "key[,key2...]", 2470 "sort by key(s): runtime, max, count"), 2471 OPT_STRING('C', "cpu", &kwork.cpu_list, "cpu", 2472 "list of cpus to profile"), 2473 OPT_STRING('n', "name", &kwork.profile_name, "name", 2474 "event name to profile"), 2475 OPT_STRING(0, "time", &kwork.time_str, "str", 2476 "Time span for analysis (start,stop)"), 2477 OPT_STRING('i', "input", &input_name, "file", 2478 "input file name"), 2479 OPT_BOOLEAN('S', "with-summary", &kwork.summary, 2480 "Show summary with statistics"), 2481 #ifdef HAVE_BPF_SKEL 2482 OPT_BOOLEAN('b', "use-bpf", &kwork.use_bpf, 2483 "Use BPF to measure kwork runtime"), 2484 #endif 2485 OPT_PARENT(kwork_options) 2486 }; 2487 const struct option latency_options[] = { 2488 OPT_STRING('s', "sort", &kwork.sort_order, "key[,key2...]", 2489 "sort by key(s): avg, max, count"), 2490 OPT_STRING('C', "cpu", &kwork.cpu_list, "cpu", 2491 "list of cpus to profile"), 2492 OPT_STRING('n', "name", &kwork.profile_name, "name", 2493 "event name to profile"), 2494 OPT_STRING(0, "time", &kwork.time_str, "str", 2495 "Time span for analysis (start,stop)"), 2496 OPT_STRING('i', "input", &input_name, "file", 2497 "input file name"), 2498 #ifdef HAVE_BPF_SKEL 2499 OPT_BOOLEAN('b', "use-bpf", &kwork.use_bpf, 2500 "Use BPF to measure kwork latency"), 2501 #endif 2502 OPT_PARENT(kwork_options) 2503 }; 2504 const struct option timehist_options[] = { 2505 OPT_STRING('k', "vmlinux", &symbol_conf.vmlinux_name, 2506 "file", "vmlinux pathname"), 2507 OPT_STRING(0, "kallsyms", &symbol_conf.kallsyms_name, 2508 "file", "kallsyms pathname"), 2509 OPT_BOOLEAN('g', "call-graph", &kwork.show_callchain, 2510 "Display call chains if present"), 2511 OPT_UINTEGER(0, "max-stack", &kwork.max_stack, 2512 "Maximum number of functions to display backtrace."), 2513 OPT_CALLBACK(0, "symfs", NULL, "directory[,layout]", SYMFS_HELP, 2514 symbol__config_symfs), 2515 OPT_STRING(0, "time", &kwork.time_str, "str", 2516 "Time span for analysis (start,stop)"), 2517 OPT_STRING('C', "cpu", &kwork.cpu_list, "cpu", 2518 "list of cpus to profile"), 2519 OPT_STRING('n', "name", &kwork.profile_name, "name", 2520 "event name to profile"), 2521 OPT_STRING('i', "input", &input_name, "file", 2522 "input file name"), 2523 OPT_PARENT(kwork_options) 2524 }; 2525 const struct option top_options[] = { 2526 OPT_STRING('s', "sort", &kwork.sort_order, "key[,key2...]", 2527 "sort by key(s): rate, runtime, tid"), 2528 OPT_STRING('C', "cpu", &kwork.cpu_list, "cpu", 2529 "list of cpus to profile"), 2530 OPT_STRING('n', "name", &kwork.profile_name, "name", 2531 "event name to profile"), 2532 OPT_STRING(0, "time", &kwork.time_str, "str", 2533 "Time span for analysis (start,stop)"), 2534 OPT_STRING('i', "input", &input_name, "file", 2535 "input file name"), 2536 #ifdef HAVE_BPF_SKEL 2537 OPT_BOOLEAN('b', "use-bpf", &kwork.use_bpf, 2538 "Use BPF to measure task cpu usage"), 2539 #endif 2540 OPT_PARENT(kwork_options) 2541 }; 2542 const char *kwork_usage[] = { 2543 NULL, 2544 NULL 2545 }; 2546 const char * const report_usage[] = { 2547 "perf kwork report [<options>]", 2548 NULL 2549 }; 2550 const char * const latency_usage[] = { 2551 "perf kwork latency [<options>]", 2552 NULL 2553 }; 2554 const char * const timehist_usage[] = { 2555 "perf kwork timehist [<options>]", 2556 NULL 2557 }; 2558 const char * const top_usage[] = { 2559 "perf kwork top [<options>]", 2560 NULL 2561 }; 2562 const char *const kwork_subcommands[] = { 2563 "record", "report", "latency", "timehist", "top", NULL 2564 }; 2565 int ret = 0; 2566 2567 perf_tool__init(&kwork.tool, /*ordered_events=*/true); 2568 kwork.tool.mmap = perf_event__process_mmap; 2569 kwork.tool.mmap2 = perf_event__process_mmap2; 2570 kwork.tool.sample = perf_kwork__process_tracepoint_sample; 2571 2572 argc = parse_options_subcommand(argc, argv, kwork_options, 2573 kwork_subcommands, kwork_usage, 2574 PARSE_OPT_STOP_AT_NON_OPTION); 2575 if (!argc) 2576 usage_with_options(kwork_usage, kwork_options); 2577 2578 sort_dimension__add(&kwork, "id", &kwork.cmp_id); 2579 2580 if (strlen(argv[0]) > 2 && strstarts("record", argv[0])) { 2581 setup_event_list(&kwork, kwork_options, kwork_usage); 2582 ret = perf_kwork__record(&kwork, argc, argv); 2583 } else if (strlen(argv[0]) > 2 && strstarts("report", argv[0])) { 2584 kwork.sort_order = default_report_sort_order; 2585 if (argc > 1) { 2586 argc = parse_options(argc, argv, report_options, report_usage, 0); 2587 if (argc) 2588 usage_with_options(report_usage, report_options); 2589 } 2590 kwork.report = KWORK_REPORT_RUNTIME; 2591 setup_sorting(&kwork, report_options, report_usage); 2592 setup_event_list(&kwork, kwork_options, kwork_usage); 2593 ret = perf_kwork__report(&kwork); 2594 } else if (strlen(argv[0]) > 2 && strstarts("latency", argv[0])) { 2595 kwork.sort_order = default_latency_sort_order; 2596 if (argc > 1) { 2597 argc = parse_options(argc, argv, latency_options, latency_usage, 0); 2598 if (argc) 2599 usage_with_options(latency_usage, latency_options); 2600 } 2601 kwork.report = KWORK_REPORT_LATENCY; 2602 setup_sorting(&kwork, latency_options, latency_usage); 2603 setup_event_list(&kwork, kwork_options, kwork_usage); 2604 ret = perf_kwork__report(&kwork); 2605 } else if (strlen(argv[0]) > 2 && strstarts("timehist", argv[0])) { 2606 if (argc > 1) { 2607 argc = parse_options(argc, argv, timehist_options, timehist_usage, 0); 2608 if (argc) 2609 usage_with_options(timehist_usage, timehist_options); 2610 } 2611 kwork.report = KWORK_REPORT_TIMEHIST; 2612 setup_event_list(&kwork, kwork_options, kwork_usage); 2613 ret = perf_kwork__timehist(&kwork); 2614 } else if (strlen(argv[0]) > 2 && strstarts("top", argv[0])) { 2615 kwork.sort_order = default_top_sort_order; 2616 if (argc > 1) { 2617 argc = parse_options(argc, argv, top_options, top_usage, 0); 2618 if (argc) 2619 usage_with_options(top_usage, top_options); 2620 } 2621 kwork.report = KWORK_REPORT_TOP; 2622 if (!kwork.event_list_str) 2623 kwork.event_list_str = "sched, irq, softirq"; 2624 setup_event_list(&kwork, kwork_options, kwork_usage); 2625 setup_sorting(&kwork, top_options, top_usage); 2626 ret = perf_kwork__top(&kwork); 2627 } else 2628 usage_with_options(kwork_usage, kwork_options); 2629 2630 perf_kwork__exit(&kwork); 2631 2632 /* free usage string allocated by parse_options_subcommand */ 2633 free((void *)kwork_usage[0]); 2634 2635 return ret; 2636 } 2637