lttnganalyses/cli/irq.py

   1 #!/usr/bin/env python3
   2 #
   3 # The MIT License (MIT)
   4 #
   5 # Copyright (C) 2015 - Julien Desfossez <jdesfossez@efficios.com>
   6 #               2015 - Antoine Busque <abusque@efficios.com>
   7 #
   8 # Permission is hereby granted, free of charge, to any person obtaining a copy
   9 # of this software and associated documentation files (the "Software"), to deal
  10 # in the Software without restriction, including without limitation the rights
  11 # to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
  12 # copies of the Software, and to permit persons to whom the Software is
  13 # furnished to do so, subject to the following conditions:
  14 #
  15 # The above copyright notice and this permission notice shall be included in
  16 # all copies or substantial portions of the Software.
  17 #
  18 # THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
  19 # IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
  20 # FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
  21 # AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
  22 # LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
  23 # OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
  24 # SOFTWARE.
  25
  26 from .command import Command
  27 from ..core import irq as core_irq
  28 from ..linuxautomaton import common, sv
  29 from ..ascii_graph import Pyasciigraph
  30
  31 import math
  32 import statistics
  33
  34
  35 class IrqAnalysisCommand(Command):
  36     _DESC = """The irq command."""
  37
  38     def __init__(self):
  39         super().__init__(self._add_arguments,
  40                          enable_max_min_args=True,
  41                          enable_freq_arg=True,
  42                          enable_log_arg=True,
  43                          enable_stats_arg=True)
  44
  45     def _validate_transform_args(self):
  46         self._arg_irq_filter_list = None
  47         self._arg_softirq_filter_list = None
  48
  49         if self._args.irq:
  50             self._arg_irq_filter_list = self._args.irq.split(',')
  51         if self._args.softirq:
  52             self._arg_softirq_filter_list = self._args.softirq.split(',')
  53
  54     def _default_args(self, stats, log, freq):
  55         if stats:
  56             self._arg_stats = True
  57         if log:
  58             self._arg_log = True
  59         if freq:
  60             self._arg_freq = True
  61
  62     def run(self, stats=False, log=False, freq=False):
  63         # parse arguments first
  64         self._parse_args()
  65         # validate, transform and save specific arguments
  66         self._validate_transform_args()
  67         # handle the default args for different executables
  68         self._default_args(stats, log, freq)
  69         # open the trace
  70         self._open_trace()
  71         # create the appropriate analysis/analyses
  72         self._create_analysis()
  73         # run the analysis
  74         self._run_analysis(self._reset_total, self._refresh)
  75         # print results
  76         self._print_results(self.start_ns, self.trace_end_ts)
  77         # close the trace
  78         self._close_trace()
  79
  80     def run_stats(self):
  81         self.run(stats=True)
  82
  83     def run_log(self):
  84         self.run(log=True)
  85
  86     def run_freq(self):
  87         self.run(freq=True)
  88
  89     def _create_analysis(self):
  90         self._analysis = core_irq.IrqAnalysis(self.state,
  91                                                        self._arg_min,
  92                                                        self._arg_max)
  93
  94     def _compute_duration_stdev(self, irq_stats_item):
  95         if irq_stats_item.count < 2:
  96             return float('nan')
  97
  98         durations = []
  99         for irq in irq_stats_item.irq_list:
 100             durations.append(irq.end_ts - irq.begin_ts)
 101
 102         return statistics.stdev(durations)
 103
 104     def _compute_raise_latency_stdev(self, irq_stats_item):
 105         if irq_stats_item.raise_count < 2:
 106             return float('nan')
 107
 108         raise_latencies = []
 109         for irq in irq_stats_item.irq_list:
 110             if irq.raise_ts is None:
 111                 continue
 112
 113             raise_latencies.append(irq.begin_ts - irq.raise_ts)
 114
 115         return statistics.stdev(raise_latencies)
 116
 117     def _print_frequency_distribution(self, irq_stats_item, id):
 118         # The number of bins for the histogram
 119         resolution = self._arg_freq_resolution
 120
 121         min_duration = irq_stats_item.min_duration
 122         max_duration = irq_stats_item.max_duration
 123         # ns to µs
 124         min_duration /= 1000
 125         max_duration /= 1000
 126
 127         step = (max_duration - min_duration) / resolution
 128         if step == 0:
 129             return
 130
 131         buckets = []
 132         values = []
 133         graph = Pyasciigraph()
 134         for i in range(resolution):
 135             buckets.append(i * step)
 136             values.append(0)
 137         for irq in irq_stats_item.irq_list:
 138             duration = (irq.end_ts - irq.begin_ts) / 1000
 139             index = min(int((duration - min_duration) / step), resolution - 1)
 140             values[index] += 1
 141
 142         graph_data = []
 143         for index, value in enumerate(values):
 144             # The graph data format is a tuple (info, value). Here info
 145             # is the lower bound of the bucket, value the bucket's count
 146             graph_data.append(('%0.03f' % (index * step + min_duration),
 147                                value))
 148
 149         graph_lines = graph.graph(
 150             'Handler duration frequency distribution %s (%s) (usec)' %
 151             (irq_stats_item.name, id),
 152             graph_data,
 153             info_before=True,
 154             count=True
 155         )
 156
 157         for line in graph_lines:
 158             print(line)
 159
 160     def _filter_irq(self, irq):
 161         if type(irq) is sv.HardIRQ:
 162             if self._arg_irq_filter_list:
 163                 return str(irq.id) in self._arg_irq_filter_list
 164             if self._arg_softirq_filter_list:
 165                 return False
 166         else:  # SoftIRQ
 167             if self._arg_softirq_filter_list:
 168                 return str(irq.id) in self._arg_softirq_filter_list
 169             if self._arg_irq_filter_list:
 170                 return False
 171
 172         return True
 173
 174     def _print_irq_log(self):
 175         fmt = '[{:<18}, {:<18}] {:>15} {:>4}  {:<9} {:>4}  {:<22}'
 176         title_fmt = '{:<20} {:<19} {:>15} {:>4}  {:<9} {:>4}  {:<22}'
 177         print(title_fmt.format('Begin', 'End', 'Duration (us)', 'CPU',
 178                                'Type', '#', 'Name'))
 179         for irq in self._analysis.irq_list:
 180             if not self._filter_irq(irq):
 181                 continue
 182
 183             raise_ts = ''
 184             if type(irq) is sv.HardIRQ:
 185                 name = self._analysis.hard_irq_stats[irq.id].name
 186                 irqtype = 'IRQ'
 187             else:
 188                 name = self._analysis.softirq_stats[irq.id].name
 189                 irqtype = 'SoftIRQ'
 190                 if irq.raise_ts is not None:
 191                     raise_ts = ' (raised at %s)' % \
 192                                (common.ns_to_hour_nsec(irq.raise_ts,
 193                                                        self._arg_multi_day,
 194                                                        self._arg_gmt))
 195
 196             print(fmt.format(common.ns_to_hour_nsec(irq.begin_ts,
 197                                                     self._arg_multi_day,
 198                                                     self._arg_gmt),
 199                              common.ns_to_hour_nsec(irq.end_ts,
 200                                                     self._arg_multi_day,
 201                                                     self._arg_gmt),
 202                              '%0.03f' % ((irq.end_ts - irq.begin_ts) / 1000),
 203                              '%d' % irq.cpu_id, irqtype, irq.id,
 204                              name + raise_ts))
 205
 206     def _print_irq_stats(self, irq_stats, filter_list, header):
 207         header_printed = False
 208         for id in sorted(irq_stats):
 209             if filter_list and str(id) not in filter_list:
 210                 continue
 211
 212             irq_stats_item = irq_stats[id]
 213             if irq_stats_item.count == 0:
 214                 continue
 215
 216             if self._arg_stats:
 217                 if self._arg_freq or not header_printed:
 218                     print(header)
 219                     header_printed = True
 220
 221                 if type(irq_stats_item) is core_irq.HardIrqStats:
 222                     self._print_hard_irq_stats_item(irq_stats_item, id)
 223                 else:
 224                     self._print_soft_irq_stats_item(irq_stats_item, id)
 225
 226             if self._arg_freq:
 227                 self._print_frequency_distribution(irq_stats_item, id)
 228
 229         print()
 230
 231     def _print_hard_irq_stats_item(self, irq_stats_item, id):
 232         output_str = self._get_duration_stats_str(irq_stats_item, id)
 233         print(output_str)
 234
 235     def _print_soft_irq_stats_item(self, irq_stats_item, id):
 236         output_str = self._get_duration_stats_str(irq_stats_item, id)
 237         if irq_stats_item.raise_count != 0:
 238             output_str += self._get_raise_latency_str(irq_stats_item, id)
 239
 240         print(output_str)
 241
 242     def _get_duration_stats_str(self, irq_stats_item, id):
 243         format_str = '{:<3} {:<18} {:>5} {:>12} {:>12} {:>12} {:>12} {:<2}'
 244
 245         avg_duration = irq_stats_item.total_duration / irq_stats_item.count
 246         duration_stdev = self._compute_duration_stdev(irq_stats_item)
 247         min_duration = irq_stats_item.min_duration
 248         max_duration = irq_stats_item.max_duration
 249         # ns to µs
 250         avg_duration /= 1000
 251         duration_stdev /= 1000
 252         min_duration /= 1000
 253         max_duration /= 1000
 254
 255         if math.isnan(duration_stdev):
 256             duration_stdev_str = '?'
 257         else:
 258             duration_stdev_str = '%0.03f' % duration_stdev
 259
 260         output_str = format_str.format('%d:' % id,
 261                                        '<%s>' % irq_stats_item.name,
 262                                        '%d' % irq_stats_item.count,
 263                                        '%0.03f' % min_duration,
 264                                        '%0.03f' % avg_duration,
 265                                        '%0.03f' % max_duration,
 266                                        '%s' % duration_stdev_str,
 267                                        ' |')
 268         return output_str
 269
 270     def _get_raise_latency_str(self, irq_stats_item, id):
 271         format_str = ' {:>6} {:>12} {:>12} {:>12} {:>12}'
 272
 273         avg_raise_latency = (irq_stats_item.total_raise_latency /
 274                              irq_stats_item.raise_count)
 275         raise_latency_stdev = self._compute_raise_latency_stdev(irq_stats_item)
 276         min_raise_latency = irq_stats_item.min_raise_latency
 277         max_raise_latency = irq_stats_item.max_raise_latency
 278         # ns to µs
 279         avg_raise_latency /= 1000
 280         raise_latency_stdev /= 1000
 281         min_raise_latency /= 1000
 282         max_raise_latency /= 1000
 283
 284         if math.isnan(raise_latency_stdev):
 285             raise_latency_stdev_str = '?'
 286         else:
 287             raise_latency_stdev_str = '%0.03f' % raise_latency_stdev
 288
 289         output_str = format_str.format(irq_stats_item.raise_count,
 290                                        '%0.03f' % min_raise_latency,
 291                                        '%0.03f' % avg_raise_latency,
 292                                        '%0.03f' % max_raise_latency,
 293                                        '%s' % raise_latency_stdev_str)
 294         return output_str
 295
 296     def _print_results(self, begin_ns, end_ns):
 297         if self._arg_stats or self._arg_freq:
 298             self._print_stats(begin_ns, end_ns)
 299         if self._arg_log:
 300             self._print_irq_log()
 301
 302     def _print_stats(self, begin_ns, end_ns):
 303         self._print_date(begin_ns, end_ns)
 304
 305         if self._arg_irq_filter_list is not None or \
 306            self._arg_softirq_filter_list is None:
 307             header_format = '{:<52} {:<12}\n' \
 308                             '{:<22} {:<14} {:<12} {:<12} {:<10} {:<12}\n'
 309             header = header_format.format(
 310                 'Hard IRQ', 'Duration (us)',
 311                 '', 'count', 'min', 'avg', 'max', 'stdev'
 312             )
 313             header += ('-' * 82 + '|')
 314             self._print_irq_stats(self._analysis.hard_irq_stats,
 315                                   self._arg_irq_filter_list,
 316                                   header)
 317
 318         if self._arg_softirq_filter_list is not None or \
 319            self._arg_irq_filter_list is None:
 320             header_format = '{:<52} {:<52} {:<12}\n' \
 321                             '{:<22} {:<14} {:<12} {:<12} {:<10} {:<4} ' \
 322                             '{:<3} {:<14} {:<12} {:<12} {:<10} {:<12}\n'
 323             header = header_format.format(
 324                 'Soft IRQ', 'Duration (us)',
 325                 'Raise latency (us)', '',
 326                 'count', 'min', 'avg', 'max', 'stdev', ' |',
 327                 'count', 'min', 'avg', 'max', 'stdev'
 328             )
 329             header += '-' * 82 + '|' + '-' * 60
 330             self._print_irq_stats(self._analysis.softirq_stats,
 331                                   self._arg_softirq_filter_list,
 332                                   header)
 333
 334     def _reset_total(self, start_ts):
 335         self._analysis.reset()
 336
 337     def _refresh(self, begin, end):
 338         self._print_results(begin, end)
 339         self._reset_total(end)
 340
 341     def _add_arguments(self, ap):
 342         ap.add_argument('--irq', type=str, default=None,
 343                         help='Show results only for the list of IRQ')
 344         ap.add_argument('--softirq', type=str, default=None,
 345                         help='Show results only for the list of '
 346                              'SoftIRQ')
 347
 348
 349 # entry point
 350 def runstats():
 351     # create command
 352     irqcmd = IrqAnalysisCommand()
 353     # execute command
 354     irqcmd.run_stats()
 355
 356
 357 def runlog():
 358     # create command
 359     irqcmd = IrqAnalysisCommand()
 360     # execute command
 361     irqcmd.run_log()
 362
 363
 364 def runfreq():
 365     # create command
 366     irqcmd = IrqAnalysisCommand()
 367     # execute command
 368     irqcmd.run_freq()