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