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 10 #include "util/data.h" 11 #include "util/kwork.h" 12 #include "util/debug.h" 13 #include "util/symbol.h" 14 #include "util/thread.h" 15 #include "util/string2.h" 16 #include "util/callchain.h" 17 #include "util/evsel_fprintf.h" 18 19 #include <subcmd/pager.h> 20 #include <subcmd/parse-options.h> 21 22 #include <errno.h> 23 #include <inttypes.h> 24 #include <linux/err.h> 25 #include <linux/time64.h> 26 #include <linux/zalloc.h> 27 28 /* 29 * report header elements width 30 */ 31 #define PRINT_CPU_WIDTH 4 32 #define PRINT_COUNT_WIDTH 9 33 #define PRINT_RUNTIME_WIDTH 10 34 #define PRINT_TIMESTAMP_WIDTH 17 35 #define PRINT_KWORK_NAME_WIDTH 30 36 #define RPINT_DECIMAL_WIDTH 3 37 #define PRINT_TIME_UNIT_SEC_WIDTH 2 38 #define PRINT_TIME_UNIT_MESC_WIDTH 3 39 #define PRINT_RUNTIME_HEADER_WIDTH (PRINT_RUNTIME_WIDTH + PRINT_TIME_UNIT_MESC_WIDTH) 40 #define PRINT_TIMESTAMP_HEADER_WIDTH (PRINT_TIMESTAMP_WIDTH + PRINT_TIME_UNIT_SEC_WIDTH) 41 42 struct sort_dimension { 43 const char *name; 44 int (*cmp)(struct kwork_work *l, struct kwork_work *r); 45 struct list_head list; 46 }; 47 48 static int id_cmp(struct kwork_work *l, struct kwork_work *r) 49 { 50 if (l->cpu > r->cpu) 51 return 1; 52 if (l->cpu < r->cpu) 53 return -1; 54 55 if (l->id > r->id) 56 return 1; 57 if (l->id < r->id) 58 return -1; 59 60 return 0; 61 } 62 63 static int count_cmp(struct kwork_work *l, struct kwork_work *r) 64 { 65 if (l->nr_atoms > r->nr_atoms) 66 return 1; 67 if (l->nr_atoms < r->nr_atoms) 68 return -1; 69 70 return 0; 71 } 72 73 static int runtime_cmp(struct kwork_work *l, struct kwork_work *r) 74 { 75 if (l->total_runtime > r->total_runtime) 76 return 1; 77 if (l->total_runtime < r->total_runtime) 78 return -1; 79 80 return 0; 81 } 82 83 static int max_runtime_cmp(struct kwork_work *l, struct kwork_work *r) 84 { 85 if (l->max_runtime > r->max_runtime) 86 return 1; 87 if (l->max_runtime < r->max_runtime) 88 return -1; 89 90 return 0; 91 } 92 93 static int sort_dimension__add(struct perf_kwork *kwork __maybe_unused, 94 const char *tok, struct list_head *list) 95 { 96 size_t i; 97 static struct sort_dimension max_sort_dimension = { 98 .name = "max", 99 .cmp = max_runtime_cmp, 100 }; 101 static struct sort_dimension id_sort_dimension = { 102 .name = "id", 103 .cmp = id_cmp, 104 }; 105 static struct sort_dimension runtime_sort_dimension = { 106 .name = "runtime", 107 .cmp = runtime_cmp, 108 }; 109 static struct sort_dimension count_sort_dimension = { 110 .name = "count", 111 .cmp = count_cmp, 112 }; 113 struct sort_dimension *available_sorts[] = { 114 &id_sort_dimension, 115 &max_sort_dimension, 116 &count_sort_dimension, 117 &runtime_sort_dimension, 118 }; 119 120 for (i = 0; i < ARRAY_SIZE(available_sorts); i++) { 121 if (!strcmp(available_sorts[i]->name, tok)) { 122 list_add_tail(&available_sorts[i]->list, list); 123 return 0; 124 } 125 } 126 127 return -1; 128 } 129 130 static void setup_sorting(struct perf_kwork *kwork, 131 const struct option *options, 132 const char * const usage_msg[]) 133 { 134 char *tmp, *tok, *str = strdup(kwork->sort_order); 135 136 for (tok = strtok_r(str, ", ", &tmp); 137 tok; tok = strtok_r(NULL, ", ", &tmp)) { 138 if (sort_dimension__add(kwork, tok, &kwork->sort_list) < 0) 139 usage_with_options_msg(usage_msg, options, 140 "Unknown --sort key: `%s'", tok); 141 } 142 143 pr_debug("Sort order: %s\n", kwork->sort_order); 144 free(str); 145 } 146 147 static struct kwork_atom *atom_new(struct perf_kwork *kwork, 148 struct perf_sample *sample) 149 { 150 unsigned long i; 151 struct kwork_atom_page *page; 152 struct kwork_atom *atom = NULL; 153 154 list_for_each_entry(page, &kwork->atom_page_list, list) { 155 if (!bitmap_full(page->bitmap, NR_ATOM_PER_PAGE)) { 156 i = find_first_zero_bit(page->bitmap, NR_ATOM_PER_PAGE); 157 BUG_ON(i >= NR_ATOM_PER_PAGE); 158 atom = &page->atoms[i]; 159 goto found_atom; 160 } 161 } 162 163 /* 164 * new page 165 */ 166 page = zalloc(sizeof(*page)); 167 if (page == NULL) { 168 pr_err("Failed to zalloc kwork atom page\n"); 169 return NULL; 170 } 171 172 i = 0; 173 atom = &page->atoms[0]; 174 list_add_tail(&page->list, &kwork->atom_page_list); 175 176 found_atom: 177 set_bit(i, page->bitmap); 178 atom->time = sample->time; 179 atom->prev = NULL; 180 atom->page_addr = page; 181 atom->bit_inpage = i; 182 return atom; 183 } 184 185 static void atom_free(struct kwork_atom *atom) 186 { 187 if (atom->prev != NULL) 188 atom_free(atom->prev); 189 190 clear_bit(atom->bit_inpage, 191 ((struct kwork_atom_page *)atom->page_addr)->bitmap); 192 } 193 194 static void atom_del(struct kwork_atom *atom) 195 { 196 list_del(&atom->list); 197 atom_free(atom); 198 } 199 200 static int work_cmp(struct list_head *list, 201 struct kwork_work *l, struct kwork_work *r) 202 { 203 int ret = 0; 204 struct sort_dimension *sort; 205 206 BUG_ON(list_empty(list)); 207 208 list_for_each_entry(sort, list, list) { 209 ret = sort->cmp(l, r); 210 if (ret) 211 return ret; 212 } 213 214 return ret; 215 } 216 217 static struct kwork_work *work_search(struct rb_root_cached *root, 218 struct kwork_work *key, 219 struct list_head *sort_list) 220 { 221 int cmp; 222 struct kwork_work *work; 223 struct rb_node *node = root->rb_root.rb_node; 224 225 while (node) { 226 work = container_of(node, struct kwork_work, node); 227 cmp = work_cmp(sort_list, key, work); 228 if (cmp > 0) 229 node = node->rb_left; 230 else if (cmp < 0) 231 node = node->rb_right; 232 else { 233 if (work->name == NULL) 234 work->name = key->name; 235 return work; 236 } 237 } 238 return NULL; 239 } 240 241 static void work_insert(struct rb_root_cached *root, 242 struct kwork_work *key, struct list_head *sort_list) 243 { 244 int cmp; 245 bool leftmost = true; 246 struct kwork_work *cur; 247 struct rb_node **new = &(root->rb_root.rb_node), *parent = NULL; 248 249 while (*new) { 250 cur = container_of(*new, struct kwork_work, node); 251 parent = *new; 252 cmp = work_cmp(sort_list, key, cur); 253 254 if (cmp > 0) 255 new = &((*new)->rb_left); 256 else { 257 new = &((*new)->rb_right); 258 leftmost = false; 259 } 260 } 261 262 rb_link_node(&key->node, parent, new); 263 rb_insert_color_cached(&key->node, root, leftmost); 264 } 265 266 static struct kwork_work *work_new(struct kwork_work *key) 267 { 268 int i; 269 struct kwork_work *work = zalloc(sizeof(*work)); 270 271 if (work == NULL) { 272 pr_err("Failed to zalloc kwork work\n"); 273 return NULL; 274 } 275 276 for (i = 0; i < KWORK_TRACE_MAX; i++) 277 INIT_LIST_HEAD(&work->atom_list[i]); 278 279 work->id = key->id; 280 work->cpu = key->cpu; 281 work->name = key->name; 282 work->class = key->class; 283 return work; 284 } 285 286 static struct kwork_work *work_findnew(struct rb_root_cached *root, 287 struct kwork_work *key, 288 struct list_head *sort_list) 289 { 290 struct kwork_work *work = NULL; 291 292 work = work_search(root, key, sort_list); 293 if (work != NULL) 294 return work; 295 296 work = work_new(key); 297 if (work == NULL) 298 return NULL; 299 300 work_insert(root, work, sort_list); 301 return work; 302 } 303 304 static void profile_update_timespan(struct perf_kwork *kwork, 305 struct perf_sample *sample) 306 { 307 if (!kwork->summary) 308 return; 309 310 if ((kwork->timestart == 0) || (kwork->timestart > sample->time)) 311 kwork->timestart = sample->time; 312 313 if (kwork->timeend < sample->time) 314 kwork->timeend = sample->time; 315 } 316 317 static bool profile_event_match(struct perf_kwork *kwork, 318 struct kwork_work *work, 319 struct perf_sample *sample) 320 { 321 int cpu = work->cpu; 322 u64 time = sample->time; 323 struct perf_time_interval *ptime = &kwork->ptime; 324 325 if ((kwork->cpu_list != NULL) && !test_bit(cpu, kwork->cpu_bitmap)) 326 return false; 327 328 if (((ptime->start != 0) && (ptime->start > time)) || 329 ((ptime->end != 0) && (ptime->end < time))) 330 return false; 331 332 if ((kwork->profile_name != NULL) && 333 (work->name != NULL) && 334 (strcmp(work->name, kwork->profile_name) != 0)) 335 return false; 336 337 profile_update_timespan(kwork, sample); 338 return true; 339 } 340 341 static int work_push_atom(struct perf_kwork *kwork, 342 struct kwork_class *class, 343 enum kwork_trace_type src_type, 344 enum kwork_trace_type dst_type, 345 struct evsel *evsel, 346 struct perf_sample *sample, 347 struct machine *machine, 348 struct kwork_work **ret_work) 349 { 350 struct kwork_atom *atom, *dst_atom; 351 struct kwork_work *work, key; 352 353 BUG_ON(class->work_init == NULL); 354 class->work_init(class, &key, evsel, sample, machine); 355 356 atom = atom_new(kwork, sample); 357 if (atom == NULL) 358 return -1; 359 360 work = work_findnew(&class->work_root, &key, &kwork->cmp_id); 361 if (work == NULL) { 362 free(atom); 363 return -1; 364 } 365 366 if (!profile_event_match(kwork, work, sample)) 367 return 0; 368 369 if (dst_type < KWORK_TRACE_MAX) { 370 dst_atom = list_last_entry_or_null(&work->atom_list[dst_type], 371 struct kwork_atom, list); 372 if (dst_atom != NULL) { 373 atom->prev = dst_atom; 374 list_del(&dst_atom->list); 375 } 376 } 377 378 if (ret_work != NULL) 379 *ret_work = work; 380 381 list_add_tail(&atom->list, &work->atom_list[src_type]); 382 383 return 0; 384 } 385 386 static struct kwork_atom *work_pop_atom(struct perf_kwork *kwork, 387 struct kwork_class *class, 388 enum kwork_trace_type src_type, 389 enum kwork_trace_type dst_type, 390 struct evsel *evsel, 391 struct perf_sample *sample, 392 struct machine *machine, 393 struct kwork_work **ret_work) 394 { 395 struct kwork_atom *atom, *src_atom; 396 struct kwork_work *work, key; 397 398 BUG_ON(class->work_init == NULL); 399 class->work_init(class, &key, evsel, sample, machine); 400 401 work = work_findnew(&class->work_root, &key, &kwork->cmp_id); 402 if (ret_work != NULL) 403 *ret_work = work; 404 405 if (work == NULL) 406 return NULL; 407 408 if (!profile_event_match(kwork, work, sample)) 409 return NULL; 410 411 atom = list_last_entry_or_null(&work->atom_list[dst_type], 412 struct kwork_atom, list); 413 if (atom != NULL) 414 return atom; 415 416 src_atom = atom_new(kwork, sample); 417 if (src_atom != NULL) 418 list_add_tail(&src_atom->list, &work->atom_list[src_type]); 419 else { 420 if (ret_work != NULL) 421 *ret_work = NULL; 422 } 423 424 return NULL; 425 } 426 427 static void report_update_exit_event(struct kwork_work *work, 428 struct kwork_atom *atom, 429 struct perf_sample *sample) 430 { 431 u64 delta; 432 u64 exit_time = sample->time; 433 u64 entry_time = atom->time; 434 435 if ((entry_time != 0) && (exit_time >= entry_time)) { 436 delta = exit_time - entry_time; 437 if ((delta > work->max_runtime) || 438 (work->max_runtime == 0)) { 439 work->max_runtime = delta; 440 work->max_runtime_start = entry_time; 441 work->max_runtime_end = exit_time; 442 } 443 work->total_runtime += delta; 444 work->nr_atoms++; 445 } 446 } 447 448 static int report_entry_event(struct perf_kwork *kwork, 449 struct kwork_class *class, 450 struct evsel *evsel, 451 struct perf_sample *sample, 452 struct machine *machine) 453 { 454 return work_push_atom(kwork, class, KWORK_TRACE_ENTRY, 455 KWORK_TRACE_MAX, evsel, sample, 456 machine, NULL); 457 } 458 459 static int report_exit_event(struct perf_kwork *kwork, 460 struct kwork_class *class, 461 struct evsel *evsel, 462 struct perf_sample *sample, 463 struct machine *machine) 464 { 465 struct kwork_atom *atom = NULL; 466 struct kwork_work *work = NULL; 467 468 atom = work_pop_atom(kwork, class, KWORK_TRACE_EXIT, 469 KWORK_TRACE_ENTRY, evsel, sample, 470 machine, &work); 471 if (work == NULL) 472 return -1; 473 474 if (atom != NULL) { 475 report_update_exit_event(work, atom, sample); 476 atom_del(atom); 477 } 478 479 return 0; 480 } 481 482 static struct kwork_class kwork_irq; 483 static int process_irq_handler_entry_event(struct perf_tool *tool, 484 struct evsel *evsel, 485 struct perf_sample *sample, 486 struct machine *machine) 487 { 488 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 489 490 if (kwork->tp_handler->entry_event) 491 return kwork->tp_handler->entry_event(kwork, &kwork_irq, 492 evsel, sample, machine); 493 return 0; 494 } 495 496 static int process_irq_handler_exit_event(struct perf_tool *tool, 497 struct evsel *evsel, 498 struct perf_sample *sample, 499 struct machine *machine) 500 { 501 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 502 503 if (kwork->tp_handler->exit_event) 504 return kwork->tp_handler->exit_event(kwork, &kwork_irq, 505 evsel, sample, machine); 506 return 0; 507 } 508 509 const struct evsel_str_handler irq_tp_handlers[] = { 510 { "irq:irq_handler_entry", process_irq_handler_entry_event, }, 511 { "irq:irq_handler_exit", process_irq_handler_exit_event, }, 512 }; 513 514 static int irq_class_init(struct kwork_class *class, 515 struct perf_session *session) 516 { 517 if (perf_session__set_tracepoints_handlers(session, irq_tp_handlers)) { 518 pr_err("Failed to set irq tracepoints handlers\n"); 519 return -1; 520 } 521 522 class->work_root = RB_ROOT_CACHED; 523 return 0; 524 } 525 526 static void irq_work_init(struct kwork_class *class, 527 struct kwork_work *work, 528 struct evsel *evsel, 529 struct perf_sample *sample, 530 struct machine *machine __maybe_unused) 531 { 532 work->class = class; 533 work->cpu = sample->cpu; 534 work->id = evsel__intval(evsel, sample, "irq"); 535 work->name = evsel__strval(evsel, sample, "name"); 536 } 537 538 static void irq_work_name(struct kwork_work *work, char *buf, int len) 539 { 540 snprintf(buf, len, "%s:%" PRIu64 "", work->name, work->id); 541 } 542 543 static struct kwork_class kwork_irq = { 544 .name = "irq", 545 .type = KWORK_CLASS_IRQ, 546 .nr_tracepoints = 2, 547 .tp_handlers = irq_tp_handlers, 548 .class_init = irq_class_init, 549 .work_init = irq_work_init, 550 .work_name = irq_work_name, 551 }; 552 553 static struct kwork_class kwork_softirq; 554 static int process_softirq_entry_event(struct perf_tool *tool, 555 struct evsel *evsel, 556 struct perf_sample *sample, 557 struct machine *machine) 558 { 559 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 560 561 if (kwork->tp_handler->entry_event) 562 return kwork->tp_handler->entry_event(kwork, &kwork_softirq, 563 evsel, sample, machine); 564 565 return 0; 566 } 567 568 static int process_softirq_exit_event(struct perf_tool *tool, 569 struct evsel *evsel, 570 struct perf_sample *sample, 571 struct machine *machine) 572 { 573 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 574 575 if (kwork->tp_handler->exit_event) 576 return kwork->tp_handler->exit_event(kwork, &kwork_softirq, 577 evsel, sample, machine); 578 579 return 0; 580 } 581 582 const struct evsel_str_handler softirq_tp_handlers[] = { 583 { "irq:softirq_raise", NULL, }, 584 { "irq:softirq_entry", process_softirq_entry_event, }, 585 { "irq:softirq_exit", process_softirq_exit_event, }, 586 }; 587 588 static int softirq_class_init(struct kwork_class *class, 589 struct perf_session *session) 590 { 591 if (perf_session__set_tracepoints_handlers(session, 592 softirq_tp_handlers)) { 593 pr_err("Failed to set softirq tracepoints handlers\n"); 594 return -1; 595 } 596 597 class->work_root = RB_ROOT_CACHED; 598 return 0; 599 } 600 601 static char *evsel__softirq_name(struct evsel *evsel, u64 num) 602 { 603 char *name = NULL; 604 bool found = false; 605 struct tep_print_flag_sym *sym = NULL; 606 struct tep_print_arg *args = evsel->tp_format->print_fmt.args; 607 608 if ((args == NULL) || (args->next == NULL)) 609 return NULL; 610 611 /* skip softirq field: "REC->vec" */ 612 for (sym = args->next->symbol.symbols; sym != NULL; sym = sym->next) { 613 if ((eval_flag(sym->value) == (unsigned long long)num) && 614 (strlen(sym->str) != 0)) { 615 found = true; 616 break; 617 } 618 } 619 620 if (!found) 621 return NULL; 622 623 name = strdup(sym->str); 624 if (name == NULL) { 625 pr_err("Failed to copy symbol name\n"); 626 return NULL; 627 } 628 return name; 629 } 630 631 static void softirq_work_init(struct kwork_class *class, 632 struct kwork_work *work, 633 struct evsel *evsel, 634 struct perf_sample *sample, 635 struct machine *machine __maybe_unused) 636 { 637 u64 num = evsel__intval(evsel, sample, "vec"); 638 639 work->id = num; 640 work->class = class; 641 work->cpu = sample->cpu; 642 work->name = evsel__softirq_name(evsel, num); 643 } 644 645 static void softirq_work_name(struct kwork_work *work, char *buf, int len) 646 { 647 snprintf(buf, len, "(s)%s:%" PRIu64 "", work->name, work->id); 648 } 649 650 static struct kwork_class kwork_softirq = { 651 .name = "softirq", 652 .type = KWORK_CLASS_SOFTIRQ, 653 .nr_tracepoints = 3, 654 .tp_handlers = softirq_tp_handlers, 655 .class_init = softirq_class_init, 656 .work_init = softirq_work_init, 657 .work_name = softirq_work_name, 658 }; 659 660 static struct kwork_class kwork_workqueue; 661 static int process_workqueue_execute_start_event(struct perf_tool *tool, 662 struct evsel *evsel, 663 struct perf_sample *sample, 664 struct machine *machine) 665 { 666 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 667 668 if (kwork->tp_handler->entry_event) 669 return kwork->tp_handler->entry_event(kwork, &kwork_workqueue, 670 evsel, sample, machine); 671 672 return 0; 673 } 674 675 static int process_workqueue_execute_end_event(struct perf_tool *tool, 676 struct evsel *evsel, 677 struct perf_sample *sample, 678 struct machine *machine) 679 { 680 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 681 682 if (kwork->tp_handler->exit_event) 683 return kwork->tp_handler->exit_event(kwork, &kwork_workqueue, 684 evsel, sample, machine); 685 686 return 0; 687 } 688 689 const struct evsel_str_handler workqueue_tp_handlers[] = { 690 { "workqueue:workqueue_activate_work", NULL, }, 691 { "workqueue:workqueue_execute_start", process_workqueue_execute_start_event, }, 692 { "workqueue:workqueue_execute_end", process_workqueue_execute_end_event, }, 693 }; 694 695 static int workqueue_class_init(struct kwork_class *class, 696 struct perf_session *session) 697 { 698 if (perf_session__set_tracepoints_handlers(session, 699 workqueue_tp_handlers)) { 700 pr_err("Failed to set workqueue tracepoints handlers\n"); 701 return -1; 702 } 703 704 class->work_root = RB_ROOT_CACHED; 705 return 0; 706 } 707 708 static void workqueue_work_init(struct kwork_class *class, 709 struct kwork_work *work, 710 struct evsel *evsel, 711 struct perf_sample *sample, 712 struct machine *machine) 713 { 714 char *modp = NULL; 715 unsigned long long function_addr = evsel__intval(evsel, 716 sample, "function"); 717 718 work->class = class; 719 work->cpu = sample->cpu; 720 work->id = evsel__intval(evsel, sample, "work"); 721 work->name = function_addr == 0 ? NULL : 722 machine__resolve_kernel_addr(machine, &function_addr, &modp); 723 } 724 725 static void workqueue_work_name(struct kwork_work *work, char *buf, int len) 726 { 727 if (work->name != NULL) 728 snprintf(buf, len, "(w)%s", work->name); 729 else 730 snprintf(buf, len, "(w)0x%" PRIx64, work->id); 731 } 732 733 static struct kwork_class kwork_workqueue = { 734 .name = "workqueue", 735 .type = KWORK_CLASS_WORKQUEUE, 736 .nr_tracepoints = 3, 737 .tp_handlers = workqueue_tp_handlers, 738 .class_init = workqueue_class_init, 739 .work_init = workqueue_work_init, 740 .work_name = workqueue_work_name, 741 }; 742 743 static struct kwork_class *kwork_class_supported_list[KWORK_CLASS_MAX] = { 744 [KWORK_CLASS_IRQ] = &kwork_irq, 745 [KWORK_CLASS_SOFTIRQ] = &kwork_softirq, 746 [KWORK_CLASS_WORKQUEUE] = &kwork_workqueue, 747 }; 748 749 static void print_separator(int len) 750 { 751 printf(" %.*s\n", len, graph_dotted_line); 752 } 753 754 static int report_print_work(struct perf_kwork *kwork, struct kwork_work *work) 755 { 756 int ret = 0; 757 char kwork_name[PRINT_KWORK_NAME_WIDTH]; 758 char max_runtime_start[32], max_runtime_end[32]; 759 760 printf(" "); 761 762 /* 763 * kwork name 764 */ 765 if (work->class && work->class->work_name) { 766 work->class->work_name(work, kwork_name, 767 PRINT_KWORK_NAME_WIDTH); 768 ret += printf(" %-*s |", PRINT_KWORK_NAME_WIDTH, kwork_name); 769 } else { 770 ret += printf(" %-*s |", PRINT_KWORK_NAME_WIDTH, ""); 771 } 772 773 /* 774 * cpu 775 */ 776 ret += printf(" %0*d |", PRINT_CPU_WIDTH, work->cpu); 777 778 /* 779 * total runtime 780 */ 781 if (kwork->report == KWORK_REPORT_RUNTIME) { 782 ret += printf(" %*.*f ms |", 783 PRINT_RUNTIME_WIDTH, RPINT_DECIMAL_WIDTH, 784 (double)work->total_runtime / NSEC_PER_MSEC); 785 } 786 787 /* 788 * count 789 */ 790 ret += printf(" %*" PRIu64 " |", PRINT_COUNT_WIDTH, work->nr_atoms); 791 792 /* 793 * max runtime, max runtime start, max runtime end 794 */ 795 if (kwork->report == KWORK_REPORT_RUNTIME) { 796 timestamp__scnprintf_usec(work->max_runtime_start, 797 max_runtime_start, 798 sizeof(max_runtime_start)); 799 timestamp__scnprintf_usec(work->max_runtime_end, 800 max_runtime_end, 801 sizeof(max_runtime_end)); 802 ret += printf(" %*.*f ms | %*s s | %*s s |", 803 PRINT_RUNTIME_WIDTH, RPINT_DECIMAL_WIDTH, 804 (double)work->max_runtime / NSEC_PER_MSEC, 805 PRINT_TIMESTAMP_WIDTH, max_runtime_start, 806 PRINT_TIMESTAMP_WIDTH, max_runtime_end); 807 } 808 809 printf("\n"); 810 return ret; 811 } 812 813 static int report_print_header(struct perf_kwork *kwork) 814 { 815 int ret; 816 817 printf("\n "); 818 ret = printf(" %-*s | %-*s |", 819 PRINT_KWORK_NAME_WIDTH, "Kwork Name", 820 PRINT_CPU_WIDTH, "Cpu"); 821 822 if (kwork->report == KWORK_REPORT_RUNTIME) { 823 ret += printf(" %-*s |", 824 PRINT_RUNTIME_HEADER_WIDTH, "Total Runtime"); 825 } 826 827 ret += printf(" %-*s |", PRINT_COUNT_WIDTH, "Count"); 828 829 if (kwork->report == KWORK_REPORT_RUNTIME) { 830 ret += printf(" %-*s | %-*s | %-*s |", 831 PRINT_RUNTIME_HEADER_WIDTH, "Max runtime", 832 PRINT_TIMESTAMP_HEADER_WIDTH, "Max runtime start", 833 PRINT_TIMESTAMP_HEADER_WIDTH, "Max runtime end"); 834 } 835 836 printf("\n"); 837 print_separator(ret); 838 return ret; 839 } 840 841 static void print_summary(struct perf_kwork *kwork) 842 { 843 u64 time = kwork->timeend - kwork->timestart; 844 845 printf(" Total count : %9" PRIu64 "\n", kwork->all_count); 846 printf(" Total runtime (msec) : %9.3f (%.3f%% load average)\n", 847 (double)kwork->all_runtime / NSEC_PER_MSEC, 848 time == 0 ? 0 : (double)kwork->all_runtime / time); 849 printf(" Total time span (msec) : %9.3f\n", 850 (double)time / NSEC_PER_MSEC); 851 } 852 853 static unsigned long long nr_list_entry(struct list_head *head) 854 { 855 struct list_head *pos; 856 unsigned long long n = 0; 857 858 list_for_each(pos, head) 859 n++; 860 861 return n; 862 } 863 864 static void print_skipped_events(struct perf_kwork *kwork) 865 { 866 int i; 867 const char *const kwork_event_str[] = { 868 [KWORK_TRACE_ENTRY] = "entry", 869 [KWORK_TRACE_EXIT] = "exit", 870 }; 871 872 if ((kwork->nr_skipped_events[KWORK_TRACE_MAX] != 0) && 873 (kwork->nr_events != 0)) { 874 printf(" INFO: %.3f%% skipped events (%" PRIu64 " including ", 875 (double)kwork->nr_skipped_events[KWORK_TRACE_MAX] / 876 (double)kwork->nr_events * 100.0, 877 kwork->nr_skipped_events[KWORK_TRACE_MAX]); 878 879 for (i = 0; i < KWORK_TRACE_MAX; i++) { 880 printf("%" PRIu64 " %s%s", 881 kwork->nr_skipped_events[i], 882 kwork_event_str[i], 883 (i == KWORK_TRACE_MAX - 1) ? ")\n" : ", "); 884 } 885 } 886 887 if (verbose > 0) 888 printf(" INFO: use %lld atom pages\n", 889 nr_list_entry(&kwork->atom_page_list)); 890 } 891 892 static void print_bad_events(struct perf_kwork *kwork) 893 { 894 if ((kwork->nr_lost_events != 0) && (kwork->nr_events != 0)) { 895 printf(" INFO: %.3f%% lost events (%ld out of %ld, in %ld chunks)\n", 896 (double)kwork->nr_lost_events / 897 (double)kwork->nr_events * 100.0, 898 kwork->nr_lost_events, kwork->nr_events, 899 kwork->nr_lost_chunks); 900 } 901 } 902 903 static void work_sort(struct perf_kwork *kwork, struct kwork_class *class) 904 { 905 struct rb_node *node; 906 struct kwork_work *data; 907 struct rb_root_cached *root = &class->work_root; 908 909 pr_debug("Sorting %s ...\n", class->name); 910 for (;;) { 911 node = rb_first_cached(root); 912 if (!node) 913 break; 914 915 rb_erase_cached(node, root); 916 data = rb_entry(node, struct kwork_work, node); 917 work_insert(&kwork->sorted_work_root, 918 data, &kwork->sort_list); 919 } 920 } 921 922 static void perf_kwork__sort(struct perf_kwork *kwork) 923 { 924 struct kwork_class *class; 925 926 list_for_each_entry(class, &kwork->class_list, list) 927 work_sort(kwork, class); 928 } 929 930 static int perf_kwork__check_config(struct perf_kwork *kwork, 931 struct perf_session *session) 932 { 933 int ret; 934 struct kwork_class *class; 935 936 static struct trace_kwork_handler report_ops = { 937 .entry_event = report_entry_event, 938 .exit_event = report_exit_event, 939 }; 940 941 switch (kwork->report) { 942 case KWORK_REPORT_RUNTIME: 943 kwork->tp_handler = &report_ops; 944 break; 945 default: 946 pr_debug("Invalid report type %d\n", kwork->report); 947 return -1; 948 } 949 950 list_for_each_entry(class, &kwork->class_list, list) 951 if ((class->class_init != NULL) && 952 (class->class_init(class, session) != 0)) 953 return -1; 954 955 if (kwork->cpu_list != NULL) { 956 ret = perf_session__cpu_bitmap(session, 957 kwork->cpu_list, 958 kwork->cpu_bitmap); 959 if (ret < 0) { 960 pr_err("Invalid cpu bitmap\n"); 961 return -1; 962 } 963 } 964 965 if (kwork->time_str != NULL) { 966 ret = perf_time__parse_str(&kwork->ptime, kwork->time_str); 967 if (ret != 0) { 968 pr_err("Invalid time span\n"); 969 return -1; 970 } 971 } 972 973 return 0; 974 } 975 976 static int perf_kwork__read_events(struct perf_kwork *kwork) 977 { 978 int ret = -1; 979 struct perf_session *session = NULL; 980 981 struct perf_data data = { 982 .path = input_name, 983 .mode = PERF_DATA_MODE_READ, 984 .force = kwork->force, 985 }; 986 987 session = perf_session__new(&data, &kwork->tool); 988 if (IS_ERR(session)) { 989 pr_debug("Error creating perf session\n"); 990 return PTR_ERR(session); 991 } 992 993 symbol__init(&session->header.env); 994 995 if (perf_kwork__check_config(kwork, session) != 0) 996 goto out_delete; 997 998 if (session->tevent.pevent && 999 tep_set_function_resolver(session->tevent.pevent, 1000 machine__resolve_kernel_addr, 1001 &session->machines.host) < 0) { 1002 pr_err("Failed to set libtraceevent function resolver\n"); 1003 goto out_delete; 1004 } 1005 1006 ret = perf_session__process_events(session); 1007 if (ret) { 1008 pr_debug("Failed to process events, error %d\n", ret); 1009 goto out_delete; 1010 } 1011 1012 kwork->nr_events = session->evlist->stats.nr_events[0]; 1013 kwork->nr_lost_events = session->evlist->stats.total_lost; 1014 kwork->nr_lost_chunks = session->evlist->stats.nr_events[PERF_RECORD_LOST]; 1015 1016 out_delete: 1017 perf_session__delete(session); 1018 return ret; 1019 } 1020 1021 static void process_skipped_events(struct perf_kwork *kwork, 1022 struct kwork_work *work) 1023 { 1024 int i; 1025 unsigned long long count; 1026 1027 for (i = 0; i < KWORK_TRACE_MAX; i++) { 1028 count = nr_list_entry(&work->atom_list[i]); 1029 kwork->nr_skipped_events[i] += count; 1030 kwork->nr_skipped_events[KWORK_TRACE_MAX] += count; 1031 } 1032 } 1033 1034 static int perf_kwork__report(struct perf_kwork *kwork) 1035 { 1036 int ret; 1037 struct rb_node *next; 1038 struct kwork_work *work; 1039 1040 ret = perf_kwork__read_events(kwork); 1041 if (ret != 0) 1042 return -1; 1043 1044 perf_kwork__sort(kwork); 1045 1046 setup_pager(); 1047 1048 ret = report_print_header(kwork); 1049 next = rb_first_cached(&kwork->sorted_work_root); 1050 while (next) { 1051 work = rb_entry(next, struct kwork_work, node); 1052 process_skipped_events(kwork, work); 1053 1054 if (work->nr_atoms != 0) { 1055 report_print_work(kwork, work); 1056 if (kwork->summary) { 1057 kwork->all_runtime += work->total_runtime; 1058 kwork->all_count += work->nr_atoms; 1059 } 1060 } 1061 next = rb_next(next); 1062 } 1063 print_separator(ret); 1064 1065 if (kwork->summary) { 1066 print_summary(kwork); 1067 print_separator(ret); 1068 } 1069 1070 print_bad_events(kwork); 1071 print_skipped_events(kwork); 1072 printf("\n"); 1073 1074 return 0; 1075 } 1076 1077 typedef int (*tracepoint_handler)(struct perf_tool *tool, 1078 struct evsel *evsel, 1079 struct perf_sample *sample, 1080 struct machine *machine); 1081 1082 static int perf_kwork__process_tracepoint_sample(struct perf_tool *tool, 1083 union perf_event *event __maybe_unused, 1084 struct perf_sample *sample, 1085 struct evsel *evsel, 1086 struct machine *machine) 1087 { 1088 int err = 0; 1089 1090 if (evsel->handler != NULL) { 1091 tracepoint_handler f = evsel->handler; 1092 1093 err = f(tool, evsel, sample, machine); 1094 } 1095 1096 return err; 1097 } 1098 1099 static void setup_event_list(struct perf_kwork *kwork, 1100 const struct option *options, 1101 const char * const usage_msg[]) 1102 { 1103 int i; 1104 struct kwork_class *class; 1105 char *tmp, *tok, *str; 1106 1107 if (kwork->event_list_str == NULL) 1108 goto null_event_list_str; 1109 1110 str = strdup(kwork->event_list_str); 1111 for (tok = strtok_r(str, ", ", &tmp); 1112 tok; tok = strtok_r(NULL, ", ", &tmp)) { 1113 for (i = 0; i < KWORK_CLASS_MAX; i++) { 1114 class = kwork_class_supported_list[i]; 1115 if (strcmp(tok, class->name) == 0) { 1116 list_add_tail(&class->list, &kwork->class_list); 1117 break; 1118 } 1119 } 1120 if (i == KWORK_CLASS_MAX) { 1121 usage_with_options_msg(usage_msg, options, 1122 "Unknown --event key: `%s'", tok); 1123 } 1124 } 1125 free(str); 1126 1127 null_event_list_str: 1128 /* 1129 * config all kwork events if not specified 1130 */ 1131 if (list_empty(&kwork->class_list)) { 1132 for (i = 0; i < KWORK_CLASS_MAX; i++) { 1133 list_add_tail(&kwork_class_supported_list[i]->list, 1134 &kwork->class_list); 1135 } 1136 } 1137 1138 pr_debug("Config event list:"); 1139 list_for_each_entry(class, &kwork->class_list, list) 1140 pr_debug(" %s", class->name); 1141 pr_debug("\n"); 1142 } 1143 1144 static int perf_kwork__record(struct perf_kwork *kwork, 1145 int argc, const char **argv) 1146 { 1147 const char **rec_argv; 1148 unsigned int rec_argc, i, j; 1149 struct kwork_class *class; 1150 1151 const char *const record_args[] = { 1152 "record", 1153 "-a", 1154 "-R", 1155 "-m", "1024", 1156 "-c", "1", 1157 }; 1158 1159 rec_argc = ARRAY_SIZE(record_args) + argc - 1; 1160 1161 list_for_each_entry(class, &kwork->class_list, list) 1162 rec_argc += 2 * class->nr_tracepoints; 1163 1164 rec_argv = calloc(rec_argc + 1, sizeof(char *)); 1165 if (rec_argv == NULL) 1166 return -ENOMEM; 1167 1168 for (i = 0; i < ARRAY_SIZE(record_args); i++) 1169 rec_argv[i] = strdup(record_args[i]); 1170 1171 list_for_each_entry(class, &kwork->class_list, list) { 1172 for (j = 0; j < class->nr_tracepoints; j++) { 1173 rec_argv[i++] = strdup("-e"); 1174 rec_argv[i++] = strdup(class->tp_handlers[j].name); 1175 } 1176 } 1177 1178 for (j = 1; j < (unsigned int)argc; j++, i++) 1179 rec_argv[i] = argv[j]; 1180 1181 BUG_ON(i != rec_argc); 1182 1183 pr_debug("record comm: "); 1184 for (j = 0; j < rec_argc; j++) 1185 pr_debug("%s ", rec_argv[j]); 1186 pr_debug("\n"); 1187 1188 return cmd_record(i, rec_argv); 1189 } 1190 1191 int cmd_kwork(int argc, const char **argv) 1192 { 1193 static struct perf_kwork kwork = { 1194 .class_list = LIST_HEAD_INIT(kwork.class_list), 1195 .tool = { 1196 .mmap = perf_event__process_mmap, 1197 .mmap2 = perf_event__process_mmap2, 1198 .sample = perf_kwork__process_tracepoint_sample, 1199 }, 1200 .atom_page_list = LIST_HEAD_INIT(kwork.atom_page_list), 1201 .sort_list = LIST_HEAD_INIT(kwork.sort_list), 1202 .cmp_id = LIST_HEAD_INIT(kwork.cmp_id), 1203 .sorted_work_root = RB_ROOT_CACHED, 1204 .tp_handler = NULL, 1205 .profile_name = NULL, 1206 .cpu_list = NULL, 1207 .time_str = NULL, 1208 .force = false, 1209 .event_list_str = NULL, 1210 .summary = false, 1211 .sort_order = NULL, 1212 .timestart = 0, 1213 .timeend = 0, 1214 .nr_events = 0, 1215 .nr_lost_chunks = 0, 1216 .nr_lost_events = 0, 1217 .all_runtime = 0, 1218 .all_count = 0, 1219 .nr_skipped_events = { 0 }, 1220 }; 1221 static const char default_report_sort_order[] = "runtime, max, count"; 1222 const struct option kwork_options[] = { 1223 OPT_INCR('v', "verbose", &verbose, 1224 "be more verbose (show symbol address, etc)"), 1225 OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace, 1226 "dump raw trace in ASCII"), 1227 OPT_STRING('k', "kwork", &kwork.event_list_str, "kwork", 1228 "list of kwork to profile (irq, softirq, workqueue, etc)"), 1229 OPT_BOOLEAN('f', "force", &kwork.force, "don't complain, do it"), 1230 OPT_END() 1231 }; 1232 const struct option report_options[] = { 1233 OPT_STRING('s', "sort", &kwork.sort_order, "key[,key2...]", 1234 "sort by key(s): runtime, max, count"), 1235 OPT_STRING('C', "cpu", &kwork.cpu_list, "cpu", 1236 "list of cpus to profile"), 1237 OPT_STRING('n', "name", &kwork.profile_name, "name", 1238 "event name to profile"), 1239 OPT_STRING(0, "time", &kwork.time_str, "str", 1240 "Time span for analysis (start,stop)"), 1241 OPT_STRING('i', "input", &input_name, "file", 1242 "input file name"), 1243 OPT_BOOLEAN('S', "with-summary", &kwork.summary, 1244 "Show summary with statistics"), 1245 OPT_PARENT(kwork_options) 1246 }; 1247 const char *kwork_usage[] = { 1248 NULL, 1249 NULL 1250 }; 1251 const char * const report_usage[] = { 1252 "perf kwork report [<options>]", 1253 NULL 1254 }; 1255 const char *const kwork_subcommands[] = { 1256 "record", "report", NULL 1257 }; 1258 1259 argc = parse_options_subcommand(argc, argv, kwork_options, 1260 kwork_subcommands, kwork_usage, 1261 PARSE_OPT_STOP_AT_NON_OPTION); 1262 if (!argc) 1263 usage_with_options(kwork_usage, kwork_options); 1264 1265 setup_event_list(&kwork, kwork_options, kwork_usage); 1266 sort_dimension__add(&kwork, "id", &kwork.cmp_id); 1267 1268 if (strlen(argv[0]) > 2 && strstarts("record", argv[0])) 1269 return perf_kwork__record(&kwork, argc, argv); 1270 else if (strlen(argv[0]) > 2 && strstarts("report", argv[0])) { 1271 kwork.sort_order = default_report_sort_order; 1272 if (argc > 1) { 1273 argc = parse_options(argc, argv, report_options, report_usage, 0); 1274 if (argc) 1275 usage_with_options(report_usage, report_options); 1276 } 1277 kwork.report = KWORK_REPORT_RUNTIME; 1278 setup_sorting(&kwork, report_options, report_usage); 1279 return perf_kwork__report(&kwork); 1280 } else 1281 usage_with_options(kwork_usage, kwork_options); 1282 1283 return 0; 1284 } 1285