Commit graph

2 commits

Author SHA1 Message Date
Mel Gorman
b898cc7001 vmscan: tracing: add a postprocessing script for reclaim-related ftrace events
Add a simple post-processing script for the reclaim-related trace events.
It can be used to give an indication of how much traffic there is on the
LRU lists and how severe latencies due to reclaim are.  Example output
looks like the following

Reclaim latencies expressed as order-latency_in_ms
uname-3942             9-200.179000000004 9-98.7900000000373 9-99.8330000001006
kswapd0-311            0-662.097999999998 0-2.79700000002049 \
	0-149.100000000035 0-3295.73600000003 0-9806.31799999997 0-35528.833 \
	0-10043.197 0-129740.979 0-3.50500000000466 0-3.54899999999907 \
	0-9297.78999999992 0-3.48499999998603 0-3596.97999999998 0-3.92799999995623 \
	0-3.35000000009313 0-16729.017 0-3.57799999997951 0-47435.0630000001 \
	0-3.7819999998901 0-5864.06999999995 0-18635.334 0-10541.289 9-186011.565 \
	9-3680.86300000001 9-1379.06499999994 9-958571.115 9-66215.474 \
	9-6721.14699999988 9-1962.15299999993 9-1094806.125 9-2267.83199999994 \
	9-47120.9029999999 9-427653.886 9-2.6359999999404 9-632.148999999976 \
	9-476.753000000026 9-495.577000000048 9-8.45900000003166 9-6.6820000000298 \
	9-1.30500000016764 9-251.746000000043 9-383.905000000028 9-80.1419999999925 \
	9-281.160000000149 9-14.8780000000261 9-381.45299999998 9-512.07799999998 \
	9-49.5519999999087 9-167.439000000013 9-183.820999999996 9-239.527999999933 \
	9-19.9479999998584 9-148.747999999905 9-164.583000000101 9-16.9480000000913 \
	9-192.376000000164 9-64.1010000000242 9-1.40800000005402 9-3.60800000000745 \
	9-17.1359999999404 9-4.69500000006519 9-2.06400000001304 9-1582488.554 \
	9-6244.19499999983 9-348153.812 9-2.0999999998603 9-0.987999999895692 \
	0-32218.473 0-1.6140000000596 0-1.28100000019185 0-1.41300000017509 \
	0-1.32299999985844 0-602.584000000032 0-1.34400000004098 0-1.6929999999702 \
	1-22101.8190000001 9-174876.724 9-16.2420000000857 9-175.165999999736 \
	9-15.8589999997057 9-0.604999999981374 9-3061.09000000032 9-479.277000000235 \
	9-1.54499999992549 9-771.985000000335 9-4.88700000010431 9-15.0649999999441 \
	9-0.879999999888241 9-252.01500000013 9-1381.03600000031 9-545.689999999944 \
	9-3438.0129999998 9-3343.70099999988
