summaryrefslogtreecommitdiffstats
path: root/Documentation/trace/postprocess
AgeCommit message (Collapse)Author
2010-08-09vmscan: tracing: add a postprocessing script for reclaim-related ftrace eventsMel Gorman
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>
2009-09-22tracing, page-allocator: add a postprocessing script for ↵Mel Gorman
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>