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_LATENCY_WIDTH 10
35 #define PRINT_TIMESTAMP_WIDTH 17
36 #define PRINT_KWORK_NAME_WIDTH 30
37 #define RPINT_DECIMAL_WIDTH 3
38 #define PRINT_BRACKETPAIR_WIDTH 2
39 #define PRINT_TIME_UNIT_SEC_WIDTH 2
40 #define PRINT_TIME_UNIT_MESC_WIDTH 3
41 #define PRINT_RUNTIME_HEADER_WIDTH (PRINT_RUNTIME_WIDTH + PRINT_TIME_UNIT_MESC_WIDTH)
42 #define PRINT_LATENCY_HEADER_WIDTH (PRINT_LATENCY_WIDTH + PRINT_TIME_UNIT_MESC_WIDTH)
43 #define PRINT_TIMEHIST_CPU_WIDTH (PRINT_CPU_WIDTH + PRINT_BRACKETPAIR_WIDTH)
44 #define PRINT_TIMESTAMP_HEADER_WIDTH (PRINT_TIMESTAMP_WIDTH + PRINT_TIME_UNIT_SEC_WIDTH)
45
46 struct sort_dimension {
47 const char *name;
48 int (*cmp)(struct kwork_work *l, struct kwork_work *r);
49 struct list_head list;
50 };
51
id_cmp(struct kwork_work * l,struct kwork_work * r)52 static int id_cmp(struct kwork_work *l, struct kwork_work *r)
53 {
54 if (l->cpu > r->cpu)
55 return 1;
56 if (l->cpu < r->cpu)
57 return -1;
58
59 if (l->id > r->id)
60 return 1;
61 if (l->id < r->id)
62 return -1;
63
64 return 0;
65 }
66
count_cmp(struct kwork_work * l,struct kwork_work * r)67 static int count_cmp(struct kwork_work *l, struct kwork_work *r)
68 {
69 if (l->nr_atoms > r->nr_atoms)
70 return 1;
71 if (l->nr_atoms < r->nr_atoms)
72 return -1;
73
74 return 0;
75 }
76
runtime_cmp(struct kwork_work * l,struct kwork_work * r)77 static int runtime_cmp(struct kwork_work *l, struct kwork_work *r)
78 {
79 if (l->total_runtime > r->total_runtime)
80 return 1;
81 if (l->total_runtime < r->total_runtime)
82 return -1;
83
84 return 0;
85 }
86
max_runtime_cmp(struct kwork_work * l,struct kwork_work * r)87 static int max_runtime_cmp(struct kwork_work *l, struct kwork_work *r)
88 {
89 if (l->max_runtime > r->max_runtime)
90 return 1;
91 if (l->max_runtime < r->max_runtime)
92 return -1;
93
94 return 0;
95 }
96
avg_latency_cmp(struct kwork_work * l,struct kwork_work * r)97 static int avg_latency_cmp(struct kwork_work *l, struct kwork_work *r)
98 {
99 u64 avgl, avgr;
100
101 if (!r->nr_atoms)
102 return 1;
103 if (!l->nr_atoms)
104 return -1;
105
106 avgl = l->total_latency / l->nr_atoms;
107 avgr = r->total_latency / r->nr_atoms;
108
109 if (avgl > avgr)
110 return 1;
111 if (avgl < avgr)
112 return -1;
113
114 return 0;
115 }
116
max_latency_cmp(struct kwork_work * l,struct kwork_work * r)117 static int max_latency_cmp(struct kwork_work *l, struct kwork_work *r)
118 {
119 if (l->max_latency > r->max_latency)
120 return 1;
121 if (l->max_latency < r->max_latency)
122 return -1;
123
124 return 0;
125 }
126
sort_dimension__add(struct perf_kwork * kwork __maybe_unused,const char * tok,struct list_head * list)127 static int sort_dimension__add(struct perf_kwork *kwork __maybe_unused,
128 const char *tok, struct list_head *list)
129 {
130 size_t i;
131 static struct sort_dimension max_sort_dimension = {
132 .name = "max",
133 .cmp = max_runtime_cmp,
134 };
135 static struct sort_dimension id_sort_dimension = {
136 .name = "id",
137 .cmp = id_cmp,
138 };
139 static struct sort_dimension runtime_sort_dimension = {
140 .name = "runtime",
141 .cmp = runtime_cmp,
142 };
143 static struct sort_dimension count_sort_dimension = {
144 .name = "count",
145 .cmp = count_cmp,
146 };
147 static struct sort_dimension avg_sort_dimension = {
148 .name = "avg",
149 .cmp = avg_latency_cmp,
150 };
151 struct sort_dimension *available_sorts[] = {
152 &id_sort_dimension,
153 &max_sort_dimension,
154 &count_sort_dimension,
155 &runtime_sort_dimension,
156 &avg_sort_dimension,
157 };
158
159 if (kwork->report == KWORK_REPORT_LATENCY)
160 max_sort_dimension.cmp = max_latency_cmp;
161
162 for (i = 0; i < ARRAY_SIZE(available_sorts); i++) {
163 if (!strcmp(available_sorts[i]->name, tok)) {
164 list_add_tail(&available_sorts[i]->list, list);
165 return 0;
166 }
167 }
168
169 return -1;
170 }
171
setup_sorting(struct perf_kwork * kwork,const struct option * options,const char * const usage_msg[])172 static void setup_sorting(struct perf_kwork *kwork,
173 const struct option *options,
174 const char * const usage_msg[])
175 {
176 char *tmp, *tok, *str = strdup(kwork->sort_order);
177
178 for (tok = strtok_r(str, ", ", &tmp);
179 tok; tok = strtok_r(NULL, ", ", &tmp)) {
180 if (sort_dimension__add(kwork, tok, &kwork->sort_list) < 0)
181 usage_with_options_msg(usage_msg, options,
182 "Unknown --sort key: `%s'", tok);
183 }
184
185 pr_debug("Sort order: %s\n", kwork->sort_order);
186 free(str);
187 }
188
atom_new(struct perf_kwork * kwork,struct perf_sample * sample)189 static struct kwork_atom *atom_new(struct perf_kwork *kwork,
190 struct perf_sample *sample)
191 {
192 unsigned long i;
193 struct kwork_atom_page *page;
194 struct kwork_atom *atom = NULL;
195
196 list_for_each_entry(page, &kwork->atom_page_list, list) {
197 if (!bitmap_full(page->bitmap, NR_ATOM_PER_PAGE)) {
198 i = find_first_zero_bit(page->bitmap, NR_ATOM_PER_PAGE);
199 BUG_ON(i >= NR_ATOM_PER_PAGE);
200 atom = &page->atoms[i];
201 goto found_atom;
202 }
203 }
204
205 /*
206 * new page
207 */
208 page = zalloc(sizeof(*page));
209 if (page == NULL) {
210 pr_err("Failed to zalloc kwork atom page\n");
211 return NULL;
212 }
213
214 i = 0;
215 atom = &page->atoms[0];
216 list_add_tail(&page->list, &kwork->atom_page_list);
217
218 found_atom:
219 set_bit(i, page->bitmap);
220 atom->time = sample->time;
221 atom->prev = NULL;
222 atom->page_addr = page;
223 atom->bit_inpage = i;
224 return atom;
225 }
226
atom_free(struct kwork_atom * atom)227 static void atom_free(struct kwork_atom *atom)
228 {
229 if (atom->prev != NULL)
230 atom_free(atom->prev);
231
232 clear_bit(atom->bit_inpage,
233 ((struct kwork_atom_page *)atom->page_addr)->bitmap);
234 }
235
atom_del(struct kwork_atom * atom)236 static void atom_del(struct kwork_atom *atom)
237 {
238 list_del(&atom->list);
239 atom_free(atom);
240 }
241
work_cmp(struct list_head * list,struct kwork_work * l,struct kwork_work * r)242 static int work_cmp(struct list_head *list,
243 struct kwork_work *l, struct kwork_work *r)
244 {
245 int ret = 0;
246 struct sort_dimension *sort;
247
248 BUG_ON(list_empty(list));
249
250 list_for_each_entry(sort, list, list) {
251 ret = sort->cmp(l, r);
252 if (ret)
253 return ret;
254 }
255
256 return ret;
257 }
258
work_search(struct rb_root_cached * root,struct kwork_work * key,struct list_head * sort_list)259 static struct kwork_work *work_search(struct rb_root_cached *root,
260 struct kwork_work *key,
261 struct list_head *sort_list)
262 {
263 int cmp;
264 struct kwork_work *work;
265 struct rb_node *node = root->rb_root.rb_node;
266
267 while (node) {
268 work = container_of(node, struct kwork_work, node);
269 cmp = work_cmp(sort_list, key, work);
270 if (cmp > 0)
271 node = node->rb_left;
272 else if (cmp < 0)
273 node = node->rb_right;
274 else {
275 if (work->name == NULL)
276 work->name = key->name;
277 return work;
278 }
279 }
280 return NULL;
281 }
282
work_insert(struct rb_root_cached * root,struct kwork_work * key,struct list_head * sort_list)283 static void work_insert(struct rb_root_cached *root,
284 struct kwork_work *key, struct list_head *sort_list)
285 {
286 int cmp;
287 bool leftmost = true;
288 struct kwork_work *cur;
289 struct rb_node **new = &(root->rb_root.rb_node), *parent = NULL;
290
291 while (*new) {
292 cur = container_of(*new, struct kwork_work, node);
293 parent = *new;
294 cmp = work_cmp(sort_list, key, cur);
295
296 if (cmp > 0)
297 new = &((*new)->rb_left);
298 else {
299 new = &((*new)->rb_right);
300 leftmost = false;
301 }
302 }
303
304 rb_link_node(&key->node, parent, new);
305 rb_insert_color_cached(&key->node, root, leftmost);
306 }
307
work_new(struct kwork_work * key)308 static struct kwork_work *work_new(struct kwork_work *key)
309 {
310 int i;
311 struct kwork_work *work = zalloc(sizeof(*work));
312
313 if (work == NULL) {
314 pr_err("Failed to zalloc kwork work\n");
315 return NULL;
316 }
317
318 for (i = 0; i < KWORK_TRACE_MAX; i++)
319 INIT_LIST_HEAD(&work->atom_list[i]);
320
321 work->id = key->id;
322 work->cpu = key->cpu;
323 work->name = key->name;
324 work->class = key->class;
325 return work;
326 }
327
work_findnew(struct rb_root_cached * root,struct kwork_work * key,struct list_head * sort_list)328 static struct kwork_work *work_findnew(struct rb_root_cached *root,
329 struct kwork_work *key,
330 struct list_head *sort_list)
331 {
332 struct kwork_work *work = work_search(root, key, sort_list);
333
334 if (work != NULL)
335 return work;
336
337 work = work_new(key);
338 if (work)
339 work_insert(root, work, sort_list);
340
341 return work;
342 }
343
profile_update_timespan(struct perf_kwork * kwork,struct perf_sample * sample)344 static void profile_update_timespan(struct perf_kwork *kwork,
345 struct perf_sample *sample)
346 {
347 if (!kwork->summary)
348 return;
349
350 if ((kwork->timestart == 0) || (kwork->timestart > sample->time))
351 kwork->timestart = sample->time;
352
353 if (kwork->timeend < sample->time)
354 kwork->timeend = sample->time;
355 }
356
profile_event_match(struct perf_kwork * kwork,struct kwork_work * work,struct perf_sample * sample)357 static bool profile_event_match(struct perf_kwork *kwork,
358 struct kwork_work *work,
359 struct perf_sample *sample)
360 {
361 int cpu = work->cpu;
362 u64 time = sample->time;
363 struct perf_time_interval *ptime = &kwork->ptime;
364
365 if ((kwork->cpu_list != NULL) && !test_bit(cpu, kwork->cpu_bitmap))
366 return false;
367
368 if (((ptime->start != 0) && (ptime->start > time)) ||
369 ((ptime->end != 0) && (ptime->end < time)))
370 return false;
371
372 if ((kwork->profile_name != NULL) &&
373 (work->name != NULL) &&
374 (strcmp(work->name, kwork->profile_name) != 0))
375 return false;
376
377 profile_update_timespan(kwork, sample);
378 return true;
379 }
380
work_push_atom(struct perf_kwork * kwork,struct kwork_class * class,enum kwork_trace_type src_type,enum kwork_trace_type dst_type,struct evsel * evsel,struct perf_sample * sample,struct machine * machine,struct kwork_work ** ret_work)381 static int work_push_atom(struct perf_kwork *kwork,
382 struct kwork_class *class,
383 enum kwork_trace_type src_type,
384 enum kwork_trace_type dst_type,
385 struct evsel *evsel,
386 struct perf_sample *sample,
387 struct machine *machine,
388 struct kwork_work **ret_work)
389 {
390 struct kwork_atom *atom, *dst_atom;
391 struct kwork_work *work, key;
392
393 BUG_ON(class->work_init == NULL);
394 class->work_init(class, &key, evsel, sample, machine);
395
396 atom = atom_new(kwork, sample);
397 if (atom == NULL)
398 return -1;
399
400 work = work_findnew(&class->work_root, &key, &kwork->cmp_id);
401 if (work == NULL) {
402 free(atom);
403 return -1;
404 }
405
406 if (!profile_event_match(kwork, work, sample))
407 return 0;
408
409 if (dst_type < KWORK_TRACE_MAX) {
410 dst_atom = list_last_entry_or_null(&work->atom_list[dst_type],
411 struct kwork_atom, list);
412 if (dst_atom != NULL) {
413 atom->prev = dst_atom;
414 list_del(&dst_atom->list);
415 }
416 }
417
418 if (ret_work != NULL)
419 *ret_work = work;
420
421 list_add_tail(&atom->list, &work->atom_list[src_type]);
422
423 return 0;
424 }
425
work_pop_atom(struct perf_kwork * kwork,struct kwork_class * class,enum kwork_trace_type src_type,enum kwork_trace_type dst_type,struct evsel * evsel,struct perf_sample * sample,struct machine * machine,struct kwork_work ** ret_work)426 static struct kwork_atom *work_pop_atom(struct perf_kwork *kwork,
427 struct kwork_class *class,
428 enum kwork_trace_type src_type,
429 enum kwork_trace_type dst_type,
430 struct evsel *evsel,
431 struct perf_sample *sample,
432 struct machine *machine,
433 struct kwork_work **ret_work)
434 {
435 struct kwork_atom *atom, *src_atom;
436 struct kwork_work *work, key;
437
438 BUG_ON(class->work_init == NULL);
439 class->work_init(class, &key, evsel, sample, machine);
440
441 work = work_findnew(&class->work_root, &key, &kwork->cmp_id);
442 if (ret_work != NULL)
443 *ret_work = work;
444
445 if (work == NULL)
446 return NULL;
447
448 if (!profile_event_match(kwork, work, sample))
449 return NULL;
450
451 atom = list_last_entry_or_null(&work->atom_list[dst_type],
452 struct kwork_atom, list);
453 if (atom != NULL)
454 return atom;
455
456 src_atom = atom_new(kwork, sample);
457 if (src_atom != NULL)
458 list_add_tail(&src_atom->list, &work->atom_list[src_type]);
459 else {
460 if (ret_work != NULL)
461 *ret_work = NULL;
462 }
463
464 return NULL;
465 }
466
report_update_exit_event(struct kwork_work * work,struct kwork_atom * atom,struct perf_sample * sample)467 static void report_update_exit_event(struct kwork_work *work,
468 struct kwork_atom *atom,
469 struct perf_sample *sample)
470 {
471 u64 delta;
472 u64 exit_time = sample->time;
473 u64 entry_time = atom->time;
474
475 if ((entry_time != 0) && (exit_time >= entry_time)) {
476 delta = exit_time - entry_time;
477 if ((delta > work->max_runtime) ||
478 (work->max_runtime == 0)) {
479 work->max_runtime = delta;
480 work->max_runtime_start = entry_time;
481 work->max_runtime_end = exit_time;
482 }
483 work->total_runtime += delta;
484 work->nr_atoms++;
485 }
486 }
487
report_entry_event(struct perf_kwork * kwork,struct kwork_class * class,struct evsel * evsel,struct perf_sample * sample,struct machine * machine)488 static int report_entry_event(struct perf_kwork *kwork,
489 struct kwork_class *class,
490 struct evsel *evsel,
491 struct perf_sample *sample,
492 struct machine *machine)
493 {
494 return work_push_atom(kwork, class, KWORK_TRACE_ENTRY,
495 KWORK_TRACE_MAX, evsel, sample,
496 machine, NULL);
497 }
498
report_exit_event(struct perf_kwork * kwork,struct kwork_class * class,struct evsel * evsel,struct perf_sample * sample,struct machine * machine)499 static int report_exit_event(struct perf_kwork *kwork,
500 struct kwork_class *class,
501 struct evsel *evsel,
502 struct perf_sample *sample,
503 struct machine *machine)
504 {
505 struct kwork_atom *atom = NULL;
506 struct kwork_work *work = NULL;
507
508 atom = work_pop_atom(kwork, class, KWORK_TRACE_EXIT,
509 KWORK_TRACE_ENTRY, evsel, sample,
510 machine, &work);
511 if (work == NULL)
512 return -1;
513
514 if (atom != NULL) {
515 report_update_exit_event(work, atom, sample);
516 atom_del(atom);
517 }
518
519 return 0;
520 }
521
latency_update_entry_event(struct kwork_work * work,struct kwork_atom * atom,struct perf_sample * sample)522 static void latency_update_entry_event(struct kwork_work *work,
523 struct kwork_atom *atom,
524 struct perf_sample *sample)
525 {
526 u64 delta;
527 u64 entry_time = sample->time;
528 u64 raise_time = atom->time;
529
530 if ((raise_time != 0) && (entry_time >= raise_time)) {
531 delta = entry_time - raise_time;
532 if ((delta > work->max_latency) ||
533 (work->max_latency == 0)) {
534 work->max_latency = delta;
535 work->max_latency_start = raise_time;
536 work->max_latency_end = entry_time;
537 }
538 work->total_latency += delta;
539 work->nr_atoms++;
540 }
541 }
542
latency_raise_event(struct perf_kwork * kwork,struct kwork_class * class,struct evsel * evsel,struct perf_sample * sample,struct machine * machine)543 static int latency_raise_event(struct perf_kwork *kwork,
544 struct kwork_class *class,
545 struct evsel *evsel,
546 struct perf_sample *sample,
547 struct machine *machine)
548 {
549 return work_push_atom(kwork, class, KWORK_TRACE_RAISE,
550 KWORK_TRACE_MAX, evsel, sample,
551 machine, NULL);
552 }
553
latency_entry_event(struct perf_kwork * kwork,struct kwork_class * class,struct evsel * evsel,struct perf_sample * sample,struct machine * machine)554 static int latency_entry_event(struct perf_kwork *kwork,
555 struct kwork_class *class,
556 struct evsel *evsel,
557 struct perf_sample *sample,
558 struct machine *machine)
559 {
560 struct kwork_atom *atom = NULL;
561 struct kwork_work *work = NULL;
562
563 atom = work_pop_atom(kwork, class, KWORK_TRACE_ENTRY,
564 KWORK_TRACE_RAISE, evsel, sample,
565 machine, &work);
566 if (work == NULL)
567 return -1;
568
569 if (atom != NULL) {
570 latency_update_entry_event(work, atom, sample);
571 atom_del(atom);
572 }
573
574 return 0;
575 }
576
timehist_save_callchain(struct perf_kwork * kwork,struct perf_sample * sample,struct evsel * evsel,struct machine * machine)577 static void timehist_save_callchain(struct perf_kwork *kwork,
578 struct perf_sample *sample,
579 struct evsel *evsel,
580 struct machine *machine)
581 {
582 struct symbol *sym;
583 struct thread *thread;
584 struct callchain_cursor_node *node;
585 struct callchain_cursor *cursor = &callchain_cursor;
586
587 if (!kwork->show_callchain || sample->callchain == NULL)
588 return;
589
590 /* want main thread for process - has maps */
591 thread = machine__findnew_thread(machine, sample->pid, sample->pid);
592 if (thread == NULL) {
593 pr_debug("Failed to get thread for pid %d\n", sample->pid);
594 return;
595 }
596
597 if (thread__resolve_callchain(thread, cursor, evsel, sample,
598 NULL, NULL, kwork->max_stack + 2) != 0) {
599 pr_debug("Failed to resolve callchain, skipping\n");
600 goto out_put;
601 }
602
603 callchain_cursor_commit(cursor);
604
605 while (true) {
606 node = callchain_cursor_current(cursor);
607 if (node == NULL)
608 break;
609
610 sym = node->ms.sym;
611 if (sym) {
612 if (!strcmp(sym->name, "__softirqentry_text_start") ||
613 !strcmp(sym->name, "__do_softirq"))
614 sym->ignore = 1;
615 }
616
617 callchain_cursor_advance(cursor);
618 }
619
620 out_put:
621 thread__put(thread);
622 }
623
timehist_print_event(struct perf_kwork * kwork,struct kwork_work * work,struct kwork_atom * atom,struct perf_sample * sample,struct addr_location * al)624 static void timehist_print_event(struct perf_kwork *kwork,
625 struct kwork_work *work,
626 struct kwork_atom *atom,
627 struct perf_sample *sample,
628 struct addr_location *al)
629 {
630 char entrytime[32], exittime[32];
631 char kwork_name[PRINT_KWORK_NAME_WIDTH];
632
633 /*
634 * runtime start
635 */
636 timestamp__scnprintf_usec(atom->time,
637 entrytime, sizeof(entrytime));
638 printf(" %*s ", PRINT_TIMESTAMP_WIDTH, entrytime);
639
640 /*
641 * runtime end
642 */
643 timestamp__scnprintf_usec(sample->time,
644 exittime, sizeof(exittime));
645 printf(" %*s ", PRINT_TIMESTAMP_WIDTH, exittime);
646
647 /*
648 * cpu
649 */
650 printf(" [%0*d] ", PRINT_CPU_WIDTH, work->cpu);
651
652 /*
653 * kwork name
654 */
655 if (work->class && work->class->work_name) {
656 work->class->work_name(work, kwork_name,
657 PRINT_KWORK_NAME_WIDTH);
658 printf(" %-*s ", PRINT_KWORK_NAME_WIDTH, kwork_name);
659 } else
660 printf(" %-*s ", PRINT_KWORK_NAME_WIDTH, "");
661
662 /*
663 *runtime
664 */
665 printf(" %*.*f ",
666 PRINT_RUNTIME_WIDTH, RPINT_DECIMAL_WIDTH,
667 (double)(sample->time - atom->time) / NSEC_PER_MSEC);
668
669 /*
670 * delaytime
671 */
672 if (atom->prev != NULL)
673 printf(" %*.*f ", PRINT_LATENCY_WIDTH, RPINT_DECIMAL_WIDTH,
674 (double)(atom->time - atom->prev->time) / NSEC_PER_MSEC);
675 else
676 printf(" %*s ", PRINT_LATENCY_WIDTH, " ");
677
678 /*
679 * callchain
680 */
681 if (kwork->show_callchain) {
682 printf(" ");
683 sample__fprintf_sym(sample, al, 0,
684 EVSEL__PRINT_SYM | EVSEL__PRINT_ONELINE |
685 EVSEL__PRINT_CALLCHAIN_ARROW |
686 EVSEL__PRINT_SKIP_IGNORED,
687 &callchain_cursor, symbol_conf.bt_stop_list,
688 stdout);
689 }
690
691 printf("\n");
692 }
693
timehist_raise_event(struct perf_kwork * kwork,struct kwork_class * class,struct evsel * evsel,struct perf_sample * sample,struct machine * machine)694 static int timehist_raise_event(struct perf_kwork *kwork,
695 struct kwork_class *class,
696 struct evsel *evsel,
697 struct perf_sample *sample,
698 struct machine *machine)
699 {
700 return work_push_atom(kwork, class, KWORK_TRACE_RAISE,
701 KWORK_TRACE_MAX, evsel, sample,
702 machine, NULL);
703 }
704
timehist_entry_event(struct perf_kwork * kwork,struct kwork_class * class,struct evsel * evsel,struct perf_sample * sample,struct machine * machine)705 static int timehist_entry_event(struct perf_kwork *kwork,
706 struct kwork_class *class,
707 struct evsel *evsel,
708 struct perf_sample *sample,
709 struct machine *machine)
710 {
711 int ret;
712 struct kwork_work *work = NULL;
713
714 ret = work_push_atom(kwork, class, KWORK_TRACE_ENTRY,
715 KWORK_TRACE_RAISE, evsel, sample,
716 machine, &work);
717 if (ret)
718 return ret;
719
720 if (work != NULL)
721 timehist_save_callchain(kwork, sample, evsel, machine);
722
723 return 0;
724 }
725
timehist_exit_event(struct perf_kwork * kwork,struct kwork_class * class,struct evsel * evsel,struct perf_sample * sample,struct machine * machine)726 static int timehist_exit_event(struct perf_kwork *kwork,
727 struct kwork_class *class,
728 struct evsel *evsel,
729 struct perf_sample *sample,
730 struct machine *machine)
731 {
732 struct kwork_atom *atom = NULL;
733 struct kwork_work *work = NULL;
734 struct addr_location al;
735
736 if (machine__resolve(machine, &al, sample) < 0) {
737 pr_debug("Problem processing event, skipping it\n");
738 return -1;
739 }
740
741 atom = work_pop_atom(kwork, class, KWORK_TRACE_EXIT,
742 KWORK_TRACE_ENTRY, evsel, sample,
743 machine, &work);
744 if (work == NULL)
745 return -1;
746
747 if (atom != NULL) {
748 work->nr_atoms++;
749 timehist_print_event(kwork, work, atom, sample, &al);
750 atom_del(atom);
751 }
752
753 return 0;
754 }
755
756 static struct kwork_class kwork_irq;
process_irq_handler_entry_event(struct perf_tool * tool,struct evsel * evsel,struct perf_sample * sample,struct machine * machine)757 static int process_irq_handler_entry_event(struct perf_tool *tool,
758 struct evsel *evsel,
759 struct perf_sample *sample,
760 struct machine *machine)
761 {
762 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool);
763
764 if (kwork->tp_handler->entry_event)
765 return kwork->tp_handler->entry_event(kwork, &kwork_irq,
766 evsel, sample, machine);
767 return 0;
768 }
769
process_irq_handler_exit_event(struct perf_tool * tool,struct evsel * evsel,struct perf_sample * sample,struct machine * machine)770 static int process_irq_handler_exit_event(struct perf_tool *tool,
771 struct evsel *evsel,
772 struct perf_sample *sample,
773 struct machine *machine)
774 {
775 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool);
776
777 if (kwork->tp_handler->exit_event)
778 return kwork->tp_handler->exit_event(kwork, &kwork_irq,
779 evsel, sample, machine);
780 return 0;
781 }
782
783 const struct evsel_str_handler irq_tp_handlers[] = {
784 { "irq:irq_handler_entry", process_irq_handler_entry_event, },
785 { "irq:irq_handler_exit", process_irq_handler_exit_event, },
786 };
787
irq_class_init(struct kwork_class * class,struct perf_session * session)788 static int irq_class_init(struct kwork_class *class,
789 struct perf_session *session)
790 {
791 if (perf_session__set_tracepoints_handlers(session, irq_tp_handlers)) {
792 pr_err("Failed to set irq tracepoints handlers\n");
793 return -1;
794 }
795
796 class->work_root = RB_ROOT_CACHED;
797 return 0;
798 }
799
irq_work_init(struct kwork_class * class,struct kwork_work * work,struct evsel * evsel,struct perf_sample * sample,struct machine * machine __maybe_unused)800 static void irq_work_init(struct kwork_class *class,
801 struct kwork_work *work,
802 struct evsel *evsel,
803 struct perf_sample *sample,
804 struct machine *machine __maybe_unused)
805 {
806 work->class = class;
807 work->cpu = sample->cpu;
808 work->id = evsel__intval(evsel, sample, "irq");
809 work->name = evsel__strval(evsel, sample, "name");
810 }
811
irq_work_name(struct kwork_work * work,char * buf,int len)812 static void irq_work_name(struct kwork_work *work, char *buf, int len)
813 {
814 snprintf(buf, len, "%s:%" PRIu64 "", work->name, work->id);
815 }
816
817 static struct kwork_class kwork_irq = {
818 .name = "irq",
819 .type = KWORK_CLASS_IRQ,
820 .nr_tracepoints = 2,
821 .tp_handlers = irq_tp_handlers,
822 .class_init = irq_class_init,
823 .work_init = irq_work_init,
824 .work_name = irq_work_name,
825 };
826
827 static struct kwork_class kwork_softirq;
process_softirq_raise_event(struct perf_tool * tool,struct evsel * evsel,struct perf_sample * sample,struct machine * machine)828 static int process_softirq_raise_event(struct perf_tool *tool,
829 struct evsel *evsel,
830 struct perf_sample *sample,
831 struct machine *machine)
832 {
833 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool);
834
835 if (kwork->tp_handler->raise_event)
836 return kwork->tp_handler->raise_event(kwork, &kwork_softirq,
837 evsel, sample, machine);
838
839 return 0;
840 }
841
process_softirq_entry_event(struct perf_tool * tool,struct evsel * evsel,struct perf_sample * sample,struct machine * machine)842 static int process_softirq_entry_event(struct perf_tool *tool,
843 struct evsel *evsel,
844 struct perf_sample *sample,
845 struct machine *machine)
846 {
847 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool);
848
849 if (kwork->tp_handler->entry_event)
850 return kwork->tp_handler->entry_event(kwork, &kwork_softirq,
851 evsel, sample, machine);
852
853 return 0;
854 }
855
process_softirq_exit_event(struct perf_tool * tool,struct evsel * evsel,struct perf_sample * sample,struct machine * machine)856 static int process_softirq_exit_event(struct perf_tool *tool,
857 struct evsel *evsel,
858 struct perf_sample *sample,
859 struct machine *machine)
860 {
861 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool);
862
863 if (kwork->tp_handler->exit_event)
864 return kwork->tp_handler->exit_event(kwork, &kwork_softirq,
865 evsel, sample, machine);
866
867 return 0;
868 }
869
870 const struct evsel_str_handler softirq_tp_handlers[] = {
871 { "irq:softirq_raise", process_softirq_raise_event, },
872 { "irq:softirq_entry", process_softirq_entry_event, },
873 { "irq:softirq_exit", process_softirq_exit_event, },
874 };
875
softirq_class_init(struct kwork_class * class,struct perf_session * session)876 static int softirq_class_init(struct kwork_class *class,
877 struct perf_session *session)
878 {
879 if (perf_session__set_tracepoints_handlers(session,
880 softirq_tp_handlers)) {
881 pr_err("Failed to set softirq tracepoints handlers\n");
882 return -1;
883 }
884
885 class->work_root = RB_ROOT_CACHED;
886 return 0;
887 }
888
evsel__softirq_name(struct evsel * evsel,u64 num)889 static char *evsel__softirq_name(struct evsel *evsel, u64 num)
890 {
891 char *name = NULL;
892 bool found = false;
893 struct tep_print_flag_sym *sym = NULL;
894 struct tep_print_arg *args = evsel->tp_format->print_fmt.args;
895
896 if ((args == NULL) || (args->next == NULL))
897 return NULL;
898
899 /* skip softirq field: "REC->vec" */
900 for (sym = args->next->symbol.symbols; sym != NULL; sym = sym->next) {
901 if ((eval_flag(sym->value) == (unsigned long long)num) &&
902 (strlen(sym->str) != 0)) {
903 found = true;
904 break;
905 }
906 }
907
908 if (!found)
909 return NULL;
910
911 name = strdup(sym->str);
912 if (name == NULL) {
913 pr_err("Failed to copy symbol name\n");
914 return NULL;
915 }
916 return name;
917 }
918
softirq_work_init(struct kwork_class * class,struct kwork_work * work,struct evsel * evsel,struct perf_sample * sample,struct machine * machine __maybe_unused)919 static void softirq_work_init(struct kwork_class *class,
920 struct kwork_work *work,
921 struct evsel *evsel,
922 struct perf_sample *sample,
923 struct machine *machine __maybe_unused)
924 {
925 u64 num = evsel__intval(evsel, sample, "vec");
926
927 work->id = num;
928 work->class = class;
929 work->cpu = sample->cpu;
930 work->name = evsel__softirq_name(evsel, num);
931 }
932
softirq_work_name(struct kwork_work * work,char * buf,int len)933 static void softirq_work_name(struct kwork_work *work, char *buf, int len)
934 {
935 snprintf(buf, len, "(s)%s:%" PRIu64 "", work->name, work->id);
936 }
937
938 static struct kwork_class kwork_softirq = {
939 .name = "softirq",
940 .type = KWORK_CLASS_SOFTIRQ,
941 .nr_tracepoints = 3,
942 .tp_handlers = softirq_tp_handlers,
943 .class_init = softirq_class_init,
944 .work_init = softirq_work_init,
945 .work_name = softirq_work_name,
946 };
947
948 static struct kwork_class kwork_workqueue;
process_workqueue_activate_work_event(struct perf_tool * tool,struct evsel * evsel,struct perf_sample * sample,struct machine * machine)949 static int process_workqueue_activate_work_event(struct perf_tool *tool,
950 struct evsel *evsel,
951 struct perf_sample *sample,
952 struct machine *machine)
953 {
954 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool);
955
956 if (kwork->tp_handler->raise_event)
957 return kwork->tp_handler->raise_event(kwork, &kwork_workqueue,
958 evsel, sample, machine);
959
960 return 0;
961 }
962
process_workqueue_execute_start_event(struct perf_tool * tool,struct evsel * evsel,struct perf_sample * sample,struct machine * machine)963 static int process_workqueue_execute_start_event(struct perf_tool *tool,
964 struct evsel *evsel,
965 struct perf_sample *sample,
966 struct machine *machine)
967 {
968 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool);
969
970 if (kwork->tp_handler->entry_event)
971 return kwork->tp_handler->entry_event(kwork, &kwork_workqueue,
972 evsel, sample, machine);
973
974 return 0;
975 }
976
process_workqueue_execute_end_event(struct perf_tool * tool,struct evsel * evsel,struct perf_sample * sample,struct machine * machine)977 static int process_workqueue_execute_end_event(struct perf_tool *tool,
978 struct evsel *evsel,
979 struct perf_sample *sample,
980 struct machine *machine)
981 {
982 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool);
983
984 if (kwork->tp_handler->exit_event)
985 return kwork->tp_handler->exit_event(kwork, &kwork_workqueue,
986 evsel, sample, machine);
987
988 return 0;
989 }
990
991 const struct evsel_str_handler workqueue_tp_handlers[] = {
992 { "workqueue:workqueue_activate_work", process_workqueue_activate_work_event, },
993 { "workqueue:workqueue_execute_start", process_workqueue_execute_start_event, },
994 { "workqueue:workqueue_execute_end", process_workqueue_execute_end_event, },
995 };
996
workqueue_class_init(struct kwork_class * class,struct perf_session * session)997 static int workqueue_class_init(struct kwork_class *class,
998 struct perf_session *session)
999 {
1000 if (perf_session__set_tracepoints_handlers(session,
1001 workqueue_tp_handlers)) {
1002 pr_err("Failed to set workqueue tracepoints handlers\n");
1003 return -1;
1004 }
1005
1006 class->work_root = RB_ROOT_CACHED;
1007 return 0;
1008 }
1009
workqueue_work_init(struct kwork_class * class,struct kwork_work * work,struct evsel * evsel,struct perf_sample * sample,struct machine * machine)1010 static void workqueue_work_init(struct kwork_class *class,
1011 struct kwork_work *work,
1012 struct evsel *evsel,
1013 struct perf_sample *sample,
1014 struct machine *machine)
1015 {
1016 char *modp = NULL;
1017 unsigned long long function_addr = evsel__intval(evsel,
1018 sample, "function");
1019
1020 work->class = class;
1021 work->cpu = sample->cpu;
1022 work->id = evsel__intval(evsel, sample, "work");
1023 work->name = function_addr == 0 ? NULL :
1024 machine__resolve_kernel_addr(machine, &function_addr, &modp);
1025 }
1026
workqueue_work_name(struct kwork_work * work,char * buf,int len)1027 static void workqueue_work_name(struct kwork_work *work, char *buf, int len)
1028 {
1029 if (work->name != NULL)
1030 snprintf(buf, len, "(w)%s", work->name);
1031 else
1032 snprintf(buf, len, "(w)0x%" PRIx64, work->id);
1033 }
1034
1035 static struct kwork_class kwork_workqueue = {
1036 .name = "workqueue",
1037 .type = KWORK_CLASS_WORKQUEUE,
1038 .nr_tracepoints = 3,
1039 .tp_handlers = workqueue_tp_handlers,
1040 .class_init = workqueue_class_init,
1041 .work_init = workqueue_work_init,
1042 .work_name = workqueue_work_name,
1043 };
1044
1045 static struct kwork_class *kwork_class_supported_list[KWORK_CLASS_MAX] = {
1046 [KWORK_CLASS_IRQ] = &kwork_irq,
1047 [KWORK_CLASS_SOFTIRQ] = &kwork_softirq,
1048 [KWORK_CLASS_WORKQUEUE] = &kwork_workqueue,
1049 };
1050
print_separator(int len)1051 static void print_separator(int len)
1052 {
1053 printf(" %.*s\n", len, graph_dotted_line);
1054 }
1055
report_print_work(struct perf_kwork * kwork,struct kwork_work * work)1056 static int report_print_work(struct perf_kwork *kwork, struct kwork_work *work)
1057 {
1058 int ret = 0;
1059 char kwork_name[PRINT_KWORK_NAME_WIDTH];
1060 char max_runtime_start[32], max_runtime_end[32];
1061 char max_latency_start[32], max_latency_end[32];
1062
1063 printf(" ");
1064
1065 /*
1066 * kwork name
1067 */
1068 if (work->class && work->class->work_name) {
1069 work->class->work_name(work, kwork_name,
1070 PRINT_KWORK_NAME_WIDTH);
1071 ret += printf(" %-*s |", PRINT_KWORK_NAME_WIDTH, kwork_name);
1072 } else {
1073 ret += printf(" %-*s |", PRINT_KWORK_NAME_WIDTH, "");
1074 }
1075
1076 /*
1077 * cpu
1078 */
1079 ret += printf(" %0*d |", PRINT_CPU_WIDTH, work->cpu);
1080
1081 /*
1082 * total runtime
1083 */
1084 if (kwork->report == KWORK_REPORT_RUNTIME) {
1085 ret += printf(" %*.*f ms |",
1086 PRINT_RUNTIME_WIDTH, RPINT_DECIMAL_WIDTH,
1087 (double)work->total_runtime / NSEC_PER_MSEC);
1088 } else if (kwork->report == KWORK_REPORT_LATENCY) { // avg delay
1089 ret += printf(" %*.*f ms |",
1090 PRINT_LATENCY_WIDTH, RPINT_DECIMAL_WIDTH,
1091 (double)work->total_latency /
1092 work->nr_atoms / NSEC_PER_MSEC);
1093 }
1094
1095 /*
1096 * count
1097 */
1098 ret += printf(" %*" PRIu64 " |", PRINT_COUNT_WIDTH, work->nr_atoms);
1099
1100 /*
1101 * max runtime, max runtime start, max runtime end
1102 */
1103 if (kwork->report == KWORK_REPORT_RUNTIME) {
1104 timestamp__scnprintf_usec(work->max_runtime_start,
1105 max_runtime_start,
1106 sizeof(max_runtime_start));
1107 timestamp__scnprintf_usec(work->max_runtime_end,
1108 max_runtime_end,
1109 sizeof(max_runtime_end));
1110 ret += printf(" %*.*f ms | %*s s | %*s s |",
1111 PRINT_RUNTIME_WIDTH, RPINT_DECIMAL_WIDTH,
1112 (double)work->max_runtime / NSEC_PER_MSEC,
1113 PRINT_TIMESTAMP_WIDTH, max_runtime_start,
1114 PRINT_TIMESTAMP_WIDTH, max_runtime_end);
1115 }
1116 /*
1117 * max delay, max delay start, max delay end
1118 */
1119 else if (kwork->report == KWORK_REPORT_LATENCY) {
1120 timestamp__scnprintf_usec(work->max_latency_start,
1121 max_latency_start,
1122 sizeof(max_latency_start));
1123 timestamp__scnprintf_usec(work->max_latency_end,
1124 max_latency_end,
1125 sizeof(max_latency_end));
1126 ret += printf(" %*.*f ms | %*s s | %*s s |",
1127 PRINT_LATENCY_WIDTH, RPINT_DECIMAL_WIDTH,
1128 (double)work->max_latency / NSEC_PER_MSEC,
1129 PRINT_TIMESTAMP_WIDTH, max_latency_start,
1130 PRINT_TIMESTAMP_WIDTH, max_latency_end);
1131 }
1132
1133 printf("\n");
1134 return ret;
1135 }
1136
report_print_header(struct perf_kwork * kwork)1137 static int report_print_header(struct perf_kwork *kwork)
1138 {
1139 int ret;
1140
1141 printf("\n ");
1142 ret = printf(" %-*s | %-*s |",
1143 PRINT_KWORK_NAME_WIDTH, "Kwork Name",
1144 PRINT_CPU_WIDTH, "Cpu");
1145
1146 if (kwork->report == KWORK_REPORT_RUNTIME) {
1147 ret += printf(" %-*s |",
1148 PRINT_RUNTIME_HEADER_WIDTH, "Total Runtime");
1149 } else if (kwork->report == KWORK_REPORT_LATENCY) {
1150 ret += printf(" %-*s |",
1151 PRINT_LATENCY_HEADER_WIDTH, "Avg delay");
1152 }
1153
1154 ret += printf(" %-*s |", PRINT_COUNT_WIDTH, "Count");
1155
1156 if (kwork->report == KWORK_REPORT_RUNTIME) {
1157 ret += printf(" %-*s | %-*s | %-*s |",
1158 PRINT_RUNTIME_HEADER_WIDTH, "Max runtime",
1159 PRINT_TIMESTAMP_HEADER_WIDTH, "Max runtime start",
1160 PRINT_TIMESTAMP_HEADER_WIDTH, "Max runtime end");
1161 } else if (kwork->report == KWORK_REPORT_LATENCY) {
1162 ret += printf(" %-*s | %-*s | %-*s |",
1163 PRINT_LATENCY_HEADER_WIDTH, "Max delay",
1164 PRINT_TIMESTAMP_HEADER_WIDTH, "Max delay start",
1165 PRINT_TIMESTAMP_HEADER_WIDTH, "Max delay end");
1166 }
1167
1168 printf("\n");
1169 print_separator(ret);
1170 return ret;
1171 }
1172
timehist_print_header(void)1173 static void timehist_print_header(void)
1174 {
1175 /*
1176 * header row
1177 */
1178 printf(" %-*s %-*s %-*s %-*s %-*s %-*s\n",
1179 PRINT_TIMESTAMP_WIDTH, "Runtime start",
1180 PRINT_TIMESTAMP_WIDTH, "Runtime end",
1181 PRINT_TIMEHIST_CPU_WIDTH, "Cpu",
1182 PRINT_KWORK_NAME_WIDTH, "Kwork name",
1183 PRINT_RUNTIME_WIDTH, "Runtime",
1184 PRINT_RUNTIME_WIDTH, "Delaytime");
1185
1186 /*
1187 * units row
1188 */
1189 printf(" %-*s %-*s %-*s %-*s %-*s %-*s\n",
1190 PRINT_TIMESTAMP_WIDTH, "",
1191 PRINT_TIMESTAMP_WIDTH, "",
1192 PRINT_TIMEHIST_CPU_WIDTH, "",
1193 PRINT_KWORK_NAME_WIDTH, "(TYPE)NAME:NUM",
1194 PRINT_RUNTIME_WIDTH, "(msec)",
1195 PRINT_RUNTIME_WIDTH, "(msec)");
1196
1197 /*
1198 * separator
1199 */
1200 printf(" %.*s %.*s %.*s %.*s %.*s %.*s\n",
1201 PRINT_TIMESTAMP_WIDTH, graph_dotted_line,
1202 PRINT_TIMESTAMP_WIDTH, graph_dotted_line,
1203 PRINT_TIMEHIST_CPU_WIDTH, graph_dotted_line,
1204 PRINT_KWORK_NAME_WIDTH, graph_dotted_line,
1205 PRINT_RUNTIME_WIDTH, graph_dotted_line,
1206 PRINT_RUNTIME_WIDTH, graph_dotted_line);
1207 }
1208
print_summary(struct perf_kwork * kwork)1209 static void print_summary(struct perf_kwork *kwork)
1210 {
1211 u64 time = kwork->timeend - kwork->timestart;
1212
1213 printf(" Total count : %9" PRIu64 "\n", kwork->all_count);
1214 printf(" Total runtime (msec) : %9.3f (%.3f%% load average)\n",
1215 (double)kwork->all_runtime / NSEC_PER_MSEC,
1216 time == 0 ? 0 : (double)kwork->all_runtime / time);
1217 printf(" Total time span (msec) : %9.3f\n",
1218 (double)time / NSEC_PER_MSEC);
1219 }
1220
nr_list_entry(struct list_head * head)1221 static unsigned long long nr_list_entry(struct list_head *head)
1222 {
1223 struct list_head *pos;
1224 unsigned long long n = 0;
1225
1226 list_for_each(pos, head)
1227 n++;
1228
1229 return n;
1230 }
1231
print_skipped_events(struct perf_kwork * kwork)1232 static void print_skipped_events(struct perf_kwork *kwork)
1233 {
1234 int i;
1235 const char *const kwork_event_str[] = {
1236 [KWORK_TRACE_RAISE] = "raise",
1237 [KWORK_TRACE_ENTRY] = "entry",
1238 [KWORK_TRACE_EXIT] = "exit",
1239 };
1240
1241 if ((kwork->nr_skipped_events[KWORK_TRACE_MAX] != 0) &&
1242 (kwork->nr_events != 0)) {
1243 printf(" INFO: %.3f%% skipped events (%" PRIu64 " including ",
1244 (double)kwork->nr_skipped_events[KWORK_TRACE_MAX] /
1245 (double)kwork->nr_events * 100.0,
1246 kwork->nr_skipped_events[KWORK_TRACE_MAX]);
1247
1248 for (i = 0; i < KWORK_TRACE_MAX; i++) {
1249 printf("%" PRIu64 " %s%s",
1250 kwork->nr_skipped_events[i],
1251 kwork_event_str[i],
1252 (i == KWORK_TRACE_MAX - 1) ? ")\n" : ", ");
1253 }
1254 }
1255
1256 if (verbose > 0)
1257 printf(" INFO: use %lld atom pages\n",
1258 nr_list_entry(&kwork->atom_page_list));
1259 }
1260
print_bad_events(struct perf_kwork * kwork)1261 static void print_bad_events(struct perf_kwork *kwork)
1262 {
1263 if ((kwork->nr_lost_events != 0) && (kwork->nr_events != 0)) {
1264 printf(" INFO: %.3f%% lost events (%ld out of %ld, in %ld chunks)\n",
1265 (double)kwork->nr_lost_events /
1266 (double)kwork->nr_events * 100.0,
1267 kwork->nr_lost_events, kwork->nr_events,
1268 kwork->nr_lost_chunks);
1269 }
1270 }
1271
work_sort(struct perf_kwork * kwork,struct kwork_class * class)1272 static void work_sort(struct perf_kwork *kwork, struct kwork_class *class)
1273 {
1274 struct rb_node *node;
1275 struct kwork_work *data;
1276 struct rb_root_cached *root = &class->work_root;
1277
1278 pr_debug("Sorting %s ...\n", class->name);
1279 for (;;) {
1280 node = rb_first_cached(root);
1281 if (!node)
1282 break;
1283
1284 rb_erase_cached(node, root);
1285 data = rb_entry(node, struct kwork_work, node);
1286 work_insert(&kwork->sorted_work_root,
1287 data, &kwork->sort_list);
1288 }
1289 }
1290
perf_kwork__sort(struct perf_kwork * kwork)1291 static void perf_kwork__sort(struct perf_kwork *kwork)
1292 {
1293 struct kwork_class *class;
1294
1295 list_for_each_entry(class, &kwork->class_list, list)
1296 work_sort(kwork, class);
1297 }
1298
perf_kwork__check_config(struct perf_kwork * kwork,struct perf_session * session)1299 static int perf_kwork__check_config(struct perf_kwork *kwork,
1300 struct perf_session *session)
1301 {
1302 int ret;
1303 struct evsel *evsel;
1304 struct kwork_class *class;
1305
1306 static struct trace_kwork_handler report_ops = {
1307 .entry_event = report_entry_event,
1308 .exit_event = report_exit_event,
1309 };
1310 static struct trace_kwork_handler latency_ops = {
1311 .raise_event = latency_raise_event,
1312 .entry_event = latency_entry_event,
1313 };
1314 static struct trace_kwork_handler timehist_ops = {
1315 .raise_event = timehist_raise_event,
1316 .entry_event = timehist_entry_event,
1317 .exit_event = timehist_exit_event,
1318 };
1319
1320 switch (kwork->report) {
1321 case KWORK_REPORT_RUNTIME:
1322 kwork->tp_handler = &report_ops;
1323 break;
1324 case KWORK_REPORT_LATENCY:
1325 kwork->tp_handler = &latency_ops;
1326 break;
1327 case KWORK_REPORT_TIMEHIST:
1328 kwork->tp_handler = &timehist_ops;
1329 break;
1330 default:
1331 pr_debug("Invalid report type %d\n", kwork->report);
1332 return -1;
1333 }
1334
1335 list_for_each_entry(class, &kwork->class_list, list)
1336 if ((class->class_init != NULL) &&
1337 (class->class_init(class, session) != 0))
1338 return -1;
1339
1340 if (kwork->cpu_list != NULL) {
1341 ret = perf_session__cpu_bitmap(session,
1342 kwork->cpu_list,
1343 kwork->cpu_bitmap);
1344 if (ret < 0) {
1345 pr_err("Invalid cpu bitmap\n");
1346 return -1;
1347 }
1348 }
1349
1350 if (kwork->time_str != NULL) {
1351 ret = perf_time__parse_str(&kwork->ptime, kwork->time_str);
1352 if (ret != 0) {
1353 pr_err("Invalid time span\n");
1354 return -1;
1355 }
1356 }
1357
1358 list_for_each_entry(evsel, &session->evlist->core.entries, core.node) {
1359 if (kwork->show_callchain && !evsel__has_callchain(evsel)) {
1360 pr_debug("Samples do not have callchains\n");
1361 kwork->show_callchain = 0;
1362 symbol_conf.use_callchain = 0;
1363 }
1364 }
1365
1366 return 0;
1367 }
1368
perf_kwork__read_events(struct perf_kwork * kwork)1369 static int perf_kwork__read_events(struct perf_kwork *kwork)
1370 {
1371 int ret = -1;
1372 struct perf_session *session = NULL;
1373
1374 struct perf_data data = {
1375 .path = input_name,
1376 .mode = PERF_DATA_MODE_READ,
1377 .force = kwork->force,
1378 };
1379
1380 session = perf_session__new(&data, &kwork->tool);
1381 if (IS_ERR(session)) {
1382 pr_debug("Error creating perf session\n");
1383 return PTR_ERR(session);
1384 }
1385
1386 symbol__init(&session->header.env);
1387
1388 if (perf_kwork__check_config(kwork, session) != 0)
1389 goto out_delete;
1390
1391 if (session->tevent.pevent &&
1392 tep_set_function_resolver(session->tevent.pevent,
1393 machine__resolve_kernel_addr,
1394 &session->machines.host) < 0) {
1395 pr_err("Failed to set libtraceevent function resolver\n");
1396 goto out_delete;
1397 }
1398
1399 if (kwork->report == KWORK_REPORT_TIMEHIST)
1400 timehist_print_header();
1401
1402 ret = perf_session__process_events(session);
1403 if (ret) {
1404 pr_debug("Failed to process events, error %d\n", ret);
1405 goto out_delete;
1406 }
1407
1408 kwork->nr_events = session->evlist->stats.nr_events[0];
1409 kwork->nr_lost_events = session->evlist->stats.total_lost;
1410 kwork->nr_lost_chunks = session->evlist->stats.nr_events[PERF_RECORD_LOST];
1411
1412 out_delete:
1413 perf_session__delete(session);
1414 return ret;
1415 }
1416
process_skipped_events(struct perf_kwork * kwork,struct kwork_work * work)1417 static void process_skipped_events(struct perf_kwork *kwork,
1418 struct kwork_work *work)
1419 {
1420 int i;
1421 unsigned long long count;
1422
1423 for (i = 0; i < KWORK_TRACE_MAX; i++) {
1424 count = nr_list_entry(&work->atom_list[i]);
1425 kwork->nr_skipped_events[i] += count;
1426 kwork->nr_skipped_events[KWORK_TRACE_MAX] += count;
1427 }
1428 }
1429
perf_kwork_add_work(struct perf_kwork * kwork,struct kwork_class * class,struct kwork_work * key)1430 struct kwork_work *perf_kwork_add_work(struct perf_kwork *kwork,
1431 struct kwork_class *class,
1432 struct kwork_work *key)
1433 {
1434 struct kwork_work *work = NULL;
1435
1436 work = work_new(key);
1437 if (work == NULL)
1438 return NULL;
1439
1440 work_insert(&class->work_root, work, &kwork->cmp_id);
1441 return work;
1442 }
1443
sig_handler(int sig)1444 static void sig_handler(int sig)
1445 {
1446 /*
1447 * Simply capture termination signal so that
1448 * the program can continue after pause returns
1449 */
1450 pr_debug("Captuer signal %d\n", sig);
1451 }
1452
perf_kwork__report_bpf(struct perf_kwork * kwork)1453 static int perf_kwork__report_bpf(struct perf_kwork *kwork)
1454 {
1455 int ret;
1456
1457 signal(SIGINT, sig_handler);
1458 signal(SIGTERM, sig_handler);
1459
1460 ret = perf_kwork__trace_prepare_bpf(kwork);
1461 if (ret)
1462 return -1;
1463
1464 printf("Starting trace, Hit <Ctrl+C> to stop and report\n");
1465
1466 perf_kwork__trace_start();
1467
1468 /*
1469 * a simple pause, wait here for stop signal
1470 */
1471 pause();
1472
1473 perf_kwork__trace_finish();
1474
1475 perf_kwork__report_read_bpf(kwork);
1476
1477 perf_kwork__report_cleanup_bpf();
1478
1479 return 0;
1480 }
1481
perf_kwork__report(struct perf_kwork * kwork)1482 static int perf_kwork__report(struct perf_kwork *kwork)
1483 {
1484 int ret;
1485 struct rb_node *next;
1486 struct kwork_work *work;
1487
1488 if (kwork->use_bpf)
1489 ret = perf_kwork__report_bpf(kwork);
1490 else
1491 ret = perf_kwork__read_events(kwork);
1492
1493 if (ret != 0)
1494 return -1;
1495
1496 perf_kwork__sort(kwork);
1497
1498 setup_pager();
1499
1500 ret = report_print_header(kwork);
1501 next = rb_first_cached(&kwork->sorted_work_root);
1502 while (next) {
1503 work = rb_entry(next, struct kwork_work, node);
1504 process_skipped_events(kwork, work);
1505
1506 if (work->nr_atoms != 0) {
1507 report_print_work(kwork, work);
1508 if (kwork->summary) {
1509 kwork->all_runtime += work->total_runtime;
1510 kwork->all_count += work->nr_atoms;
1511 }
1512 }
1513 next = rb_next(next);
1514 }
1515 print_separator(ret);
1516
1517 if (kwork->summary) {
1518 print_summary(kwork);
1519 print_separator(ret);
1520 }
1521
1522 print_bad_events(kwork);
1523 print_skipped_events(kwork);
1524 printf("\n");
1525
1526 return 0;
1527 }
1528
1529 typedef int (*tracepoint_handler)(struct perf_tool *tool,
1530 struct evsel *evsel,
1531 struct perf_sample *sample,
1532 struct machine *machine);
1533
perf_kwork__process_tracepoint_sample(struct perf_tool * tool,union perf_event * event __maybe_unused,struct perf_sample * sample,struct evsel * evsel,struct machine * machine)1534 static int perf_kwork__process_tracepoint_sample(struct perf_tool *tool,
1535 union perf_event *event __maybe_unused,
1536 struct perf_sample *sample,
1537 struct evsel *evsel,
1538 struct machine *machine)
1539 {
1540 int err = 0;
1541
1542 if (evsel->handler != NULL) {
1543 tracepoint_handler f = evsel->handler;
1544
1545 err = f(tool, evsel, sample, machine);
1546 }
1547
1548 return err;
1549 }
1550
perf_kwork__timehist(struct perf_kwork * kwork)1551 static int perf_kwork__timehist(struct perf_kwork *kwork)
1552 {
1553 /*
1554 * event handlers for timehist option
1555 */
1556 kwork->tool.comm = perf_event__process_comm;
1557 kwork->tool.exit = perf_event__process_exit;
1558 kwork->tool.fork = perf_event__process_fork;
1559 kwork->tool.attr = perf_event__process_attr;
1560 kwork->tool.tracing_data = perf_event__process_tracing_data;
1561 kwork->tool.build_id = perf_event__process_build_id;
1562 kwork->tool.ordered_events = true;
1563 kwork->tool.ordering_requires_timestamps = true;
1564 symbol_conf.use_callchain = kwork->show_callchain;
1565
1566 if (symbol__validate_sym_arguments()) {
1567 pr_err("Failed to validate sym arguments\n");
1568 return -1;
1569 }
1570
1571 setup_pager();
1572
1573 return perf_kwork__read_events(kwork);
1574 }
1575
setup_event_list(struct perf_kwork * kwork,const struct option * options,const char * const usage_msg[])1576 static void setup_event_list(struct perf_kwork *kwork,
1577 const struct option *options,
1578 const char * const usage_msg[])
1579 {
1580 int i;
1581 struct kwork_class *class;
1582 char *tmp, *tok, *str;
1583
1584 if (kwork->event_list_str == NULL)
1585 goto null_event_list_str;
1586
1587 str = strdup(kwork->event_list_str);
1588 for (tok = strtok_r(str, ", ", &tmp);
1589 tok; tok = strtok_r(NULL, ", ", &tmp)) {
1590 for (i = 0; i < KWORK_CLASS_MAX; i++) {
1591 class = kwork_class_supported_list[i];
1592 if (strcmp(tok, class->name) == 0) {
1593 list_add_tail(&class->list, &kwork->class_list);
1594 break;
1595 }
1596 }
1597 if (i == KWORK_CLASS_MAX) {
1598 usage_with_options_msg(usage_msg, options,
1599 "Unknown --event key: `%s'", tok);
1600 }
1601 }
1602 free(str);
1603
1604 null_event_list_str:
1605 /*
1606 * config all kwork events if not specified
1607 */
1608 if (list_empty(&kwork->class_list)) {
1609 for (i = 0; i < KWORK_CLASS_MAX; i++) {
1610 list_add_tail(&kwork_class_supported_list[i]->list,
1611 &kwork->class_list);
1612 }
1613 }
1614
1615 pr_debug("Config event list:");
1616 list_for_each_entry(class, &kwork->class_list, list)
1617 pr_debug(" %s", class->name);
1618 pr_debug("\n");
1619 }
1620
perf_kwork__record(struct perf_kwork * kwork,int argc,const char ** argv)1621 static int perf_kwork__record(struct perf_kwork *kwork,
1622 int argc, const char **argv)
1623 {
1624 const char **rec_argv;
1625 unsigned int rec_argc, i, j;
1626 struct kwork_class *class;
1627
1628 const char *const record_args[] = {
1629 "record",
1630 "-a",
1631 "-R",
1632 "-m", "1024",
1633 "-c", "1",
1634 };
1635
1636 rec_argc = ARRAY_SIZE(record_args) + argc - 1;
1637
1638 list_for_each_entry(class, &kwork->class_list, list)
1639 rec_argc += 2 * class->nr_tracepoints;
1640
1641 rec_argv = calloc(rec_argc + 1, sizeof(char *));
1642 if (rec_argv == NULL)
1643 return -ENOMEM;
1644
1645 for (i = 0; i < ARRAY_SIZE(record_args); i++)
1646 rec_argv[i] = strdup(record_args[i]);
1647
1648 list_for_each_entry(class, &kwork->class_list, list) {
1649 for (j = 0; j < class->nr_tracepoints; j++) {
1650 rec_argv[i++] = strdup("-e");
1651 rec_argv[i++] = strdup(class->tp_handlers[j].name);
1652 }
1653 }
1654
1655 for (j = 1; j < (unsigned int)argc; j++, i++)
1656 rec_argv[i] = argv[j];
1657
1658 BUG_ON(i != rec_argc);
1659
1660 pr_debug("record comm: ");
1661 for (j = 0; j < rec_argc; j++)
1662 pr_debug("%s ", rec_argv[j]);
1663 pr_debug("\n");
1664
1665 return cmd_record(i, rec_argv);
1666 }
1667
cmd_kwork(int argc,const char ** argv)1668 int cmd_kwork(int argc, const char **argv)
1669 {
1670 static struct perf_kwork kwork = {
1671 .class_list = LIST_HEAD_INIT(kwork.class_list),
1672 .tool = {
1673 .mmap = perf_event__process_mmap,
1674 .mmap2 = perf_event__process_mmap2,
1675 .sample = perf_kwork__process_tracepoint_sample,
1676 },
1677 .atom_page_list = LIST_HEAD_INIT(kwork.atom_page_list),
1678 .sort_list = LIST_HEAD_INIT(kwork.sort_list),
1679 .cmp_id = LIST_HEAD_INIT(kwork.cmp_id),
1680 .sorted_work_root = RB_ROOT_CACHED,
1681 .tp_handler = NULL,
1682 .profile_name = NULL,
1683 .cpu_list = NULL,
1684 .time_str = NULL,
1685 .force = false,
1686 .event_list_str = NULL,
1687 .summary = false,
1688 .sort_order = NULL,
1689 .show_callchain = false,
1690 .max_stack = 5,
1691 .timestart = 0,
1692 .timeend = 0,
1693 .nr_events = 0,
1694 .nr_lost_chunks = 0,
1695 .nr_lost_events = 0,
1696 .all_runtime = 0,
1697 .all_count = 0,
1698 .nr_skipped_events = { 0 },
1699 };
1700 static const char default_report_sort_order[] = "runtime, max, count";
1701 static const char default_latency_sort_order[] = "avg, max, count";
1702 const struct option kwork_options[] = {
1703 OPT_INCR('v', "verbose", &verbose,
1704 "be more verbose (show symbol address, etc)"),
1705 OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace,
1706 "dump raw trace in ASCII"),
1707 OPT_STRING('k', "kwork", &kwork.event_list_str, "kwork",
1708 "list of kwork to profile (irq, softirq, workqueue, etc)"),
1709 OPT_BOOLEAN('f', "force", &kwork.force, "don't complain, do it"),
1710 OPT_END()
1711 };
1712 const struct option report_options[] = {
1713 OPT_STRING('s', "sort", &kwork.sort_order, "key[,key2...]",
1714 "sort by key(s): runtime, max, count"),
1715 OPT_STRING('C', "cpu", &kwork.cpu_list, "cpu",
1716 "list of cpus to profile"),
1717 OPT_STRING('n', "name", &kwork.profile_name, "name",
1718 "event name to profile"),
1719 OPT_STRING(0, "time", &kwork.time_str, "str",
1720 "Time span for analysis (start,stop)"),
1721 OPT_STRING('i', "input", &input_name, "file",
1722 "input file name"),
1723 OPT_BOOLEAN('S', "with-summary", &kwork.summary,
1724 "Show summary with statistics"),
1725 #ifdef HAVE_BPF_SKEL
1726 OPT_BOOLEAN('b', "use-bpf", &kwork.use_bpf,
1727 "Use BPF to measure kwork runtime"),
1728 #endif
1729 OPT_PARENT(kwork_options)
1730 };
1731 const struct option latency_options[] = {
1732 OPT_STRING('s', "sort", &kwork.sort_order, "key[,key2...]",
1733 "sort by key(s): avg, max, count"),
1734 OPT_STRING('C', "cpu", &kwork.cpu_list, "cpu",
1735 "list of cpus to profile"),
1736 OPT_STRING('n', "name", &kwork.profile_name, "name",
1737 "event name to profile"),
1738 OPT_STRING(0, "time", &kwork.time_str, "str",
1739 "Time span for analysis (start,stop)"),
1740 OPT_STRING('i', "input", &input_name, "file",
1741 "input file name"),
1742 #ifdef HAVE_BPF_SKEL
1743 OPT_BOOLEAN('b', "use-bpf", &kwork.use_bpf,
1744 "Use BPF to measure kwork latency"),
1745 #endif
1746 OPT_PARENT(kwork_options)
1747 };
1748 const struct option timehist_options[] = {
1749 OPT_STRING('k', "vmlinux", &symbol_conf.vmlinux_name,
1750 "file", "vmlinux pathname"),
1751 OPT_STRING(0, "kallsyms", &symbol_conf.kallsyms_name,
1752 "file", "kallsyms pathname"),
1753 OPT_BOOLEAN('g', "call-graph", &kwork.show_callchain,
1754 "Display call chains if present"),
1755 OPT_UINTEGER(0, "max-stack", &kwork.max_stack,
1756 "Maximum number of functions to display backtrace."),
1757 OPT_STRING(0, "symfs", &symbol_conf.symfs, "directory",
1758 "Look for files with symbols relative to this directory"),
1759 OPT_STRING(0, "time", &kwork.time_str, "str",
1760 "Time span for analysis (start,stop)"),
1761 OPT_STRING('C', "cpu", &kwork.cpu_list, "cpu",
1762 "list of cpus to profile"),
1763 OPT_STRING('n', "name", &kwork.profile_name, "name",
1764 "event name to profile"),
1765 OPT_STRING('i', "input", &input_name, "file",
1766 "input file name"),
1767 OPT_PARENT(kwork_options)
1768 };
1769 const char *kwork_usage[] = {
1770 NULL,
1771 NULL
1772 };
1773 const char * const report_usage[] = {
1774 "perf kwork report [<options>]",
1775 NULL
1776 };
1777 const char * const latency_usage[] = {
1778 "perf kwork latency [<options>]",
1779 NULL
1780 };
1781 const char * const timehist_usage[] = {
1782 "perf kwork timehist [<options>]",
1783 NULL
1784 };
1785 const char *const kwork_subcommands[] = {
1786 "record", "report", "latency", "timehist", NULL
1787 };
1788
1789 argc = parse_options_subcommand(argc, argv, kwork_options,
1790 kwork_subcommands, kwork_usage,
1791 PARSE_OPT_STOP_AT_NON_OPTION);
1792 if (!argc)
1793 usage_with_options(kwork_usage, kwork_options);
1794
1795 setup_event_list(&kwork, kwork_options, kwork_usage);
1796 sort_dimension__add(&kwork, "id", &kwork.cmp_id);
1797
1798 if (strlen(argv[0]) > 2 && strstarts("record", argv[0]))
1799 return perf_kwork__record(&kwork, argc, argv);
1800 else if (strlen(argv[0]) > 2 && strstarts("report", argv[0])) {
1801 kwork.sort_order = default_report_sort_order;
1802 if (argc > 1) {
1803 argc = parse_options(argc, argv, report_options, report_usage, 0);
1804 if (argc)
1805 usage_with_options(report_usage, report_options);
1806 }
1807 kwork.report = KWORK_REPORT_RUNTIME;
1808 setup_sorting(&kwork, report_options, report_usage);
1809 return perf_kwork__report(&kwork);
1810 } else if (strlen(argv[0]) > 2 && strstarts("latency", argv[0])) {
1811 kwork.sort_order = default_latency_sort_order;
1812 if (argc > 1) {
1813 argc = parse_options(argc, argv, latency_options, latency_usage, 0);
1814 if (argc)
1815 usage_with_options(latency_usage, latency_options);
1816 }
1817 kwork.report = KWORK_REPORT_LATENCY;
1818 setup_sorting(&kwork, latency_options, latency_usage);
1819 return perf_kwork__report(&kwork);
1820 } else if (strlen(argv[0]) > 2 && strstarts("timehist", argv[0])) {
1821 if (argc > 1) {
1822 argc = parse_options(argc, argv, timehist_options, timehist_usage, 0);
1823 if (argc)
1824 usage_with_options(timehist_usage, timehist_options);
1825 }
1826 kwork.report = KWORK_REPORT_TIMEHIST;
1827 return perf_kwork__timehist(&kwork);
1828 } else
1829 usage_with_options(kwork_usage, kwork_options);
1830
1831 return 0;
1832 }
1833