bench-stresshig-3942   9-7063.33900000004 9-129960.482 9-2062.27500000002 \
	9-3845.59399999992 9-171.82799999998 9-16493.821 9-7615.23900000006 \
	9-10217.848 9-983.138000000035 9-2698.39999999991 9-4016.1540000001 \
	9-5522.37700000009 9-21630.429 \
	9-15061.048 9-10327.953 9-542.69700000016 9-317.652000000002 \
	9-8554.71699999995 9-1786.61599999992 9-1899.31499999994 9-2093.41899999999 \
	9-4992.62400000007 9-942.648999999976 9-1923.98300000001 9-3.7980000001844 \
	9-5.99899999983609 9-0.912000000011176 9-1603.67700000014 9-1.98300000000745 \
	9-3.96500000008382 9-0.902999999932945 9-2802.72199999983 9-1078.24799999991 \
	9-2155.82900000014 9-10.058999999892 9-1984.723 9-1687.97999999998 \
	9-1136.05300000007 9-3183.61699999985 9-458.731000000145 9-6.48600000003353 \
	9-1013.25200000009 9-8415.22799999989 9-10065.584 9-2076.79600000009 \
	9-3792.65699999989 9-71.2010000001173 9-2560.96999999997 9-2260.68400000012 \
	9-2862.65799999982 9-1255.81500000018 9-15.7440000001807 9-4.33499999996275 \
	9-1446.63800000004 9-238.635000000009 9-60.1790000000037 9-4.38800000003539 \
	9-639.567000000039 9-306.698000000091 9-31.4070000001229 9-74.997999999905 \
	9-632.725999999791 9-1625.93200000003 9-931.266000000061 9-98.7749999999069 \
	9-984.606999999844 9-225.638999999966 9-421.316000000108 9-653.744999999879 \
	9-572.804000000004 9-769.158999999985 9-603.918000000063 9-4.28499999991618 \
	9-626.21399999992 9-1721.25 9-0.854999999981374 9-572.39599999995 \
	9-681.881999999983 9-1345.12599999993 9-363.666999999899 9-3823.31099999999 \
	9-2991.28200000012 9-4.27099999994971 9-309.76500000013 9-3068.35700000008 \
	9-788.25 9-3515.73999999999 9-2065.96100000013 9-286.719999999972 \
	9-316.076000000117 9-344.151000000071 9-2.51000000000931 9-306.688000000082 \
	9-1515.00099999993 9-336.528999999864 9-793.491999999853 9-457.348999999929 \
	9-13620.155 9-119.933999999892 9-35.0670000000391 9-918.266999999993 \
	9-828.569000000134 9-4863.81099999999 9-105.222000000067 9-894.23900000006 \
	9-110.964999999851 9-0.662999999942258 9-12753.3150000002 9-12.6129999998957 \
	9-13368.0899999999 9-12.4199999999255 9-1.00300000002608 9-1.41100000008009 \
	9-10300.5290000001 9-16.502000000095 9-30.7949999999255 9-6283.0140000002 \
	9-4320.53799999994 9-6826.27300000004 9-3.07299999985844 9-1497.26799999992 \
	9-13.4040000000969 9-3.12999999988824 9-3.86100000003353 9-11.3539999998175 \
	9-0.10799999977462 9-21.780999999959 9-209.695999999996 9-299.647000000114 \
	9-6.01699999999255 9-20.8349999999627 9-22.5470000000205 9-5470.16800000006 \
	9-7.60499999998137 9-0.821000000229105 9-1.56600000010803 9-14.1669999998994 \
	9-0.209000000031665 9-1.82300000009127 9-1.70000000018626 9-19.9429999999702 \
	9-124.266999999993 9-0.0389999998733401 9-6.71400000015274 9-16.7710000001825 \
	9-31.0409999999683 9-0.516999999992549 9-115.888000000035 9-5.19900000002235 \
	9-222.389999999898 9-11.2739999999758 9-80.9050000000279 9-8.14500000001863 \
	9-4.44599999999627 9-0.218999999808148 9-0.715000000083819 9-0.233000000007451
\
	9-48.2630000000354 9-248.560999999987 9-374.96800000011 9-644.179000000004 \
	9-0.835999999893829 9-79.0060000000522 9-128.447999999858 9-0.692000000039116 \
	9-5.26500000013039 9-128.449000000022 9-2.04799999995157 9-12.0990000001621 \
	9-8.39899999997579 9-10.3860000001732 9-11.9310000000987 9-53.4450000000652 \
	9-0.46999999997206 9-2.96299999998882 9-17.9699999999721 9-0.776000000070781 \
	9-25.2919999998994 9-33.1110000000335 9-0.434000000124797 9-0.641000000061467 \
	9-0.505000000121072 9-1.12800000002608 9-149.222000000067 9-1.17599999997765 \
	9-3247.33100000001 9-10.7439999999478 9-153.523000000045 9-1.38300000014715 \
	9-794.762000000104 9-3.36199999996461 9-128.765999999829 9-181.543999999994 \
	9-78149.8229999999 9-176.496999999974 9-89.9940000001807 9-9.12700000009499 \
	9-250.827000000048 9-0.224999999860302 9-0.388999999966472 9-1.16700000036508 \
	9-32.1740000001155 9-12.6800000001676 9-0.0720000001601875 9-0.274999999906868
