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