xref: /aosp_15_r20/external/bcc/tools/offwaketime.py (revision 387f9dfdfa2baef462e92476d413c7bc2470293e)
1#!/usr/bin/env python
2#
3# offwaketime   Summarize blocked time by kernel off-CPU stack + waker stack
4#               For Linux, uses BCC, eBPF.
5#
6# USAGE: offwaketime [-h] [-p PID | -u | -k] [-U | -K] [-f] [duration]
7#
8# Copyright 2016 Netflix, Inc.
9# Licensed under the Apache License, Version 2.0 (the "License")
10#
11# 20-Jan-2016   Brendan Gregg   Created this.
12# 04-Apr-2023   Rocky Xing      Updated default stack storage size.
13
14from __future__ import print_function
15from bcc import BPF
16from time import sleep
17import argparse
18import signal
19import errno
20from sys import stderr
21
22# arg validation
23def positive_int(val):
24    dest = []
25    # Filter up to 5 pids, arbitrary
26    args_list = val.split(",", 5)
27    pids_to_add = min(len(args_list), 5)
28    for i in range(pids_to_add):
29        dest.append(_positive_int(args_list[i]))
30
31    return dest
32
33def _positive_int(val):
34    try:
35        ival = int(val)
36    except ValueError:
37        raise argparse.ArgumentTypeError("must be an integer")
38
39    if ival < 0:
40        raise argparse.ArgumentTypeError("must be positive")
41    return ival
42
43def positive_nonzero_int(val):
44    ival = _positive_int(val)
45    if ival == 0:
46        raise argparse.ArgumentTypeError("must be nonzero")
47    return ival
48
49def build_filter(filter_name, values):
50    filter_string = "((%s == %d)" % (filter_name, values[0])
51
52    for val in values[1:]:
53        filter_string += " || (%s == %d )" % (filter_name , val)
54
55    filter_string += ")"
56
57    return filter_string
58
59def stack_id_err(stack_id):
60    # -EFAULT in get_stackid normally means the stack-trace is not available,
61    # Such as getting kernel stack trace in userspace code
62    return (stack_id < 0) and (stack_id != -errno.EFAULT)
63
64# arguments
65examples = """examples:
66    ./offwaketime             # trace off-CPU + waker stack time until Ctrl-C
67    ./offwaketime 5           # trace for 5 seconds only
68    ./offwaketime -f 5        # 5 seconds, and output in folded format
69    ./offwaketime -m 1000     # trace only events that last more than 1000 usec
70    ./offwaketime -M 9000     # trace only events that last less than 9000 usec
71    ./offwaketime -p 185      # only trace threads for PID 185
72    ./offwaketime -t 188      # only trace thread 188
73    ./offwaketime -u          # only trace user threads (no kernel)
74    ./offwaketime -k          # only trace kernel threads (no user)
75    ./offwaketime -U          # only show user space stacks (no kernel)
76    ./offwaketime -K          # only show kernel space stacks (no user)
77"""
78parser = argparse.ArgumentParser(
79    description="Summarize blocked time by kernel stack trace + waker stack",
80    formatter_class=argparse.RawDescriptionHelpFormatter,
81    epilog=examples)
82thread_group = parser.add_mutually_exclusive_group()
83# Note: this script provides --pid and --tid flags but their arguments are
84# referred to internally using kernel nomenclature: TGID and PID.
85thread_group.add_argument("-p", "--pid", metavar="PIDS", dest="tgid",
86     type=positive_int,
87     help="trace these PIDS only. Can be a comma separated list of PIDS.")
88thread_group.add_argument("-t", "--tid", metavar="TIDS", dest="pid",
89    type=positive_int,
90    help="trace these TIDS only. Can be a comma separated list of TIDS.")
91thread_group.add_argument("-u", "--user-threads-only", action="store_true",
92    help="user threads only (no kernel threads)")
93thread_group.add_argument("-k", "--kernel-threads-only", action="store_true",
94    help="kernel threads only (no user threads)")
95stack_group = parser.add_mutually_exclusive_group()
96stack_group.add_argument("-U", "--user-stacks-only", action="store_true",
97    help="show stacks from user space only (no kernel space stacks)")
98stack_group.add_argument("-K", "--kernel-stacks-only", action="store_true",
99    help="show stacks from kernel space only (no user space stacks)")
100parser.add_argument("-d", "--delimited", action="store_true",
101    help="insert delimiter between kernel/user stacks")
102parser.add_argument("-f", "--folded", action="store_true",
103    help="output folded format")
104parser.add_argument("--stack-storage-size", default=16384,
105    type=positive_nonzero_int,
106    help="the number of unique stack traces that can be stored and "
107         "displayed (default 16384)")
108parser.add_argument("duration", nargs="?", default=99999999,
109    type=positive_nonzero_int,
110    help="duration of trace, in seconds")
111parser.add_argument("-m", "--min-block-time", default=1,
112    type=positive_nonzero_int,
113    help="the amount of time in microseconds over which we " +
114         "store traces (default 1)")
115parser.add_argument("-M", "--max-block-time", default=(1 << 64) - 1,
116    type=positive_nonzero_int,
117    help="the amount of time in microseconds under which we " +
118         "store traces (default U64_MAX)")
119parser.add_argument("--state", type=_positive_int,
120    help="filter on this thread state bitmask (eg, 2 == TASK_UNINTERRUPTIBLE" +
121         ") see include/linux/sched.h")
122parser.add_argument("--ebpf", action="store_true",
123    help=argparse.SUPPRESS)
124args = parser.parse_args()
125folded = args.folded
126duration = int(args.duration)
127
128# signal handler
129def signal_ignore(signal, frame):
130    print()
131
132# define BPF program
133bpf_text = """
134#include <uapi/linux/ptrace.h>
135#include <linux/sched.h>
136
137#define MINBLOCK_US    MINBLOCK_US_VALUEULL
138#define MAXBLOCK_US    MAXBLOCK_US_VALUEULL
139
140struct key_t {
141    char waker[TASK_COMM_LEN];
142    char target[TASK_COMM_LEN];
143    s64 w_k_stack_id;
144    s64 w_u_stack_id;
145    s64 t_k_stack_id;
146    s64 t_u_stack_id;
147    u64 t_pid;
148    u64 t_tgid;
149    u32 w_pid;
150    u32 w_tgid;
151};
152BPF_HASH(counts, struct key_t);
153
154// Key of this hash is PID of waiting Process,
155// value is timestamp when it went into waiting
156BPF_HASH(start, u32);
157
158struct wokeby_t {
159    char name[TASK_COMM_LEN];
160    int k_stack_id;
161    int u_stack_id;
162    int w_pid;
163    int w_tgid;
164};
165// Key of the hash is PID of the Process to be waken, value is information
166// of the Process who wakes it
167BPF_HASH(wokeby, u32, struct wokeby_t);
168
169BPF_STACK_TRACE(stack_traces, STACK_STORAGE_SIZE);
170
171int waker(struct pt_regs *ctx, struct task_struct *p) {
172    // PID and TGID of the target Process to be waken
173    u32 pid = p->pid;
174    u32 tgid = p->tgid;
175
176    if (!((THREAD_FILTER) && (STATE_FILTER))) {
177        return 0;
178    }
179
180    // Construct information about current (the waker) Process
181    struct wokeby_t woke = {};
182    bpf_get_current_comm(&woke.name, sizeof(woke.name));
183    woke.k_stack_id = KERNEL_STACK_GET;
184    woke.u_stack_id = USER_STACK_GET;
185    woke.w_pid = bpf_get_current_pid_tgid();
186    woke.w_tgid = bpf_get_current_pid_tgid() >> 32;
187
188    wokeby.update(&pid, &woke);
189    return 0;
190}
191
192int oncpu(struct pt_regs *ctx, struct task_struct *p) {
193    // PID and TGID of the previous Process (Process going into waiting)
194    u32 pid = p->pid;
195    u32 tgid = p->tgid;
196    u64 *tsp;
197    u64 ts = bpf_ktime_get_ns();
198
199    // Record timestamp for the previous Process (Process going into waiting)
200    if ((THREAD_FILTER) && (STATE_FILTER)) {
201        start.update(&pid, &ts);
202    }
203
204    // Calculate current Process's wait time by finding the timestamp of when
205    // it went into waiting.
206    // pid and tgid are now the PID and TGID of the current (waking) Process.
207    pid = bpf_get_current_pid_tgid();
208    tgid = bpf_get_current_pid_tgid() >> 32;
209    tsp = start.lookup(&pid);
210    if (tsp == 0) {
211        // Missed or filtered when the Process went into waiting
212        return 0;
213    }
214    u64 delta = ts - *tsp;
215    start.delete(&pid);
216    delta = delta / 1000;
217    if ((delta < MINBLOCK_US) || (delta > MAXBLOCK_US)) {
218        return 0;
219    }
220
221    // create map key
222    struct key_t key = {};
223    struct wokeby_t *woke;
224
225    bpf_get_current_comm(&key.target, sizeof(key.target));
226    key.t_pid = pid;
227    key.t_tgid = tgid;
228    key.t_k_stack_id = KERNEL_STACK_GET;
229    key.t_u_stack_id = USER_STACK_GET;
230
231    woke = wokeby.lookup(&pid);
232    if (woke) {
233        key.w_k_stack_id = woke->k_stack_id;
234        key.w_u_stack_id = woke->u_stack_id;
235        key.w_pid = woke->w_pid;
236        key.w_tgid = woke->w_tgid;
237        __builtin_memcpy(&key.waker, woke->name, TASK_COMM_LEN);
238        wokeby.delete(&pid);
239    }
240
241    counts.increment(key, delta);
242    return 0;
243}
244"""
245
246# set thread filter
247if args.tgid is not None:
248    thread_filter = build_filter("tgid", args.tgid)
249elif args.pid is not None:
250    thread_filter = build_filter("pid", args.pid)
251elif args.user_threads_only:
252    thread_filter = '!(p->flags & PF_KTHREAD)'
253elif args.kernel_threads_only:
254    thread_filter = 'p->flags & PF_KTHREAD'
255else:
256    thread_filter = '1'
257if args.state == 0:
258    state_filter = 'p->STATE_FIELD == 0'
259elif args.state:
260    # these states are sometimes bitmask checked
261    state_filter = 'p->STATE_FIELD & %d' % args.state
262else:
263    state_filter = '1'
264bpf_text = bpf_text.replace('THREAD_FILTER', thread_filter)
265bpf_text = bpf_text.replace('STATE_FILTER', state_filter)
266if BPF.kernel_struct_has_field(b'task_struct', b'__state') == 1:
267    bpf_text = bpf_text.replace('STATE_FIELD', '__state')
268else:
269    bpf_text = bpf_text.replace('STATE_FIELD', 'state')
270
271# set stack storage size
272bpf_text = bpf_text.replace('STACK_STORAGE_SIZE', str(args.stack_storage_size))
273bpf_text = bpf_text.replace('MINBLOCK_US_VALUE', str(args.min_block_time))
274bpf_text = bpf_text.replace('MAXBLOCK_US_VALUE', str(args.max_block_time))
275
276# handle stack args
277kernel_stack_get = "stack_traces.get_stackid(ctx, 0)"
278user_stack_get = "stack_traces.get_stackid(ctx, BPF_F_USER_STACK)"
279stack_context = ""
280if args.user_stacks_only:
281    stack_context = "user"
282    kernel_stack_get = "-1"
283elif args.kernel_stacks_only:
284    stack_context = "kernel"
285    user_stack_get = "-1"
286else:
287    stack_context = "user + kernel"
288bpf_text = bpf_text.replace('USER_STACK_GET', user_stack_get)
289bpf_text = bpf_text.replace('KERNEL_STACK_GET', kernel_stack_get)
290if args.ebpf:
291    print(bpf_text)
292    exit()
293
294# initialize BPF
295b = BPF(text=bpf_text)
296b.attach_kprobe(event_re="^finish_task_switch$|^finish_task_switch\.isra\.\d$",
297                fn_name="oncpu")
298b.attach_kprobe(event="try_to_wake_up", fn_name="waker")
299matched = b.num_open_kprobes()
300if matched == 0:
301    print("0 functions traced. Exiting.")
302    exit()
303
304# header
305if not folded:
306    print("Tracing blocked time (us) by %s off-CPU and waker stack" %
307        stack_context, end="")
308    if duration < 99999999:
309        print(" for %d secs." % duration)
310    else:
311        print("... Hit Ctrl-C to end.")
312
313try:
314    sleep(duration)
315except KeyboardInterrupt:
316    # as cleanup can take many seconds, trap Ctrl-C:
317    # print a newline for folded output on Ctrl-C
318    signal.signal(signal.SIGINT, signal_ignore)
319
320
321if not folded:
322    print()
323
324missing_stacks = 0
325has_enomem = False
326counts = b.get_table("counts")
327stack_traces = b.get_table("stack_traces")
328need_delimiter = args.delimited and not (args.kernel_stacks_only or
329                                         args.user_stacks_only)
330for k, v in sorted(counts.items(), key=lambda counts: counts[1].value):
331    # handle get_stackid errors
332    if not args.user_stacks_only:
333        missing_stacks += int(stack_id_err(k.w_k_stack_id))
334        missing_stacks += int(stack_id_err(k.t_k_stack_id))
335        has_enomem = has_enomem or (k.w_k_stack_id == -errno.ENOMEM) or \
336                     (k.t_k_stack_id == -errno.ENOMEM)
337    if not args.kernel_stacks_only:
338        missing_stacks += int(stack_id_err(k.w_u_stack_id))
339        missing_stacks += int(stack_id_err(k.t_u_stack_id))
340        has_enomem = has_enomem or (k.w_u_stack_id == -errno.ENOMEM) or \
341                     (k.t_u_stack_id == -errno.ENOMEM)
342
343    waker_user_stack = [] if k.w_u_stack_id < 1 else \
344        reversed(list(stack_traces.walk(k.w_u_stack_id))[1:])
345    waker_kernel_stack = [] if k.w_k_stack_id < 1 else \
346        reversed(list(stack_traces.walk(k.w_k_stack_id))[1:])
347    target_user_stack = [] if k.t_u_stack_id < 1 else \
348        stack_traces.walk(k.t_u_stack_id)
349    target_kernel_stack = [] if k.t_k_stack_id < 1 else \
350        stack_traces.walk(k.t_k_stack_id)
351
352    if folded:
353        # print folded stack output
354        line = [k.target.decode('utf-8', 'replace')]
355        if not args.kernel_stacks_only:
356            if stack_id_err(k.t_u_stack_id):
357                line.append("[Missed User Stack] %d" % k.t_u_stack_id)
358            else:
359                line.extend([b.sym(addr, k.t_tgid).decode('utf-8', 'replace')
360                    for addr in reversed(list(target_user_stack)[1:])])
361        if not args.user_stacks_only:
362            line.extend(["-"] if (need_delimiter and k.t_k_stack_id > 0 and k.t_u_stack_id > 0) else [])
363            if stack_id_err(k.t_k_stack_id):
364                line.append("[Missed Kernel Stack]")
365            else:
366                line.extend([b.ksym(addr).decode('utf-8', 'replace')
367                    for addr in reversed(list(target_kernel_stack)[1:])])
368        line.append("--")
369        if not args.user_stacks_only:
370            if stack_id_err(k.w_k_stack_id):
371                line.append("[Missed Kernel Stack]")
372            else:
373                line.extend([b.ksym(addr).decode('utf-8', 'replace')
374                    for addr in reversed(list(waker_kernel_stack))])
375        if not args.kernel_stacks_only:
376            line.extend(["-"] if (need_delimiter and k.w_u_stack_id > 0 and k.w_k_stack_id > 0) else [])
377            if stack_id_err(k.w_u_stack_id):
378                line.append("[Missed User Stack]")
379            else:
380                line.extend([b.sym(addr, k.w_tgid).decode('utf-8', 'replace')
381                    for addr in reversed(list(waker_user_stack))])
382        line.append(k.waker.decode('utf-8', 'replace'))
383        print("%s %d" % (";".join(line), v.value))
384    else:
385        # print wakeup name then stack in reverse order
386        print("    %-16s %s %s" % ("waker:", k.waker.decode('utf-8', 'replace'), k.w_pid))
387        if not args.kernel_stacks_only:
388            if stack_id_err(k.w_u_stack_id):
389                print("    [Missed User Stack] %d" % k.w_u_stack_id)
390            else:
391                for addr in waker_user_stack:
392                    print("    %s" % b.sym(addr, k.w_tgid).decode('utf-8', 'replace'))
393        if not args.user_stacks_only:
394            if need_delimiter and k.w_u_stack_id > 0 and k.w_k_stack_id > 0:
395                print("    -")
396            if stack_id_err(k.w_k_stack_id):
397                print("    [Missed Kernel Stack]")
398            else:
399                for addr in waker_kernel_stack:
400                    print("    %s" % b.ksym(addr).decode('utf-8', 'replace'))
401
402        # print waker/wakee delimiter
403        print("    %-16s %s" % ("--", "--"))
404
405        if not args.user_stacks_only:
406            if stack_id_err(k.t_k_stack_id):
407                print("    [Missed Kernel Stack]")
408            else:
409                for addr in target_kernel_stack:
410                    print("    %s" % b.ksym(addr).decode('utf-8', 'replace'))
411        if not args.kernel_stacks_only:
412            if need_delimiter and k.t_u_stack_id > 0 and k.t_k_stack_id > 0:
413                print("    -")
414            if stack_id_err(k.t_u_stack_id):
415                print("    [Missed User Stack]")
416            else:
417                for addr in target_user_stack:
418                    print("    %s" % b.sym(addr, k.t_tgid).decode('utf-8', 'replace'))
419        print("    %-16s %s %s" % ("target:", k.target.decode('utf-8', 'replace'), k.t_pid))
420        print("        %d\n" % v.value)
421
422if missing_stacks > 0:
423    enomem_str = " Consider increasing --stack-storage-size."
424    print("WARNING: %d stack traces lost and could not be displayed.%s" %
425        (missing_stacks, (enomem_str if has_enomem else "")),
426        file=stderr)
427