\
	9-0.724000000394881 9-266.866000000387 9-45.5709999999963 9-4.54399999976158 \
	9-8.27199999988079 9-4.38099999958649 9-0.512000000104308 9-0.0640000002458692
\
	9-5.20000000018626 9-0.0839999997988343 9-12.816000000108 9-0.503000000026077 \
	9-0.507999999914318 9-6.23999999975786 9-3.35100000025705 9-18.8530000001192 \
	9-25.2220000000671 9-68.2309999996796 9-98.9939999999478 9-0.441000000108033 \
	9-4.24599999981001 9-261.702000000048 9-3.01599999982864 9-0.0749999997206032 \
	9-0.0370000000111759 9-4.375 9-3.21800000034273 9-11.3960000001825 \
	9-0.0540000000037253 9-0.286000000312924 9-0.865999999921769 \
	9-0.294999999925494 9-6.45999999996275 9-4.31099999975413 9-128.248999999836 \
	9-0.282999999821186 9-102.155000000261 9-0.0860000001266599 \
	9-0.0540000000037253 9-0.935000000055879 9-0.0670000002719462 \
	9-5.8640000000596 9-19.9860000000335 9-4.18699999991804 9-0.566000000108033 \
	9-2.55099999997765 9-0.702000000048429 9-131.653999999631 9-0.638999999966472 \
	9-14.3229999998584 9-183.398000000045 9-178.095999999903 9-3.22899999981746 \
	9-7.31399999978021 9-22.2400000002235 9-11.7979999999516 9-108.10599999968 \
	9-99.0159999998286 9-102.640999999829 9-38.414000000339
