irq with the new code architecture
authorJulien Desfossez <jdesfossez@efficios.com>
Wed, 28 Jan 2015 05:36:19 +0000 (00:36 -0500)
committerJulien Desfossez <jdesfossez@efficios.com>
Wed, 28 Jan 2015 05:36:19 +0000 (00:36 -0500)
Signed-off-by: Julien Desfossez <jdesfossez@efficios.com>
linuxautomaton/linuxautomaton/automaton.py
linuxautomaton/linuxautomaton/irq.py [new file with mode: 0644]
lttnganalyses/lttnganalyses/irq.py [new file with mode: 0644]
lttnganalysescli/lttnganalysescli/command.py
lttnganalysescli/lttnganalysescli/cputop.py
lttnganalysescli/lttnganalysescli/irq.py [new file with mode: 0644]
lttnganalysescli/lttnganalysescli/memtop.py

index d94b31675d071eacfa9f638981e52c468ddc1393..7f5a8b8c6c62585afe8bb6b73d59a24898080330 100644 (file)
@@ -1,5 +1,6 @@
 from .sched import SchedStateProvider
 from .mem import MemStateProvider
+from .irq import IrqStateProvider
 
 
 class State:
@@ -21,6 +22,7 @@ class Automaton:
         self._state_providers = [
             SchedStateProvider(self._state),
             MemStateProvider(self._state),
+            IrqStateProvider(self._state),
         ]
 
     def process_event(self, ev):
