Commit | Line | Data |
---|---|---|
b9f05f8d AB |
1 | # The MIT License (MIT) |
2 | # | |
3 | # Copyright (C) 2015 - Julien Desfossez <jdesfossez@efficios.com> | |
4 | # 2015 - Antoine Busque <abusque@efficios.com> | |
5 | # | |
6 | # Permission is hereby granted, free of charge, to any person obtaining a copy | |
7 | # of this software and associated documentation files (the "Software"), to deal | |
8 | # in the Software without restriction, including without limitation the rights | |
9 | # to use, copy, modify, merge, publish, distribute, sublicense, and/or sell | |
10 | # copies of the Software, and to permit persons to whom the Software is | |
11 | # furnished to do so, subject to the following conditions: | |
12 | # | |
13 | # The above copyright notice and this permission notice shall be included in | |
14 | # all copies or substantial portions of the Software. | |
15 | # | |
16 | # THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR | |
17 | # IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, | |
18 | # FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE | |
19 | # AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER | |
20 | # LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, | |
21 | # OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE | |
22 | # SOFTWARE. | |
23 | ||
2f52d0c9 | 24 | import sys |
b9f05f8d AB |
25 | import math |
26 | import operator | |
27 | import statistics | |
dbbdd963 | 28 | import collections |
2f52d0c9 AB |
29 | from . import mi |
30 | from ..core import sched | |
31 | from .command import Command | |
32 | from ..linuxautomaton import common | |
33 | from ..ascii_graph import Pyasciigraph | |
b9f05f8d AB |
34 | |
35 | ||
dbbdd963 PP |
36 | _SchedStats = collections.namedtuple('_SchedStats', [ |
37 | 'count', | |
38 | 'min', | |
39 | 'max', | |
40 | 'stdev', | |
41 | 'total', | |
42 | ]) | |
43 | ||
44 | ||
b9f05f8d AB |
45 | class SchedAnalysisCommand(Command): |
46 | _DESC = """The sched command.""" | |
47 | _ANALYSIS_CLASS = sched.SchedAnalysis | |
48 | _MI_TITLE = 'Scheduling latencies analysis' | |
49 | _MI_DESCRIPTION = \ | |
50 | 'Scheduling latencies frequency distribution, statistics, top, and log' | |
51 | _MI_TAGS = [mi.Tags.SCHED, mi.Tags.STATS, mi.Tags.FREQ, mi.Tags.TOP, | |
52 | mi.Tags.LOG] | |
53 | _MI_TABLE_CLASS_LOG = 'log' | |
54 | _MI_TABLE_CLASS_TOP = 'top' | |
55 | _MI_TABLE_CLASS_TOTAL_STATS = 'total_stats' | |
56 | _MI_TABLE_CLASS_PER_TID_STATS = 'per_tid_stats' | |
57 | _MI_TABLE_CLASS_PER_PRIO_STATS = 'per_prio_stats' | |
dbbdd963 | 58 | _MI_TABLE_CLASS_FREQ = 'freq' |
b9f05f8d AB |
59 | # _MI_TABLE_CLASS_SUMMARY = 'summary' |
60 | _MI_TABLE_CLASSES = [ | |
61 | ( | |
62 | _MI_TABLE_CLASS_LOG, | |
dbbdd963 | 63 | 'Scheduling log', [ |
b9f05f8d AB |
64 | ('wakeup_ts', 'Wakeup timestamp', mi.Timestamp), |
65 | ('switch_ts', 'Switch timestamp', mi.Timestamp), | |
66 | ('latency', 'Scheduling latency', mi.Duration), | |
67 | ('prio', 'Priority', mi.Integer), | |
fdd1ffc9 | 68 | ('target_cpu', 'Target CPU', mi.Integer), |
b9f05f8d AB |
69 | ('wakee_proc', 'Wakee process', mi.Process), |
70 | ('waker_proc', 'Waker process', mi.Process), | |
71 | ] | |
72 | ), | |
73 | ( | |
74 | _MI_TABLE_CLASS_TOP, | |
dbbdd963 | 75 | 'Scheduling top', [ |
b9f05f8d AB |
76 | ('wakeup_ts', 'Wakeup timestamp', mi.Timestamp), |
77 | ('switch_ts', 'Switch timestamp', mi.Timestamp), | |
78 | ('latency', 'Scheduling latency', mi.Duration), | |
79 | ('prio', 'Priority', mi.Integer), | |
fdd1ffc9 | 80 | ('target_cpu', 'Target CPU', mi.Integer), |
b9f05f8d AB |
81 | ('wakee_proc', 'Wakee process', mi.Process), |
82 | ('waker_proc', 'Waker process', mi.Process), | |
83 | ] | |
84 | ), | |
85 | ( | |
86 | _MI_TABLE_CLASS_TOTAL_STATS, | |
dbbdd963 PP |
87 | 'Scheduling latency stats (total)', [ |
88 | ('count', 'Scheduling count', mi.Integer, 'schedulings'), | |
b9f05f8d AB |
89 | ('min_latency', 'Minimum latency', mi.Duration), |
90 | ('avg_latency', 'Average latency', mi.Duration), | |
91 | ('max_latency', 'Maximum latency', mi.Duration), | |
92 | ('stdev_latency', 'Scheduling latency standard deviation', | |
93 | mi.Duration), | |
94 | ] | |
95 | ), | |
96 | ( | |
97 | _MI_TABLE_CLASS_PER_TID_STATS, | |
dbbdd963 | 98 | 'Scheduling latency stats (per-TID)', [ |
b9f05f8d | 99 | ('process', 'Wakee process', mi.Process), |
dbbdd963 | 100 | ('count', 'Scheduling count', mi.Integer, 'schedulings'), |
b9f05f8d AB |
101 | ('min_latency', 'Minimum latency', mi.Duration), |
102 | ('avg_latency', 'Average latency', mi.Duration), | |
103 | ('max_latency', 'Maximum latency', mi.Duration), | |
104 | ('stdev_latency', 'Scheduling latency standard deviation', | |
105 | mi.Duration), | |
106 | ] | |
107 | ), | |
108 | ( | |
109 | _MI_TABLE_CLASS_PER_PRIO_STATS, | |
dbbdd963 | 110 | 'Scheduling latency stats (per-prio)', [ |
b9f05f8d | 111 | ('prio', 'Priority', mi.Integer), |
dbbdd963 | 112 | ('count', 'Scheduling count', mi.Integer, 'schedulings'), |
b9f05f8d AB |
113 | ('min_latency', 'Minimum latency', mi.Duration), |
114 | ('avg_latency', 'Average latency', mi.Duration), | |
115 | ('max_latency', 'Maximum latency', mi.Duration), | |
116 | ('stdev_latency', 'Scheduling latency standard deviation', | |
117 | mi.Duration), | |
118 | ] | |
119 | ), | |
dbbdd963 PP |
120 | ( |
121 | _MI_TABLE_CLASS_FREQ, | |
122 | 'Scheduling latency frequency distribution', [ | |
123 | ('duration_lower', 'Duration (lower bound)', mi.Duration), | |
124 | ('duration_upper', 'Duration (upper bound)', mi.Duration), | |
125 | ('count', 'Scheduling count', mi.Integer, 'schedulings'), | |
126 | ] | |
127 | ), | |
b9f05f8d AB |
128 | ] |
129 | ||
130 | def _analysis_tick(self, begin_ns, end_ns): | |
131 | log_table = None | |
132 | top_table = None | |
133 | total_stats_table = None | |
134 | per_tid_stats_table = None | |
135 | per_prio_stats_table = None | |
2f52d0c9 AB |
136 | total_freq_tables = None |
137 | per_tid_freq_tables = None | |
138 | per_prio_freq_tables = None | |
b9f05f8d AB |
139 | |
140 | if self._args.log: | |
141 | log_table = self._get_log_result_table(begin_ns, end_ns) | |
142 | ||
143 | if self._args.top: | |
144 | top_table = self._get_top_result_table(begin_ns, end_ns) | |
145 | ||
146 | if self._args.stats: | |
147 | if self._args.total: | |
148 | total_stats_table = self._get_total_stats_result_table( | |
149 | begin_ns, end_ns) | |
150 | ||
151 | if self._args.per_tid: | |
152 | per_tid_stats_table = self._get_per_tid_stats_result_table( | |
153 | begin_ns, end_ns) | |
154 | ||
155 | if self._args.per_prio: | |
156 | per_prio_stats_table = self._get_per_prio_stats_result_table( | |
157 | begin_ns, end_ns) | |
158 | ||
dbbdd963 | 159 | if self._args.freq: |
2f52d0c9 AB |
160 | if self._args.total: |
161 | total_freq_tables = self._get_total_freq_result_tables( | |
162 | begin_ns, end_ns) | |
163 | ||
164 | if self._args.per_tid: | |
165 | per_tid_freq_tables = self._get_per_tid_freq_result_tables( | |
166 | begin_ns, end_ns) | |
167 | ||
dbbdd963 | 168 | if self._args.per_prio: |
2f52d0c9 AB |
169 | per_prio_freq_tables = self._get_per_prio_freq_result_tables( |
170 | begin_ns, end_ns) | |
dbbdd963 | 171 | |
b9f05f8d AB |
172 | if self._mi_mode: |
173 | if log_table: | |
174 | self._mi_append_result_table(log_table) | |
175 | ||
176 | if top_table: | |
177 | self._mi_append_result_table(top_table) | |
178 | ||
179 | if total_stats_table and total_stats_table.rows: | |
180 | self._mi_append_result_table(total_stats_table) | |
181 | ||
182 | if per_tid_stats_table and per_tid_stats_table.rows: | |
183 | self._mi_append_result_table(per_tid_stats_table) | |
184 | ||
185 | if per_prio_stats_table and per_prio_stats_table.rows: | |
186 | self._mi_append_result_table(per_prio_stats_table) | |
dbbdd963 PP |
187 | |
188 | if self._args.freq_series: | |
2f52d0c9 AB |
189 | if total_freq_tables: |
190 | self._mi_append_result_tables(total_freq_tables) | |
dbbdd963 | 191 | |
2f52d0c9 AB |
192 | if per_tid_freq_tables: |
193 | per_tid_freq_tables = [ | |
194 | self._get_per_tid_freq_series_table( | |
195 | per_tid_freq_tables) | |
196 | ] | |
197 | ||
198 | self._mi_append_result_tables(per_tid_freq_tables) | |
199 | ||
200 | if per_prio_freq_tables: | |
201 | per_prio_freq_tables = [ | |
202 | self._get_per_prio_freq_series_table( | |
203 | per_prio_freq_tables) | |
204 | ] | |
205 | ||
206 | self._mi_append_result_tables(per_prio_freq_tables) | |
b9f05f8d AB |
207 | else: |
208 | self._print_date(begin_ns, end_ns) | |
209 | ||
210 | if self._args.stats: | |
211 | if total_stats_table: | |
212 | self._print_total_stats(total_stats_table) | |
213 | if per_tid_stats_table: | |
214 | self._print_per_tid_stats(per_tid_stats_table) | |
215 | if per_prio_stats_table: | |
216 | self._print_per_prio_stats(per_prio_stats_table) | |
217 | ||
2f52d0c9 AB |
218 | if self._args.freq: |
219 | if total_freq_tables: | |
220 | self._print_freq(total_freq_tables) | |
221 | if per_tid_freq_tables: | |
222 | self._print_freq(per_tid_freq_tables) | |
223 | if per_prio_freq_tables: | |
224 | self._print_freq(per_prio_freq_tables) | |
225 | ||
b9f05f8d AB |
226 | if log_table: |
227 | self._print_sched_events(log_table) | |
228 | ||
229 | if top_table: | |
230 | self._print_sched_events(top_table) | |
231 | ||
2f52d0c9 AB |
232 | def _get_total_sched_lists_stats(self): |
233 | total_list = self._analysis.sched_list | |
234 | stdev = self._compute_sched_latency_stdev(total_list) | |
235 | total_stats = _SchedStats( | |
236 | count=self._analysis.count, | |
237 | min=self._analysis.min_latency, | |
238 | max=self._analysis.max_latency, | |
239 | stdev=stdev, | |
240 | total=self._analysis.total_latency | |
241 | ) | |
242 | ||
243 | return [total_list], total_stats | |
244 | ||
245 | def _get_tid_sched_lists_stats(self): | |
246 | tid_sched_lists = {} | |
247 | tid_stats = {} | |
248 | ||
249 | for sched_event in self._analysis.sched_list: | |
250 | tid = sched_event.wakee_proc.tid | |
251 | if tid not in tid_sched_lists: | |
252 | tid_sched_lists[tid] = [] | |
253 | ||
254 | tid_sched_lists[tid].append(sched_event) | |
255 | ||
256 | for tid in tid_sched_lists: | |
257 | sched_list = tid_sched_lists[tid] | |
258 | ||
259 | if not sched_list: | |
260 | continue | |
261 | ||
262 | stdev = self._compute_sched_latency_stdev(sched_list) | |
263 | latencies = [sched.latency for sched in sched_list] | |
264 | count = len(latencies) | |
265 | min_latency = min(latencies) | |
266 | max_latency = max(latencies) | |
267 | total_latency = sum(latencies) | |
268 | ||
269 | tid_stats[tid] = _SchedStats( | |
270 | count=count, | |
271 | min=min_latency, | |
272 | max=max_latency, | |
273 | stdev=stdev, | |
274 | total=total_latency, | |
275 | ) | |
276 | ||
277 | return tid_sched_lists, tid_stats | |
278 | ||
279 | def _get_prio_sched_lists_stats(self): | |
280 | prio_sched_lists = {} | |
281 | prio_stats = {} | |
282 | ||
283 | for sched_event in self._analysis.sched_list: | |
284 | if sched_event.prio not in prio_sched_lists: | |
285 | prio_sched_lists[sched_event.prio] = [] | |
286 | ||
287 | prio_sched_lists[sched_event.prio].append(sched_event) | |
288 | ||
289 | for prio in prio_sched_lists: | |
290 | sched_list = prio_sched_lists[prio] | |
291 | ||
292 | if not sched_list: | |
293 | continue | |
294 | ||
295 | stdev = self._compute_sched_latency_stdev(sched_list) | |
296 | latencies = [sched.latency for sched in sched_list] | |
297 | count = len(latencies) | |
298 | min_latency = min(latencies) | |
299 | max_latency = max(latencies) | |
300 | total_latency = sum(latencies) | |
301 | ||
302 | prio_stats[prio] = _SchedStats( | |
303 | count=count, | |
304 | min=min_latency, | |
305 | max=max_latency, | |
306 | stdev=stdev, | |
307 | total=total_latency, | |
308 | ) | |
309 | ||
310 | return prio_sched_lists, prio_stats | |
311 | ||
b9f05f8d AB |
312 | def _get_log_result_table(self, begin_ns, end_ns): |
313 | result_table = self._mi_create_result_table(self._MI_TABLE_CLASS_LOG, | |
314 | begin_ns, end_ns) | |
315 | ||
316 | for sched_event in self._analysis.sched_list: | |
317 | wakee_proc = mi.Process(sched_event.wakee_proc.comm, | |
318 | sched_event.wakee_proc.pid, | |
319 | sched_event.wakee_proc.tid) | |
320 | ||
321 | if sched_event.waker_proc: | |
322 | waker_proc = mi.Process(sched_event.waker_proc.comm, | |
323 | sched_event.waker_proc.pid, | |
324 | sched_event.waker_proc.tid) | |
325 | else: | |
326 | waker_proc = mi.Empty() | |
327 | ||
328 | result_table.append_row( | |
329 | wakeup_ts=mi.Timestamp(sched_event.wakeup_ts), | |
330 | switch_ts=mi.Timestamp(sched_event.switch_ts), | |
331 | latency=mi.Duration(sched_event.latency), | |
332 | prio=mi.Integer(sched_event.prio), | |
fdd1ffc9 | 333 | target_cpu=mi.Integer(sched_event.target_cpu), |
b9f05f8d AB |
334 | wakee_proc=wakee_proc, |
335 | waker_proc=waker_proc, | |
336 | ) | |
337 | ||
338 | return result_table | |
339 | ||
340 | def _get_top_result_table(self, begin_ns, end_ns): | |
650e7f57 AB |
341 | result_table = self._mi_create_result_table( |
342 | self._MI_TABLE_CLASS_TOP, begin_ns, end_ns) | |
b9f05f8d AB |
343 | |
344 | top_events = sorted(self._analysis.sched_list, | |
345 | key=operator.attrgetter('latency'), | |
346 | reverse=True) | |
347 | top_events = top_events[:self._args.limit] | |
348 | ||
349 | for sched_event in top_events: | |
350 | wakee_proc = mi.Process(sched_event.wakee_proc.comm, | |
351 | sched_event.wakee_proc.pid, | |
352 | sched_event.wakee_proc.tid) | |
353 | ||
354 | if sched_event.waker_proc: | |
355 | waker_proc = mi.Process(sched_event.waker_proc.comm, | |
356 | sched_event.waker_proc.pid, | |
357 | sched_event.waker_proc.tid) | |
358 | else: | |
359 | waker_proc = mi.Empty() | |
360 | ||
361 | result_table.append_row( | |
362 | wakeup_ts=mi.Timestamp(sched_event.wakeup_ts), | |
363 | switch_ts=mi.Timestamp(sched_event.switch_ts), | |
364 | latency=mi.Duration(sched_event.latency), | |
365 | prio=mi.Integer(sched_event.prio), | |
fdd1ffc9 | 366 | target_cpu=mi.Integer(sched_event.target_cpu), |
b9f05f8d AB |
367 | wakee_proc=wakee_proc, |
368 | waker_proc=waker_proc, | |
369 | ) | |
370 | ||
371 | return result_table | |
372 | ||
373 | def _get_total_stats_result_table(self, begin_ns, end_ns): | |
374 | stats_table = \ | |
375 | self._mi_create_result_table(self._MI_TABLE_CLASS_TOTAL_STATS, | |
376 | begin_ns, end_ns) | |
377 | ||
378 | stdev = self._compute_sched_latency_stdev(self._analysis.sched_list) | |
379 | if math.isnan(stdev): | |
380 | stdev = mi.Unknown() | |
381 | else: | |
382 | stdev = mi.Duration(stdev) | |
383 | ||
384 | stats_table.append_row( | |
385 | count=mi.Integer(self._analysis.count), | |
386 | min_latency=mi.Duration(self._analysis.min_latency), | |
387 | avg_latency=mi.Duration(self._analysis.total_latency / | |
388 | self._analysis.count), | |
389 | max_latency=mi.Duration(self._analysis.max_latency), | |
390 | stdev_latency=stdev, | |
391 | ) | |
392 | ||
393 | return stats_table | |
394 | ||
395 | def _get_per_tid_stats_result_table(self, begin_ns, end_ns): | |
396 | stats_table = \ | |
397 | self._mi_create_result_table(self._MI_TABLE_CLASS_PER_TID_STATS, | |
398 | begin_ns, end_ns) | |
399 | ||
400 | tid_stats_list = sorted(list(self._analysis.tids.values()), | |
401 | key=operator.attrgetter('comm')) | |
402 | ||
403 | for tid_stats in tid_stats_list: | |
404 | if not tid_stats.sched_list: | |
405 | continue | |
406 | ||
407 | stdev = self._compute_sched_latency_stdev(tid_stats.sched_list) | |
408 | if math.isnan(stdev): | |
409 | stdev = mi.Unknown() | |
410 | else: | |
411 | stdev = mi.Duration(stdev) | |
412 | ||
413 | stats_table.append_row( | |
414 | process=mi.Process(tid=tid_stats.tid, name=tid_stats.comm), | |
415 | count=mi.Integer(tid_stats.count), | |
416 | min_latency=mi.Duration(tid_stats.min_latency), | |
417 | avg_latency=mi.Duration(tid_stats.total_latency / | |
418 | tid_stats.count), | |
419 | max_latency=mi.Duration(tid_stats.max_latency), | |
420 | stdev_latency=stdev, | |
421 | ) | |
422 | ||
423 | return stats_table | |
424 | ||
dbbdd963 PP |
425 | def _get_per_prio_stats_result_table(self, begin_ns, end_ns): |
426 | stats_table = \ | |
427 | self._mi_create_result_table(self._MI_TABLE_CLASS_PER_PRIO_STATS, | |
428 | begin_ns, end_ns) | |
429 | ||
c7630e44 | 430 | _, prio_stats = self._get_prio_sched_lists_stats() |
dbbdd963 PP |
431 | |
432 | for prio in sorted(prio_stats): | |
433 | stats = prio_stats[prio] | |
434 | stdev = stats.stdev | |
435 | ||
436 | if math.isnan(stdev): | |
437 | stdev = mi.Unknown() | |
438 | else: | |
439 | stdev = mi.Duration(stdev) | |
440 | ||
441 | count = stats.count | |
442 | min_latency = stats.min | |
443 | max_latency = stats.max | |
444 | total_latency = stats.total | |
445 | ||
b9f05f8d AB |
446 | stats_table.append_row( |
447 | prio=mi.Integer(prio), | |
448 | count=mi.Integer(count), | |
449 | min_latency=mi.Duration(min_latency), | |
450 | avg_latency=mi.Duration(total_latency / count), | |
451 | max_latency=mi.Duration(max_latency), | |
452 | stdev_latency=stdev, | |
453 | ) | |
454 | ||
455 | return stats_table | |
456 | ||
2f52d0c9 AB |
457 | def _get_per_tid_freq_series_table(self, freq_tables): |
458 | if not freq_tables: | |
459 | return | |
460 | ||
461 | column_infos = [ | |
462 | ('duration_lower', 'Duration (lower bound)', mi.Duration), | |
463 | ('duration_upper', 'Duration (upper bound)', mi.Duration), | |
464 | ] | |
465 | ||
466 | for index, freq_table in enumerate(freq_tables): | |
467 | column_infos.append(( | |
468 | 'tid{}'.format(index), | |
469 | freq_table.subtitle, | |
470 | mi.Integer, | |
471 | 'schedulings' | |
472 | )) | |
473 | ||
474 | title = 'Scheduling latencies frequency distributions' | |
475 | table_class = mi.TableClass(None, title, column_infos) | |
476 | begin = freq_tables[0].timerange.begin | |
477 | end = freq_tables[0].timerange.end | |
478 | result_table = mi.ResultTable(table_class, begin, end) | |
479 | ||
480 | for row_index, freq0_row in enumerate(freq_tables[0].rows): | |
481 | row_tuple = [ | |
482 | freq0_row.duration_lower, | |
483 | freq0_row.duration_upper, | |
484 | ] | |
485 | ||
486 | for freq_table in freq_tables: | |
487 | freq_row = freq_table.rows[row_index] | |
488 | row_tuple.append(freq_row.count) | |
489 | ||
490 | result_table.append_row_tuple(tuple(row_tuple)) | |
491 | ||
492 | return result_table | |
493 | ||
dbbdd963 PP |
494 | def _get_per_prio_freq_series_table(self, freq_tables): |
495 | if not freq_tables: | |
496 | return | |
497 | ||
498 | column_infos = [ | |
499 | ('duration_lower', 'Duration (lower bound)', mi.Duration), | |
500 | ('duration_upper', 'Duration (upper bound)', mi.Duration), | |
501 | ] | |
502 | ||
503 | for index, freq_table in enumerate(freq_tables): | |
504 | column_infos.append(( | |
505 | 'prio{}'.format(index), | |
506 | freq_table.subtitle, | |
507 | mi.Integer, | |
508 | 'schedulings' | |
509 | )) | |
510 | ||
511 | title = 'Scheduling latencies frequency distributions' | |
512 | table_class = mi.TableClass(None, title, column_infos) | |
513 | begin = freq_tables[0].timerange.begin | |
514 | end = freq_tables[0].timerange.end | |
515 | result_table = mi.ResultTable(table_class, begin, end) | |
516 | ||
517 | for row_index, freq0_row in enumerate(freq_tables[0].rows): | |
518 | row_tuple = [ | |
519 | freq0_row.duration_lower, | |
520 | freq0_row.duration_upper, | |
521 | ] | |
522 | ||
523 | for freq_table in freq_tables: | |
524 | freq_row = freq_table.rows[row_index] | |
525 | row_tuple.append(freq_row.count) | |
526 | ||
527 | result_table.append_row_tuple(tuple(row_tuple)) | |
528 | ||
529 | return result_table | |
530 | ||
531 | def _fill_freq_result_table(self, sched_list, stats, min_duration, | |
532 | max_duration, step, freq_table): | |
533 | # The number of bins for the histogram | |
534 | resolution = self._args.freq_resolution | |
535 | ||
536 | if not self._args.freq_uniform: | |
537 | if self._args.min is not None: | |
538 | min_duration = self._args.min | |
539 | else: | |
540 | min_duration = stats.min | |
541 | ||
542 | if self._args.max is not None: | |
543 | max_duration = self._args.max | |
544 | else: | |
545 | max_duration = stats.max | |
546 | ||
547 | # ns to µs | |
548 | min_duration /= 1000 | |
549 | max_duration /= 1000 | |
550 | ||
551 | step = (max_duration - min_duration) / resolution | |
552 | ||
553 | if step == 0: | |
554 | return | |
555 | ||
556 | buckets = [] | |
557 | counts = [] | |
558 | ||
559 | for i in range(resolution): | |
560 | buckets.append(i * step) | |
561 | counts.append(0) | |
562 | ||
c7630e44 AB |
563 | for sched_event in sched_list: |
564 | duration = sched_event.latency / 1000 | |
dbbdd963 PP |
565 | index = int((duration - min_duration) / step) |
566 | ||
567 | if index >= resolution: | |
568 | # special case for max value: put in last bucket (includes | |
569 | # its upper bound) | |
570 | if duration == max_duration: | |
571 | counts[index - 1] += 1 | |
572 | ||
573 | continue | |
574 | ||
575 | counts[index] += 1 | |
576 | ||
577 | for index, count in enumerate(counts): | |
578 | lower_bound = index * step + min_duration | |
579 | upper_bound = (index + 1) * step + min_duration | |
580 | freq_table.append_row( | |
581 | duration_lower=mi.Duration.from_us(lower_bound), | |
582 | duration_upper=mi.Duration.from_us(upper_bound), | |
583 | count=mi.Integer(count), | |
584 | ) | |
585 | ||
2f52d0c9 AB |
586 | def _get_total_freq_result_tables(self, begin_ns, end_ns): |
587 | freq_tables = [] | |
588 | sched_lists, sched_stats = self._get_total_sched_lists_stats() | |
589 | min_duration = None | |
590 | max_duration = None | |
591 | step = None | |
592 | ||
593 | if self._args.freq_uniform: | |
594 | latencies = [] | |
595 | ||
596 | for sched_list in sched_lists: | |
597 | latencies += [sched.latency for sched in sched_list] | |
598 | ||
599 | min_duration, max_duration, step = \ | |
600 | self._get_uniform_freq_values(latencies) | |
601 | ||
602 | for sched_list in sched_lists: | |
603 | freq_table = \ | |
604 | self._mi_create_result_table(self._MI_TABLE_CLASS_FREQ, | |
605 | begin_ns, end_ns) | |
606 | self._fill_freq_result_table(sched_list, sched_stats, min_duration, | |
607 | max_duration, step, freq_table) | |
608 | freq_tables.append(freq_table) | |
609 | ||
610 | return freq_tables | |
611 | ||
612 | def _get_per_tid_freq_result_tables(self, begin_ns, end_ns): | |
613 | freq_tables = [] | |
614 | tid_sched_lists, tid_stats = self._get_tid_sched_lists_stats() | |
615 | min_duration = None | |
616 | max_duration = None | |
617 | step = None | |
618 | ||
619 | if self._args.freq_uniform: | |
620 | latencies = [] | |
621 | ||
622 | for sched_list in tid_sched_lists.values(): | |
623 | latencies += [sched.latency for sched in sched_list] | |
624 | ||
625 | min_duration, max_duration, step = \ | |
626 | self._get_uniform_freq_values(latencies) | |
627 | ||
628 | for tid in sorted(tid_sched_lists): | |
629 | sched_list = tid_sched_lists[tid] | |
630 | stats = tid_stats[tid] | |
631 | subtitle = 'TID: {}'.format(tid) | |
632 | freq_table = \ | |
633 | self._mi_create_result_table(self._MI_TABLE_CLASS_FREQ, | |
634 | begin_ns, end_ns, subtitle) | |
635 | self._fill_freq_result_table(sched_list, stats, min_duration, | |
636 | max_duration, step, freq_table) | |
637 | freq_tables.append(freq_table) | |
638 | ||
639 | return freq_tables | |
640 | ||
dbbdd963 PP |
641 | def _get_per_prio_freq_result_tables(self, begin_ns, end_ns): |
642 | freq_tables = [] | |
643 | prio_sched_lists, prio_stats = self._get_prio_sched_lists_stats() | |
644 | min_duration = None | |
645 | max_duration = None | |
646 | step = None | |
647 | ||
648 | if self._args.freq_uniform: | |
649 | latencies = [] | |
650 | ||
651 | for sched_list in prio_sched_lists.values(): | |
652 | latencies += [sched.latency for sched in sched_list] | |
653 | ||
654 | min_duration, max_duration, step = \ | |
655 | self._get_uniform_freq_values(latencies) | |
656 | ||
657 | for prio in sorted(prio_sched_lists): | |
658 | sched_list = prio_sched_lists[prio] | |
659 | stats = prio_stats[prio] | |
660 | subtitle = 'Priority: {}'.format(prio) | |
661 | freq_table = \ | |
662 | self._mi_create_result_table(self._MI_TABLE_CLASS_FREQ, | |
663 | begin_ns, end_ns, subtitle) | |
664 | self._fill_freq_result_table(sched_list, stats, min_duration, | |
665 | max_duration, step, freq_table) | |
666 | freq_tables.append(freq_table) | |
667 | ||
668 | return freq_tables | |
669 | ||
b9f05f8d AB |
670 | def _compute_sched_latency_stdev(self, sched_events): |
671 | if len(sched_events) < 2: | |
672 | return float('nan') | |
673 | ||
674 | sched_latencies = [] | |
675 | for sched_event in sched_events: | |
676 | sched_latencies.append(sched_event.latency) | |
677 | ||
678 | return statistics.stdev(sched_latencies) | |
679 | ||
680 | def _ns_to_hour_nsec(self, ts): | |
681 | return common.ns_to_hour_nsec(ts, self._args.multi_day, self._args.gmt) | |
682 | ||
683 | def _print_sched_events(self, result_table): | |
fdd1ffc9 AB |
684 | fmt = '[{:<18}, {:<18}] {:>15} {:>10} {:>3} {:<25} {:<25}' |
685 | title_fmt = '{:<20} {:<19} {:>15} {:>10} {:>3} {:<25} {:<25}' | |
b9f05f8d AB |
686 | print() |
687 | print(result_table.title) | |
688 | print(title_fmt.format('Wakeup', 'Switch', 'Latency (us)', 'Priority', | |
fdd1ffc9 | 689 | 'CPU', 'Wakee', 'Waker')) |
b9f05f8d AB |
690 | for row in result_table.rows: |
691 | wakeup_ts = row.wakeup_ts.value | |
692 | switch_ts = row.switch_ts.value | |
693 | latency = row.latency.value | |
694 | prio = row.prio.value | |
fdd1ffc9 | 695 | target_cpu = row.target_cpu.value |
b9f05f8d AB |
696 | wakee_proc = row.wakee_proc |
697 | waker_proc = row.waker_proc | |
698 | ||
699 | wakee_str = '%s (%d)' % (wakee_proc.name, wakee_proc.tid) | |
700 | if isinstance(waker_proc, mi.Empty): | |
701 | waker_str = 'Unknown (N/A)' | |
702 | else: | |
703 | waker_str = '%s (%d)' % (waker_proc.name, waker_proc.tid) | |
704 | ||
705 | print(fmt.format(self._ns_to_hour_nsec(wakeup_ts), | |
706 | self._ns_to_hour_nsec(switch_ts), | |
707 | '%0.03f' % (latency / 1000), prio, | |
fdd1ffc9 | 708 | target_cpu, wakee_str, waker_str)) |
b9f05f8d AB |
709 | |
710 | def _print_total_stats(self, stats_table): | |
711 | row_format = '{:<12} {:<12} {:<12} {:<12} {:<12}' | |
712 | header = row_format.format( | |
713 | 'Count', 'Min', 'Avg', 'Max', 'Stdev' | |
714 | ) | |
715 | ||
716 | if stats_table.rows: | |
717 | print() | |
718 | print(stats_table.title + ' (us)') | |
719 | print(header) | |
720 | for row in stats_table.rows: | |
721 | if type(row.stdev_latency) is mi.Unknown: | |
722 | stdev_str = '?' | |
723 | else: | |
724 | stdev_str = '%0.03f' % row.stdev_latency.to_us() | |
725 | ||
726 | row_str = row_format.format( | |
727 | '%d' % row.count.value, | |
728 | '%0.03f' % row.min_latency.to_us(), | |
729 | '%0.03f' % row.avg_latency.to_us(), | |
730 | '%0.03f' % row.max_latency.to_us(), | |
731 | '%s' % stdev_str, | |
732 | ) | |
733 | ||
734 | print(row_str) | |
735 | ||
736 | def _print_per_tid_stats(self, stats_table): | |
737 | row_format = '{:<25} {:>8} {:>12} {:>12} {:>12} {:>12}' | |
738 | header = row_format.format( | |
739 | 'Process', 'Count', 'Min', 'Avg', 'Max', 'Stdev' | |
740 | ) | |
741 | ||
742 | if stats_table.rows: | |
743 | print() | |
744 | print(stats_table.title + ' (us)') | |
745 | print(header) | |
746 | for row in stats_table.rows: | |
747 | if type(row.stdev_latency) is mi.Unknown: | |
748 | stdev_str = '?' | |
749 | else: | |
750 | stdev_str = '%0.03f' % row.stdev_latency.to_us() | |
751 | ||
752 | proc = row.process | |
753 | proc_str = '%s (%d)' % (proc.name, proc.tid) | |
754 | ||
755 | row_str = row_format.format( | |
756 | '%s' % proc_str, | |
757 | '%d' % row.count.value, | |
758 | '%0.03f' % row.min_latency.to_us(), | |
759 | '%0.03f' % row.avg_latency.to_us(), | |
760 | '%0.03f' % row.max_latency.to_us(), | |
761 | '%s' % stdev_str, | |
762 | ) | |
763 | ||
764 | print(row_str) | |
765 | ||
766 | def _print_per_prio_stats(self, stats_table): | |
767 | row_format = '{:>4} {:>8} {:>12} {:>12} {:>12} {:>12}' | |
768 | header = row_format.format( | |
769 | 'Prio', 'Count', 'Min', 'Avg', 'Max', 'Stdev' | |
770 | ) | |
771 | ||
772 | if stats_table.rows: | |
773 | print() | |
774 | print(stats_table.title + ' (us)') | |
775 | print(header) | |
776 | for row in stats_table.rows: | |
777 | if type(row.stdev_latency) is mi.Unknown: | |
778 | stdev_str = '?' | |
779 | else: | |
780 | stdev_str = '%0.03f' % row.stdev_latency.to_us() | |
781 | ||
782 | row_str = row_format.format( | |
783 | '%d' % row.prio.value, | |
784 | '%d' % row.count.value, | |
785 | '%0.03f' % row.min_latency.to_us(), | |
786 | '%0.03f' % row.avg_latency.to_us(), | |
787 | '%0.03f' % row.max_latency.to_us(), | |
788 | '%s' % stdev_str, | |
789 | ) | |
790 | ||
791 | print(row_str) | |
792 | ||
2f52d0c9 AB |
793 | def _print_frequency_distribution(self, freq_table): |
794 | graph = Pyasciigraph() | |
795 | graph_data = [] | |
796 | ||
797 | for row in freq_table.rows: | |
798 | # The graph data format is a tuple (info, value). Here info | |
799 | # is the lower bound of the bucket, value the bucket's count | |
800 | lower_bound_us = row.duration_lower.to_us() | |
801 | count = row.count.value | |
802 | ||
803 | graph_data.append(('%0.03f' % lower_bound_us, count)) | |
804 | ||
805 | title_fmt = 'Scheduling latency (µs) frequency distribution - {}' | |
806 | ||
807 | graph_lines = graph.graph( | |
808 | title_fmt.format(freq_table.subtitle), | |
809 | graph_data, | |
810 | info_before=True, | |
811 | count=True | |
812 | ) | |
813 | ||
814 | for line in graph_lines: | |
815 | print(line) | |
816 | ||
817 | def _print_freq(self, freq_tables): | |
818 | for freq_table in freq_tables: | |
819 | if freq_table.rows: | |
820 | print() | |
821 | self._print_frequency_distribution(freq_table) | |
822 | ||
b9f05f8d AB |
823 | def _validate_transform_args(self, args): |
824 | # If neither --total nor --per-prio are specified, default | |
825 | # to --per-tid | |
826 | if not (args.total or args.per_prio): | |
827 | args.per_tid = True | |
828 | ||
829 | def _add_arguments(self, ap): | |
830 | Command._add_min_max_args(ap) | |
43b66dd6 | 831 | Command._add_proc_filter_args(ap) |
b9f05f8d AB |
832 | Command._add_freq_args( |
833 | ap, help='Output the frequency distribution of sched switch ' | |
834 | 'latencies') | |
835 | Command._add_top_args(ap, help='Output the top sched switch latencies') | |
836 | Command._add_log_args( | |
837 | ap, help='Output the sched switches in chronological order') | |
838 | Command._add_stats_args(ap, help='Output sched switch statistics') | |
839 | ap.add_argument('--total', action='store_true', | |
840 | help='Group all results (applies to stats and freq)') | |
841 | ap.add_argument('--per-tid', action='store_true', | |
842 | help='Group results per-TID (applies to stats and ' | |
843 | 'freq) (default)') | |
844 | ap.add_argument('--per-prio', action='store_true', | |
845 | help='Group results per-prio (applies to stats and ' | |
846 | 'freq)') | |
847 | ||
848 | ||
849 | def _run(mi_mode): | |
850 | schedcmd = SchedAnalysisCommand(mi_mode=mi_mode) | |
851 | schedcmd.run() | |
852 | ||
853 | ||
854 | def _runstats(mi_mode): | |
855 | sys.argv.insert(1, '--stats') | |
856 | _run(mi_mode) | |
857 | ||
858 | ||
859 | def _runlog(mi_mode): | |
860 | sys.argv.insert(1, '--log') | |
861 | _run(mi_mode) | |
862 | ||
863 | ||
864 | def _runtop(mi_mode): | |
865 | sys.argv.insert(1, '--top') | |
866 | _run(mi_mode) | |
867 | ||
868 | ||
869 | def _runfreq(mi_mode): | |
870 | sys.argv.insert(1, '--freq') | |
871 | _run(mi_mode) | |
872 | ||
873 | ||
874 | def runstats(): | |
875 | _runstats(mi_mode=False) | |
876 | ||
877 | ||
878 | def runlog(): | |
879 | _runlog(mi_mode=False) | |
880 | ||
881 | ||
882 | def runtop(): | |
883 | _runtop(mi_mode=False) | |
884 | ||
885 | ||
886 | def runfreq(): | |
887 | _runfreq(mi_mode=False) | |
888 | ||
889 | ||
890 | def runstats_mi(): | |
891 | _runstats(mi_mode=True) | |
892 | ||
893 | ||
894 | def runlog_mi(): | |
895 | _runlog(mi_mode=True) | |
896 | ||
897 | ||
898 | def runtop_mi(): | |
899 | _runtop(mi_mode=True) | |
900 | ||
901 | ||
902 | def runfreq_mi(): | |
903 | _runfreq(mi_mode=True) |