Process                  Direct     Wokeup      Pages      Pages    Pages
details                   Rclms     Kswapd    Scanned    Sync-IO ASync-IO
cc1-30800                     0          1          0          0        0      wakeup-0=1
cc1-24260                     0          1          0          0        0      wakeup-0=1
cc1-24152                     0         12          0          0        0      wakeup-0=12
cc1-8139                      0          1          0          0        0      wakeup-0=1
cc1-4390                      0          1          0          0        0      wakeup-0=1
cc1-4648                      0          7          0          0        0      wakeup-0=7
cc1-4552                      0          3          0          0        0      wakeup-0=3
dd-4550                       0         31          0          0        0      wakeup-0=31
date-4898                     0          1          0          0        0      wakeup-0=1
cc1-6549                      0          7          0          0        0      wakeup-0=7
as-22202                      0         17          0          0        0      wakeup-0=17
cc1-6495                      0          9          0          0        0      wakeup-0=9
cc1-8299                      0          1          0          0        0      wakeup-0=1
cc1-6009                      0          1          0          0        0      wakeup-0=1
cc1-2574                      0          2          0          0        0      wakeup-0=2
cc1-30568                     0          1          0          0        0      wakeup-0=1
cc1-2679                      0          6          0          0        0      wakeup-0=6
sh-13747                      0         12          0          0        0      wakeup-0=12
cc1-22193                     0         18          0          0        0      wakeup-0=18
cc1-30725                     0          2          0          0        0      wakeup-0=2
as-4392                       0          2          0          0        0      wakeup-0=2
cc1-28180                     0         14          0          0        0      wakeup-0=14
cc1-13697                     0          2          0          0        0      wakeup-0=2
cc1-22207                     0          8          0          0        0      wakeup-0=8
cc1-15270                     0        179          0          0        0      wakeup-0=179
cc1-22011                     0         82          0          0        0      wakeup-0=82
cp-14682                      0          1          0          0        0      wakeup-0=1
as-11926                      0          2          0          0        0      wakeup-0=2
cc1-6016                      0          5          0          0        0      wakeup-0=5
make-18554                    0         13          0          0        0      wakeup-0=13
cc1-8292                      0         12          0          0        0      wakeup-0=12
make-24381                    0          1          0          0        0      wakeup-1=1
date-18681                    0         33          0          0        0      wakeup-0=33
cc1-32276                     0          1          0          0        0      wakeup-0=1
timestamp-outpu-2809          0        253          0          0        0      wakeup-0=240 wakeup-1=13
date-18624                    0          7          0          0        0      wakeup-0=7
cc1-30960                     0          9          0          0        0      wakeup-0=9
cc1-4014                      0          1          0          0        0      wakeup-0=1
cc1-30706                     0         22          0          0        0      wakeup-0=22
uname-3942                    4          1        306          0       17      direct-9=4       wakeup-9=1
cc1-28207                     0          1          0          0        0      wakeup-0=1
cc1-30563                     0          9          0          0        0      wakeup-0=9
cc1-22214                     0         10          0          0        0      wakeup-0=10
cc1-28221                     0         11          0          0        0      wakeup-0=11
cc1-28123                     0          6          0          0        0      wakeup-0=6
kswapd0-311                   0          7     357302          0    34233      wakeup-0=7
cc1-5988                      0          7          0          0        0      wakeup-0=7
as-30734                      0        161          0          0        0      wakeup-0=161
cc1-22004                     0         45          0          0        0      wakeup-0=45
date-4590                     0          4          0          0        0      wakeup-0=4
cc1-15279                     0        213          0          0        0      wakeup-0=213
date-30735                    0          1          0          0        0      wakeup-0=1
cc1-30583                     0          4          0          0        0      wakeup-0=4
cc1-32324                     0          2          0          0        0      wakeup-0=2
cc1-23933                     0          3          0          0        0      wakeup-0=3
cc1-22001                     0         36          0          0        0      wakeup-0=36
bench-stresshig-3942        287        287      80186       6295    12196      direct-9=287       wakeup-9=287
cc1-28170                     0          7          0          0        0      wakeup-0=7
date-7932                     0         92          0          0        0      wakeup-0=92
cc1-22222                     0          6          0          0        0      wakeup-0=6
cc1-32334                     0         16          0          0        0      wakeup-0=16
cc1-2690                      0          6          0          0        0      wakeup-0=6
cc1-30733                     0          9          0          0        0      wakeup-0=9
cc1-32298                     0          2          0          0        0      wakeup-0=2
cc1-13743                     0         18          0          0        0      wakeup-0=18
cc1-22186                     0          4          0          0        0      wakeup-0=4
cc1-28214                     0         11          0          0        0      wakeup-0=11
cc1-13735                     0          1          0          0        0      wakeup-0=1
updatedb-8173                 0         18          0          0        0      wakeup-0=18
cc1-13750                     0          3          0          0        0      wakeup-0=3
cat-2808                      0          2          0          0        0      wakeup-0=2
cc1-15277                     0        169          0          0        0      wakeup-0=169
date-18317                    0          1          0          0        0      wakeup-0=1
cc1-15274                     0        197          0          0        0      wakeup-0=197
cc1-30732                     0          1          0          0        0      wakeup-0=1

Kswapd                   Kswapd      Order      Pages      Pages    Pages
Instance                Wakeups  Re-wakeup    Scanned    Sync-IO ASync-IO
kswapd0-311                  91         24     357302          0    34233      wake-0=31 wake-1=1 wake-9=59       rewake-0=10 rewake-1=1 rewake-9=13

Summary
Direct reclaims:     		291
Direct reclaim pages scanned:	437794
Direct reclaim write sync I/O:	6295
Direct reclaim write async I/O:	46446
Wake kswapd requests:		2152
Time stalled direct reclaim: 	519.163009000002 ms

Kswapd wakeups:			91
Kswapd pages scanned:		357302
Kswapd reclaim write sync I/O:	0
Kswapd reclaim write async I/O:	34233
Time kswapd awake:		5282.749757 ms