diff --git a/linuxautomaton/linuxautomaton/irq.py b/linuxautomaton/linuxautomaton/irq.py
new file mode 100644 (file)
index 0000000..823c6f0
--- /dev/null
@@ -0,0 +1,127 @@
+from linuxautomaton import sp, sv
+
+
+class IrqStateProvider(sp.StateProvider):
+    def __init__(self, state):
+        self.state = state
+        self.irq = state.interrupts
+        self.cpus = state.cpus
+        self.tids = state.tids
+        self.irq["hard_count"] = 0
+        self.irq["soft_count"] = 0
+        self.irq["hard-per-cpu"] = {}
+        self.irq["soft-per-cpu"] = {}
+        self.irq["raise-per-cpu"] = {}
+        self.irq["names"] = {}
+        self.irq["hard-irqs"] = {}
+        self.irq["soft-irqs"] = {}
+        self.irq["raise-latency"] = {}
+        self.irq["irq-list"] = []
+        cbs = {
+            'irq_handler_entry': self._process_irq_handler_entry,
+            'irq_handler_exit': self._process_irq_handler_exit,
+            'softirq_entry': self._process_softirq_entry,
+            'softirq_exit': self._process_softirq_exit,
+            'softirq_raise': self._process_softirq_raise,
+        }
+        self._register_cbs(cbs)
+
+    def process_event(self, ev):
+        self._process_event_cb(ev)
+
+    def init_irq(self):
+        irq = {}
+        irq["list"] = []
+        irq["max"] = 0
+        irq["min"] = -1
+        irq["count"] = 0
+        irq["total"] = 0
+        irq["raise_max"] = 0
+        irq["raise_min"] = -1
+        irq["raise_count"] = 0
+        irq["raise_total"] = 0
+        return irq
+
+    def entry(self, event, irqclass, idfield):
+        cpu_id = event["cpu_id"]
+        i = sv.IRQ()
+        i.irqclass = irqclass
+        i.start_ts = event.timestamp
+        i.cpu_id = cpu_id
+        i.nr = event[idfield]
+        return i
+
+    def _process_irq_handler_entry(self, event):
+        cpu_id = event["cpu_id"]
+        self.irq["names"][event["irq"]] = event["name"]
+        self.irq["hard_count"] += 1
+        i = self.entry(event, sv.IRQ.HARD_IRQ, "irq")
+        self.irq["hard-per-cpu"][cpu_id] = i
+
+    def _process_softirq_entry(self, event):
+        cpu_id = event["cpu_id"]
+        self.irq["soft_count"] += 1
+        i = self.entry(event, sv.IRQ.SOFT_IRQ, "vec")
+        self.irq["soft-per-cpu"][cpu_id] = i
+        if cpu_id in self.irq["raise-per-cpu"].keys() and \
+                self.irq["raise-per-cpu"][cpu_id] is not None and \
+                self.irq["raise-per-cpu"][cpu_id][1] == event["vec"]:
+                    i.raise_ts = self.irq["raise-per-cpu"][cpu_id][0]
+                    self.irq["raise-per-cpu"][cpu_id] = None
+
+    def compute_stats(self, irq_entry, i):
+        duration = i.stop_ts - i.start_ts
+        if duration > irq_entry["max"]:
+            irq_entry["max"] = duration
+        if irq_entry["min"] == -1 or duration < irq_entry["min"]:
+            irq_entry["min"] = duration
+        irq_entry["count"] += 1
+        irq_entry["total"] += duration
+        # compute raise latency if applicable
+        if i.raise_ts == -1:
+            return True
+        latency = i.start_ts - i.raise_ts
+        if latency > irq_entry["raise_max"]:
+            irq_entry["raise_max"] = latency
+        if irq_entry["raise_min"] == -1 or latency < irq_entry["raise_min"]:
+            irq_entry["raise_min"] = latency
+        irq_entry["raise_count"] += 1
+        irq_entry["raise_total"] += latency
+        return True
+
+    def exit(self, event, idfield, per_cpu_key, irq_type):
+        cpu_id = event["cpu_id"]
+        if cpu_id not in self.irq[per_cpu_key].keys() or \
+                self.irq[per_cpu_key][cpu_id] is None:
+                    return
+        i = self.irq[per_cpu_key][cpu_id]
+        if i.nr != event[idfield]:
+            self.irq[per_cpu_key][cpu_id] = None
+            return
+        i.stop_ts = event.timestamp
+        if not i.nr in self.irq[irq_type].keys():
+            self.irq[irq_type][i.nr] = self.init_irq()
+
+        # filter out max/min
+        duration = i.stop_ts - i.start_ts
+        if self.state.max and duration > self.state.max * 1000:
+            return False
+        if self.state.min and duration < self.state.min * 1000:
+            return False
+        self.irq[irq_type][i.nr]["list"].append(i)
+        self.compute_stats(self.irq[irq_type][i.nr], i)
+        self.irq["irq-list"].append(i)
+        return i
+
+    def _process_irq_handler_exit(self, event):
+        i = self.exit(event, "irq", "hard-per-cpu", "hard-irqs")
+        if not i:
+            return
+        i.ret = event["ret"]
+
+    def _process_softirq_exit(self, event):
+        self.exit(event, "vec", "soft-per-cpu", "soft-irqs")
+
+    def _process_softirq_raise(self, event):
+        cpu_id = event["cpu_id"]
+        self.irq["raise-per-cpu"][cpu_id] = ((event.timestamp, event["vec"]))
diff --git a/lttnganalyses/lttnganalyses/irq.py b/lttnganalyses/lttnganalyses/irq.py
new file mode 100644 (file)
index 0000000..22d3b84
--- /dev/null
@@ -0,0 +1,9 @@
+from .analysis import Analysis
+
+
+class IrqAnalysis(Analysis):
+    def __init__(self, state):
+        self._state = state
+
+    def process_event(self, ev):
+        pass
index 2aea9b363b1ee150ba7f3fc7f047d670cbfffbc2..4e8ae074ad7667554e9883bbee339bf6296191fa 100644 (file)
@@ -7,10 +7,11 @@ import sys
 
 
 class Command:
-    def __init__(self, add_arguments_cb, enable_proc_filter_args):
+    def __init__(self, add_arguments_cb, enable_proc_filter_args=False,
+                 enable_max_min_args=False):
         self._add_arguments_cb = add_arguments_cb
-        if enable_proc_filter_args:
-            self._enable_proc_filter_args = True
+        self._enable_proc_filter_args = enable_proc_filter_args
+        self._enable_max_min_arg = enable_max_min_args
         self._create_automaton()
 
     def _error(self, msg, exit_code=1):
@@ -63,10 +64,10 @@ class Command:
             self.end_ns = event.timestamp
             self._check_refresh(event, refresh_cb)
             self.trace_end_ts = event.timestamp
-            # feed automaton
-            self._automaton.process_event(event)
             # feed analysis
             self._analysis.process_event(event)
+            # feed automaton
+            self._automaton.process_event(event)
         progressbar.progressbar_finish(self)
 
     def _check_refresh(self, event, refresh_cb):
@@ -84,12 +85,6 @@ class Command:
 
     def _validate_transform_common_args(self, args):
         self._arg_path = args.path
-        self._arg_proc_list = None
-        if args.procname:
-            self._arg_proc_list = args.procname.split(",")
-        self._arg_pid_list = None
-        if args.pid:
-            self._arg_pid_list = args.pid.split(",")
         if args.limit:
             self._arg_limit = args.limit
         self._arg_begin = None
