1#!/usr/bin/python
2#
3# wakeuptime    Summarize sleep to wakeup time by waker kernel stack
4#               For Linux, uses BCC, eBPF.
5#
6# USAGE: wakeuptime [-h] [-u] [-p PID] [-v] [-f] [duration]
7#
8# Copyright 2016 Netflix, Inc.
9# Licensed under the Apache License, Version 2.0 (the "License")
10#
11# 14-Jan-2016	Brendan Gregg	Created this.
12
13from __future__ import print_function
14from bcc import BPF
15from bcc.utils import printb
16from time import sleep, strftime
17import argparse
18import signal
19import errno
20from sys import stderr
21
22# arg validation
23def positive_int(val):
24    try:
25        ival = int(val)
26    except ValueError:
27        raise argparse.ArgumentTypeError("must be an integer")
28
29    if ival < 0:
30        raise argparse.ArgumentTypeError("must be positive")
31    return ival
32
33def positive_nonzero_int(val):
34    ival = positive_int(val)
35    if ival == 0:
36        raise argparse.ArgumentTypeError("must be nonzero")
37    return ival
38
39# arguments
40examples = """examples:
41    ./wakeuptime             # trace blocked time with waker stacks
42    ./wakeuptime 5           # trace for 5 seconds only
43    ./wakeuptime -f 5        # 5 seconds, and output in folded format
44    ./wakeuptime -u          # don't include kernel threads (user only)
45    ./wakeuptime -p 185      # trace for PID 185 only
46"""
47parser = argparse.ArgumentParser(
48    description="Summarize sleep to wakeup time by waker kernel stack",
49    formatter_class=argparse.RawDescriptionHelpFormatter,
50    epilog=examples)
51parser.add_argument("-u", "--useronly", action="store_true",
52    help="user threads only (no kernel threads)")
53parser.add_argument("-p", "--pid",
54    type=positive_int,
55    help="trace this PID only")
56parser.add_argument("-v", "--verbose", action="store_true",
57    help="show raw addresses")
58parser.add_argument("-f", "--folded", action="store_true",
59    help="output folded format")
60parser.add_argument("--stack-storage-size", default=1024,
61    type=positive_nonzero_int,
62    help="the number of unique stack traces that can be stored and "
63         "displayed (default 1024)")
64parser.add_argument("duration", nargs="?", default=99999999,
65    type=positive_nonzero_int,
66    help="duration of trace, in seconds")
67parser.add_argument("-m", "--min-block-time", default=1,
68    type=positive_nonzero_int,
69    help="the amount of time in microseconds over which we " +
70         "store traces (default 1)")
71parser.add_argument("-M", "--max-block-time", default=(1 << 64) - 1,
72    type=positive_nonzero_int,
73    help="the amount of time in microseconds under which we " +
74         "store traces (default U64_MAX)")
75parser.add_argument("--ebpf", action="store_true",
76    help=argparse.SUPPRESS)
77args = parser.parse_args()
78folded = args.folded
79duration = int(args.duration)
80debug = 0
81if args.pid and args.useronly:
82    parser.error("use either -p or -u.")
83
84# signal handler
85def signal_ignore(signal, frame):
86    print()
87
88# define BPF program
89bpf_text = """
90#include <uapi/linux/ptrace.h>
91#include <linux/sched.h>
92
93#define MINBLOCK_US    MINBLOCK_US_VALUEULL
94#define MAXBLOCK_US    MAXBLOCK_US_VALUEULL
95
96struct key_t {
97    int  w_k_stack_id;
98    char waker[TASK_COMM_LEN];
99    char target[TASK_COMM_LEN];
100};
101BPF_HASH(counts, struct key_t);
102BPF_HASH(start, u32);
103BPF_STACK_TRACE(stack_traces, STACK_STORAGE_SIZE);
104
105int offcpu(struct pt_regs *ctx) {
106    u32 pid = bpf_get_current_pid_tgid();
107    struct task_struct *p = (struct task_struct *) bpf_get_current_task();
108    u64 ts;
109
110    if (FILTER)
111        return 0;
112
113    ts = bpf_ktime_get_ns();
114    start.update(&pid, &ts);
115    return 0;
116}
117
118int waker(struct pt_regs *ctx, struct task_struct *p) {
119    u32 pid = p->pid;
120    u64 delta, *tsp, ts;
121
122    tsp = start.lookup(&pid);
123    if (tsp == 0)
124        return 0;        // missed start
125    start.delete(&pid);
126
127    if (FILTER)
128        return 0;
129
130    // calculate delta time
131    delta = bpf_ktime_get_ns() - *tsp;
132    delta = delta / 1000;
133    if ((delta < MINBLOCK_US) || (delta > MAXBLOCK_US))
134        return 0;
135
136    struct key_t key = {};
137
138    key.w_k_stack_id = stack_traces.get_stackid(ctx, BPF_F_REUSE_STACKID);
139    bpf_probe_read(&key.target, sizeof(key.target), p->comm);
140    bpf_get_current_comm(&key.waker, sizeof(key.waker));
141
142    counts.increment(key, delta);
143    return 0;
144}
145"""
146if args.pid:
147    filter = 'pid != %s' % args.pid
148elif args.useronly:
149    filter = 'p->flags & PF_KTHREAD'
150else:
151    filter = '0'
152bpf_text = bpf_text.replace('FILTER', filter)
153
154# set stack storage size
155bpf_text = bpf_text.replace('STACK_STORAGE_SIZE', str(args.stack_storage_size))
156bpf_text = bpf_text.replace('MINBLOCK_US_VALUE', str(args.min_block_time))
157bpf_text = bpf_text.replace('MAXBLOCK_US_VALUE', str(args.max_block_time))
158
159if debug or args.ebpf:
160    print(bpf_text)
161    if args.ebpf:
162        exit()
163
164# initialize BPF
165b = BPF(text=bpf_text)
166b.attach_kprobe(event="schedule", fn_name="offcpu")
167b.attach_kprobe(event="try_to_wake_up", fn_name="waker")
168matched = b.num_open_kprobes()
169if matched == 0:
170    print("0 functions traced. Exiting.")
171    exit()
172
173# header
174if not folded:
175    print("Tracing blocked time (us) by kernel stack", end="")
176    if duration < 99999999:
177        print(" for %d secs." % duration)
178    else:
179        print("... Hit Ctrl-C to end.")
180
181# output
182while (1):
183    try:
184        sleep(duration)
185    except KeyboardInterrupt:
186        # as cleanup can take many seconds, trap Ctrl-C:
187        signal.signal(signal.SIGINT, signal_ignore)
188
189    if not folded:
190        print()
191    missing_stacks = 0
192    has_enomem = False
193    counts = b.get_table("counts")
194    stack_traces = b.get_table("stack_traces")
195    for k, v in sorted(counts.items(), key=lambda counts: counts[1].value):
196        # handle get_stackid errors
197        # check for an ENOMEM error
198        if k.w_k_stack_id == -errno.ENOMEM:
199            missing_stacks += 1
200            continue
201
202        waker_kernel_stack = [] if k.w_k_stack_id < 1 else \
203            reversed(list(stack_traces.walk(k.w_k_stack_id))[1:])
204
205        if folded:
206            # print folded stack output
207            line = \
208                [k.waker] + \
209                [b.ksym(addr)
210                    for addr in reversed(list(waker_kernel_stack))] + \
211                [k.target]
212            printb(b"%s %d" % (b";".join(line), v.value))
213        else:
214            # print default multi-line stack output
215            printb(b"    %-16s %s" % (b"target:", k.target))
216            for addr in waker_kernel_stack:
217                printb(b"    %-16x %s" % (addr, b.ksym(addr)))
218            printb(b"    %-16s %s" % (b"waker:", k.waker))
219            print("        %d\n" % v.value)
220    counts.clear()
221
222    if missing_stacks > 0:
223        enomem_str = " Consider increasing --stack-storage-size."
224        print("WARNING: %d stack traces could not be displayed.%s" %
225            (missing_stacks, enomem_str),
226            file=stderr)
227
228    if not folded:
229        print("Detaching...")
230    exit()
231