Signed-off-by: Mel Gorman <mel@csn.ul.ie>
Acked-by: Rik van Riel <riel@redhat.com>
Acked-by: Larry Woodman <lwoodman@redhat.com>
Cc: Dave Chinner <david@fromorbit.com>
Cc: Chris Mason <chris.mason@oracle.com>
Cc: Nick Piggin <npiggin@suse.de>
Cc: Rik van Riel <riel@redhat.com>
Cc: Johannes Weiner <hannes@cmpxchg.org>
Cc: Christoph Hellwig <hch@infradead.org>
Cc: KAMEZAWA Hiroyuki <kamezawa.hiroyu@jp.fujitsu.com>
Cc: KOSAKI Motohiro <kosaki.motohiro@jp.fujitsu.com>
Cc: Andrea Arcangeli <aarcange@redhat.com>
Cc: Michael Rubin <mrubin@google.com>
Signed-off-by: Andrew Morton <akpm@linux-foundation.org>
Signed-off-by: Linus Torvalds <torvalds@linux-foundation.org>
2010-08-09 20:45:00 -07:00
Mel Gorman
c9d05cfc00 tracing, page-allocator: add a postprocessing script for page-allocator-related ftrace events
This patch adds a simple post-processing script for the
page-allocator-related trace events.  It can be used to give an indication
of who the most allocator-intensive processes are and how often the zone
lock was taken during the tracing period.  Example output looks like

Process                   Pages      Pages      Pages    Pages       PCPU     PCPU     PCPU   Fragment Fragment  MigType Fragment Fragment  Unknown
details                  allocd     allocd      freed    freed      pages   drains  refills   Fallback  Causing  Changed   Severe Moderate
                                under lock     direct  pagevec      drain
swapper-0                     0          0          2        0          0        0        0          0        0        0        0        0        0
Xorg-3770                 10603       5952       3685     6978       5996      194      192          0        0        0        0        0        0
modprobe-21397               51          0          0       86         31        1        0          0        0        0        0        0        0
xchat-5370                  228         93          0        0          0        0        3          0        0        0        0        0        0
awesome-4317                 32         32          0        0          0        0       32          0        0        0        0        0        0
thinkfan-3863                 2          0          1        1          0        0        0          0        0        0        0        0        0
hald-addon-stor-3935          2          0          0        0          0        0        0          0        0        0        0        0        0
akregator-4506                1          1          0        0          0        0        1          0        0        0        0        0        0
xmms-14888                    0          0          1        0          0        0        0          0        0        0        0        0        0
khelper-12                    1          0          0        0          0        0        0          0        0        0        0        0        0

Optionally, the output can include information on the parent or aggregate
based on process name instead of aggregating based on each pid. Example output
including parent information and stripped out the PID looks something like;

Process                        Pages      Pages      Pages    Pages       PCPU     PCPU     PCPU   Fragment Fragment  MigType Fragment Fragment  Unknown
details                       allocd     allocd      freed    freed      pages   drains  refills   Fallback  Causing  Changed   Severe Moderate
                                     under lock     direct  pagevec      drain
gdm-3756 :: Xorg-3770           3796       2976         99     3813       3224      104       98          0        0        0        0        0        0
init-1 :: hald-3892                1          0          0        0          0        0        0          0        0        0        0        0        0
git-21447 :: editor-21448          4          0          4        0          0        0        0          0        0        0        0        0        0

This says that Xorg allocated 3796 pages and it's parent process is gdm
with a PID of 3756;

The postprocessor parses the text output of tracing.  While there is a
binary format, the expectation is that the binary output can be readily
translated into text and post-processed offline.  Obviously if the text
format changes, the parser will break but the regular expression parser is
fairly rudimentary so should be readily adjustable.

Signed-off-by: Mel Gorman <mel@csn.ul.ie>
Cc: Rik van Riel <riel@redhat.com>
Reviewed-by: Ingo Molnar <mingo@elte.hu>
Cc: Larry Woodman <lwoodman@redhat.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Li Ming Chun <macli@brc.ubc.ca>
Signed-off-by: Andrew Morton <akpm@linux-foundation.org>
Signed-off-by: Linus Torvalds <torvalds@linux-foundation.org>
2009-09-22 07:17:34 -07:00