@@ -107,6 +102,24 @@ class Command:
         self._arg_refresh = args.refresh
         self._arg_no_progress = args.no_progress
 
+        if self._enable_proc_filter_args:
+            self._arg_proc_list = None
+            if args.procname:
+                self._arg_proc_list = args.procname.split(",")
+            self._arg_pid_list = None
+            if args.pid:
+                self._arg_pid_list = args.pid.split(",")
+
+        if self._enable_max_min_arg:
+            if args.max == -1:
+                self._arg_max = None
+            else:
+                self._arg_max = args.max
+            if args.min == -1:
+                self._arg_min = None
+            else:
+                self._arg_min = args.min
+
     def _parse_args(self):
         ap = argparse.ArgumentParser(description=self._DESC)
 
@@ -136,6 +149,12 @@ class Command:
                             help='Filter the results only for this list '
                                  'of PIDs')
 
+        if self._enable_max_min_arg:
+            ap.add_argument('--max', type=float, default=-1,
+                            help='Filter out, duration longer than max usec')
+            ap.add_argument('--min', type=float, default=-1,
+                            help='Filter out, duration shorter than min usec')
+
         # specific arguments
         self._add_arguments_cb(ap)
 
index 33dad64e4585efce742ea739bd1942fa61f6caae..078b66f9d4694a23a1fb235214600d33e4d74271 100644 (file)
@@ -10,7 +10,7 @@ class Cputop(Command):
     _DESC = """The cputop command."""
 
     def __init__(self):
-        super().__init__(self._add_arguments, True)
+        super().__init__(self._add_arguments, enable_proc_filter_args=True)
 
     def _validate_transform_args(self):
         pass
