1 #!/usr/bin/python 2 # @lint-avoid-python-3-compatibility-imports 3 # 4 # softirqs Summarize soft IRQ (interrupt) event time. 5 # For Linux, uses BCC, eBPF. 6 # 7 # USAGE: softirqs [-h] [-T] [-N] [-d] [interval] [count] 8 # 9 # Copyright (c) 2015 Brendan Gregg. 10 # Licensed under the Apache License, Version 2.0 (the "License") 11 # 12 # 20-Oct-2015 Brendan Gregg Created this. 13 14 from __future__ import print_function 15 from bcc import BPF 16 from time import sleep, strftime 17 import argparse 18 19 # arguments 20 examples = """examples: 21 ./softirqs # sum soft irq event time 22 ./softirqs -d # show soft irq event time as histograms 23 ./softirqs 1 10 # print 1 second summaries, 10 times 24 ./softirqs -NT 1 # 1s summaries, nanoseconds, and timestamps 25 """ 26 parser = argparse.ArgumentParser( 27 description="Summarize soft irq event time as histograms", 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("-N", "--nanoseconds", action="store_true", 33 help="output in nanoseconds") 34 parser.add_argument("-d", "--dist", action="store_true", 35 help="show distributions as histograms") 36 parser.add_argument("-C", "--bycpu", action="store_true", 37 help="break down softirqs to individual cpus") 38 parser.add_argument("interval", nargs="?", default=99999999, 39 help="output interval, in seconds") 40 parser.add_argument("count", nargs="?", default=99999999, 41 help="number of outputs") 42 args = parser.parse_args() 43 countdown = int(args.count) 44 if args.nanoseconds: 45 factor = 1 46 label = "nsecs" 47 else: 48 factor = 1000 49 label = "usecs" 50 debug = 0 51 52 # define BPF program 53 bpf_text = "" 54 if args.bycpu: 55 bpf_text = """ 56 #include <uapi/linux/ptrace.h> 57 58 typedef struct irq_cpu_key { 59 s64 cpu; 60 u64 slot; 61 } irq_key_t; 62 63 BPF_HASH(start, u32); 64 BPF_HISTOGRAM(dist, irq_key_t); 65 66 // time IRQ 67 int trace_start_cpu(struct pt_regs *ctx) 68 { 69 int curr_cpu = bpf_get_smp_processor_id(); 70 u64 ts = bpf_ktime_get_ns(); 71 start.update(&curr_cpu, &ts); 72 return 0; 73 } 74 75 int trace_completion_cpu(struct pt_regs *ctx) 76 { 77 u64 *tsp, delta; 78 int curr_cpu = bpf_get_smp_processor_id(); 79 80 // fetch timestamp and calculate delta 81 tsp = start.lookup(&curr_cpu); 82 COMMON 83 84 // store as sum or histogram 85 irq_key_t key = {.cpu = curr_cpu, 86 STORE 87 88 start.delete(&curr_cpu); 89 return 0; 90 } 91 """ 92 else: 93 bpf_text = """ 94 #include <uapi/linux/ptrace.h> 95 96 typedef struct irq_key { 97 u64 ip; 98 u64 slot; 99 } irq_key_t; 100 101 BPF_HASH(start, u32); 102 BPF_HASH(iptr, u32); 103 BPF_HISTOGRAM(dist, irq_key_t); 104 105 // time IRQ 106 int trace_start(struct pt_regs *ctx) 107 { 108 u32 pid = bpf_get_current_pid_tgid(); 109 u64 ip = PT_REGS_IP(ctx), ts = bpf_ktime_get_ns(); 110 start.update(&pid, &ts); 111 iptr.update(&pid, &ip); 112 return 0; 113 } 114 115 int trace_completion(struct pt_regs *ctx) 116 { 117 u64 *tsp, delta, ip, *ipp; 118 u32 pid = bpf_get_current_pid_tgid(); 119 // fetch timestamp and calculate delta 120 tsp = start.lookup(&pid); 121 ipp = iptr.lookup(&pid); 122 COMMON 123 124 // store as sum or histogram 125 irq_key_t key = { 126 STORE 127 128 start.delete(&pid); 129 iptr.delete(&pid); 130 return 0; 131 } 132 """ 133 134 # code substitutions 135 bpf_text = bpf_text.replace('COMMON', 136 """if (tsp == 0) { 137 return 0; // missed start 138 } 139 delta = bpf_ktime_get_ns() - *tsp; 140 """) 141 142 if args.dist: 143 bpf_text = bpf_text.replace('STORE', 144 '.slot = bpf_log2l(delta)};' + 145 'dist.increment(key);') 146 else: 147 bpf_text = bpf_text.replace('STORE', 148 ' .ip = ip, .slot = 0 /* ignore */};' + 149 'u64 zero = 0, *vp = dist.lookup_or_init(&key, &zero);' + 150 '(*vp) += delta;') 151 if debug: 152 print(bpf_text) 153 154 # load BPF program 155 b = BPF(text=bpf_text) 156 157 # this should really use irq:softirq_entry/exit tracepoints; for now the 158 # soft irq functions are individually traced (search your kernel for 159 # open_softirq() calls, and adjust the following list as needed). 160 for softirqfunc in ("blk_iopoll_softirq", "blk_done_softirq", 161 "rcu_process_callbacks", "run_rebalance_domains", "tasklet_action", 162 "tasklet_hi_action", "run_timer_softirq", "net_tx_action", 163 "net_rx_action"): 164 if args.bycpu: 165 b.attach_kprobe(event=softirqfunc, fn_name="trace_start_cpu") 166 b.attach_kretprobe(event=softirqfunc, fn_name="trace_completion_cpu") 167 else: 168 b.attach_kprobe(event=softirqfunc, fn_name="trace_start") 169 b.attach_kretprobe(event=softirqfunc, fn_name="trace_completion") 170 171 print("Tracing soft irq event time... Hit Ctrl-C to end.") 172 173 # output 174 exiting = 0 if args.interval else 1 175 dist = b.get_table("dist") 176 while (1): 177 try: 178 sleep(int(args.interval)) 179 except KeyboardInterrupt: 180 exiting = 1 181 182 print() 183 if args.timestamp: 184 print("%-8s\n" % strftime("%H:%M:%S"), end="") 185 186 if args.dist: 187 if args.bycpu: 188 dist.print_log2_hist(label, "CPU") 189 else: 190 dist.print_log2_hist(label, "softirq", section_print_fn=b.ksym) 191 else: 192 if args.bycpu: 193 print("%-26s %11s %11s" % ("SOFTIRQ", "CPU", "TOTAL_" + label)) 194 for k, v in sorted(dist.items(), key=lambda dist: dist[1].value): 195 print("%-26s %11d %11d" % (b.ksym(k.ip), k.cpu, v.value / factor)) 196 else: 197 print("%-26s %11s" % ("SOFTIRQ", "TOTAL_" + label)) 198 for k, v in sorted(dist.items(), key=lambda dist: dist[1].value): 199 print("%-26s %11d" % (b.ksym(k.ip), v.value / factor)) 200 dist.clear() 201 202 countdown -= 1 203 if exiting or countdown == 0: 204 exit() 205
