5 This repository contains various scripts to extract monitoring data and metrics
6 from LTTng kernel traces.
8 As opposed to other diagnostic or monitoring solutions, this approach is designed
9 to allow users to record their system's activity with a low overhead, wait
10 for a problem to occur and then diagnose its cause offline.
12 This solution allows the user to target hard to find problems and dig until the
15 This README describes the implemented analyses as well as how to use them.
29 * Babeltrace >= 1.2 (with python bindings built)
41 On **Ubuntu** (12.04 and up) using the LTTng ppa:
45 apt-get install -y software-properties-common (or python-software-properties on 12.04)
46 apt-add-repository -y ppa:lttng/ppa
48 apt-get -y install lttng-tools babeltrace lttng-modules-dkms python3-babeltrace python3-progressbar python3-lttnganalyses
54 apt-get -y install lttng-tools babeltrace lttng-modules-dkms python3-babeltrace python3-progressbar python3-lttnganalyses
56 On other distributions:
58 Please refer to the `LTTng documentation <http://lttng.org/download/>`_ to
59 install LTTng and the `Babeltrace README
60 <http://git.efficios.com/?p=babeltrace.git;a=blob_plain;f=README;hb=HEAD>`_
61 to install ``babeltrace`` with the python bindings. Optionally install the
62 ``progressbar`` python module, and then:
66 pip3 install lttnganalyses
73 The **latest development version** can be installed directly from GitHub:
77 pip3 install --upgrade https://github.com/lttng/lttng-analyses/tarball/master
84 Here are the basic commands to create a trace, for more information on the
85 LTTng setup, please refer to the `LTTng documentation Getting started guide
86 <http://lttng.org/docs/#doc-getting-started>`_.
92 From the cloned git tree:
96 ./lttng-analyses-record
106 lttng enable-channel -k bla --subbuf-size=4M
107 lttng enable-event -k sched_switch,block_rq_complete,block_rq_issue,block_bio_remap,block_bio_backmerge,netif_receive_skb,net_dev_xmit,sched_process_fork,sched_process_exec,lttng_statedump_process_state,lttng_statedump_file_descriptor,lttng_statedump_block_device,writeback_pages_written,mm_vmscan_wakeup_kswapd,mm_page_free,mm_page_alloc,block_dirty_buffer,irq_handler_entry,irq_handler_exit,softirq_entry,softirq_exit,softirq_raise -c bla
108 lttng enable-event -k --syscall -a -c bla
119 You can also create a trace on a server and send it to a remote host. The
120 remote host only needs to run ``lttng-relayd -d`` and be reachable over the network.
121 The only difference with the above commands is the tracing session's creation:
125 lttng create -U net://<remote-host>
132 * CPU usage for the whole system
133 * CPU usage per-process
134 * Process CPU migration count
135 * Memory usage per-process (as seen by the kernel)
136 * Memory usage system-wide (as seen by the kernel)
137 * I/O usage (syscalls, disk, network)
138 * I/O operations log (with latency and usage)
139 * I/O latency statistics (open, read, write, sync operations)
140 * I/O latency frequency distribution
141 * Interrupt handler duration statistics (count, min, max, average stdev)
142 * Interrupt handler duration top
143 * Interrupt handler duration log
144 * Interrupt handler duration frequency distribution
145 * SoftIRQ handler latency statistics
146 * Syscalls usage statistics
148 All of the analyses share the same code architecture making it possible
149 to filter by timerange, process name, PID, min and max values using the
150 same command-line options. Also note that reported timestamps can
151 optionally be expressed in the GMT timezone to allow easy sharing between
154 The project's architecture makes it easy to add new analyses or to reuse
155 the analysis backend in external tools which may then present the results
156 in their own format (as opposed to text).
163 After having collected your trace, any script contained in this repository
164 can be used to run an analysis. Read on for some examples!
176 $ ./lttng-iolatencystats mytrace/
177 Timerange: [2015-01-06 10:58:26.140545481, 2015-01-06 10:58:27.229358936]
178 Syscalls latency statistics (usec):
179 Type Count Min Average Max Stdev
180 -----------------------------------------------------------------------------------------
181 Open 45 5.562 13.835 77.683 15.263
182 Read 109 0.316 5.774 62.569 9.277
183 Write 101 0.256 7.060 48.531 8.555
184 Sync 207 19.384 40.664 160.188 21.201
186 Disk latency statistics (usec):
187 Name Count Min Average Max Stdev
188 -----------------------------------------------------------------------------------------
189 dm-0 108 0.001 0.004 0.007 1.306
192 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
193 I/O latency frequency distribution
194 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
198 $ ./lttng-iolatencyfreq mytrace/
199 Timerange: [2015-01-06 10:58:26.140545481, 2015-01-06 10:58:27.229358936]
200 Open latency distribution (usec)
201 ###############################################################################
202 5.562 ███████████████████████████████████████████████████████████████████ 25
204 12.774 █████████████████████ 8
230 $ ./lttng-iolatencytop analysis-20150115-120942/ --limit 3 --minsize 2
231 Checking the trace for lost events...
232 Timerange: [2015-01-15 12:18:37.216484041, 2015-01-15 12:18:53.821580313]
233 Top open syscall latencies (usec)
234 Begin End Name Duration (usec) Size Proc PID Filename
235 [12:18:50.432950815,12:18:50.870648568] open 437697.753 N/A apache2 31517 /var/lib/php5/sess_0ifir2hangm8ggaljdphl9o5b5 (fd=13)
236 [12:18:52.946080165,12:18:52.946132278] open 52.113 N/A apache2 31588 /var/lib/php5/sess_mr9045p1k55vin1h0vg7rhgd63 (fd=13)
237 [12:18:46.800846035,12:18:46.800874916] open 28.881 N/A apache2 31591 /var/lib/php5/sess_r7c12pccfvjtas15g3j69u14h0 (fd=13)
238 [12:18:51.389797604,12:18:51.389824426] open 26.822 N/A apache2 31520 /var/lib/php5/sess_4sdb1rtjkhb78sabnoj8gpbl00 (fd=13)
240 Top read syscall latencies (usec)
241 Begin End Name Duration (usec) Size Proc PID Filename
242 [12:18:37.256073107,12:18:37.256555967] read 482.860 7.00 B bash 10237 unknown (origin not found) (fd=3)
243 [12:18:52.000209798,12:18:52.000252304] read 42.506 1.00 KB irqbalance 1337 /proc/interrupts (fd=3)
244 [12:18:37.256559439,12:18:37.256601615] read 42.176 5.00 B bash 10237 unknown (origin not found) (fd=3)
245 [12:18:42.000281918,12:18:42.000320016] read 38.098 1.00 KB irqbalance 1337 /proc/interrupts (fd=3)
247 Top write syscall latencies (usec)
248 Begin End Name Duration (usec) Size Proc PID Filename
249 [12:18:49.913241516,12:18:49.915908862] write 2667.346 95.00 B apache2 31584 /var/log/apache2/access.log (fd=8)
250 [12:18:37.472823631,12:18:37.472859836] writev 36.205 21.97 KB apache2 31544 unknown (origin not found) (fd=12)
251 [12:18:37.991578372,12:18:37.991612724] writev 34.352 21.97 KB apache2 31589 unknown (origin not found) (fd=12)
252 [12:18:39.547778549,12:18:39.547812515] writev 33.966 21.97 KB apache2 31584 unknown (origin not found) (fd=12)
254 Top sync syscall latencies (usec)
255 Begin End Name Duration (usec) Size Proc PID Filename
256 [12:18:50.162776739,12:18:51.157522361] sync 994745.622 N/A sync 22791 None (fd=None)
257 [12:18:37.227867532,12:18:37.232289687] sync_file_range 4422.155 N/A lttng-consumerd 19964 /home/julien/lttng-traces/analysis-20150115-120942/kernel/metadata (fd=32)
258 [12:18:37.238076585,12:18:37.239012027] sync_file_range 935.442 N/A lttng-consumerd 19964 /home/julien/lttng-traces/analysis-20150115-120942/kernel/metadata (fd=32)
259 [12:18:37.220974711,12:18:37.221647124] sync_file_range 672.413 N/A lttng-consumerd 19964 /home/julien/lttng-traces/analysis-20150115-120942/kernel/metadata (fd=32)
268 $ ./lttng-iolog mytrace/
269 [10:58:26.221618530,10:58:26.221620659] write 2.129 8.00 B /usr/bin/x-term 11793 anon_inode:[eventfd] (fd=5)
270 [10:58:26.221623609,10:58:26.221628055] read 4.446 50.00 B /usr/bin/x-term 11793 /dev/ptmx (fd=24)
271 [10:58:26.221638929,10:58:26.221640008] write 1.079 8.00 B /usr/bin/x-term 11793 anon_inode:[eventfd] (fd=5)
272 [10:58:26.221676232,10:58:26.221677385] read 1.153 8.00 B /usr/bin/x-term 11793 anon_inode:[eventfd] (fd=5)
273 [10:58:26.223401804,10:58:26.223411683] open 9.879 N/A sleep 12420 /etc/ld.so.cache (fd=3)
274 [10:58:26.223448060,10:58:26.223455577] open 7.517 N/A sleep 12420 /lib/x86_64-linux-gnu/libc.so.6 (fd=3)
275 [10:58:26.223456522,10:58:26.223458898] read 2.376 832.00 B sleep 12420 /lib/x86_64-linux-gnu/libc.so.6 (fd=3)
276 [10:58:26.223918068,10:58:26.223929316] open 11.248 N/A sleep 12420 (fd=3)
277 [10:58:26.231881565,10:58:26.231895970] writev 14.405 16.00 B /usr/bin/x-term 11793 socket:[45650] (fd=4)
278 [10:58:26.231979636,10:58:26.231988446] recvmsg 8.810 16.00 B Xorg 1827 socket:[47480] (fd=38)
287 $ ./lttng-iousagetop traces/pgread-writes
288 Timerange: [2014-10-07 16:36:00.733214969, 2014-10-07 16:36:18.804584183]
290 ###############################################################################
291 ██████████████████████████████████████████████████ 16.00 MB lttng-consumerd (2619) 0 B file 4.00 B net 16.00 MB unknown
292 █████ 1.72 MB lttng-consumerd (2619) 0 B file 0 B net 1.72 MB unknown
293 █ 398.13 KB postgres (4219) 121.05 KB file 277.07 KB net 8.00 B unknown
294 256.09 KB postgres (1348) 0 B file 255.97 KB net 117.00 B unknown
295 204.81 KB postgres (4218) 204.81 KB file 0 B net 0 B unknown
296 123.77 KB postgres (4220) 117.50 KB file 6.26 KB net 8.00 B unknown
297 Per-process I/O Write
298 ###############################################################################
299 ██████████████████████████████████████████████████ 16.00 MB lttng-consumerd (2619) 0 B file 8.00 MB net 8.00 MB unknown
300 ██████ 2.20 MB postgres (4219) 2.00 MB file 202.23 KB net 0 B unknown
301 █████ 1.73 MB lttng-consumerd (2619) 0 B file 887.73 KB net 882.58 KB unknown
302 ██ 726.33 KB postgres (1165) 8.00 KB file 6.33 KB net 712.00 KB unknown
303 158.69 KB postgres (1168) 158.69 KB file 0 B net 0 B unknown
304 80.66 KB postgres (1348) 0 B file 80.66 KB net 0 B unknown
306 ###############################################################################
307 ██████████████████████████████████████████████████ 8.00 MB anon_inode:[lttng_stream] (lttng-consumerd) 'fd 32 in lttng-consumerd (2619)'
308 █████ 834.41 KB base/16384/pg_internal.init 'fd 7 in postgres (4219)', 'fd 7 in postgres (4220)', 'fd 7 in postgres (4221)', 'fd 7 in postgres (4222)', 'fd 7 in postgres (4223)', 'fd 7 in postgres (4224)', 'fd 7 in postgres (4225)', 'fd 7 in postgres (4226)'
309 █ 256.09 KB socket:[8893] (postgres) 'fd 9 in postgres (1348)'
310 █ 174.69 KB pg_stat_tmp/pgstat.stat 'fd 9 in postgres (4218)', 'fd 9 in postgres (1167)'
311 109.48 KB global/pg_internal.init 'fd 7 in postgres (4218)', 'fd 7 in postgres (4219)', 'fd 7 in postgres (4220)', 'fd 7 in postgres (4221)', 'fd 7 in postgres (4222)', 'fd 7 in postgres (4223)', 'fd 7 in postgres (4224)', 'fd 7 in postgres (4225)', 'fd 7 in postgres (4226)'
312 104.30 KB base/11951/pg_internal.init 'fd 7 in postgres (4218)'
313 12.85 KB socket (lttng-sessiond) 'fd 30 in lttng-sessiond (384)'
314 4.50 KB global/pg_filenode.map 'fd 7 in postgres (4218)', 'fd 7 in postgres (4219)', 'fd 7 in postgres (4220)', 'fd 7 in postgres (4221)', 'fd 7 in postgres (4222)', 'fd 7 in postgres (4223)', 'fd 7 in postgres (4224)', 'fd 7 in postgres (4225)', 'fd 7 in postgres (4226)'
315 4.16 KB socket (postgres) 'fd 9 in postgres (4226)'
316 4.00 KB /proc/interrupts 'fd 3 in irqbalance (1104)'
318 ###############################################################################
319 ██████████████████████████████████████████████████ 8.00 MB socket:[56371] (lttng-consumerd) 'fd 30 in lttng-consumerd (2619)'
320 █████████████████████████████████████████████████ 8.00 MB pipe:[53306] (lttng-consumerd) 'fd 12 in lttng-consumerd (2619)'
321 ██████████ 1.76 MB pg_xlog/00000001000000000000000B 'fd 31 in postgres (4219)'
322 █████ 887.82 KB socket:[56369] (lttng-consumerd) 'fd 26 in lttng-consumerd (2619)'
323 █████ 882.58 KB pipe:[53309] (lttng-consumerd) 'fd 18 in lttng-consumerd (2619)'
324 160.00 KB /var/lib/postgresql/9.1/main/base/16384/16602 'fd 14 in postgres (1165)'
325 158.69 KB pg_stat_tmp/pgstat.tmp 'fd 3 in postgres (1168)'
326 144.00 KB /var/lib/postgresql/9.1/main/base/16384/16613 'fd 12 in postgres (1165)'
327 88.00 KB /var/lib/postgresql/9.1/main/base/16384/16609 'fd 11 in postgres (1165)'
328 78.28 KB socket:[8893] (postgres) 'fd 9 in postgres (1348)'
330 ###############################################################################
332 ###############################################################################
333 ██████████████████████████████████████████████████ 1.76 MB postgres (pid=4219)
334 ████ 160.00 KB postgres (pid=1168)
335 ██ 100.00 KB kworker/u8:0 (pid=1540)
336 ██ 96.00 KB jbd2/vda1-8 (pid=257)
337 █ 40.00 KB postgres (pid=1166)
338 8.00 KB kworker/u9:0 (pid=4197)
339 4.00 KB kworker/u9:2 (pid=1381)
341 ###############################################################################
342 ███████████████████████████████████████████████████████████████████ 4416.00 sectors vda1
344 ###############################################################################
345 ████████████████████████████████████████████████████████████████████ 177.00 requests vda1
346 Disk request time/sector
347 ###############################################################################
348 ██████████████████████████████████████████████████████████████████ 0.01 ms vda1
350 ###############################################################################
351 ███████████████████████████████████████████████████████ 739.50 KB eth0
354 ###############################################################################
355 ████████████████████████████████████████████████████████ 9.36 MB eth0
368 $ ./lttng-syscallstats mytrace/
369 Timerange: [2015-01-15 12:18:37.216484041, 2015-01-15 12:18:53.821580313]
370 Per-TID syscalls statistics (usec)
371 find (22785) Count Min Average Max Stdev Return values
372 - getdents 14240 0.380 364.301 43372.450 1629.390 {'success': 14240}
373 - close 14236 0.233 0.506 4.932 0.217 {'success': 14236}
374 - fchdir 14231 0.252 0.407 5.769 0.117 {'success': 14231}
375 - open 7123 0.779 2.321 12.697 0.936 {'success': 7119, 'ENOENT': 4}
376 - newfstatat 7118 1.457 143.562 28103.532 1410.281 {'success': 7118}
377 - openat 7118 1.525 2.411 9.107 0.771 {'success': 7118}
378 - newfstat 7117 0.272 0.654 8.707 0.248 {'success': 7117}
379 - write 573 0.298 0.715 8.584 0.391 {'success': 573}
380 - brk 27 0.615 5.768 30.792 7.830 {'success': 27}
381 - rt_sigaction 22 0.227 0.283 0.589 0.098 {'success': 22}
382 - mmap 12 1.116 2.116 3.597 0.762 {'success': 12}
383 - mprotect 6 1.185 2.235 3.923 1.148 {'success': 6}
384 - read 5 0.925 2.101 6.300 2.351 {'success': 5}
385 - ioctl 4 0.342 1.151 2.280 0.873 {'success': 2, 'ENOTTY': 2}
386 - access 4 1.166 2.530 4.202 1.527 {'ENOENT': 4}
387 - rt_sigprocmask 3 0.325 0.570 0.979 0.357 {'success': 3}
388 - dup2 2 0.250 0.562 0.874 ? {'success': 2}
389 - munmap 2 3.006 5.399 7.792 ? {'success': 2}
390 - execve 1 7277.974 7277.974 7277.974 ? {'success': 1}
391 - setpgid 1 0.945 0.945 0.945 ? {'success': 1}
392 - fcntl 1 ? 0.000 0.000 ? {}
393 - newuname 1 1.240 1.240 1.240 ? {'success': 1}
395 -----------------------------------------------------------------------------------------------------------------
396 apache2 (31517) Count Min Average Max Stdev Return values
397 - fcntl 192 ? 0.000 0.000 ? {}
398 - newfstat 156 0.237 0.484 1.102 0.222 {'success': 156}
399 - read 144 0.307 1.602 16.307 1.698 {'success': 117, 'EAGAIN': 27}
400 - access 96 0.705 1.580 3.364 0.670 {'success': 12, 'ENOENT': 84}
401 - newlstat 84 0.459 0.738 1.456 0.186 {'success': 63, 'ENOENT': 21}
402 - newstat 74 0.735 2.266 11.212 1.772 {'success': 50, 'ENOENT': 24}
403 - lseek 72 0.317 0.522 0.915 0.112 {'success': 72}
404 - close 39 0.471 0.615 0.867 0.069 {'success': 39}
405 - open 36 2.219 12162.689 437697.753 72948.868 {'success': 36}
406 - getcwd 28 0.287 0.701 1.331 0.277 {'success': 28}
407 - poll 27 1.080 1139.669 2851.163 856.723 {'success': 27}
408 - times 24 0.765 0.956 1.327 0.107 {'success': 24}
409 - setitimer 24 0.499 5.848 16.668 4.041 {'success': 24}
410 - write 24 5.467 6.784 16.827 2.459 {'success': 24}
411 - writev 24 10.241 17.645 29.817 5.116 {'success': 24}
412 - mmap 15 3.060 3.482 4.406 0.317 {'success': 15}
413 - munmap 15 2.944 3.502 4.154 0.427 {'success': 15}
414 - brk 12 0.738 4.579 13.795 4.437 {'success': 12}
415 - chdir 12 0.989 1.600 2.353 0.385 {'success': 12}
416 - flock 6 0.906 1.282 2.043 0.423 {'success': 6}
417 - rt_sigaction 6 0.530 0.725 1.123 0.217 {'success': 6}
418 - pwrite64 6 1.262 1.430 1.692 0.143 {'success': 6}
419 - rt_sigprocmask 6 0.539 0.650 0.976 0.162 {'success': 6}
420 - shutdown 3 7.323 8.487 10.281 1.576 {'success': 3}
421 - getsockname 3 1.015 1.228 1.585 0.311 {'success': 3}
422 - accept4 3 5174453.611 3450157.282 5176018.235 ? {'success': 2}
430 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
431 Handler duration and raise latency statistics
432 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
436 $ ./lttng-irqstats mytrace/
437 Timerange: [2014-03-11 16:05:41.314824752, 2014-03-11 16:05:45.041994298]
438 Hard IRQ Duration (us)
439 count min avg max stdev
440 ----------------------------------------------------------------------------------|
441 1: <i8042> 30 10.901 45.500 64.510 18.447 |
442 42: <ahci> 259 3.203 7.863 21.426 3.183 |
443 43: <eth0> 2 3.859 3.976 4.093 0.165 |
444 44: <iwlwifi> 92 0.300 3.995 6.542 2.181 |
446 Soft IRQ Duration (us) Raise latency (us)
447 count min avg max stdev | count min avg max stdev
448 ----------------------------------------------------------------------------------|------------------------------------------------------------
449 1: <TIMER_SOFTIRQ> 495 0.202 21.058 51.060 11.047 | 53 2.141 11.217 20.005 7.233
450 3: <NET_RX_SOFTIRQ> 14 0.133 9.177 32.774 10.483 | 14 0.763 3.703 10.902 3.448
451 4: <BLOCK_SOFTIRQ> 257 5.981 29.064 125.862 15.891 | 257 0.891 3.104 15.054 2.046
452 6: <TASKLET_SOFTIRQ> 26 0.309 1.198 1.748 0.329 | 26 9.636 39.222 51.430 11.246
453 7: <SCHED_SOFTIRQ> 299 1.185 14.768 90.465 15.992 | 298 1.286 31.387 61.700 11.866
454 9: <RCU_SOFTIRQ> 338 0.592 3.387 13.745 1.356 | 147 2.480 29.299 64.453 14.286
457 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
458 Handler duration frequency distribution
459 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
463 $ ./lttng-irqfreq --timerange [16:05:42,16:05:45] --irq 44 --stats mytrace/
464 Timerange: [2014-03-11 16:05:42.042034570, 2014-03-11 16:05:44.998914297]
465 Hard IRQ Duration (us)
466 count min avg max stdev
467 ----------------------------------------------------------------------------------|
468 44: <iwlwifi> 72 0.300 4.018 6.542 2.164 |
469 Frequency distribution iwlwifi (44)
470 ###############################################################################
472 0.612 ██████████████████████████████████████████████████████████████ 12.00
473 0.924 ████████████████████ 4.00
474 1.236 ██████████ 2.00
479 2.797 ██████████████████████████ 5.00
481 3.421 ███████████████ 3.00
485 4.669 ██████████ 2.00
486 4.981 ██████████ 2.00
487 5.294 █████████████████████████████████████████ 8.00
488 5.606 ████████████████████████████████████████████████████████████████████ 13.00
489 5.918 ██████████████████████████████████████████████████████████████ 12.00
490 6.230 ███████████████ 3.00
497 There are a lot of other scripts, we encourage you to try them and read the
498 ``--help`` to see all the available options.
505 Track the page cache and extract the latencies associated with pages flush to disk.
506 In order to do that, we rely on the assumption that the pages are flushed in a FIFO
507 order. It might not be 100% accurate, but it already gives great results :
509 An example here when saving a file in vim::
511 [19:57:51.173332284 - 19:57:51.177794657] vim (31517) syscall_entry_fsync(fd = 4 <blabla>) = 0, 4.462 ms
512 1 dirty page(s) were flushed (assuming FIFO):
515 13 active dirty filesystem page(s) (known):
516 redis-server (2092): 2 pages
517 - /var/log/redis/redis-server.log : 2 pages
519 - .blabla.swp : 2 pages
520 lttng-consumerd (6750): 9 pages
521 - unknown (origin not found) : 9 pages
524 An other example when running the 'sync' command::
526 [19:57:53.046840755 - 19:57:53.072809609] sync (31554) syscall_entry_sync(fd = <unknown>) = 0, 25.969 ms
527 23 dirty page(s) were flushed (assuming FIFO):
528 redis-server (2092): 2 pages
529 - /var/log/redis/redis-server.log : 2 pages
531 - /home/julien/.viminfo.tmp : 6 pages
532 - .blabla.swp : 3 pages
533 lttng-consumerd (6750): 12 pages
534 - unknown (origin not found) : 12 pages
537 PostgreSQL with 'sys_fdatasync'::
539 [13:49:39.908599447 - 13:49:39.915930730] postgres (1137) sys_fdatasync(fd = 7 </var/lib/postgresql/9.1/main/pg_xlog/000000010000000000000008>) = 0, 7.331 ms
540 2 pages allocated during the period
541 88 dirty page(s) were flushed (assuming FIFO):
542 postgres (1137): 88 pages
543 - /var/lib/postgresql/9.1/main/pg_xlog/000000010000000000000008 : 88 pages
544 68 last dirtied filesystem page(s):
545 postgres (2419): 68 pages
546 - base/11951/18410 : 46 pages
547 - base/11951/18407 : 10 pages
548 - base/11951/18407_fsm : 6 pages
549 - base/11951/18410_fsm : 6 pages
552 Detecting a fight for the I/O between a huge write and postgresql::
554 [13:49:47.242730583 - 13:49:47.442835037] python (2353) sys_write(fd = 3 </root/bla>, count = 102395904) = 102395904, 200.104 ms
555 34760 pages allocated during the period
556 woke up kswapd during the period
557 10046 pages written on disk
558 freed 33753 pages from the cache during the period
559 1397 last dirtied filesystem page(s):
560 python (2353): 1325 pages
561 - /root/bla : 1325 pages
562 postgres (2419): 72 pages
563 - base/11951/18419 : 72 pages
570 The main limitation of this project is the fact that it can be quite slow to
571 process a large trace. This project is a work in progress and we focus on the
572 problem-solving aspect. Therefore, features have been prioritized over
575 One other aspect is the fact that the state is not persistent; the trace has
576 to be re-processed if another analysis script is to be used on the same trace.
577 Some scripts belonging to the same category allow the combination of multiple
578 analyses into a single pass (see ``--freq``, ``--log``, ``--usage``,
579 ``--latencystats``, etc). We are planning to add a way to save the state
580 and/or create an interactive environment to allow the user to run multiple
581 analyses on the same trace without having to process the trace every time.
588 We hope you have fun trying this project and please remember it is a work in
589 progress; feedback, bug reports and improvement ideas are always welcome!
592 .. _pip: http://www.pip-installer.org/en/latest/index.html
595 .. |pypi| image:: https://img.shields.io/pypi/v/lttnganalyses.svg?style=flat-square&label=latest%20version
596 :target: https://pypi.python.org/pypi/lttnganalyses
597 :alt: Latest version released on PyPi