Commit | Line | Data |
---|---|---|
4ed24f86 JD |
1 | #!/usr/bin/env python3 |
2 | # | |
3 | # The MIT License (MIT) | |
4 | # | |
a3fa57c0 | 5 | # Copyright (C) 2015 - Julien Desfossez <jdesfossez@efficios.com> |
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 | ||
a9c9a2a6 JD |
25 | from .command import Command |
26 | import lttnganalyses.syscalls | |
27 | from linuxautomaton import common, sv | |
28 | from ascii_graph import Pyasciigraph | |
29 | import operator | |
30 | import statistics | |
31 | ||
32 | ||
33 | class IoAnalysis(Command): | |
34 | _VERSION = '0.1.0' | |
35 | _DESC = """The I/O command.""" | |
36 | ||
37 | def __init__(self): | |
38 | super().__init__(self._add_arguments, | |
39 | enable_proc_filter_args=True, | |
40 | enable_max_min_args=True, | |
41 | enable_max_min_size_arg=True, | |
1c0f0e3c | 42 | enable_log_arg=True) |
a9c9a2a6 JD |
43 | |
44 | def _validate_transform_args(self): | |
45 | self._arg_extra = self._args.extra | |
1c0f0e3c JD |
46 | self._arg_usage = self._args.usage |
47 | self._arg_stats = self._args.latencystats | |
275bdbb4 | 48 | self._arg_latencytop = self._args.latencytop |
1c0f0e3c JD |
49 | self._arg_freq = self._args.latencyfreq |
50 | self._arg_freq_resolution = self._args.freq_resolution | |
51 | ||
275bdbb4 | 52 | def _default_args(self, stats, log, freq, usage, latencytop): |
1c0f0e3c JD |
53 | if stats: |
54 | self._arg_stats = True | |
55 | if log: | |
56 | self._arg_log = True | |
57 | if freq: | |
58 | self._arg_freq = True | |
59 | if usage: | |
60 | self._arg_usage = True | |
275bdbb4 JD |
61 | if latencytop: |
62 | self._arg_latencytop = True | |
1c0f0e3c | 63 | |
275bdbb4 JD |
64 | def run(self, stats=False, log=False, freq=False, usage=False, |
65 | latencytop=False): | |
a9c9a2a6 JD |
66 | # parse arguments first |
67 | self._parse_args() | |
68 | # validate, transform and save specific arguments | |
69 | self._validate_transform_args() | |
1c0f0e3c | 70 | # handle the default args for different executables |
275bdbb4 | 71 | self._default_args(stats, log, freq, usage, latencytop) |
a9c9a2a6 JD |
72 | # open the trace |
73 | self._open_trace() | |
74 | # create the appropriate analysis/analyses | |
75 | self._create_analysis() | |
76 | # run the analysis | |
119f6cef JD |
77 | self._run_analysis(self._reset_total, self._refresh, |
78 | break_cb=self._breakcb) | |
a9c9a2a6 JD |
79 | # process the results |
80 | self._compute_stats() | |
81 | # print results | |
82 | self._print_results(self.start_ns, self.trace_end_ts, final=1) | |
83 | # close the trace | |
84 | self._close_trace() | |
85 | ||
1c0f0e3c JD |
86 | def run_stats(self): |
87 | self.run(stats=True) | |
88 | ||
275bdbb4 JD |
89 | def run_latencytop(self): |
90 | self.run(latencytop=True) | |
91 | ||
1c0f0e3c JD |
92 | def run_log(self): |
93 | self.run(log=True) | |
94 | ||
95 | def run_freq(self): | |
96 | self.run(freq=True) | |
97 | ||
98 | def run_usage(self): | |
99 | self.run(usage=True) | |
100 | ||
a9c9a2a6 JD |
101 | def _create_analysis(self): |
102 | self._analysis = lttnganalyses.syscalls.SyscallsAnalysis( | |
103 | self._automaton.state) | |
119f6cef | 104 | self.state = self._automaton.state |
a9c9a2a6 JD |
105 | |
106 | def _compute_stats(self): | |
a9c9a2a6 JD |
107 | pass |
108 | ||
119f6cef JD |
109 | def _breakcb(self): |
110 | if len(self.state.pending_syscalls) > 0: | |
111 | return False | |
112 | return True | |
113 | ||
a9c9a2a6 JD |
114 | def _refresh(self, begin, end): |
115 | self._compute_stats() | |
116 | self._print_results(begin, end, final=0) | |
117 | self._reset_total(end) | |
118 | ||
119 | def add_fd_dict(self, tid, fd, files): | |
120 | if fd.read == 0 and fd.write == 0: | |
121 | return | |
122 | if fd.filename.startswith("pipe") or \ | |
123 | fd.filename.startswith("socket") or \ | |
124 | fd.filename.startswith("anon_inode") or \ | |
125 | fd.filename.startswith("unknown"): | |
126 | filename = "%s (%s)" % (fd.filename, tid.comm) | |
127 | files[filename] = {} | |
128 | files[filename]["read"] = fd.read | |
129 | files[filename]["write"] = fd.write | |
130 | files[filename]["name"] = filename | |
131 | files[filename]["other"] = ["fd %d in %s (%d)" % (fd.fd, | |
132 | tid.comm, tid.pid)] | |
133 | else: | |
134 | # merge counters of shared files | |
135 | filename = fd.filename | |
136 | if filename not in files.keys(): | |
137 | files[filename] = {} | |
138 | files[filename]["read"] = fd.read | |
139 | files[filename]["write"] = fd.write | |
140 | files[filename]["name"] = filename | |
141 | files[filename]["other"] = ["fd %d in %s (%d)" % | |
142 | (fd.fd, tid.comm, tid.pid)] | |
143 | files[filename]["tids"] = [tid.tid] | |
144 | else: | |
145 | files[filename]["read"] += fd.read | |
146 | files[filename]["write"] += fd.write | |
147 | files[filename]["other"].append("fd %d in %s (%d)" % | |
148 | (fd.fd, tid.comm, | |
149 | tid.pid)) | |
150 | ||
151 | def create_files_dict(self): | |
152 | files = {} | |
153 | for tid in self.state.tids.values(): | |
154 | if not self.filter_process(tid): | |
155 | continue | |
156 | for fd in tid.fds.values(): | |
157 | self.add_fd_dict(tid, fd, files) | |
158 | for fd in tid.closed_fds.values(): | |
159 | self.add_fd_dict(tid, fd, files) | |
160 | return files | |
161 | ||
162 | # iotop functions | |
163 | def iotop_output_print_file_read(self, files): | |
164 | count = 0 | |
165 | limit = self._arg_limit | |
166 | graph = Pyasciigraph() | |
167 | values = [] | |
168 | sorted_f = sorted(files.items(), key=lambda files: files[1]['read'], | |
169 | reverse=True) | |
170 | for f in sorted_f: | |
171 | if f[1]["read"] == 0: | |
172 | continue | |
173 | info_fmt = "{:>10}".format(common.convert_size(f[1]["read"], | |
174 | padding_after=True)) | |
175 | values.append(("%s %s %s" % (info_fmt, | |
176 | f[1]["name"], | |
177 | str(f[1]["other"])[1:-1]), | |
178 | f[1]["read"])) | |
179 | count = count + 1 | |
180 | if limit > 0 and count >= limit: | |
181 | break | |
182 | for line in graph.graph('Files Read', values, sort=2, | |
183 | with_value=False): | |
184 | print(line) | |
185 | ||
186 | def iotop_output_print_file_write(self, files): | |
187 | # Compute files read | |
188 | count = 0 | |
189 | limit = self._arg_limit | |
190 | graph = Pyasciigraph() | |
191 | values = [] | |
192 | sorted_f = sorted(files.items(), key=lambda files: files[1]['write'], | |
193 | reverse=True) | |
194 | for f in sorted_f: | |
195 | if f[1]["write"] == 0: | |
196 | continue | |
197 | info_fmt = "{:>10}".format(common.convert_size(f[1]["write"], | |
198 | padding_after=True)) | |
199 | values.append(("%s %s %s" % (info_fmt, | |
200 | f[1]["name"], | |
201 | str(f[1]["other"])[1:-1]), | |
202 | f[1]["write"])) | |
203 | count = count + 1 | |
204 | if limit > 0 and count >= limit: | |
205 | break | |
206 | for line in graph.graph('Files Write', values, sort=2, | |
207 | with_value=False): | |
208 | print(line) | |
209 | ||
210 | def iotop_output_file_read_write(self): | |
211 | files = self.create_files_dict() | |
212 | self.iotop_output_print_file_read(files) | |
213 | self.iotop_output_print_file_write(files) | |
214 | ||
215 | def filter_process(self, proc): | |
216 | if self._arg_proc_list and proc.comm not in self._arg_proc_list: | |
217 | return False | |
218 | if self._arg_pid_list and str(proc.pid) not in self._arg_pid_list: | |
219 | return False | |
220 | return True | |
221 | ||
222 | def filter_size(self, size): | |
223 | # don't filter sync and open | |
224 | if size is None: | |
225 | return True | |
226 | if self._arg_maxsize is not None and size > self._arg_maxsize: | |
227 | return False | |
228 | if self._arg_minsize is not None and size < self._arg_minsize: | |
229 | return False | |
230 | return True | |
231 | ||
232 | def filter_latency(self, duration): | |
233 | if self._arg_max is not None and (duration/1000) > self._arg_max: | |
234 | return False | |
235 | if self._arg_min is not None and (duration/1000) < self._arg_min: | |
236 | return False | |
237 | return True | |
238 | ||
239 | def iotop_output_read(self): | |
240 | count = 0 | |
241 | limit = self._arg_limit | |
242 | graph = Pyasciigraph() | |
243 | values = [] | |
244 | for tid in sorted(self.state.tids.values(), | |
245 | key=operator.attrgetter('read'), reverse=True): | |
246 | if not self.filter_process(tid): | |
247 | continue | |
248 | info_fmt = "{:>10} {:<25} {:>9} file {:>9} net {:>9} unknown" | |
249 | values.append((info_fmt.format( | |
250 | common.convert_size(tid.read, padding_after=True), | |
251 | "%s (%d)" % (tid.comm, tid.pid), | |
252 | common.convert_size(tid.disk_read, | |
253 | padding_after=True), | |
254 | common.convert_size(tid.net_read, | |
255 | padding_after=True), | |
256 | common.convert_size(tid.unk_read, | |
257 | padding_after=True)), | |
258 | tid.read)) | |
259 | count = count + 1 | |
260 | if limit > 0 and count >= limit: | |
261 | break | |
262 | for line in graph.graph('Per-process I/O Read', values, | |
263 | with_value=False): | |
264 | print(line) | |
265 | ||
266 | def iotop_output_write(self): | |
267 | count = 0 | |
268 | limit = self._arg_limit | |
269 | graph = Pyasciigraph() | |
270 | values = [] | |
271 | for tid in sorted(self.state.tids.values(), | |
272 | key=operator.attrgetter('write'), reverse=True): | |
273 | if not self.filter_process(tid): | |
274 | continue | |
275 | info_fmt = "{:>10} {:<25} {:>9} file {:>9} net {:>9} unknown " | |
276 | values.append((info_fmt.format( | |
277 | common.convert_size(tid.write, padding_after=True), | |
278 | "%s (%d)" % (tid.comm, tid.pid), | |
279 | common.convert_size(tid.disk_write, | |
280 | padding_after=True), | |
281 | common.convert_size(tid.net_write, | |
282 | padding_after=True), | |
283 | common.convert_size(tid.unk_write, | |
284 | padding_after=True)), | |
285 | tid.write)) | |
286 | count = count + 1 | |
287 | if limit > 0 and count >= limit: | |
288 | break | |
289 | for line in graph.graph('Per-process I/O Write', values, | |
290 | with_value=False): | |
291 | print(line) | |
292 | ||
293 | def iotop_output_disk_read(self): | |
294 | count = 0 | |
295 | limit = self._arg_limit | |
296 | graph = Pyasciigraph() | |
297 | values = [] | |
298 | for tid in sorted(self.state.tids.values(), | |
299 | key=operator.attrgetter('block_read'), reverse=True): | |
300 | if not self.filter_process(tid): | |
301 | continue | |
302 | if tid.block_read == 0: | |
303 | continue | |
304 | info_fmt = "{:>10} {:<22}" | |
305 | values.append((info_fmt.format(common.convert_size(tid.block_read, | |
306 | padding_after=True), | |
307 | "%s (pid=%d)" % (tid.comm, | |
308 | tid.pid)), | |
309 | tid.block_read)) | |
310 | count = count + 1 | |
311 | if limit > 0 and count >= limit: | |
312 | break | |
313 | for line in graph.graph('Block I/O Read', values, with_value=False): | |
314 | print(line) | |
315 | ||
316 | def iotop_output_disk_write(self): | |
317 | count = 0 | |
318 | limit = self._arg_limit | |
319 | graph = Pyasciigraph() | |
320 | values = [] | |
321 | for tid in sorted(self.state.tids.values(), | |
322 | key=operator.attrgetter('block_write'), | |
323 | reverse=True): | |
324 | if not self.filter_process(tid): | |
325 | continue | |
326 | if tid.block_write == 0: | |
327 | continue | |
328 | info_fmt = "{:>10} {:<22}" | |
329 | values.append((info_fmt.format(common.convert_size(tid.block_write, | |
330 | padding_after=True), | |
331 | "%s (pid=%d)" % (tid.comm, | |
332 | tid.pid)), | |
333 | tid.block_write)) | |
334 | count = count + 1 | |
335 | if limit > 0 and count >= limit: | |
336 | break | |
337 | for line in graph.graph('Block I/O Write', values, with_value=False): | |
338 | print(line) | |
339 | ||
340 | def iotop_output_nr_sector(self): | |
341 | graph = Pyasciigraph() | |
342 | values = [] | |
343 | for disk in sorted(self.state.disks.values(), | |
344 | key=operator.attrgetter('nr_sector'), reverse=True): | |
345 | if disk.nr_sector == 0: | |
346 | continue | |
347 | values.append((disk.prettyname, disk.nr_sector)) | |
348 | for line in graph.graph('Disk nr_sector', values, unit=" sectors"): | |
349 | print(line) | |
350 | ||
351 | def iotop_output_nr_requests(self): | |
352 | graph = Pyasciigraph() | |
353 | values = [] | |
354 | for disk in sorted(self.state.disks.values(), | |
355 | key=operator.attrgetter('nr_requests'), | |
356 | reverse=True): | |
357 | if disk.nr_sector == 0: | |
358 | continue | |
359 | values.append((disk.prettyname, disk.nr_requests)) | |
360 | for line in graph.graph('Disk nr_requests', values, unit=" requests"): | |
361 | print(line) | |
362 | ||
363 | def iotop_output_dev_latency(self): | |
364 | graph = Pyasciigraph() | |
365 | values = [] | |
366 | for disk in self.state.disks.values(): | |
367 | if disk.completed_requests == 0: | |
368 | continue | |
369 | total = (disk.request_time / disk.completed_requests) \ | |
9ecee826 | 370 | / common.MSEC_PER_NSEC |
a9c9a2a6 JD |
371 | total = float("%0.03f" % total) |
372 | values.append(("%s" % disk.prettyname, total)) | |
373 | for line in graph.graph('Disk request time/sector', values, sort=2, | |
374 | unit=" ms"): | |
375 | print(line) | |
376 | ||
377 | def iotop_output_net_recv_bytes(self): | |
378 | graph = Pyasciigraph() | |
379 | values = [] | |
380 | for iface in sorted(self.state.ifaces.values(), | |
381 | key=operator.attrgetter('recv_bytes'), | |
382 | reverse=True): | |
383 | values.append(("%s %s" % (common.convert_size(iface.recv_bytes), | |
384 | iface.name), | |
385 | iface.recv_bytes)) | |
386 | for line in graph.graph('Network recv_bytes', values, | |
387 | with_value=False): | |
388 | print(line) | |
389 | ||
390 | def iotop_output_net_sent_bytes(self): | |
391 | graph = Pyasciigraph() | |
392 | values = [] | |
393 | for iface in sorted(self.state.ifaces.values(), | |
394 | key=operator.attrgetter('send_bytes'), | |
395 | reverse=True): | |
396 | values.append(("%s %s" % (common.convert_size(iface.send_bytes), | |
397 | iface.name), | |
398 | iface.send_bytes)) | |
399 | for line in graph.graph('Network sent_bytes', values, | |
400 | with_value=False): | |
401 | print(line) | |
402 | ||
403 | def iotop_output(self): | |
404 | self.iotop_output_read() | |
405 | self.iotop_output_write() | |
406 | self.iotop_output_file_read_write() | |
407 | self.iotop_output_disk_read() | |
408 | self.iotop_output_disk_write() | |
409 | self.iotop_output_nr_sector() | |
410 | self.iotop_output_nr_requests() | |
411 | self.iotop_output_dev_latency() | |
412 | self.iotop_output_net_recv_bytes() | |
413 | self.iotop_output_net_sent_bytes() | |
414 | # self.output_latencies() | |
415 | ||
416 | def iolatency_freq_histogram(self, _min, _max, res, rq_list, title): | |
417 | step = (_max - _min) / res | |
418 | if step == 0: | |
419 | return | |
420 | buckets = [] | |
421 | values = [] | |
422 | graph = Pyasciigraph() | |
423 | for i in range(res): | |
424 | buckets.append(i * step) | |
425 | values.append(0) | |
426 | for i in rq_list: | |
427 | v = i / 1000 | |
428 | b = min(int((v-_min)/step), res - 1) | |
429 | values[b] += 1 | |
430 | g = [] | |
431 | i = 0 | |
432 | for v in values: | |
433 | g.append(("%0.03f" % (i * step + _min), v)) | |
434 | i += 1 | |
09071fb9 | 435 | for line in graph.graph(title, g, info_before=True, count=True): |
a9c9a2a6 JD |
436 | print(line) |
437 | print("") | |
438 | ||
439 | def compute_disk_stats(self, dev): | |
440 | _max = 0 | |
441 | _min = -1 | |
442 | total = 0 | |
443 | values = [] | |
444 | count = len(dev.rq_list) | |
445 | if count == 0: | |
446 | return | |
447 | for rq in dev.rq_list: | |
448 | if rq.duration > _max: | |
449 | _max = rq.duration | |
450 | if _min == -1 or rq.duration < _min: | |
451 | _min = rq.duration | |
452 | total += rq.duration | |
453 | values.append(rq.duration) | |
454 | if count > 2: | |
455 | stdev = statistics.stdev(values) / 1000 | |
456 | else: | |
457 | stdev = "?" | |
458 | dev.min = _min / 1000 | |
459 | dev.max = _max / 1000 | |
460 | dev.total = total / 1000 | |
461 | dev.count = count | |
462 | dev.rq_values = values | |
463 | dev.stdev = stdev | |
464 | ||
465 | # iolatency functions | |
466 | def iolatency_output_disk(self): | |
467 | for dev in self.state.disks.keys(): | |
468 | d = self.state.disks[dev] | |
469 | if d.max is None: | |
470 | self.compute_disk_stats(d) | |
471 | if d.count is not None: | |
472 | self.iolatency_freq_histogram(d.min, d.max, | |
473 | self._arg_freq_resolution, | |
474 | d.rq_values, | |
475 | "Frequency distribution for " | |
476 | "disk %s (usec)" % | |
477 | (d.prettyname)) | |
478 | ||
479 | def iolatency_output(self): | |
480 | self.iolatency_output_disk() | |
481 | ||
482 | # def output_latencies(self): | |
483 | # graph = Pyasciigraph() | |
484 | # for proc in self.latency_hist.keys(): | |
485 | # values = [] | |
486 | # for v in self.latency_hist[proc]: | |
487 | # values.append(("%s" % (v[0]), v[1])) | |
488 | # for line in graph.graph('%s requests latency (ms)' % proc, values, | |
489 | # unit=" ms"): | |
490 | # print(line) | |
491 | ||
492 | def iostats_minmax(self, duration, current_min, current_max): | |
493 | _min = current_min | |
494 | _max = current_max | |
495 | if current_min is None or duration < current_min: | |
496 | _min = duration | |
497 | if duration > current_max: | |
498 | _max = duration | |
499 | return (_min, _max) | |
500 | ||
501 | def iostats_syscalls_line(self, fmt, name, count, _min, _max, total, rq): | |
502 | if count < 2: | |
503 | stdev = "?" | |
504 | else: | |
505 | stdev = "%0.03f" % (statistics.stdev(rq) / 1000) | |
506 | if count < 1: | |
507 | avg = "0.000" | |
508 | else: | |
509 | avg = "%0.03f" % (total / (count * 1000)) | |
510 | if _min is None: | |
511 | _min = 0 | |
512 | _min = "%0.03f" % (_min / 1000) | |
513 | _max = "%0.03f" % (_max / 1000) | |
514 | print(fmt.format(name, count, _min, avg, _max, stdev)) | |
515 | ||
516 | def account_syscall_iorequests(self, s, iorequests): | |
517 | for rq in iorequests: | |
518 | # filter out if completely out of range but accept the | |
519 | # union to show the real begin/end time | |
520 | if self._arg_begin and self._arg_end and rq.end and \ | |
521 | rq.begin > self._arg_end: | |
522 | continue | |
523 | if rq.iotype != sv.IORequest.IO_SYSCALL: | |
524 | continue | |
525 | if not self.filter_size(rq.size): | |
526 | continue | |
527 | if not self.filter_latency(rq.duration): | |
528 | continue | |
529 | if rq.operation == sv.IORequest.OP_READ: | |
530 | s.read_count += 1 | |
531 | s.read_total += rq.duration | |
532 | s.read_rq.append(rq.duration) | |
533 | s.all_read.append(rq) | |
534 | s.read_min, s.read_max = self.iostats_minmax( | |
535 | rq.duration, s.read_min, s.read_max) | |
536 | elif rq.operation == sv.IORequest.OP_WRITE: | |
537 | s.write_count += 1 | |
538 | s.write_total += rq.duration | |
539 | s.write_rq.append(rq.duration) | |
540 | s.all_write.append(rq) | |
541 | s.write_min, s.write_max = self.iostats_minmax( | |
542 | rq.duration, s.write_min, s.write_max) | |
543 | elif rq.operation == sv.IORequest.OP_SYNC: | |
544 | s.sync_count += 1 | |
545 | s.sync_total += rq.duration | |
546 | s.sync_rq.append(rq.duration) | |
547 | s.all_sync.append(rq) | |
548 | s.sync_min, s.sync_max = self.iostats_minmax( | |
549 | rq.duration, s.sync_min, s.sync_max) | |
550 | elif rq.operation == sv.IORequest.OP_OPEN: | |
551 | s.open_count += 1 | |
552 | s.open_total += rq.duration | |
553 | s.open_rq.append(rq.duration) | |
554 | s.all_open.append(rq) | |
555 | s.open_min, s.open_max = self.iostats_minmax( | |
556 | rq.duration, s.open_min, s.open_max) | |
557 | ||
558 | def compute_syscalls_latency_stats(self, end_ns): | |
559 | s = sv.Syscalls_stats() | |
560 | for tid in self.state.tids.values(): | |
561 | if not self.filter_process(tid): | |
562 | continue | |
563 | self.account_syscall_iorequests(s, tid.iorequests) | |
564 | for fd in tid.fds.values(): | |
565 | self.account_syscall_iorequests(s, fd.iorequests) | |
566 | for fd in tid.closed_fds.values(): | |
567 | self.account_syscall_iorequests(s, fd.iorequests) | |
568 | return s | |
569 | ||
570 | def iostats_output_syscalls(self): | |
571 | s = self.syscalls_stats | |
572 | print("\nSyscalls latency statistics (usec):") | |
573 | fmt = "{:<14} {:>14} {:>14} {:>14} {:>14} {:>14}" | |
574 | print(fmt.format("Type", "Count", "Min", "Average", | |
575 | "Max", "Stdev")) | |
576 | print("-" * 89) | |
577 | self.iostats_syscalls_line(fmt, "Open", s.open_count, s.open_min, | |
578 | s.open_max, s.open_total, s.open_rq) | |
579 | self.iostats_syscalls_line(fmt, "Read", s.read_count, s.read_min, | |
580 | s.read_max, s.read_total, s.read_rq) | |
581 | self.iostats_syscalls_line(fmt, "Write", s.write_count, s.write_min, | |
582 | s.write_max, s.write_total, s.write_rq) | |
583 | self.iostats_syscalls_line(fmt, "Sync", s.sync_count, s.sync_min, | |
584 | s.sync_max, s.sync_total, s.sync_rq) | |
585 | ||
586 | def iolatency_syscalls_output(self): | |
587 | s = self.syscalls_stats | |
588 | print("") | |
589 | if s.open_count > 0: | |
590 | self.iolatency_freq_histogram(s.open_min/1000, s.open_max/1000, | |
591 | self._arg_freq_resolution, s.open_rq, | |
592 | "Open latency distribution (usec)") | |
593 | if s.read_count > 0: | |
594 | self.iolatency_freq_histogram(s.read_min/1000, s.read_max/1000, | |
595 | self._arg_freq_resolution, s.read_rq, | |
596 | "Read latency distribution (usec)") | |
597 | if s.write_count > 0: | |
598 | self.iolatency_freq_histogram(s.write_min/1000, s.write_max/1000, | |
599 | self._arg_freq_resolution, | |
600 | s.write_rq, | |
601 | "Write latency distribution (usec)") | |
602 | if s.sync_count > 0: | |
603 | self.iolatency_freq_histogram(s.sync_min/1000, s.sync_max/1000, | |
604 | self._arg_freq_resolution, s.sync_rq, | |
605 | "Sync latency distribution (usec)") | |
606 | ||
607 | def iolatency_syscalls_list_output(self, title, rq_list, | |
608 | sortkey, reverse): | |
609 | limit = self._arg_limit | |
610 | count = 0 | |
611 | outrange_legend = False | |
612 | if len(rq_list) == 0: | |
613 | return | |
614 | print(title) | |
615 | if self._arg_extra: | |
616 | extra_fmt = "{:<48}" | |
617 | extra_title = "{:<8} {:<8} {:<8} {:<8} {:<8} {:<8} ".format( | |
618 | "Dirtied", "Alloc", "Free", "Written", "Kswap", "Cleared") | |
619 | else: | |
620 | extra_fmt = "{:<0}" | |
621 | extra_title = "" | |
622 | title_fmt = "{:<19} {:<20} {:<16} {:<23} {:<5} {:<24} {:<8} " + \ | |
623 | extra_fmt + "{:<14}" | |
119f6cef | 624 | fmt = "{:<40} {:<16} {:>16} {:>11} {:<24} {:<8} " + \ |
a9c9a2a6 JD |
625 | extra_fmt + "{:<14}" |
626 | print(title_fmt.format("Begin", "End", "Name", "Duration (usec)", | |
627 | "Size", "Proc", "PID", extra_title, "Filename")) | |
628 | for rq in sorted(rq_list, | |
629 | key=operator.attrgetter(sortkey), reverse=reverse): | |
630 | # only limit the output if in the "top" view | |
631 | if reverse and count > limit: | |
632 | break | |
633 | if rq.size is None: | |
634 | size = "N/A" | |
635 | else: | |
636 | size = common.convert_size(rq.size) | |
637 | if self._arg_extra: | |
638 | extra = "{:<8} {:<8} {:<8} {:<8} {:<8} {:<8} ".format( | |
639 | rq.dirty, rq.page_alloc, rq.page_free, rq.page_written, | |
640 | rq.woke_kswapd, rq.page_cleared) | |
641 | else: | |
642 | extra = "" | |
643 | name = rq.name.replace("syscall_entry_", "").replace("sys_", "") | |
644 | if rq.fd is None: | |
645 | filename = "None" | |
646 | fd = "None" | |
647 | else: | |
648 | filename = rq.fd.filename | |
649 | fd = rq.fd.fd | |
650 | end = common.ns_to_hour_nsec(rq.end, self._arg_multi_day, | |
651 | self._arg_gmt) | |
652 | ||
653 | outrange = " " | |
654 | duration = rq.duration | |
655 | if self._arg_begin and rq.begin < self._arg_begin: | |
656 | outrange = "*" | |
657 | outrange_legend = True | |
658 | if self._arg_end and rq.end > self._arg_end: | |
659 | outrange = "*" | |
660 | outrange_legend = True | |
661 | ||
662 | print(fmt.format("[" + common.ns_to_hour_nsec( | |
663 | rq.begin, self._arg_multi_day, self._arg_gmt) + "," + | |
664 | end + "]" + outrange, | |
665 | name, | |
666 | "%0.03f" % (duration/1000) + outrange, | |
667 | size, rq.proc.comm, | |
668 | rq.proc.pid, extra, | |
669 | "%s (fd=%s)" % (filename, fd))) | |
670 | count += 1 | |
671 | if outrange_legend: | |
672 | print("*: Syscalls started and/or completed outside of the " | |
673 | "range specified") | |
674 | ||
675 | def iolatency_syscalls_top_output(self): | |
676 | s = self.syscalls_stats | |
677 | self.iolatency_syscalls_list_output( | |
678 | "\nTop open syscall latencies (usec)", s.all_open, | |
679 | "duration", True) | |
680 | self.iolatency_syscalls_list_output( | |
681 | "\nTop read syscall latencies (usec)", s.all_read, | |
682 | "duration", True) | |
683 | self.iolatency_syscalls_list_output( | |
684 | "\nTop write syscall latencies (usec)", s.all_write, | |
685 | "duration", True) | |
686 | self.iolatency_syscalls_list_output( | |
687 | "\nTop sync syscall latencies (usec)", s.all_sync, | |
688 | "duration", True) | |
689 | ||
690 | def iolatency_syscalls_log_output(self): | |
691 | s = self.syscalls_stats | |
692 | self.iolatency_syscalls_list_output( | |
693 | "\nLog of all I/O system calls", | |
694 | s.all_open + s.all_read + s.all_write + s.all_sync, | |
695 | "begin", False) | |
696 | ||
697 | # iostats functions | |
698 | def iostats_output_disk(self): | |
699 | # TODO same with network | |
700 | if len(self.state.disks.keys()) == 0: | |
701 | return | |
702 | print("\nDisk latency statistics (usec):") | |
703 | fmt = "{:<14} {:>14} {:>14} {:>14} {:>14} {:>14}" | |
704 | print(fmt.format("Name", "Count", "Min", "Average", "Max", "Stdev")) | |
705 | print("-" * 89) | |
706 | ||
707 | for dev in self.state.disks.keys(): | |
708 | d = self.state.disks[dev] | |
709 | if d.max is None: | |
710 | d = self.state.disks[dev] | |
711 | self.compute_disk_stats(d) | |
712 | if d.count is not None: | |
713 | self.iostats_syscalls_line(fmt, d.prettyname, d.count, d.min, | |
714 | d.max, d.total, d.rq_values) | |
715 | ||
716 | def iostats_output(self): | |
717 | self.iostats_output_syscalls() | |
718 | self.iostats_output_disk() | |
719 | ||
720 | def _print_results(self, begin_ns, end_ns, final=0): | |
35743f87 JD |
721 | print('Timerange: [%s, %s]' % ( |
722 | common.ns_to_hour_nsec(begin_ns, gmt=self._arg_gmt, | |
723 | multi_day=True), | |
724 | common.ns_to_hour_nsec(end_ns, gmt=self._arg_gmt, | |
725 | multi_day=True))) | |
1c0f0e3c JD |
726 | if self._arg_usage: |
727 | self.iotop_output() | |
a9c9a2a6 JD |
728 | self.syscalls_stats = self.compute_syscalls_latency_stats(end_ns) |
729 | if self._arg_stats: | |
730 | self.iostats_output() | |
275bdbb4 | 731 | if self._arg_latencytop: |
a9c9a2a6 JD |
732 | self.iolatency_syscalls_top_output() |
733 | if self._arg_freq: | |
734 | self.iolatency_syscalls_output() | |
735 | self.iolatency_output() | |
736 | if self._arg_log: | |
737 | self.iolatency_syscalls_log_output() | |
738 | ||
739 | def _reset_total(self, start_ts): | |
740 | for dev in self.state.disks.keys(): | |
741 | self.state.disks[dev].init_counts() | |
742 | ||
743 | for iface in self.state.ifaces.keys(): | |
744 | self.state.ifaces[iface].init_counts() | |
745 | ||
746 | for tid in self.state.tids.values(): | |
747 | for fd in tid.fds.values(): | |
748 | fd.init_counts() | |
749 | for fd in tid.closed_fds.values(): | |
750 | fd.init_counts() | |
751 | tid.init_counts() | |
752 | ||
753 | def _add_arguments(self, ap): | |
1c0f0e3c JD |
754 | ap.add_argument('--usage', action="store_true", |
755 | help='Show the I/O usage') | |
756 | ap.add_argument('--latencystats', action="store_true", | |
757 | help='Show the I/O latency statistics') | |
275bdbb4 JD |
758 | ap.add_argument('--latencytop', action="store_true", |
759 | help='Show the I/O latency top') | |
1c0f0e3c JD |
760 | ap.add_argument('--latencyfreq', action="store_true", |
761 | help='Show the I/O latency frequency distribution') | |
762 | ap.add_argument('--freq-resolution', type=int, default=20, | |
763 | help='Frequency distribution resolution ' | |
764 | '(default 20)') | |
a9c9a2a6 JD |
765 | ap.add_argument('--extra', type=str, default=0, |
766 | help='Show extra information in stats (beta)') | |
767 | # specific argument | |
768 | pass | |
769 | ||
770 | ||
771 | # entry point | |
1c0f0e3c | 772 | def runstats(): |
a9c9a2a6 JD |
773 | # create command |
774 | iocmd = IoAnalysis() | |
1c0f0e3c JD |
775 | # execute command |
776 | iocmd.run_stats() | |
777 | ||
a9c9a2a6 | 778 | |
275bdbb4 JD |
779 | def runlatencytop(): |
780 | # create command | |
781 | iocmd = IoAnalysis() | |
782 | # execute command | |
783 | iocmd.run_latencytop() | |
784 | ||
785 | ||
1c0f0e3c JD |
786 | def runlog(): |
787 | # create command | |
788 | iocmd = IoAnalysis() | |
789 | # execute command | |
790 | iocmd.run_log() | |
791 | ||
792 | ||
793 | def runfreq(): | |
794 | # create command | |
795 | iocmd = IoAnalysis() | |
796 | # execute command | |
797 | iocmd.run_freq() | |
798 | ||
799 | ||
800 | def runusage(): | |
801 | # create command | |
802 | iocmd = IoAnalysis() | |
a9c9a2a6 | 803 | # execute command |
1c0f0e3c | 804 | iocmd.run_usage() |