Commit | Line | Data |
---|---|---|
4ed24f86 JD |
1 | # The MIT License (MIT) |
2 | # | |
a3fa57c0 | 3 | # Copyright (C) 2015 - Julien Desfossez <jdesfossez@efficios.com> |
6cd52af3 | 4 | # 2015 - Antoine Busque <abusque@efficios.com> |
cee855a2 | 5 | # 2015 - Philippe Proulx <pproulx@efficios.com> |
4ed24f86 JD |
6 | # |
7 | # Permission is hereby granted, free of charge, to any person obtaining a copy | |
8 | # of this software and associated documentation files (the "Software"), to deal | |
9 | # in the Software without restriction, including without limitation the rights | |
10 | # to use, copy, modify, merge, publish, distribute, sublicense, and/or sell | |
11 | # copies of the Software, and to permit persons to whom the Software is | |
12 | # furnished to do so, subject to the following conditions: | |
13 | # | |
14 | # The above copyright notice and this permission notice shall be included in | |
15 | # all copies or substantial portions of the Software. | |
16 | # | |
17 | # THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR | |
18 | # IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, | |
19 | # FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE | |
20 | # AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER | |
21 | # LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, | |
22 | # OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE | |
23 | # SOFTWARE. | |
24 | ||
0b250a71 | 25 | import collections |
a9c9a2a6 JD |
26 | import operator |
27 | import statistics | |
b6d9132b | 28 | import sys |
0b250a71 | 29 | from . import mi |
8400227b | 30 | from . import termgraph |
0b250a71 | 31 | from ..core import io |
8400227b | 32 | from ..common import format_utils |
0b250a71 | 33 | from .command import Command |
a9c9a2a6 JD |
34 | |
35 | ||
a0acc08c PP |
36 | _UsageTables = collections.namedtuple('_UsageTables', [ |
37 | 'per_proc_read', | |
38 | 'per_proc_write', | |
39 | 'per_file_read', | |
40 | 'per_file_write', | |
41 | 'per_proc_block_read', | |
42 | 'per_proc_block_write', | |
43 | 'per_disk_sector', | |
44 | 'per_disk_request', | |
45 | 'per_disk_rtps', | |
46 | 'per_netif_recv', | |
47 | 'per_netif_send', | |
48 | ]) | |
49 | ||
50 | ||
087e5d00 | 51 | class IoAnalysisCommand(Command): |
a9c9a2a6 | 52 | _DESC = """The I/O command.""" |
b6d9132b | 53 | _ANALYSIS_CLASS = io.IoAnalysis |
a0acc08c PP |
54 | _MI_TITLE = 'I/O analysis' |
55 | _MI_DESCRIPTION = 'System call/disk latency statistics, system call ' + \ | |
56 | 'latency distribution, system call top latencies, ' + \ | |
57 | 'I/O usage top, and I/O operations log' | |
58 | _MI_TAGS = [ | |
59 | mi.Tags.IO, | |
60 | mi.Tags.SYSCALL, | |
61 | mi.Tags.STATS, | |
62 | mi.Tags.FREQ, | |
63 | mi.Tags.LOG, | |
64 | mi.Tags.TOP, | |
65 | ] | |
66 | _MI_TABLE_CLASS_SYSCALL_LATENCY_STATS = 'syscall-latency-stats' | |
67 | _MI_TABLE_CLASS_PART_LATENCY_STATS = 'disk-latency-stats' | |
68 | _MI_TABLE_CLASS_FREQ = 'freq' | |
69 | _MI_TABLE_CLASS_TOP_SYSCALL = 'top-syscall' | |
70 | _MI_TABLE_CLASS_LOG = 'log' | |
71 | _MI_TABLE_CLASS_PER_PROCESS_TOP = 'per-process-top' | |
72 | _MI_TABLE_CLASS_PER_FILE_TOP = 'per-file-top' | |
73 | _MI_TABLE_CLASS_PER_PROCESS_TOP_BLOCK = 'per-process-top-block' | |
74 | _MI_TABLE_CLASS_PER_DISK_TOP_SECTOR = 'per-disk-top-sector' | |
75 | _MI_TABLE_CLASS_PER_DISK_TOP_REQUEST = 'per-disk-top-request' | |
76 | _MI_TABLE_CLASS_PER_DISK_TOP_RTPS = 'per-disk-top-rps' | |
77 | _MI_TABLE_CLASS_PER_NETIF_TOP = 'per-netif-top' | |
78 | _MI_TABLE_CLASSES = [ | |
79 | ( | |
80 | _MI_TABLE_CLASS_SYSCALL_LATENCY_STATS, | |
81 | 'System call latency statistics', [ | |
82 | ('obj', 'System call category', mi.String), | |
83 | ('count', 'Call count', mi.Integer, 'calls'), | |
84 | ('min_latency', 'Minimum call latency', mi.Duration), | |
85 | ('avg_latency', 'Average call latency', mi.Duration), | |
86 | ('max_latency', 'Maximum call latency', mi.Duration), | |
650e7f57 AB |
87 | ('stdev_latency', 'System call latency standard deviation', |
88 | mi.Duration), | |
a0acc08c PP |
89 | ] |
90 | ), | |
91 | ( | |
92 | _MI_TABLE_CLASS_PART_LATENCY_STATS, | |
93 | 'Partition latency statistics', [ | |
94 | ('obj', 'Partition', mi.Disk), | |
95 | ('count', 'Access count', mi.Integer, 'accesses'), | |
96 | ('min_latency', 'Minimum access latency', mi.Duration), | |
97 | ('avg_latency', 'Average access latency', mi.Duration), | |
98 | ('max_latency', 'Maximum access latency', mi.Duration), | |
650e7f57 AB |
99 | ('stdev_latency', 'System access latency standard deviation', |
100 | mi.Duration), | |
a0acc08c PP |
101 | ] |
102 | ), | |
103 | ( | |
104 | _MI_TABLE_CLASS_FREQ, | |
105 | 'I/O request latency distribution', [ | |
106 | ('latency_lower', 'Latency (lower bound)', mi.Duration), | |
107 | ('latency_upper', 'Latency (upper bound)', mi.Duration), | |
108 | ('count', 'Request count', mi.Integer, 'requests'), | |
109 | ] | |
110 | ), | |
111 | ( | |
112 | _MI_TABLE_CLASS_TOP_SYSCALL, | |
113 | 'Top system call latencies', [ | |
114 | ('time_range', 'Call time range', mi.TimeRange), | |
115 | ('out_of_range', 'System call out of range?', mi.Boolean), | |
116 | ('duration', 'Call duration', mi.Duration), | |
117 | ('syscall', 'System call', mi.Syscall), | |
118 | ('size', 'Read/write size', mi.Size), | |
119 | ('process', 'Process', mi.Process), | |
120 | ('path', 'File path', mi.Path), | |
121 | ('fd', 'File descriptor', mi.Fd), | |
122 | ] | |
123 | ), | |
124 | ( | |
125 | _MI_TABLE_CLASS_LOG, | |
126 | 'I/O operations log', [ | |
127 | ('time_range', 'Call time range', mi.TimeRange), | |
128 | ('out_of_range', 'System call out of range?', mi.Boolean), | |
129 | ('duration', 'Call duration', mi.Duration), | |
130 | ('syscall', 'System call', mi.Syscall), | |
131 | ('size', 'Read/write size', mi.Size), | |
132 | ('process', 'Process', mi.Process), | |
133 | ('path', 'File path', mi.Path), | |
134 | ('fd', 'File descriptor', mi.Fd), | |
135 | ] | |
136 | ), | |
137 | ( | |
138 | _MI_TABLE_CLASS_PER_PROCESS_TOP, | |
139 | 'Per-process top I/O operations', [ | |
140 | ('process', 'Process', mi.Process), | |
141 | ('size', 'Total operations size', mi.Size), | |
142 | ('disk_size', 'Disk operations size', mi.Size), | |
143 | ('net_size', 'Network operations size', mi.Size), | |
144 | ('unknown_size', 'Unknown operations size', mi.Size), | |
145 | ] | |
146 | ), | |
147 | ( | |
148 | _MI_TABLE_CLASS_PER_FILE_TOP, | |
149 | 'Per-file top I/O operations', [ | |
150 | ('path', 'File path/info', mi.Path), | |
151 | ('size', 'Operations size', mi.Size), | |
152 | ('fd_owners', 'File descriptor owners', mi.String), | |
153 | ] | |
154 | ), | |
155 | ( | |
156 | _MI_TABLE_CLASS_PER_PROCESS_TOP_BLOCK, | |
157 | 'Per-process top block I/O operations', [ | |
158 | ('process', 'Process', mi.Process), | |
159 | ('size', 'Operations size', mi.Size), | |
160 | ] | |
161 | ), | |
162 | ( | |
163 | _MI_TABLE_CLASS_PER_DISK_TOP_SECTOR, | |
164 | 'Per-disk top sector I/O operations', [ | |
165 | ('disk', 'Disk', mi.Disk), | |
166 | ('count', 'Sector count', mi.Integer, 'sectors'), | |
167 | ] | |
168 | ), | |
169 | ( | |
170 | _MI_TABLE_CLASS_PER_DISK_TOP_REQUEST, | |
171 | 'Per-disk top I/O requests', [ | |
172 | ('disk', 'Disk', mi.Disk), | |
173 | ('count', 'Request count', mi.Integer, 'I/O requests'), | |
174 | ] | |
175 | ), | |
176 | ( | |
177 | _MI_TABLE_CLASS_PER_DISK_TOP_RTPS, | |
178 | 'Per-disk top I/O request time/sector', [ | |
179 | ('disk', 'Disk', mi.Disk), | |
180 | ('rtps', 'Request time/sector', mi.Duration), | |
181 | ] | |
182 | ), | |
183 | ( | |
184 | _MI_TABLE_CLASS_PER_NETIF_TOP, | |
185 | 'Per-network interface top I/O operations', [ | |
186 | ('netif', 'Network interface', mi.NetIf), | |
187 | ('size', 'Operations size', mi.Size), | |
188 | ] | |
189 | ), | |
190 | ] | |
ef49c8de AB |
191 | _LATENCY_STATS_FORMAT = '{:<14} {:>14} {:>14} {:>14} {:>14} {:>14}' |
192 | _SECTION_SEPARATOR_STRING = '-' * 89 | |
193 | ||
a0acc08c PP |
194 | def _analysis_tick(self, begin_ns, end_ns): |
195 | syscall_latency_stats_table = None | |
196 | disk_latency_stats_table = None | |
197 | freq_tables = None | |
198 | top_tables = None | |
199 | log_table = None | |
200 | usage_tables = None | |
201 | ||
202 | if self._args.stats: | |
203 | syscall_latency_stats_table, disk_latency_stats_table = \ | |
204 | self._get_latency_stats_result_tables(begin_ns, end_ns) | |
205 | ||
206 | if self._args.freq: | |
207 | freq_tables = self._get_freq_result_tables(begin_ns, end_ns) | |
208 | ||
209 | if self._args.usage: | |
210 | usage_tables = self._get_usage_result_tables(begin_ns, end_ns) | |
211 | ||
212 | if self._args.top: | |
213 | top_tables = self._get_top_result_tables(begin_ns, end_ns) | |
214 | ||
215 | if self._args.log: | |
216 | log_table = self._get_log_result_table(begin_ns, end_ns) | |
217 | ||
218 | if self._mi_mode: | |
219 | self._mi_append_result_tables([ | |
220 | log_table, | |
221 | syscall_latency_stats_table, | |
222 | disk_latency_stats_table, | |
223 | ]) | |
224 | self._mi_append_result_tables(top_tables) | |
225 | self._mi_append_result_tables(usage_tables) | |
226 | self._mi_append_result_tables(freq_tables) | |
227 | else: | |
228 | self._print_date(begin_ns, end_ns) | |
229 | ||
230 | if self._args.usage: | |
231 | self._print_usage(usage_tables) | |
232 | ||
233 | if self._args.stats: | |
234 | self._print_latency_stats(syscall_latency_stats_table, | |
235 | disk_latency_stats_table) | |
236 | ||
237 | if self._args.top: | |
238 | self._print_top(top_tables) | |
239 | ||
240 | if self._args.freq: | |
241 | self._print_freq(freq_tables) | |
242 | ||
243 | if self._args.log: | |
244 | self._print_log(log_table) | |
245 | ||
246 | def _create_summary_result_tables(self): | |
247 | # TODO: create a summary table here | |
248 | self._mi_clear_result_tables() | |
249 | ||
882fcd19 | 250 | # Filter predicates |
882fcd19 AB |
251 | def _filter_size(self, size): |
252 | if size is None: | |
253 | return True | |
b6d9132b | 254 | if self._args.maxsize is not None and size > self._args.maxsize: |
882fcd19 | 255 | return False |
b6d9132b | 256 | if self._args.minsize is not None and size < self._args.minsize: |
882fcd19 AB |
257 | return False |
258 | return True | |
259 | ||
260 | def _filter_latency(self, duration): | |
b6d9132b | 261 | if self._args.max is not None and duration > self._args.max: |
882fcd19 | 262 | return False |
b6d9132b | 263 | if self._args.min is not None and duration < self._args.min: |
882fcd19 AB |
264 | return False |
265 | return True | |
266 | ||
ef49c8de | 267 | def _filter_time_range(self, begin, end): |
b6d9132b AB |
268 | # Note: we only want to return False only when a request has |
269 | # ended and is completely outside the timerange (i.e. begun | |
270 | # after the end of the time range). | |
37df2a09 AB |
271 | return not ( |
272 | self._analysis_conf.begin_ts and self._analysis_conf.end_ts and | |
273 | end and begin > self._analysis_conf.end_ts | |
274 | ) | |
ef49c8de AB |
275 | |
276 | def _filter_io_request(self, io_rq): | |
43b66dd6 | 277 | return self._filter_size(io_rq.size) and \ |
ef49c8de AB |
278 | self._filter_latency(io_rq.duration) and \ |
279 | self._filter_time_range(io_rq.begin_ts, io_rq.end_ts) | |
280 | ||
7e73fe34 | 281 | def _is_io_rq_out_of_range(self, io_rq): |
37df2a09 AB |
282 | return ( |
283 | self._analysis_conf.begin_ts and | |
284 | io_rq.begin_ts < self._analysis_conf.begin_ts or | |
285 | self._analysis_conf.end_ts and | |
286 | io_rq.end_ts > self._analysis_conf.end_ts | |
287 | ) | |
7e73fe34 | 288 | |
a0acc08c | 289 | def _append_per_proc_read_usage_row(self, proc_stats, result_table): |
a0acc08c PP |
290 | result_table.append_row( |
291 | process=mi.Process(proc_stats.comm, pid=proc_stats.pid, | |
292 | tid=proc_stats.tid), | |
293 | size=mi.Size(proc_stats.total_read), | |
f67842f8 AB |
294 | disk_size=mi.Size(proc_stats.disk_io.read), |
295 | net_size=mi.Size(proc_stats.net_io.read), | |
296 | unknown_size=mi.Size(proc_stats.unk_io.read), | |
a0acc08c | 297 | ) |
88cfa546 | 298 | |
a0acc08c | 299 | return True |
88cfa546 | 300 | |
a0acc08c | 301 | def _append_per_proc_write_usage_row(self, proc_stats, result_table): |
a0acc08c PP |
302 | result_table.append_row( |
303 | process=mi.Process(proc_stats.comm, pid=proc_stats.pid, | |
304 | tid=proc_stats.tid), | |
305 | size=mi.Size(proc_stats.total_write), | |
f67842f8 AB |
306 | disk_size=mi.Size(proc_stats.disk_io.write), |
307 | net_size=mi.Size(proc_stats.net_io.write), | |
308 | unknown_size=mi.Size(proc_stats.unk_io.write), | |
a0acc08c | 309 | ) |
91765fd2 | 310 | |
a0acc08c | 311 | return True |
91765fd2 | 312 | |
a0acc08c | 313 | def _append_per_proc_block_read_usage_row(self, proc_stats, result_table): |
f67842f8 | 314 | if proc_stats.block_io.read == 0: |
a0acc08c | 315 | return False |
91765fd2 | 316 | |
a0acc08c PP |
317 | if proc_stats.comm: |
318 | proc_name = proc_stats.comm | |
91765fd2 | 319 | else: |
a0acc08c | 320 | proc_name = None |
91765fd2 | 321 | |
a0acc08c PP |
322 | result_table.append_row( |
323 | process=mi.Process(proc_name, pid=proc_stats.pid, | |
324 | tid=proc_stats.tid), | |
f67842f8 | 325 | size=mi.Size(proc_stats.block_io.read), |
a0acc08c | 326 | ) |
91765fd2 | 327 | |
a0acc08c | 328 | return True |
91765fd2 | 329 | |
a0acc08c | 330 | def _append_per_proc_block_write_usage_row(self, proc_stats, result_table): |
f67842f8 | 331 | if proc_stats.block_io.write == 0: |
a0acc08c | 332 | return False |
91765fd2 | 333 | |
a0acc08c PP |
334 | if proc_stats.comm: |
335 | proc_name = proc_stats.comm | |
91765fd2 | 336 | else: |
a0acc08c | 337 | proc_name = None |
91765fd2 | 338 | |
a0acc08c PP |
339 | result_table.append_row( |
340 | process=mi.Process(proc_name, pid=proc_stats.pid, | |
341 | tid=proc_stats.tid), | |
f67842f8 | 342 | size=mi.Size(proc_stats.block_io.write), |
a0acc08c | 343 | ) |
91765fd2 | 344 | |
a0acc08c | 345 | return True |
91765fd2 | 346 | |
a0acc08c PP |
347 | def _append_disk_sector_usage_row(self, disk_stats, result_table): |
348 | if disk_stats.total_rq_sectors == 0: | |
91765fd2 AB |
349 | return None |
350 | ||
a0acc08c PP |
351 | result_table.append_row( |
352 | disk=mi.Disk(disk_stats.disk_name), | |
353 | count=mi.Integer(disk_stats.total_rq_sectors), | |
354 | ) | |
91765fd2 | 355 | |
a0acc08c | 356 | return True |
91765fd2 | 357 | |
a0acc08c PP |
358 | def _append_disk_request_usage_row(self, disk_stats, result_table): |
359 | if disk_stats.rq_count == 0: | |
360 | return False | |
91765fd2 | 361 | |
a0acc08c PP |
362 | result_table.append_row( |
363 | disk=mi.Disk(disk_stats.disk_name), | |
364 | count=mi.Integer(disk_stats.rq_count), | |
365 | ) | |
91765fd2 | 366 | |
a0acc08c | 367 | return True |
91765fd2 | 368 | |
a0acc08c PP |
369 | def _append_disk_rtps_usage_row(self, disk_stats, result_table): |
370 | if disk_stats.rq_count == 0: | |
371 | return False | |
91765fd2 | 372 | |
a0acc08c PP |
373 | avg_latency = (disk_stats.total_rq_duration / disk_stats.rq_count) |
374 | result_table.append_row( | |
375 | disk=mi.Disk(disk_stats.disk_name), | |
376 | rtps=mi.Duration(avg_latency), | |
377 | ) | |
91765fd2 | 378 | |
a0acc08c | 379 | return True |
91765fd2 | 380 | |
a0acc08c PP |
381 | def _append_netif_recv_usage_row(self, netif_stats, result_table): |
382 | result_table.append_row( | |
383 | netif=mi.NetIf(netif_stats.name), | |
384 | size=mi.Size(netif_stats.recv_bytes) | |
385 | ) | |
91765fd2 | 386 | |
a0acc08c | 387 | return True |
91765fd2 | 388 | |
a0acc08c PP |
389 | def _append_netif_send_usage_row(self, netif_stats, result_table): |
390 | result_table.append_row( | |
391 | netif=mi.NetIf(netif_stats.name), | |
392 | size=mi.Size(netif_stats.sent_bytes) | |
393 | ) | |
91765fd2 | 394 | |
a0acc08c | 395 | return True |
e0e5f1fd | 396 | |
a0acc08c | 397 | def _get_file_stats_fd_owners_str(self, file_stats): |
e0e5f1fd | 398 | fd_by_pid_str = '' |
a0acc08c | 399 | |
e0e5f1fd AB |
400 | for pid, fd in file_stats.fd_by_pid.items(): |
401 | comm = self._analysis.tids[pid].comm | |
402 | fd_by_pid_str += 'fd %d in %s (%s) ' % (fd, comm, pid) | |
403 | ||
a0acc08c PP |
404 | return fd_by_pid_str |
405 | ||
406 | def _append_file_read_usage_row(self, file_stats, result_table): | |
f67842f8 | 407 | if file_stats.io.read == 0: |
a0acc08c | 408 | return False |
e0e5f1fd | 409 | |
a0acc08c PP |
410 | fd_owners = self._get_file_stats_fd_owners_str(file_stats) |
411 | result_table.append_row( | |
412 | path=mi.Path(file_stats.filename), | |
f67842f8 | 413 | size=mi.Size(file_stats.io.read), |
a0acc08c PP |
414 | fd_owners=mi.String(fd_owners), |
415 | ) | |
416 | ||
417 | return True | |
e0e5f1fd | 418 | |
a0acc08c | 419 | def _append_file_write_usage_row(self, file_stats, result_table): |
f67842f8 | 420 | if file_stats.io.write == 0: |
a0acc08c | 421 | return False |
e0e5f1fd | 422 | |
a0acc08c PP |
423 | fd_owners = self._get_file_stats_fd_owners_str(file_stats) |
424 | result_table.append_row( | |
425 | path=mi.Path(file_stats.filename), | |
f67842f8 | 426 | size=mi.Size(file_stats.io.write), |
a0acc08c PP |
427 | fd_owners=mi.String(fd_owners), |
428 | ) | |
e0e5f1fd | 429 | |
a0acc08c | 430 | return True |
e0e5f1fd | 431 | |
650e7f57 AB |
432 | def _fill_usage_result_table(self, input_list, append_row_cb, |
433 | result_table): | |
a0acc08c PP |
434 | count = 0 |
435 | limit = self._args.limit | |
e0e5f1fd | 436 | |
a0acc08c PP |
437 | for elem in input_list: |
438 | if append_row_cb(elem, result_table): | |
439 | count += 1 | |
440 | ||
441 | if limit is not None and count >= limit: | |
442 | break | |
443 | ||
444 | def _fill_per_process_read_usage_result_table(self, result_table): | |
91765fd2 AB |
445 | input_list = sorted(self._analysis.tids.values(), |
446 | key=operator.attrgetter('total_read'), | |
447 | reverse=True) | |
a0acc08c PP |
448 | self._fill_usage_result_table(input_list, |
449 | self._append_per_proc_read_usage_row, | |
450 | result_table) | |
91765fd2 | 451 | |
a0acc08c | 452 | def _fill_per_process_write_usage_result_table(self, result_table): |
91765fd2 AB |
453 | input_list = sorted(self._analysis.tids.values(), |
454 | key=operator.attrgetter('total_write'), | |
455 | reverse=True) | |
a0acc08c PP |
456 | self._fill_usage_result_table(input_list, |
457 | self._append_per_proc_write_usage_row, | |
458 | result_table) | |
91765fd2 | 459 | |
a0acc08c | 460 | def _fill_per_process_block_read_usage_result_table(self, result_table): |
91765fd2 | 461 | input_list = sorted(self._analysis.tids.values(), |
f67842f8 | 462 | key=operator.attrgetter('block_io.read'), |
91765fd2 | 463 | reverse=True) |
650e7f57 AB |
464 | self._fill_usage_result_table( |
465 | input_list, self._append_per_proc_block_read_usage_row, | |
466 | result_table) | |
91765fd2 | 467 | |
a0acc08c | 468 | def _fill_per_process_block_write_usage_result_table(self, result_table): |
91765fd2 | 469 | input_list = sorted(self._analysis.tids.values(), |
f67842f8 | 470 | key=operator.attrgetter('block_io.write'), |
91765fd2 | 471 | reverse=True) |
650e7f57 AB |
472 | self._fill_usage_result_table( |
473 | input_list, self._append_per_proc_block_write_usage_row, | |
474 | result_table) | |
91765fd2 | 475 | |
a0acc08c | 476 | def _fill_disk_sector_usage_result_table(self, result_table): |
91765fd2 AB |
477 | input_list = sorted(self._analysis.disks.values(), |
478 | key=operator.attrgetter('total_rq_sectors'), | |
479 | reverse=True) | |
a0acc08c PP |
480 | self._fill_usage_result_table(input_list, |
481 | self._append_disk_sector_usage_row, | |
482 | result_table) | |
91765fd2 | 483 | |
a0acc08c | 484 | def _fill_disk_request_usage_result_table(self, result_table): |
91765fd2 AB |
485 | input_list = sorted(self._analysis.disks.values(), |
486 | key=operator.attrgetter('rq_count'), | |
487 | reverse=True) | |
a0acc08c PP |
488 | self._fill_usage_result_table(input_list, |
489 | self._append_disk_request_usage_row, | |
490 | result_table) | |
91765fd2 | 491 | |
a0acc08c | 492 | def _fill_disk_rtps_usage_result_table(self, result_table): |
91765fd2 | 493 | input_list = self._analysis.disks.values() |
a0acc08c PP |
494 | self._fill_usage_result_table(input_list, |
495 | self._append_disk_rtps_usage_row, | |
496 | result_table) | |
91765fd2 | 497 | |
a0acc08c | 498 | def _fill_netif_recv_usage_result_table(self, result_table): |
91765fd2 AB |
499 | input_list = sorted(self._analysis.ifaces.values(), |
500 | key=operator.attrgetter('recv_bytes'), | |
501 | reverse=True) | |
a0acc08c PP |
502 | self._fill_usage_result_table(input_list, |
503 | self._append_netif_recv_usage_row, | |
504 | result_table) | |
91765fd2 | 505 | |
a0acc08c | 506 | def _fill_netif_send_usage_result_table(self, result_table): |
91765fd2 AB |
507 | input_list = sorted(self._analysis.ifaces.values(), |
508 | key=operator.attrgetter('sent_bytes'), | |
509 | reverse=True) | |
a0acc08c PP |
510 | self._fill_usage_result_table(input_list, |
511 | self._append_netif_send_usage_row, | |
512 | result_table) | |
91765fd2 | 513 | |
a0acc08c | 514 | def _fill_file_read_usage_result_table(self, files, result_table): |
e0e5f1fd | 515 | input_list = sorted(files.values(), |
f67842f8 | 516 | key=lambda file_stats: file_stats.io.read, |
e0e5f1fd | 517 | reverse=True) |
a0acc08c PP |
518 | self._fill_usage_result_table(input_list, |
519 | self._append_file_read_usage_row, | |
520 | result_table) | |
a9c9a2a6 | 521 | |
a0acc08c | 522 | def _fill_file_write_usage_result_table(self, files, result_table): |
e0e5f1fd | 523 | input_list = sorted(files.values(), |
f67842f8 | 524 | key=lambda file_stats: file_stats.io.write, |
e0e5f1fd | 525 | reverse=True) |
a0acc08c PP |
526 | self._fill_usage_result_table(input_list, |
527 | self._append_file_write_usage_row, | |
528 | result_table) | |
a9c9a2a6 | 529 | |
a0acc08c | 530 | def _fill_file_usage_result_tables(self, read_table, write_table): |
b9f05f8d | 531 | files = self._analysis.get_files_stats() |
a0acc08c PP |
532 | self._fill_file_read_usage_result_table(files, read_table) |
533 | self._fill_file_write_usage_result_table(files, write_table) | |
534 | ||
535 | def _get_usage_result_tables(self, begin, end): | |
536 | # create result tables | |
650e7f57 AB |
537 | per_proc_read_table = self._mi_create_result_table( |
538 | self._MI_TABLE_CLASS_PER_PROCESS_TOP, begin, end, 'read') | |
539 | per_proc_write_table = self._mi_create_result_table( | |
540 | self._MI_TABLE_CLASS_PER_PROCESS_TOP, begin, end, 'written') | |
541 | per_file_read_table = self._mi_create_result_table( | |
542 | self._MI_TABLE_CLASS_PER_FILE_TOP, begin, end, 'read') | |
543 | per_file_write_table = self._mi_create_result_table( | |
544 | self._MI_TABLE_CLASS_PER_FILE_TOP, begin, end, 'written') | |
545 | per_proc_block_read_table = self._mi_create_result_table( | |
546 | self._MI_TABLE_CLASS_PER_PROCESS_TOP_BLOCK, begin, end, 'read') | |
547 | per_proc_block_write_table = self._mi_create_result_table( | |
548 | self._MI_TABLE_CLASS_PER_PROCESS_TOP_BLOCK, begin, end, 'written') | |
549 | per_disk_sector_table = self._mi_create_result_table( | |
550 | self._MI_TABLE_CLASS_PER_DISK_TOP_SECTOR, begin, end) | |
551 | per_disk_request_table = self._mi_create_result_table( | |
552 | self._MI_TABLE_CLASS_PER_DISK_TOP_REQUEST, begin, end) | |
553 | per_disk_rtps_table = self._mi_create_result_table( | |
554 | self._MI_TABLE_CLASS_PER_DISK_TOP_RTPS, begin, end) | |
555 | per_netif_recv_table = self._mi_create_result_table( | |
556 | self._MI_TABLE_CLASS_PER_NETIF_TOP, begin, end, 'received') | |
557 | per_netif_send_table = self._mi_create_result_table( | |
558 | self._MI_TABLE_CLASS_PER_NETIF_TOP, begin, end, 'sent') | |
a0acc08c PP |
559 | |
560 | # fill result tables | |
561 | self._fill_per_process_read_usage_result_table(per_proc_read_table) | |
562 | self._fill_per_process_write_usage_result_table(per_proc_write_table) | |
563 | self._fill_file_usage_result_tables(per_file_read_table, | |
564 | per_file_write_table) | |
650e7f57 AB |
565 | self._fill_per_process_block_read_usage_result_table( |
566 | per_proc_block_read_table) | |
92b29247 | 567 | self._fill_per_process_block_write_usage_result_table( |
650e7f57 | 568 | per_proc_block_write_table) |
a0acc08c PP |
569 | self._fill_disk_sector_usage_result_table(per_disk_sector_table) |
570 | self._fill_disk_request_usage_result_table(per_disk_request_table) | |
571 | self._fill_disk_rtps_usage_result_table(per_disk_rtps_table) | |
572 | self._fill_netif_recv_usage_result_table(per_netif_recv_table) | |
573 | self._fill_netif_send_usage_result_table(per_netif_send_table) | |
574 | ||
575 | return _UsageTables( | |
576 | per_proc_read=per_proc_read_table, | |
577 | per_proc_write=per_proc_write_table, | |
578 | per_file_read=per_file_read_table, | |
579 | per_file_write=per_file_write_table, | |
580 | per_proc_block_read=per_proc_block_read_table, | |
581 | per_proc_block_write=per_proc_block_write_table, | |
582 | per_disk_sector=per_disk_sector_table, | |
583 | per_disk_request=per_disk_request_table, | |
584 | per_disk_rtps=per_disk_rtps_table, | |
585 | per_netif_recv=per_netif_recv_table, | |
586 | per_netif_send=per_netif_send_table, | |
587 | ) | |
588 | ||
8400227b AB |
589 | def _print_per_proc_io(self, result_table, title): |
590 | header_format = '{:<25} {:<10} {:<10} {:<10}' | |
591 | label_header = header_format.format( | |
592 | 'Process', 'Disk', 'Net', 'Unknown' | |
593 | ) | |
a0acc08c | 594 | |
8400227b AB |
595 | def get_label(row): |
596 | label_format = '{:<25} {:>10} {:>10} {:>10}' | |
597 | if row.process.pid is None: | |
598 | pid_str = 'unknown (tid=%d)' % (row.process.tid) | |
599 | else: | |
600 | pid_str = str(row.process.pid) | |
a0acc08c | 601 | |
8400227b AB |
602 | label = label_format.format( |
603 | '%s (%s)' % (row.process.name, pid_str), | |
604 | format_utils.format_size(row.disk_size.value), | |
605 | format_utils.format_size(row.net_size.value), | |
606 | format_utils.format_size(row.unknown_size.value) | |
607 | ) | |
a0acc08c | 608 | |
8400227b | 609 | return label |
a0acc08c | 610 | |
8400227b AB |
611 | graph = termgraph.BarGraph( |
612 | title='Per-process I/O ' + title, | |
613 | label_header=label_header, | |
614 | get_value=lambda row: row.size.value, | |
615 | get_value_str=format_utils.format_size, | |
616 | get_label=get_label, | |
617 | data=result_table.rows | |
618 | ) | |
a0acc08c | 619 | |
8400227b | 620 | graph.print_graph() |
a0acc08c | 621 | |
8400227b AB |
622 | def _print_per_proc_block_io(self, result_table, title): |
623 | def get_label(row): | |
624 | proc_name = row.process.name | |
a0acc08c | 625 | |
8400227b AB |
626 | if not proc_name: |
627 | proc_name = 'unknown' | |
a0acc08c | 628 | |
8400227b AB |
629 | if row.process.pid is None: |
630 | pid_str = 'unknown (tid={})'.format(row.process.tid) | |
631 | else: | |
632 | pid_str = str(row.process.pid) | |
a0acc08c | 633 | |
8400227b | 634 | return '{} (pid={})'.format(proc_name, pid_str) |
a0acc08c | 635 | |
8400227b AB |
636 | graph = termgraph.BarGraph( |
637 | title='Block I/O ' + title, | |
638 | label_header='Process', | |
639 | get_value=lambda row: row.size.value, | |
640 | get_value_str=format_utils.format_size, | |
641 | get_label=get_label, | |
642 | data=result_table.rows | |
643 | ) | |
a0acc08c | 644 | |
8400227b | 645 | graph.print_graph() |
a0acc08c | 646 | |
8400227b AB |
647 | def _print_per_disk_sector(self, result_table): |
648 | graph = termgraph.BarGraph( | |
649 | title='Disk Requests Sector Count', | |
650 | label_header='Disk', | |
651 | unit='sectors', | |
652 | get_value=lambda row: row.count.value, | |
653 | get_label=lambda row: row.disk.name, | |
654 | data=result_table.rows | |
655 | ) | |
a0acc08c | 656 | |
8400227b | 657 | graph.print_graph() |
a0acc08c | 658 | |
8400227b AB |
659 | def _print_per_disk_request(self, result_table): |
660 | graph = termgraph.BarGraph( | |
661 | title='Disk Request Count', | |
662 | label_header='Disk', | |
663 | unit='requests', | |
664 | get_value=lambda row: row.count.value, | |
665 | get_label=lambda row: row.disk.name, | |
666 | data=result_table.rows | |
667 | ) | |
a0acc08c | 668 | |
8400227b | 669 | graph.print_graph() |
a0acc08c | 670 | |
8400227b AB |
671 | def _print_per_disk_rtps(self, result_table): |
672 | graph = termgraph.BarGraph( | |
673 | title='Disk Request Average Latency', | |
674 | label_header='Disk', | |
675 | unit='ms', | |
9079847d | 676 | get_value=lambda row: row.rtps.value / 1000000, |
8400227b AB |
677 | get_label=lambda row: row.disk.name, |
678 | data=result_table.rows | |
679 | ) | |
a0acc08c | 680 | |
8400227b | 681 | graph.print_graph() |
a0acc08c | 682 | |
8400227b AB |
683 | def _print_per_netif_io(self, result_table, title): |
684 | graph = termgraph.BarGraph( | |
685 | title='Network ' + title + ' Bytes', | |
686 | label_header='Interface', | |
687 | get_value=lambda row: row.size.value, | |
688 | get_value_str=format_utils.format_size, | |
689 | get_label=lambda row: row.netif.name, | |
690 | data=result_table.rows | |
691 | ) | |
a0acc08c | 692 | |
8400227b AB |
693 | graph.print_graph() |
694 | ||
695 | def _print_per_file_io(self, result_table, title): | |
696 | # FIXME add option to show FD owners | |
697 | # FIXME why are read and write values the same? | |
698 | graph = termgraph.BarGraph( | |
699 | title='Per-file I/O ' + title, | |
700 | label_header='Path', | |
701 | get_value=lambda row: row.size.value, | |
702 | get_value_str=format_utils.format_size, | |
703 | get_label=lambda row: row.path.path, | |
704 | data=result_table.rows | |
705 | ) | |
a0acc08c | 706 | |
8400227b | 707 | graph.print_graph() |
a0acc08c PP |
708 | |
709 | def _print_usage(self, usage_tables): | |
8400227b AB |
710 | self._print_per_proc_io(usage_tables.per_proc_read, 'Read') |
711 | self._print_per_proc_io(usage_tables.per_proc_write, 'Write') | |
712 | self._print_per_file_io(usage_tables.per_file_read, 'Read') | |
713 | self._print_per_file_io(usage_tables.per_file_write, 'Write') | |
714 | self._print_per_proc_block_io(usage_tables.per_proc_block_read, 'Read') | |
715 | self._print_per_proc_block_io( | |
716 | usage_tables.per_proc_block_write, 'Write' | |
717 | ) | |
a0acc08c PP |
718 | self._print_per_disk_sector(usage_tables.per_disk_sector) |
719 | self._print_per_disk_request(usage_tables.per_disk_request) | |
720 | self._print_per_disk_rtps(usage_tables.per_disk_rtps) | |
8400227b AB |
721 | self._print_per_netif_io(usage_tables.per_netif_recv, 'Received') |
722 | self._print_per_netif_io(usage_tables.per_netif_send, 'Sent') | |
a0acc08c PP |
723 | |
724 | def _fill_freq_result_table(self, duration_list, result_table): | |
9ac03ff5 AB |
725 | if not duration_list: |
726 | return | |
727 | ||
728 | # The number of bins for the histogram | |
b6d9132b | 729 | resolution = self._args.freq_resolution |
9ac03ff5 AB |
730 | |
731 | min_duration = min(duration_list) | |
732 | max_duration = max(duration_list) | |
733 | # ns to µs | |
734 | min_duration /= 1000 | |
735 | max_duration /= 1000 | |
736 | ||
737 | step = (max_duration - min_duration) / resolution | |
a0acc08c | 738 | |
a9c9a2a6 JD |
739 | if step == 0: |
740 | return | |
9ac03ff5 | 741 | |
a9c9a2a6 JD |
742 | buckets = [] |
743 | values = [] | |
a0acc08c | 744 | |
9ac03ff5 | 745 | for i in range(resolution): |
a9c9a2a6 JD |
746 | buckets.append(i * step) |
747 | values.append(0) | |
a0acc08c | 748 | |
9ac03ff5 AB |
749 | for duration in duration_list: |
750 | duration /= 1000 | |
751 | index = min(int((duration - min_duration) / step), resolution - 1) | |
752 | values[index] += 1 | |
753 | ||
9ac03ff5 | 754 | for index, value in enumerate(values): |
a0acc08c PP |
755 | result_table.append_row( |
756 | latency_lower=mi.Duration.from_us(index * step + min_duration), | |
650e7f57 AB |
757 | latency_upper=mi.Duration.from_us((index + 1) * step + |
758 | min_duration), | |
a0acc08c PP |
759 | count=mi.Integer(value), |
760 | ) | |
761 | ||
762 | def _get_disk_freq_result_tables(self, begin, end): | |
763 | result_tables = [] | |
764 | ||
765 | for disk in self._analysis.disks.values(): | |
766 | rq_durations = [rq.duration for rq in disk.rq_list if | |
767 | self._filter_io_request(rq)] | |
768 | subtitle = 'disk: {}'.format(disk.disk_name) | |
769 | result_table = \ | |
770 | self._mi_create_result_table(self._MI_TABLE_CLASS_FREQ, | |
771 | begin, end, subtitle) | |
772 | self._fill_freq_result_table(rq_durations, result_table) | |
773 | result_tables.append(result_table) | |
774 | ||
775 | return result_tables | |
776 | ||
777 | def _get_syscall_freq_result_tables(self, begin, end): | |
778 | open_table = \ | |
779 | self._mi_create_result_table(self._MI_TABLE_CLASS_FREQ, | |
780 | begin, end, 'open') | |
781 | read_table = \ | |
782 | self._mi_create_result_table(self._MI_TABLE_CLASS_FREQ, | |
783 | begin, end, 'read') | |
784 | write_table = \ | |
785 | self._mi_create_result_table(self._MI_TABLE_CLASS_FREQ, | |
786 | begin, end, 'write') | |
787 | sync_table = \ | |
788 | self._mi_create_result_table(self._MI_TABLE_CLASS_FREQ, | |
789 | begin, end, 'sync') | |
790 | self._fill_freq_result_table([io_rq.duration for io_rq in | |
791 | self._analysis.open_io_requests if | |
792 | self._filter_io_request(io_rq)], | |
650e7f57 | 793 | open_table) |
a0acc08c PP |
794 | self._fill_freq_result_table([io_rq.duration for io_rq in |
795 | self._analysis.read_io_requests if | |
796 | self._filter_io_request(io_rq)], | |
650e7f57 | 797 | read_table) |
a0acc08c PP |
798 | self._fill_freq_result_table([io_rq.duration for io_rq in |
799 | self._analysis.write_io_requests if | |
800 | self._filter_io_request(io_rq)], | |
650e7f57 | 801 | write_table) |
a0acc08c PP |
802 | self._fill_freq_result_table([io_rq.duration for io_rq in |
803 | self._analysis.sync_io_requests if | |
804 | self._filter_io_request(io_rq)], | |
650e7f57 | 805 | sync_table) |
a0acc08c PP |
806 | |
807 | return [open_table, read_table, write_table, sync_table] | |
808 | ||
809 | def _get_freq_result_tables(self, begin, end): | |
810 | syscall_tables = self._get_syscall_freq_result_tables(begin, end) | |
811 | disk_tables = self._get_disk_freq_result_tables(begin, end) | |
812 | ||
813 | return syscall_tables + disk_tables | |
814 | ||
815 | def _print_one_freq(self, result_table): | |
74fd1623 AB |
816 | graph = termgraph.FreqGraph( |
817 | data=result_table.rows, | |
818 | get_value=lambda row: row.count.value, | |
819 | get_lower_bound=lambda row: row.latency_lower.to_us(), | |
820 | title='{} {}'.format(result_table.title, result_table.subtitle), | |
821 | unit='µs' | |
9ac03ff5 AB |
822 | ) |
823 | ||
74fd1623 | 824 | graph.print_graph() |
9ac03ff5 | 825 | |
a0acc08c PP |
826 | def _print_freq(self, freq_tables): |
827 | for freq_table in freq_tables: | |
828 | self._print_one_freq(freq_table) | |
7e73fe34 | 829 | |
a0acc08c | 830 | def _append_log_row(self, io_rq, result_table): |
7e73fe34 | 831 | if io_rq.size is None: |
a0acc08c | 832 | size = mi.Empty() |
7e73fe34 | 833 | else: |
a0acc08c | 834 | size = mi.Size(io_rq.size) |
7e73fe34 AB |
835 | |
836 | tid = io_rq.tid | |
837 | proc_stats = self._analysis.tids[tid] | |
a0acc08c | 838 | proc_name = proc_stats.comm |
7e73fe34 AB |
839 | |
840 | # TODO: handle fd_in/fd_out for RW type operations | |
841 | if io_rq.fd is None: | |
a0acc08c PP |
842 | path = mi.Empty() |
843 | fd = mi.Empty() | |
7e73fe34 | 844 | else: |
a0acc08c | 845 | fd = mi.Fd(io_rq.fd) |
7e73fe34 | 846 | parent_proc = proc_stats |
a0acc08c | 847 | |
7e73fe34 AB |
848 | if parent_proc.pid is not None: |
849 | parent_proc = self._analysis.tids[parent_proc.pid] | |
850 | ||
a0acc08c PP |
851 | fd_stats = parent_proc.get_fd(io_rq.fd, io_rq.end_ts) |
852 | ||
7e73fe34 | 853 | if fd_stats is not None: |
a0acc08c | 854 | path = mi.Path(fd_stats.filename) |
7e73fe34 | 855 | else: |
a0acc08c PP |
856 | path = mi.Unknown() |
857 | ||
858 | result_table.append_row( | |
859 | time_range=mi.TimeRange(io_rq.begin_ts, io_rq.end_ts), | |
860 | out_of_range=mi.Boolean(self._is_io_rq_out_of_range(io_rq)), | |
861 | duration=mi.Duration(io_rq.duration), | |
862 | syscall=mi.Syscall(io_rq.syscall_name), | |
863 | size=size, | |
864 | process=mi.Process(proc_name, tid=tid), | |
865 | path=path, | |
866 | fd=fd, | |
867 | ) | |
868 | ||
869 | def _fill_log_result_table(self, rq_list, sort_key, is_top, result_table): | |
870 | if not rq_list: | |
871 | return | |
872 | ||
873 | count = 0 | |
7e73fe34 | 874 | |
a0acc08c PP |
875 | for io_rq in sorted(rq_list, key=operator.attrgetter(sort_key), |
876 | reverse=is_top): | |
877 | if is_top and count > self._args.limit: | |
878 | break | |
879 | ||
880 | self._append_log_row(io_rq, result_table) | |
881 | count += 1 | |
882 | ||
883 | def _fill_log_result_table_from_io_requests(self, io_requests, sort_key, | |
884 | is_top, result_table): | |
885 | io_requests = [io_rq for io_rq in io_requests if | |
886 | self._filter_io_request(io_rq)] | |
650e7f57 AB |
887 | self._fill_log_result_table(io_requests, sort_key, is_top, |
888 | result_table) | |
a0acc08c PP |
889 | |
890 | def _get_top_result_tables(self, begin, end): | |
891 | open_table = \ | |
892 | self._mi_create_result_table(self._MI_TABLE_CLASS_TOP_SYSCALL, | |
893 | begin, end, 'open') | |
894 | read_table = \ | |
895 | self._mi_create_result_table(self._MI_TABLE_CLASS_TOP_SYSCALL, | |
896 | begin, end, 'read') | |
897 | write_table = \ | |
898 | self._mi_create_result_table(self._MI_TABLE_CLASS_TOP_SYSCALL, | |
899 | begin, end, 'write') | |
900 | sync_table = \ | |
901 | self._mi_create_result_table(self._MI_TABLE_CLASS_TOP_SYSCALL, | |
902 | begin, end, 'sync') | |
903 | self._fill_log_result_table_from_io_requests( | |
904 | self._analysis.open_io_requests, 'duration', True, open_table) | |
905 | self._fill_log_result_table_from_io_requests( | |
906 | self._analysis.read_io_requests, 'duration', True, read_table) | |
907 | self._fill_log_result_table_from_io_requests( | |
908 | self._analysis.write_io_requests, 'duration', True, write_table) | |
909 | self._fill_log_result_table_from_io_requests( | |
910 | self._analysis.sync_io_requests, 'duration', True, sync_table) | |
911 | ||
912 | return [open_table, read_table, write_table, sync_table] | |
913 | ||
914 | def _print_log_row(self, row): | |
915 | fmt = '{:<40} {:<16} {:>16} {:>11} {:<24} {:<8} {:<14}' | |
9079847d AB |
916 | time_range_str = format_utils.format_time_range( |
917 | row.time_range.begin, | |
918 | row.time_range.end, | |
919 | self._args.multi_day, | |
920 | self._args.gmt | |
921 | ) | |
a0acc08c | 922 | duration_str = '%0.03f' % row.duration.to_us() |
7e73fe34 | 923 | |
a0acc08c PP |
924 | if type(row.size) is mi.Empty: |
925 | size = 'N/A' | |
926 | else: | |
8400227b | 927 | size = format_utils.format_size(row.size.value) |
a0acc08c PP |
928 | |
929 | tid = row.process.tid | |
930 | proc_name = row.process.name | |
931 | ||
932 | if type(row.fd) is mi.Empty: | |
933 | file_str = 'N/A' | |
934 | else: | |
935 | if type(row.path) is mi.Unknown: | |
936 | path = 'unknown' | |
937 | else: | |
938 | path = row.path.path | |
939 | ||
940 | file_str = '%s (fd=%s)' % (path, row.fd.fd) | |
941 | ||
942 | if row.out_of_range.value: | |
7e73fe34 AB |
943 | time_range_str += '*' |
944 | duration_str += '*' | |
945 | else: | |
946 | time_range_str += ' ' | |
947 | duration_str += ' ' | |
948 | ||
a0acc08c PP |
949 | print(fmt.format(time_range_str, row.syscall.name, duration_str, |
950 | size, proc_name, tid, file_str)) | |
7e73fe34 | 951 | |
a0acc08c PP |
952 | def _print_log(self, result_table): |
953 | if not result_table.rows: | |
a9c9a2a6 | 954 | return |
7e73fe34 | 955 | |
7e73fe34 AB |
956 | has_out_of_range_rq = False |
957 | ||
958 | print() | |
a0acc08c PP |
959 | fmt = '{} {} (usec)' |
960 | print(fmt.format(result_table.title, result_table.subtitle)) | |
9079847d | 961 | header_fmt = '{:<20} {:<20} {:<16} {:<23} {:<5} {:<24} {:<8} {:<14}' |
7e73fe34 AB |
962 | print(header_fmt.format( |
963 | 'Begin', 'End', 'Name', 'Duration (usec)', 'Size', 'Proc', 'PID', | |
964 | 'Filename')) | |
965 | ||
a0acc08c PP |
966 | for row in result_table.rows: |
967 | self._print_log_row(row) | |
7e73fe34 | 968 | |
a0acc08c | 969 | if not has_out_of_range_rq and row.out_of_range.value: |
7e73fe34 AB |
970 | has_out_of_range_rq = True |
971 | ||
7e73fe34 | 972 | if has_out_of_range_rq: |
73b71522 AB |
973 | print('*: Syscalls started and/or completed outside of the ' |
974 | 'range specified') | |
a9c9a2a6 | 975 | |
a0acc08c PP |
976 | def _print_top(self, top_tables): |
977 | for table in top_tables: | |
978 | self._print_log(table) | |
979 | ||
980 | def _get_log_result_table(self, begin, end): | |
981 | log_table = self._mi_create_result_table(self._MI_TABLE_CLASS_LOG, | |
982 | begin, end) | |
983 | self._fill_log_result_table_from_io_requests( | |
984 | self._analysis.io_requests, 'begin_ts', False, log_table) | |
985 | ||
986 | return log_table | |
987 | ||
988 | def _append_latency_stats_row(self, obj, rq_durations, result_table): | |
a205a2b4 JD |
989 | rq_count = len(rq_durations) |
990 | total_duration = sum(rq_durations) | |
a0acc08c | 991 | |
a205a2b4 JD |
992 | if len(rq_durations) > 0: |
993 | min_duration = min(rq_durations) | |
994 | max_duration = max(rq_durations) | |
995 | else: | |
996 | min_duration = 0 | |
997 | max_duration = 0 | |
998 | ||
ef49c8de | 999 | if rq_count < 2: |
a0acc08c | 1000 | stdev = mi.Unknown() |
ef49c8de | 1001 | else: |
a0acc08c | 1002 | stdev = mi.Duration(statistics.stdev(rq_durations)) |
ef49c8de | 1003 | |
d872de29 | 1004 | if rq_count > 0: |
a0acc08c | 1005 | avg = total_duration / rq_count |
d872de29 | 1006 | else: |
a0acc08c PP |
1007 | avg = 0 |
1008 | ||
1009 | result_table.append_row( | |
1010 | obj=obj, | |
1011 | count=mi.Integer(rq_count), | |
1012 | min_latency=mi.Duration(min_duration), | |
1013 | avg_latency=mi.Duration(avg), | |
1014 | max_latency=mi.Duration(max_duration), | |
1015 | stdev_latency=stdev, | |
1016 | ) | |
ef49c8de | 1017 | |
a0acc08c PP |
1018 | def _append_latency_stats_row_from_requests(self, obj, io_requests, |
1019 | result_table): | |
ef49c8de AB |
1020 | rq_durations = [io_rq.duration for io_rq in io_requests if |
1021 | self._filter_io_request(io_rq)] | |
a0acc08c PP |
1022 | self._append_latency_stats_row(obj, rq_durations, result_table) |
1023 | ||
1024 | def _get_syscall_latency_stats_result_table(self, begin, end): | |
650e7f57 AB |
1025 | result_table = self._mi_create_result_table( |
1026 | self._MI_TABLE_CLASS_SYSCALL_LATENCY_STATS, begin, end) | |
a0acc08c PP |
1027 | append_fn = self._append_latency_stats_row_from_requests |
1028 | append_fn(mi.String('Open'), self._analysis.open_io_requests, | |
1029 | result_table) | |
1030 | append_fn(mi.String('Read'), self._analysis.read_io_requests, | |
1031 | result_table) | |
1032 | append_fn(mi.String('Write'), self._analysis.write_io_requests, | |
1033 | result_table) | |
1034 | append_fn(mi.String('Sync'), self._analysis.sync_io_requests, | |
1035 | result_table) | |
1036 | ||
1037 | return result_table | |
1038 | ||
1039 | def _get_disk_latency_stats_result_table(self, begin, end): | |
1040 | if not self._analysis.disks: | |
1041 | return | |
1042 | ||
650e7f57 AB |
1043 | result_table = self._mi_create_result_table( |
1044 | self._MI_TABLE_CLASS_PART_LATENCY_STATS, begin, end) | |
a0acc08c PP |
1045 | |
1046 | for disk in self._analysis.disks.values(): | |
1047 | if disk.rq_count: | |
1048 | rq_durations = [rq.duration for rq in disk.rq_list if | |
1049 | self._filter_io_request(rq)] | |
1050 | disk = mi.Disk(disk.disk_name) | |
650e7f57 AB |
1051 | self._append_latency_stats_row(disk, rq_durations, |
1052 | result_table) | |
a0acc08c PP |
1053 | |
1054 | return result_table | |
1055 | ||
1056 | def _get_latency_stats_result_tables(self, begin, end): | |
1057 | syscall_tbl = self._get_syscall_latency_stats_result_table(begin, end) | |
1058 | disk_tbl = self._get_disk_latency_stats_result_table(begin, end) | |
1059 | ||
1060 | return syscall_tbl, disk_tbl | |
ef49c8de | 1061 | |
a0acc08c PP |
1062 | def _print_latency_stats_row(self, row): |
1063 | if type(row.stdev_latency) is mi.Unknown: | |
1064 | stdev = '?' | |
1065 | else: | |
1066 | stdev = '%0.03f' % row.stdev_latency.to_us() | |
1067 | ||
1068 | avg = '%0.03f' % row.avg_latency.to_us() | |
1069 | min_duration = '%0.03f' % row.min_latency.to_us() | |
1070 | max_duration = '%0.03f' % row.max_latency.to_us() | |
1071 | ||
1072 | print(IoAnalysisCommand._LATENCY_STATS_FORMAT.format( | |
1073 | str(row.obj), row.count.value, min_duration, | |
1074 | avg, max_duration, stdev)) | |
1075 | ||
1076 | def _print_syscall_latency_stats(self, stats_table): | |
ef49c8de AB |
1077 | print('\nSyscalls latency statistics (usec):') |
1078 | print(IoAnalysisCommand._LATENCY_STATS_FORMAT.format( | |
1079 | 'Type', 'Count', 'Min', 'Average', 'Max', 'Stdev')) | |
1080 | print(IoAnalysisCommand._SECTION_SEPARATOR_STRING) | |
1081 | ||
a0acc08c PP |
1082 | for row in stats_table.rows: |
1083 | self._print_latency_stats_row(row) | |
ef49c8de | 1084 | |
a0acc08c PP |
1085 | def _print_disk_latency_stats(self, stats_table): |
1086 | if not stats_table.rows: | |
a9c9a2a6 | 1087 | return |
a9c9a2a6 | 1088 | |
ef49c8de AB |
1089 | print('\nDisk latency statistics (usec):') |
1090 | print(IoAnalysisCommand._LATENCY_STATS_FORMAT.format( | |
1091 | 'Name', 'Count', 'Min', 'Average', 'Max', 'Stdev')) | |
1092 | print(IoAnalysisCommand._SECTION_SEPARATOR_STRING) | |
1093 | ||
a0acc08c PP |
1094 | for row in stats_table.rows: |
1095 | self._print_latency_stats_row(row) | |
a9c9a2a6 | 1096 | |
a0acc08c PP |
1097 | def _print_latency_stats(self, syscall_latency_stats_table, |
1098 | disk_latency_stats_table): | |
1099 | self._print_syscall_latency_stats(syscall_latency_stats_table) | |
1100 | self._print_disk_latency_stats(disk_latency_stats_table) | |
a9c9a2a6 | 1101 | |
a9c9a2a6 | 1102 | def _add_arguments(self, ap): |
b6d9132b AB |
1103 | Command._add_proc_filter_args(ap) |
1104 | Command._add_min_max_args(ap) | |
1105 | Command._add_log_args( | |
1106 | ap, help='Output the I/O requests in chronological order') | |
b9f05f8d AB |
1107 | Command._add_top_args( |
1108 | ap, help='Output the top I/O latencies by category') | |
b6d9132b AB |
1109 | Command._add_stats_args(ap, help='Output the I/O latency statistics') |
1110 | Command._add_freq_args( | |
1111 | ap, help='Output the I/O latency frequency distribution') | |
73b71522 | 1112 | ap.add_argument('--usage', action='store_true', |
b6d9132b AB |
1113 | help='Output the I/O usage') |
1114 | ap.add_argument('--minsize', type=float, | |
1115 | help='Filter out, I/O operations working with ' | |
1116 | 'less that minsize bytes') | |
1117 | ap.add_argument('--maxsize', type=float, | |
1118 | help='Filter out, I/O operations working with ' | |
1119 | 'more that maxsize bytes') | |
b6d9132b AB |
1120 | |
1121 | ||
a0acc08c PP |
1122 | def _run(mi_mode): |
1123 | iocmd = IoAnalysisCommand(mi_mode=mi_mode) | |
b6d9132b | 1124 | iocmd.run() |
1c0f0e3c | 1125 | |
a9c9a2a6 | 1126 | |
a0acc08c PP |
1127 | def _runstats(mi_mode): |
1128 | sys.argv.insert(1, '--stats') | |
1129 | _run(mi_mode) | |
1130 | ||
1131 | ||
1132 | def _runlog(mi_mode): | |
1133 | sys.argv.insert(1, '--log') | |
1134 | _run(mi_mode) | |
1135 | ||
1136 | ||
1137 | def _runfreq(mi_mode): | |
1138 | sys.argv.insert(1, '--freq') | |
1139 | _run(mi_mode) | |
1140 | ||
1141 | ||
1142 | def _runlatencytop(mi_mode): | |
b6d9132b | 1143 | sys.argv.insert(1, '--top') |
a0acc08c PP |
1144 | _run(mi_mode) |
1145 | ||
1146 | ||
1147 | def _runusage(mi_mode): | |
1148 | sys.argv.insert(1, '--usage') | |
1149 | _run(mi_mode) | |
1150 | ||
1151 | ||
1152 | def runstats(): | |
1153 | _runstats(mi_mode=False) | |
275bdbb4 JD |
1154 | |
1155 | ||
1c0f0e3c | 1156 | def runlog(): |
a0acc08c | 1157 | _runlog(mi_mode=False) |
1c0f0e3c JD |
1158 | |
1159 | ||
1160 | def runfreq(): | |
a0acc08c PP |
1161 | _runfreq(mi_mode=False) |
1162 | ||
1163 | ||
1164 | def runlatencytop(): | |
1165 | _runlatencytop(mi_mode=False) | |
1c0f0e3c JD |
1166 | |
1167 | ||
1168 | def runusage(): | |
a0acc08c PP |
1169 | _runusage(mi_mode=False) |
1170 | ||
1171 | ||
1172 | def runstats_mi(): | |
1173 | _runstats(mi_mode=True) | |
1174 | ||
1175 | ||
1176 | def runlog_mi(): | |
1177 | _runlog(mi_mode=True) | |
1178 | ||
1179 | ||
1180 | def runfreq_mi(): | |
1181 | _runfreq(mi_mode=True) | |
1182 | ||
1183 | ||
1184 | def runlatencytop_mi(): | |
1185 | _runlatencytop(mi_mode=True) | |
1186 | ||
1187 | ||
1188 | def runusage_mi(): | |
1189 | _runusage(mi_mode=True) |