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 |
Brenden Blanco | e8001c3 | 2018-07-23 08:15:56 -0700 | [diff] [blame] | 15 | from bcc.utils import printb |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 16 | from time import sleep, strftime |
| 17 | import argparse |
| 18 | import signal |
Sandipan Das | 2c2d46f | 2017-11-16 17:14:38 +0530 | [diff] [blame] | 19 | import errno |
| 20 | from sys import stderr |
| 21 | |
| 22 | # arg validation |
| 23 | def 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 | |
| 33 | def positive_nonzero_int(val): |
| 34 | ival = positive_int(val) |
| 35 | if ival == 0: |
| 36 | raise argparse.ArgumentTypeError("must be nonzero") |
| 37 | return ival |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 38 | |
| 39 | # arguments |
| 40 | examples = """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 fo PID 185 only |
| 46 | """ |
| 47 | parser = argparse.ArgumentParser( |
| 48 | description="Summarize sleep to wakeup time by waker kernel stack", |
| 49 | formatter_class=argparse.RawDescriptionHelpFormatter, |
| 50 | epilog=examples) |
| 51 | parser.add_argument("-u", "--useronly", action="store_true", |
| 52 | help="user threads only (no kernel threads)") |
| 53 | parser.add_argument("-p", "--pid", |
Sandipan Das | 2c2d46f | 2017-11-16 17:14:38 +0530 | [diff] [blame] | 54 | type=positive_int, |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 55 | help="trace this PID only") |
| 56 | parser.add_argument("-v", "--verbose", action="store_true", |
| 57 | help="show raw addresses") |
| 58 | parser.add_argument("-f", "--folded", action="store_true", |
| 59 | help="output folded format") |
Sandipan Das | 2c2d46f | 2017-11-16 17:14:38 +0530 | [diff] [blame] | 60 | parser.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)") |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 64 | parser.add_argument("duration", nargs="?", default=99999999, |
Sandipan Das | 2c2d46f | 2017-11-16 17:14:38 +0530 | [diff] [blame] | 65 | type=positive_nonzero_int, |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 66 | help="duration of trace, in seconds") |
Sandipan Das | 2c2d46f | 2017-11-16 17:14:38 +0530 | [diff] [blame] | 67 | parser.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)") |
| 71 | parser.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)") |
Nathan Scott | cf0792f | 2018-02-02 16:56:50 +1100 | [diff] [blame] | 75 | parser.add_argument("--ebpf", action="store_true", |
| 76 | help=argparse.SUPPRESS) |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 77 | args = parser.parse_args() |
| 78 | folded = args.folded |
| 79 | duration = int(args.duration) |
| 80 | debug = 0 |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 81 | if args.pid and args.useronly: |
Sandipan Das | 2c2d46f | 2017-11-16 17:14:38 +0530 | [diff] [blame] | 82 | parser.error("use either -p or -u.") |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 83 | |
| 84 | # signal handler |
| 85 | def signal_ignore(signal, frame): |
| 86 | print() |
| 87 | |
| 88 | # define BPF program |
| 89 | bpf_text = """ |
| 90 | #include <uapi/linux/ptrace.h> |
| 91 | #include <linux/sched.h> |
| 92 | |
Sandipan Das | 2c2d46f | 2017-11-16 17:14:38 +0530 | [diff] [blame] | 93 | #define MINBLOCK_US MINBLOCK_US_VALUEULL |
| 94 | #define MAXBLOCK_US MAXBLOCK_US_VALUEULL |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 95 | |
| 96 | struct key_t { |
Sandipan Das | 2c2d46f | 2017-11-16 17:14:38 +0530 | [diff] [blame] | 97 | int w_k_stack_id; |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 98 | char waker[TASK_COMM_LEN]; |
| 99 | char target[TASK_COMM_LEN]; |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 100 | }; |
| 101 | BPF_HASH(counts, struct key_t); |
| 102 | BPF_HASH(start, u32); |
Song Liu | 67ae605 | 2018-02-01 14:59:24 -0800 | [diff] [blame] | 103 | BPF_STACK_TRACE(stack_traces, STACK_STORAGE_SIZE); |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 104 | |
| 105 | int offcpu(struct pt_regs *ctx) { |
| 106 | u32 pid = bpf_get_current_pid_tgid(); |
Sandipan Das | 3edb453 | 2017-11-17 12:41:06 +0530 | [diff] [blame] | 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(); |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 114 | start.update(&pid, &ts); |
| 115 | return 0; |
| 116 | } |
| 117 | |
| 118 | int 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; |
Sandipan Das | 2c2d46f | 2017-11-16 17:14:38 +0530 | [diff] [blame] | 133 | if ((delta < MINBLOCK_US) || (delta > MAXBLOCK_US)) |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 134 | return 0; |
| 135 | |
| 136 | struct key_t key = {}; |
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 | |
Javier Honduvilla Coto | 64bf965 | 2018-08-01 06:50:19 +0200 | [diff] [blame] | 142 | counts.increment(key, delta); |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 143 | return 0; |
| 144 | } |
| 145 | """ |
| 146 | if args.pid: |
| 147 | filter = 'pid != %s' % args.pid |
| 148 | elif args.useronly: |
| 149 | filter = 'p->flags & PF_KTHREAD' |
| 150 | else: |
| 151 | filter = '0' |
| 152 | bpf_text = bpf_text.replace('FILTER', filter) |
Sandipan Das | 2c2d46f | 2017-11-16 17:14:38 +0530 | [diff] [blame] | 153 | |
| 154 | # set stack storage size |
| 155 | bpf_text = bpf_text.replace('STACK_STORAGE_SIZE', str(args.stack_storage_size)) |
| 156 | bpf_text = bpf_text.replace('MINBLOCK_US_VALUE', str(args.min_block_time)) |
| 157 | bpf_text = bpf_text.replace('MAXBLOCK_US_VALUE', str(args.max_block_time)) |
| 158 | |
Nathan Scott | cf0792f | 2018-02-02 16:56:50 +1100 | [diff] [blame] | 159 | if debug or args.ebpf: |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 160 | print(bpf_text) |
Nathan Scott | cf0792f | 2018-02-02 16:56:50 +1100 | [diff] [blame] | 161 | if args.ebpf: |
| 162 | exit() |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 163 | |
| 164 | # initialize BPF |
| 165 | b = BPF(text=bpf_text) |
| 166 | b.attach_kprobe(event="schedule", fn_name="offcpu") |
| 167 | b.attach_kprobe(event="try_to_wake_up", fn_name="waker") |
| 168 | matched = b.num_open_kprobes() |
| 169 | if matched == 0: |
| 170 | print("0 functions traced. Exiting.") |
| 171 | exit() |
| 172 | |
| 173 | # header |
| 174 | if 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 |
| 182 | while (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() |
Sandipan Das | 2c2d46f | 2017-11-16 17:14:38 +0530 | [diff] [blame] | 191 | missing_stacks = 0 |
| 192 | has_enomem = False |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 193 | counts = b.get_table("counts") |
Sandipan Das | 2c2d46f | 2017-11-16 17:14:38 +0530 | [diff] [blame] | 194 | stack_traces = b.get_table("stack_traces") |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 195 | 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] | 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 | |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 205 | if folded: |
| 206 | # print folded stack output |
Sandipan Das | 2c2d46f | 2017-11-16 17:14:38 +0530 | [diff] [blame] | 207 | line = \ |
Brenden Blanco | e8001c3 | 2018-07-23 08:15:56 -0700 | [diff] [blame] | 208 | [k.waker] + \ |
Sandipan Das | 2c2d46f | 2017-11-16 17:14:38 +0530 | [diff] [blame] | 209 | [b.ksym(addr) |
| 210 | for addr in reversed(list(waker_kernel_stack))] + \ |
Brenden Blanco | e8001c3 | 2018-07-23 08:15:56 -0700 | [diff] [blame] | 211 | [k.target] |
| 212 | printb(b"%s %d" % (b";".join(line), v.value)) |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 213 | else: |
| 214 | # print default multi-line stack output |
Brenden Blanco | e8001c3 | 2018-07-23 08:15:56 -0700 | [diff] [blame] | 215 | printb(b" %-16s %s" % (b"target:", k.target)) |
Sandipan Das | 2c2d46f | 2017-11-16 17:14:38 +0530 | [diff] [blame] | 216 | for addr in waker_kernel_stack: |
Brenden Blanco | e8001c3 | 2018-07-23 08:15:56 -0700 | [diff] [blame] | 217 | printb(b" %-16x %s" % (addr, b.ksym(addr))) |
| 218 | printb(b" %-16s %s" % (b"waker:", k.waker)) |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 219 | print(" %d\n" % v.value) |
| 220 | counts.clear() |
| 221 | |
Sandipan Das | 2c2d46f | 2017-11-16 17:14:38 +0530 | [diff] [blame] | 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 | |
Brendan Gregg | 7bf0e49 | 2016-01-27 23:17:40 -0800 | [diff] [blame] | 228 | if not folded: |
| 229 | print("Detaching...") |
| 230 | exit() |