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