1#!/usr/bin/env 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
14from __future__ import print_function
15from bcc import BPF
16from time import sleep, strftime
17import argparse
18
19# arguments
20examples = """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"""
26parser = argparse.ArgumentParser(
27    description="Summarize soft irq event time as histograms",
28    formatter_class=argparse.RawDescriptionHelpFormatter,
29    epilog=examples)
30parser.add_argument("-T", "--timestamp", action="store_true",
31    help="include timestamp on output")
32parser.add_argument("-N", "--nanoseconds", action="store_true",
33    help="output in nanoseconds")
34parser.add_argument("-d", "--dist", action="store_true",
35    help="show distributions as histograms")
36parser.add_argument("-C", "--bycpu", action="store_true",
37    help="break down softirqs to individual cpus")
38parser.add_argument("interval", nargs="?", default=99999999,
39    help="output interval, in seconds")
40parser.add_argument("count", nargs="?", default=99999999,
41    help="number of outputs")
42args = parser.parse_args()
43countdown = int(args.count)
44if args.nanoseconds:
45    factor = 1
46    label = "nsecs"
47else:
48    factor = 1000
49    label = "usecs"
50debug = 0
51
52# define BPF program
53bpf_text = ""
54if 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    """
92else:
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
135bpf_text = bpf_text.replace('COMMON',
136        """if (tsp == 0) {
137            return 0;   // missed start
138        }
139        delta = bpf_ktime_get_ns() - *tsp;
140        """)
141
142if args.dist:
143    bpf_text = bpf_text.replace('STORE',
144        '.slot = bpf_log2l(delta)};' +
145        'dist.increment(key);')
146else:
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;')
151if debug:
152    print(bpf_text)
153
154# load BPF program
155b = 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).
160for 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
171print("Tracing soft irq event time... Hit Ctrl-C to end.")
172
173# output
174exiting = 0 if args.interval else 1
175dist = b.get_table("dist")
176while (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