diff --git a/lttnganalysescli/lttnganalysescli/irq.py b/lttnganalysescli/lttnganalysescli/irq.py
new file mode 100644 (file)
index 0000000..8f2c677
--- /dev/null
@@ -0,0 +1,274 @@
+from .command import Command
+import lttnganalyses.irq
+from linuxautomaton import common, sv
+from ascii_graph import Pyasciigraph
+import statistics
+
+
+class IrqAnalysis(Command):
+    _VERSION = '0.1.0'
+    _DESC = """The irq command."""
+
+    def __init__(self):
+        super().__init__(self._add_arguments, enable_max_min_args=True)
+
+    def _validate_transform_args(self):
+        self._automaton.state.max = self._arg_max
+        self._automaton.state.min = self._arg_min
+        self._arg_irq_filter_list = None
+        self._arg_softirq_filter_list = None
+        if self._args.irq:
+            self._arg_irq_filter_list = self._args.irq.split(",")
+        if self._args.softirq:
+            self._arg_softirq_filter_list = self._args.softirq.split(",")
+        if self._arg_irq_filter_list is None and \
+                self._arg_softirq_filter_list is None:
+            self._arg_irq_filter_list = []
+            self._arg_softirq_filter_list = []
+        self._arg_freq = self._args.freq
+        self._arg_freq_resolution = self._args.freq_resolution
+        self._arg_log = self._args.log
+
+    def run(self):
+        # parse arguments first
+        self._parse_args()
+        # validate, transform and save specific arguments
+        self._validate_transform_args()
+        # open the trace
+        self._open_trace()
+        # create the appropriate analysis/analyses
+        self._create_analysis()
+        # run the analysis
+        self._run_analysis(self._reset_total, self._refresh)
+        # process the results
+        self._compute_stats()
+        # print results
+        self._print_results(self.start_ns, self.trace_end_ts, final=1)
+        # close the trace
+        self._close_trace()
+
+    def _create_analysis(self):
+        self._analysis = lttnganalyses.irq.IrqAnalysis(self._automaton.state)
+
+    def compute_stdev(self, irq):
+        values = []
+        raise_delays = []
+        stdev = {}
+        for j in irq["list"]:
+            delay = j.stop_ts - j.start_ts
+            values.append(delay)
+            if j.raise_ts == -1:
+                continue
+            # Raise latency (only for some softirqs)
+            r_d = j.start_ts - j.raise_ts
+            raise_delays.append(r_d)
+        if irq["count"] < 2:
+            stdev["duration"] = "?"
+        else:
+            stdev["duration"] = "%0.03f" % (statistics.stdev(values) / 1000)
+        # format string for the raise if present
+        if irq["raise_count"] >= 2:
+            stdev["raise"] = "%0.03f" % (statistics.stdev(raise_delays)/1000)
+        return stdev
+
+    def irq_list_to_freq(self, irq, _min, _max, res):
+        step = (_max - _min) / res
+        if step == 0:
+            return
+        buckets = []
+        values = []
+        graph = Pyasciigraph()
+        for i in range(res):
+            buckets.append(i * step)
+            values.append(0)
+        for i in irq["list"]:
+            v = (i.stop_ts - i.start_ts) / 1000
+            b = min(int((v-_min)/step), res - 1)
+            values[b] += 1
+        g = []
+        i = 0
+        for v in values:
+            g.append(("%0.03f" % (i * step + _min), v))
+            i += 1
+        for line in graph.graph('Frequency distribution', g, info_before=True):
+            print(line)
+        print("")
+
+    # FIXME: there must be a way to make that more complicated/ugly
+    def filter_irq(self, i):
+        if i.irqclass == sv.IRQ.HARD_IRQ:
+            if self._arg_irq_filter_list is not None:
+                if len(self._arg_irq_filter_list) > 0 and \
+                        str(i.nr) not in self._arg_irq_filter_list:
+                    return False
+                else:
+                    return True
+            if self._arg_softirq_filter_list is not None and \
+                    len(self._arg_softirq_filter_list) > 0:
+                return False
+        else:
+            if self._arg_softirq_filter_list is not None:
+                if len(self._arg_softirq_filter_list) > 0 and \
+                        str(i.nr) not in self._arg_softirq_filter_list:
+                    return False
+                else:
+                    return True
+            if self._arg_irq_filter_list is not None and \
+                    len(self._arg_irq_filter_list) > 0:
+                return False
+        raise Exception("WTF")
+
+    def log_irq(self):
+        fmt = "[{:<18}, {:<18}] {:>15} {:>4}  {:<9} {:>4}  {:<22}"
+        title_fmt = "{:<20} {:<19} {:>15} {:>4}  {:<9} {:>4}  {:<22}"
+        print(title_fmt.format("Begin", "End", "Duration (us)", "CPU",
+                               "Type", "#", "Name"))
+        for i in self.state.interrupts["irq-list"]:
+            if not self.filter_irq(i):
+                continue
+            if i.irqclass == sv.IRQ.HARD_IRQ:
+                name = self.state.interrupts["names"][i.nr]
+                irqtype = "IRQ"
+            else:
+                name = sv.IRQ.soft_names[i.nr]
+                irqtype = "SoftIRQ"
+            if i.raise_ts != -1:
+                raise_ts = " (raised at %s)" % \
+                           (common.ns_to_hour_nsec(i.raise_ts,
+                                                   self._arg_multi_day,
+                                                   self._arg_gmt))
+            else:
+                raise_ts = ""
+            print(fmt.format(common.ns_to_hour_nsec(i.start_ts,
+                                                    self._arg_multi_day,
+                                                    self._arg_gmt),
+                             common.ns_to_hour_nsec(i.stop_ts,
+                                                    self._arg_multi_day,
+                                                    self._arg_gmt),
+                             "%0.03f" % ((i.stop_ts - i.start_ts) / 1000),
+                             "%d" % i.cpu_id, irqtype, i.nr, name + raise_ts))
+
+    def print_irq_stats(self, dic, name_table, filter_list, header):
+        header_output = 0
+        for i in sorted(dic.keys()):
+            if len(filter_list) > 0 and str(i) not in filter_list:
+                continue
+            name = name_table[i]
+            stdev = self.compute_stdev(dic[i])
+
+            # format string for the raise if present
+            if dic[i]["raise_count"] < 2:
+                raise_stats = " |"
+            else:
+                r_avg = dic[i]["raise_total"] / (dic[i]["raise_count"] * 1000)
+                raise_stats = " | {:>6} {:>12} {:>12} {:>12} {:>12}".format(
+                    dic[i]["raise_count"],
+                    "%0.03f" % (dic[i]["raise_min"] / 1000),
+                    "%0.03f" % r_avg,
+                    "%0.03f" % (dic[i]["raise_max"] / 1000),
+                    stdev["raise"])
+
+            # final output
+            if dic[i]["count"] == 0:
+                continue
+            avg = "%0.03f" % (dic[i]["total"] / (dic[i]["count"] * 1000))
+            format_str = '{:<3} {:<18} {:>5} {:>12} {:>12} {:>12} ' \
+                         '{:>12} {:<60}'
+            s = format_str.format("%d:" % i, "<%s>" % name, dic[i]["count"],
+                                  "%0.03f" % (dic[i]["min"] / 1000),
+                                  "%s" % (avg),
+                                  "%0.03f" % (dic[i]["max"] / 1000),
+                                  "%s" % (stdev["duration"]),
+                                  raise_stats)
+            if self._arg_freq or header_output == 0:
+                print(header)
+                header_output = 1
+            print(s)
+            if self._arg_freq:
+                self.irq_list_to_freq(dic[i], dic[i]["min"] / 1000,
+                                      dic[i]["max"] / 1000,
+                                      self._arg_freq_resolution)
+
+    def _print_results(self, begin_ns, end_ns, final=0):
+        self.state = self._automaton.state
+        if self._arg_no_progress:
+            clear_screen = ""
+        else:
+            clear_screen = "\r" + self.pbar.term_width * " " + "\r"
+        date = '%s to %s' % (common.ns_to_asctime(begin_ns),
+                             common.ns_to_asctime(end_ns))
+        print(clear_screen + date)
+        if self._arg_irq_filter_list is not None:
+            header = ""
+            header += '{:<52} {:<12}\n'.format("Hard IRQ", "Duration (us)")
+            header += '{:<22} {:<14} {:<12} {:<12} {:<10} ' \
+                      '{:<12}\n'.format("", "count", "min", "avg", "max",
+                                        "stdev")
+            header += ('-'*82 + "|")
+            self.print_irq_stats(self.state.interrupts["hard-irqs"],
+                                 self.state.interrupts["names"],
+                                 self._arg_irq_filter_list, header)
+            print("")
+
+        if self._arg_softirq_filter_list is not None:
+            header = ""
+            header += '{:<52} {:<52} {:<12}\n'.format("Soft IRQ",
+                                                      "Duration (us)",
+                                                      "Raise latency (us)")
+            header += '{:<22} {:<14} {:<12} {:<12} {:<10} {:<4} {:<3} {:<14} '\
+                      '{:<12} {:<12} {:<10} ' \
+                      '{:<12}\n'.format("", "count", "min", "avg", "max",
+                                        "stdev", " |", "count", "min",
+                                        "avg", "max", "stdev")
+            header += '-' * 82 + "|" + '-' * 60
+            self.print_irq_stats(self.state.interrupts["soft-irqs"],
+                                 sv.IRQ.soft_names,
+                                 self._arg_softirq_filter_list,
+                                 header)
+            print("")
+
+        if self._arg_log:
+            self.log_irq()
+
+    def _compute_stats(self):
+        pass
+
+    def _reset_total(self, start_ts):
+        self.state = self._automaton.state
+        self.state.interrupts["hard_count"] = 0
+        self.state.interrupts["soft_count"] = 0
+        self.state.interrupts["irq-list"] = []
+        for i in self.state.interrupts["hard-irqs"].keys():
+            self.state.interrupts["hard-irqs"][i] = self.state.irq.init_irq()
+        for i in self.state.interrupts["soft-irqs"].keys():
+            self.state.interrupts["soft-irqs"][i] = self.state.irq.init_irq()
+
+    def _refresh(self, begin, end):
+        self._compute_stats()
+        self._print_results(begin, end, final=0)
+        self._reset_total(end)
+
+    def _add_arguments(self, ap):
+        ap.add_argument('--irq', type=str, default=0,
+                        help='Show results only for the list of IRQ')
+        ap.add_argument('--softirq', type=str, default=0,
+                        help='Show results only for the list of '
+                             'SoftIRQ')
+        ap.add_argument('--freq', action="store_true",
+                        help='Show the frequency distribution of '
+                             'handler duration')
+        ap.add_argument('--freq-resolution', type=int, default=20,
+                        help='Frequency distribution resolution '
+                             '(default 20)')
+        ap.add_argument('--log', action="store_true",
+                        help='Display the interrupt in the order they '
+                             'were handled')
+
+
+# entry point
+def run():
+    # create command
+    irqcmd = IrqAnalysis()
+
+    # execute command
+    irqcmd.run()
index 95ec077cb27f303b7d5c6f7ca785d7ec31e07f28..3bcf290a74d011b185c62ecbb7df62f94bd4f700 100644 (file)
@@ -7,10 +7,10 @@ import operator
 
 class Memtop(Command):
     _VERSION = '0.1.0'
-    _DESC = """The cputop command."""
+    _DESC = """The memtop command."""
 
     def __init__(self):
-        super().__init__(self._add_arguments, True)
+        super().__init__(self._add_arguments, enable_proc_filter_args=True)
 
     def _validate_transform_args(self):
         pass
This page took 0.03062 seconds and 5 git commands to generate.