Sasha Goldshtein | 40975ab | 2016-06-29 03:57:01 +0300 | [diff] [blame] | 1 | #!/usr/bin/python |
| 2 | # @lint-avoid-python-3-compatibility-imports |
| 3 | # |
| 4 | # cpudist Summarize on-CPU time per task as a histogram. |
| 5 | # |
| 6 | # USAGE: cpudist [-h] [-T] [-m] [-P] [-L] [-p PID] [interval] [count] |
| 7 | # |
| 8 | # This measures the time a task spends on the CPU, and shows this time as a |
| 9 | # histogram, optionally per-process. |
| 10 | # |
| 11 | # Copyright 2016 Sasha Goldshtein |
| 12 | # Licensed under the Apache License, Version 2.0 (the "License") |
| 13 | |
| 14 | from __future__ import print_function |
| 15 | from bcc import BPF, Tracepoint |
| 16 | from time import sleep, strftime |
| 17 | import argparse |
| 18 | |
| 19 | examples = """examples: |
| 20 | cpudist # summarize on-CPU time as a histogram |
| 21 | cpudist 1 10 # print 1 second summaries, 10 times |
| 22 | cpudist -mT 1 # 1s summaries, milliseconds, and timestamps |
| 23 | cpudist -P # show each PID separately |
| 24 | cpudist -p 185 # trace PID 185 only |
| 25 | """ |
| 26 | parser = argparse.ArgumentParser( |
| 27 | description="Summarize on-CPU time per task as a histogram.", |
| 28 | formatter_class=argparse.RawDescriptionHelpFormatter, |
| 29 | epilog=examples) |
| 30 | parser.add_argument("-T", "--timestamp", action="store_true", |
| 31 | help="include timestamp on output") |
| 32 | parser.add_argument("-m", "--milliseconds", action="store_true", |
| 33 | help="millisecond histogram") |
| 34 | parser.add_argument("-P", "--pids", action="store_true", |
| 35 | help="print a histogram per process ID") |
| 36 | parser.add_argument("-L", "--tids", action="store_true", |
| 37 | help="print a histogram per thread ID") |
| 38 | parser.add_argument("-p", "--pid", |
| 39 | help="trace this PID only") |
| 40 | parser.add_argument("interval", nargs="?", default=99999999, |
| 41 | help="output interval, in seconds") |
| 42 | parser.add_argument("count", nargs="?", default=99999999, |
| 43 | help="number of outputs") |
| 44 | args = parser.parse_args() |
| 45 | countdown = int(args.count) |
| 46 | debug = 0 |
| 47 | |
| 48 | tp = Tracepoint.enable_tracepoint("sched", "sched_switch") |
| 49 | bpf_text = "#include <uapi/linux/ptrace.h>\n" |
| 50 | bpf_text += "#include <linux/sched.h>\n" |
| 51 | bpf_text += tp.generate_decl() |
| 52 | bpf_text += tp.generate_entry_probe() |
| 53 | bpf_text += tp.generate_struct() |
| 54 | |
| 55 | bpf_text += """ |
| 56 | typedef struct pid_key { |
| 57 | u64 id; |
| 58 | u64 slot; |
| 59 | } pid_key_t; |
| 60 | |
| 61 | // We need to store the start time, which is when the thread got switched in, |
| 62 | // and the tgid for the pid because the sched_switch tracepoint doesn't provide |
| 63 | // that information. |
| 64 | BPF_HASH(start, u32, u64); |
| 65 | BPF_HASH(tgid_for_pid, u32, u32); |
| 66 | STORAGE |
| 67 | |
| 68 | int sched_switch(struct pt_regs *ctx) |
| 69 | { |
| 70 | u64 pid_tgid = bpf_get_current_pid_tgid(); |
| 71 | u64 *di = __trace_di.lookup(&pid_tgid); |
| 72 | if (di == 0) |
| 73 | return 0; |
| 74 | |
| 75 | struct sched_switch_trace_entry args = {}; |
| 76 | bpf_probe_read(&args, sizeof(args), (void *)*di); |
| 77 | |
| 78 | u32 tgid, pid; |
| 79 | u64 ts = bpf_ktime_get_ns(); |
| 80 | |
| 81 | if (args.prev_state == TASK_RUNNING) { |
| 82 | pid = args.prev_pid; |
| 83 | |
| 84 | u32 *stored_tgid = tgid_for_pid.lookup(&pid); |
| 85 | if (stored_tgid == 0) |
| 86 | goto BAIL; |
| 87 | tgid = *stored_tgid; |
| 88 | |
| 89 | if (FILTER) |
| 90 | goto BAIL; |
| 91 | |
| 92 | u64 *tsp = start.lookup(&pid); |
| 93 | if (tsp == 0) |
| 94 | goto BAIL; |
| 95 | |
| 96 | u64 delta = ts - *tsp; |
| 97 | FACTOR |
| 98 | STORE |
| 99 | } |
| 100 | |
| 101 | BAIL: |
| 102 | tgid = pid_tgid >> 32; |
| 103 | pid = pid_tgid; |
| 104 | if (FILTER) |
| 105 | return 0; |
| 106 | |
| 107 | start.update(&pid, &ts); |
| 108 | tgid_for_pid.update(&pid, &tgid); |
| 109 | |
| 110 | return 0; |
| 111 | } |
| 112 | """ |
| 113 | |
| 114 | if args.pid: |
| 115 | bpf_text = bpf_text.replace('FILTER', 'tgid != %s' % args.pid) |
| 116 | else: |
| 117 | bpf_text = bpf_text.replace('FILTER', '0') |
| 118 | if args.milliseconds: |
| 119 | bpf_text = bpf_text.replace('FACTOR', 'delta /= 1000000;') |
| 120 | label = "msecs" |
| 121 | else: |
| 122 | bpf_text = bpf_text.replace('FACTOR', 'delta /= 1000;') |
| 123 | label = "usecs" |
| 124 | if args.pids or args.tids: |
| 125 | section = "pid" |
| 126 | pid = "tgid" |
| 127 | if args.tids: |
| 128 | pid = "pid" |
| 129 | section = "tid" |
| 130 | bpf_text = bpf_text.replace('STORAGE', |
| 131 | 'BPF_HISTOGRAM(dist, pid_key_t);') |
| 132 | bpf_text = bpf_text.replace('STORE', |
| 133 | 'pid_key_t key = {.id = ' + pid + ', .slot = bpf_log2l(delta)}; ' + |
| 134 | 'dist.increment(key);') |
| 135 | else: |
| 136 | section = "" |
| 137 | bpf_text = bpf_text.replace('STORAGE', 'BPF_HISTOGRAM(dist);') |
| 138 | bpf_text = bpf_text.replace('STORE', |
| 139 | 'dist.increment(bpf_log2l(delta));') |
| 140 | if debug: |
| 141 | print(bpf_text) |
| 142 | |
| 143 | b = BPF(text=bpf_text) |
| 144 | Tracepoint.attach(b) |
| 145 | b.attach_kprobe(event="perf_trace_sched_switch", fn_name="sched_switch") |
| 146 | |
| 147 | print("Tracing on-CPU time... Hit Ctrl-C to end.") |
| 148 | |
| 149 | exiting = 0 if args.interval else 1 |
| 150 | dist = b.get_table("dist") |
| 151 | while (1): |
| 152 | try: |
| 153 | sleep(int(args.interval)) |
| 154 | except KeyboardInterrupt: |
| 155 | exiting = 1 |
| 156 | |
| 157 | print() |
| 158 | if args.timestamp: |
| 159 | print("%-8s\n" % strftime("%H:%M:%S"), end="") |
| 160 | |
| 161 | dist.print_log2_hist(label, section, section_print_fn=int) |
| 162 | dist.clear() |
| 163 | |
| 164 | countdown -= 1 |
| 165 | if exiting or countdown == 0: |
| 166 | exit() |
| 167 | |