aboutsummaryrefslogtreecommitdiffstats
path: root/Documentation
diff options
context:
space:
mode:
authorMel Gorman <mel@csn.ul.ie>2010-08-09 20:19:24 -0400
committerLinus Torvalds <torvalds@linux-foundation.org>2010-08-09 23:45:00 -0400
commitb898cc70019ce1835bbf6c47bdf978adc36faa42 (patch)
tree9837f7a8677873eb44e25b841d4262cd474ee9f1 /Documentation
parent755f0225e8347b23a33ee6e3fb14a35310f95766 (diff)
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>
Diffstat (limited to 'Documentation')
-rw-r--r--Documentation/trace/postprocess/trace-vmscan-postprocess.pl686
1 files changed, 686 insertions, 0 deletions
diff --git a/Documentation/trace/postprocess/trace-vmscan-postprocess.pl b/Documentation/trace/postprocess/trace-vmscan-postprocess.pl
new file mode 100644
index 000000000000..1b55146d1c8d
--- /dev/null
+++ b/Documentation/trace/postprocess/trace-vmscan-postprocess.pl
@@ -0,0 +1,686 @@
1#!/usr/bin/perl
2# This is a POC for reading the text representation of trace output related to
3# page reclaim. It makes an attempt to extract some high-level information on
4# what is going on. The accuracy of the parser may vary
5#
6# Example usage: trace-vmscan-postprocess.pl < /sys/kernel/debug/tracing/trace_pipe
7# other options
8# --read-procstat If the trace lacks process info, get it from /proc
9# --ignore-pid Aggregate processes of the same name together
10#
11# Copyright (c) IBM Corporation 2009
12# Author: Mel Gorman <mel@csn.ul.ie>
13use strict;
14use Getopt::Long;
15
16# Tracepoint events
17use constant MM_VMSCAN_DIRECT_RECLAIM_BEGIN => 1;
18use constant MM_VMSCAN_DIRECT_RECLAIM_END => 2;
19use constant MM_VMSCAN_KSWAPD_WAKE => 3;
20use constant MM_VMSCAN_KSWAPD_SLEEP => 4;
21use constant MM_VMSCAN_LRU_SHRINK_ACTIVE => 5;
22use constant MM_VMSCAN_LRU_SHRINK_INACTIVE => 6;
23use constant MM_VMSCAN_LRU_ISOLATE => 7;
24use constant MM_VMSCAN_WRITEPAGE_FILE_SYNC => 8;
25use constant MM_VMSCAN_WRITEPAGE_ANON_SYNC => 9;
26use constant MM_VMSCAN_WRITEPAGE_FILE_ASYNC => 10;
27use constant MM_VMSCAN_WRITEPAGE_ANON_ASYNC => 11;
28use constant MM_VMSCAN_WRITEPAGE_ASYNC => 12;
29use constant EVENT_UNKNOWN => 13;
30
31# Per-order events
32use constant MM_VMSCAN_DIRECT_RECLAIM_BEGIN_PERORDER => 11;
33use constant MM_VMSCAN_WAKEUP_KSWAPD_PERORDER => 12;
34use constant MM_VMSCAN_KSWAPD_WAKE_PERORDER => 13;
35use constant HIGH_KSWAPD_REWAKEUP_PERORDER => 14;
36
37# Constants used to track state
38use constant STATE_DIRECT_BEGIN => 15;
39use constant STATE_DIRECT_ORDER => 16;
40use constant STATE_KSWAPD_BEGIN => 17;
41use constant STATE_KSWAPD_ORDER => 18;
42
43# High-level events extrapolated from tracepoints
44use constant HIGH_DIRECT_RECLAIM_LATENCY => 19;
45use constant HIGH_KSWAPD_LATENCY => 20;
46use constant HIGH_KSWAPD_REWAKEUP => 21;
47use constant HIGH_NR_SCANNED => 22;
48use constant HIGH_NR_TAKEN => 23;
49use constant HIGH_NR_RECLAIM => 24;
50use constant HIGH_NR_CONTIG_DIRTY => 25;
51
52my %perprocesspid;
53my %perprocess;
54my %last_procmap;
55my $opt_ignorepid;
56my $opt_read_procstat;
57
58my $total_wakeup_kswapd;
59my ($total_direct_reclaim, $total_direct_nr_scanned);
60my ($total_direct_latency, $total_kswapd_latency);
61my ($total_direct_writepage_file_sync, $total_direct_writepage_file_async);
62my ($total_direct_writepage_anon_sync, $total_direct_writepage_anon_async);
63my ($total_kswapd_nr_scanned, $total_kswapd_wake);
64my ($total_kswapd_writepage_file_sync, $total_kswapd_writepage_file_async);
65my ($total_kswapd_writepage_anon_sync, $total_kswapd_writepage_anon_async);
66
67# Catch sigint and exit on request
68my $sigint_report = 0;
69my $sigint_exit = 0;
70my $sigint_pending = 0;
71my $sigint_received = 0;
72sub sigint_handler {
73 my $current_time = time;
74 if ($current_time - 2 > $sigint_received) {
75 print "SIGINT received, report pending. Hit ctrl-c again to exit\n";
76 $sigint_report = 1;
77 } else {
78 if (!$sigint_exit) {
79 print "Second SIGINT received quickly, exiting\n";
80 }
81 $sigint_exit++;
82 }
83
84 if ($sigint_exit > 3) {
85 print "Many SIGINTs received, exiting now without report\n";
86 exit;
87 }
88
89 $sigint_received = $current_time;
90 $sigint_pending = 1;
91}
92$SIG{INT} = "sigint_handler";
93
94# Parse command line options
95GetOptions(
96 'ignore-pid' => \$opt_ignorepid,
97 'read-procstat' => \$opt_read_procstat,
98);
99
100# Defaults for dynamically discovered regex's
101my $regex_direct_begin_default = 'order=([0-9]*) may_writepage=([0-9]*) gfp_flags=([A-Z_|]*)';
102my $regex_direct_end_default = 'nr_reclaimed=([0-9]*)';
103my $regex_kswapd_wake_default = 'nid=([0-9]*) order=([0-9]*)';
104my $regex_kswapd_sleep_default = 'nid=([0-9]*)';
105my $regex_wakeup_kswapd_default = 'nid=([0-9]*) zid=([0-9]*) order=([0-9]*)';
106my $regex_lru_isolate_default = 'isolate_mode=([0-9]*) order=([0-9]*) nr_requested=([0-9]*) nr_scanned=([0-9]*) nr_taken=([0-9]*) contig_taken=([0-9]*) contig_dirty=([0-9]*) contig_failed=([0-9]*)';
107my $regex_lru_shrink_inactive_default = 'lru=([A-Z_]*) nr_scanned=([0-9]*) nr_reclaimed=([0-9]*) priority=([0-9]*)';
108my $regex_lru_shrink_active_default = 'lru=([A-Z_]*) nr_scanned=([0-9]*) nr_rotated=([0-9]*) priority=([0-9]*)';
109my $regex_writepage_default = 'page=([0-9a-f]*) pfn=([0-9]*) flags=([A-Z_|]*)';
110
111# Dyanically discovered regex
112my $regex_direct_begin;
113my $regex_direct_end;
114my $regex_kswapd_wake;
115my $regex_kswapd_sleep;
116my $regex_wakeup_kswapd;
117my $regex_lru_isolate;
118my $regex_lru_shrink_inactive;
119my $regex_lru_shrink_active;
120my $regex_writepage;
121
122# Static regex used. Specified like this for readability and for use with /o
123# (process_pid) (cpus ) ( time ) (tpoint ) (details)
124my $regex_traceevent = '\s*([a-zA-Z0-9-]*)\s*(\[[0-9]*\])\s*([0-9.]*):\s*([a-zA-Z_]*):\s*(.*)';
125my $regex_statname = '[-0-9]*\s\((.*)\).*';
126my $regex_statppid = '[-0-9]*\s\(.*\)\s[A-Za-z]\s([0-9]*).*';
127
128sub generate_traceevent_regex {
129 my $event = shift;
130 my $default = shift;
131 my $regex;
132
133 # Read the event format or use the default
134 if (!open (FORMAT, "/sys/kernel/debug/tracing/events/$event/format")) {
135 print("WARNING: Event $event format string not found\n");
136 return $default;
137 } else {
138 my $line;
139 while (!eof(FORMAT)) {
140 $line = <FORMAT>;
141 $line =~ s/, REC->.*//;
142 if ($line =~ /^print fmt:\s"(.*)".*/) {
143 $regex = $1;
144 $regex =~ s/%s/\([0-9a-zA-Z|_]*\)/g;
145 $regex =~ s/%p/\([0-9a-f]*\)/g;
146 $regex =~ s/%d/\([-0-9]*\)/g;
147 $regex =~ s/%ld/\([-0-9]*\)/g;
148 $regex =~ s/%lu/\([0-9]*\)/g;
149 }
150 }
151 }
152
153 # Can't handle the print_flags stuff but in the context of this
154 # script, it really doesn't matter
155 $regex =~ s/\(REC.*\) \? __print_flags.*//;
156
157 # Verify fields are in the right order
158 my $tuple;
159 foreach $tuple (split /\s/, $regex) {
160 my ($key, $value) = split(/=/, $tuple);
161 my $expected = shift;
162 if ($key ne $expected) {
163 print("WARNING: Format not as expected for event $event '$key' != '$expected'\n");
164 $regex =~ s/$key=\((.*)\)/$key=$1/;
165 }
166 }
167
168 if (defined shift) {
169 die("Fewer fields than expected in format");
170 }
171
172 return $regex;
173}
174
175$regex_direct_begin = generate_traceevent_regex(
176 "vmscan/mm_vmscan_direct_reclaim_begin",
177 $regex_direct_begin_default,
178 "order", "may_writepage",
179 "gfp_flags");
180$regex_direct_end = generate_traceevent_regex(
181 "vmscan/mm_vmscan_direct_reclaim_end",
182 $regex_direct_end_default,
183 "nr_reclaimed");
184$regex_kswapd_wake = generate_traceevent_regex(
185 "vmscan/mm_vmscan_kswapd_wake",
186 $regex_kswapd_wake_default,
187 "nid", "order");
188$regex_kswapd_sleep = generate_traceevent_regex(
189 "vmscan/mm_vmscan_kswapd_sleep",
190 $regex_kswapd_sleep_default,
191 "nid");
192$regex_wakeup_kswapd = generate_traceevent_regex(
193 "vmscan/mm_vmscan_wakeup_kswapd",
194 $regex_wakeup_kswapd_default,
195 "nid", "zid", "order");
196$regex_lru_isolate = generate_traceevent_regex(
197 "vmscan/mm_vmscan_lru_isolate",
198 $regex_lru_isolate_default,
199 "isolate_mode", "order",
200 "nr_requested", "nr_scanned", "nr_taken",
201 "contig_taken", "contig_dirty", "contig_failed");
202$regex_lru_shrink_inactive = generate_traceevent_regex(
203 "vmscan/mm_vmscan_lru_shrink_inactive",
204 $regex_lru_shrink_inactive_default,
205 "nid", "zid",
206 "lru",
207 "nr_scanned", "nr_reclaimed", "priority");
208$regex_lru_shrink_active = generate_traceevent_regex(
209 "vmscan/mm_vmscan_lru_shrink_active",
210 $regex_lru_shrink_active_default,
211 "nid", "zid",
212 "lru",
213 "nr_scanned", "nr_rotated", "priority");
214$regex_writepage = generate_traceevent_regex(
215 "vmscan/mm_vmscan_writepage",
216 $regex_writepage_default,
217 "page", "pfn", "flags");
218
219sub read_statline($) {
220 my $pid = $_[0];
221 my $statline;
222
223 if (open(STAT, "/proc/$pid/stat")) {
224 $statline = <STAT>;
225 close(STAT);
226 }
227
228 if ($statline eq '') {
229 $statline = "-1 (UNKNOWN_PROCESS_NAME) R 0";
230 }
231
232 return $statline;
233}
234
235sub guess_process_pid($$) {
236 my $pid = $_[0];
237 my $statline = $_[1];
238
239 if ($pid == 0) {
240 return "swapper-0";
241 }
242
243 if ($statline !~ /$regex_statname/o) {
244 die("Failed to math stat line for process name :: $statline");
245 }
246 return "$1-$pid";
247}
248
249# Convert sec.usec timestamp format
250sub timestamp_to_ms($) {
251 my $timestamp = $_[0];
252
253 my ($sec, $usec) = split (/\./, $timestamp);
254 return ($sec * 1000) + ($usec / 1000);
255}
256
257sub process_events {
258 my $traceevent;
259 my $process_pid;
260 my $cpus;
261 my $timestamp;
262 my $tracepoint;
263 my $details;
264 my $statline;
265
266 # Read each line of the event log
267EVENT_PROCESS:
268 while ($traceevent = <STDIN>) {
269 if ($traceevent =~ /$regex_traceevent/o) {
270 $process_pid = $1;
271 $timestamp = $3;
272 $tracepoint = $4;
273
274 $process_pid =~ /(.*)-([0-9]*)$/;
275 my $process = $1;
276 my $pid = $2;
277
278 if ($process eq "") {
279 $process = $last_procmap{$pid};
280 $process_pid = "$process-$pid";
281 }
282 $last_procmap{$pid} = $process;
283
284 if ($opt_read_procstat) {
285 $statline = read_statline($pid);
286 if ($opt_read_procstat && $process eq '') {
287 $process_pid = guess_process_pid($pid, $statline);
288 }
289 }
290 } else {
291 next;
292 }
293
294 # Perl Switch() sucks majorly
295 if ($tracepoint eq "mm_vmscan_direct_reclaim_begin") {
296 $timestamp = timestamp_to_ms($timestamp);
297 $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN}++;
298 $perprocesspid{$process_pid}->{STATE_DIRECT_BEGIN} = $timestamp;
299
300 $details = $5;
301 if ($details !~ /$regex_direct_begin/o) {
302 print "WARNING: Failed to parse mm_vmscan_direct_reclaim_begin as expected\n";
303 print " $details\n";
304 print " $regex_direct_begin\n";
305 next;
306 }
307 my $order = $1;
308 $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN_PERORDER}[$order]++;
309 $perprocesspid{$process_pid}->{STATE_DIRECT_ORDER} = $order;
310 } elsif ($tracepoint eq "mm_vmscan_direct_reclaim_end") {
311 # Count the event itself
312 my $index = $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_END};
313 $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_END}++;
314
315 # Record how long direct reclaim took this time
316 if (defined $perprocesspid{$process_pid}->{STATE_DIRECT_BEGIN}) {
317 $timestamp = timestamp_to_ms($timestamp);
318 my $order = $perprocesspid{$process_pid}->{STATE_DIRECT_ORDER};
319 my $latency = ($timestamp - $perprocesspid{$process_pid}->{STATE_DIRECT_BEGIN});
320 $perprocesspid{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index] = "$order-$latency";
321 }
322 } elsif ($tracepoint eq "mm_vmscan_kswapd_wake") {
323 $details = $5;
324 if ($details !~ /$regex_kswapd_wake/o) {
325 print "WARNING: Failed to parse mm_vmscan_kswapd_wake as expected\n";
326 print " $details\n";
327 print " $regex_kswapd_wake\n";
328 next;
329 }
330
331 my $order = $2;
332 $perprocesspid{$process_pid}->{STATE_KSWAPD_ORDER} = $order;
333 if (!$perprocesspid{$process_pid}->{STATE_KSWAPD_BEGIN}) {
334 $timestamp = timestamp_to_ms($timestamp);
335 $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE}++;
336 $perprocesspid{$process_pid}->{STATE_KSWAPD_BEGIN} = $timestamp;
337 $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE_PERORDER}[$order]++;
338 } else {
339 $perprocesspid{$process_pid}->{HIGH_KSWAPD_REWAKEUP}++;
340 $perprocesspid{$process_pid}->{HIGH_KSWAPD_REWAKEUP_PERORDER}[$order]++;
341 }
342 } elsif ($tracepoint eq "mm_vmscan_kswapd_sleep") {
343
344 # Count the event itself
345 my $index = $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_SLEEP};
346 $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_SLEEP}++;
347
348 # Record how long kswapd was awake
349 $timestamp = timestamp_to_ms($timestamp);
350 my $order = $perprocesspid{$process_pid}->{STATE_KSWAPD_ORDER};
351 my $latency = ($timestamp - $perprocesspid{$process_pid}->{STATE_KSWAPD_BEGIN});
352 $perprocesspid{$process_pid}->{HIGH_KSWAPD_LATENCY}[$index] = "$order-$latency";
353 $perprocesspid{$process_pid}->{STATE_KSWAPD_BEGIN} = 0;
354 } elsif ($tracepoint eq "mm_vmscan_wakeup_kswapd") {
355 $perprocesspid{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD}++;
356
357 $details = $5;
358 if ($details !~ /$regex_wakeup_kswapd/o) {
359 print "WARNING: Failed to parse mm_vmscan_wakeup_kswapd as expected\n";
360 print " $details\n";
361 print " $regex_wakeup_kswapd\n";
362 next;
363 }
364 my $order = $3;
365 $perprocesspid{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD_PERORDER}[$order]++;
366 } elsif ($tracepoint eq "mm_vmscan_lru_isolate") {
367 $details = $5;
368 if ($details !~ /$regex_lru_isolate/o) {
369 print "WARNING: Failed to parse mm_vmscan_lru_isolate as expected\n";
370 print " $details\n";
371 print " $regex_lru_isolate/o\n";
372 next;
373 }
374 my $nr_scanned = $4;
375 my $nr_contig_dirty = $7;
376 $perprocesspid{$process_pid}->{HIGH_NR_SCANNED} += $nr_scanned;
377 $perprocesspid{$process_pid}->{HIGH_NR_CONTIG_DIRTY} += $nr_contig_dirty;
378 } elsif ($tracepoint eq "mm_vmscan_writepage") {
379 $details = $5;
380 if ($details !~ /$regex_writepage/o) {
381 print "WARNING: Failed to parse mm_vmscan_writepage as expected\n";
382 print " $details\n";
383 print " $regex_writepage\n";
384 next;
385 }
386
387 my $flags = $3;
388 my $file = 0;
389 my $sync_io = 0;
390 if ($flags =~ /RECLAIM_WB_FILE/) {
391 $file = 1;
392 }
393 if ($flags =~ /RECLAIM_WB_SYNC/) {
394 $sync_io = 1;
395 }
396 if ($sync_io) {
397 if ($file) {
398 $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC}++;
399 } else {
400 $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC}++;
401 }
402 } else {
403 if ($file) {
404 $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC}++;
405 } else {
406 $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC}++;
407 }
408 }
409 } else {
410 $perprocesspid{$process_pid}->{EVENT_UNKNOWN}++;
411 }
412
413 if ($sigint_pending) {
414 last EVENT_PROCESS;
415 }
416 }
417}
418
419sub dump_stats {
420 my $hashref = shift;
421 my %stats = %$hashref;
422
423 # Dump per-process stats
424 my $process_pid;
425 my $max_strlen = 0;
426
427 # Get the maximum process name
428 foreach $process_pid (keys %perprocesspid) {
429 my $len = length($process_pid);
430 if ($len > $max_strlen) {
431 $max_strlen = $len;
432 }
433 }
434 $max_strlen += 2;
435
436 # Work out latencies
437 printf("\n") if !$opt_ignorepid;
438 printf("Reclaim latencies expressed as order-latency_in_ms\n") if !$opt_ignorepid;
439 foreach $process_pid (keys %stats) {
440
441 if (!$stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[0] &&
442 !$stats{$process_pid}->{HIGH_KSWAPD_LATENCY}[0]) {
443 next;
444 }
445
446 printf "%-" . $max_strlen . "s ", $process_pid if !$opt_ignorepid;
447 my $index = 0;
448 while (defined $stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index] ||
449 defined $stats{$process_pid}->{HIGH_KSWAPD_LATENCY}[$index]) {
450
451 if ($stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index]) {
452 printf("%s ", $stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index]) if !$opt_ignorepid;
453 my ($dummy, $latency) = split(/-/, $stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index]);
454 $total_direct_latency += $latency;
455 } else {
456 printf("%s ", $stats{$process_pid}->{HIGH_KSWAPD_LATENCY}[$index]) if !$opt_ignorepid;
457 my ($dummy, $latency) = split(/-/, $stats{$process_pid}->{HIGH_KSWAPD_LATENCY}[$index]);
458 $total_kswapd_latency += $latency;
459 }
460 $index++;
461 }
462 print "\n" if !$opt_ignorepid;
463 }
464
465 # Print out process activity
466 printf("\n");
467 printf("%-" . $max_strlen . "s %8s %10s %8s %8s %8s %8s %8s\n", "Process", "Direct", "Wokeup", "Pages", "Pages", "Pages", "Time");
468 printf("%-" . $max_strlen . "s %8s %10s %8s %8s %8s %8s %8s\n", "details", "Rclms", "Kswapd", "Scanned", "Sync-IO", "ASync-IO", "Stalled");
469 foreach $process_pid (keys %stats) {
470
471 if (!$stats{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN}) {
472 next;
473 }
474
475 $total_direct_reclaim += $stats{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN};
476 $total_wakeup_kswapd += $stats{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD};
477 $total_direct_nr_scanned += $stats{$process_pid}->{HIGH_NR_SCANNED};
478 $total_direct_writepage_file_sync += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC};
479 $total_direct_writepage_anon_sync += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC};
480 $total_direct_writepage_file_async += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC};
481
482 $total_direct_writepage_anon_async += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC};
483
484 my $index = 0;
485 my $this_reclaim_delay = 0;
486 while (defined $stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index]) {
487 my ($dummy, $latency) = split(/-/, $stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index]);
488 $this_reclaim_delay += $latency;
489 $index++;
490 }
491
492 printf("%-" . $max_strlen . "s %8d %10d %8u %8u %8u %8.3f",
493 $process_pid,
494 $stats{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN},
495 $stats{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD},
496 $stats{$process_pid}->{HIGH_NR_SCANNED},
497 $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC} + $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC},
498 $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC} + $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC},
499 $this_reclaim_delay / 1000);
500
501 if ($stats{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN}) {
502 print " ";
503 for (my $order = 0; $order < 20; $order++) {
504 my $count = $stats{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN_PERORDER}[$order];
505 if ($count != 0) {
506 print "direct-$order=$count ";
507 }
508 }
509 }
510 if ($stats{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD}) {
511 print " ";
512 for (my $order = 0; $order < 20; $order++) {
513 my $count = $stats{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD_PERORDER}[$order];
514 if ($count != 0) {
515 print "wakeup-$order=$count ";
516 }
517 }
518 }
519 if ($stats{$process_pid}->{HIGH_NR_CONTIG_DIRTY}) {
520 print " ";
521 my $count = $stats{$process_pid}->{HIGH_NR_CONTIG_DIRTY};
522 if ($count != 0) {
523 print "contig-dirty=$count ";
524 }
525 }
526
527 print "\n";
528 }
529
530 # Print out kswapd activity
531 printf("\n");
532 printf("%-" . $max_strlen . "s %8s %10s %8s %8s %8s %8s\n", "Kswapd", "Kswapd", "Order", "Pages", "Pages", "Pages");
533 printf("%-" . $max_strlen . "s %8s %10s %8s %8s %8s %8s\n", "Instance", "Wakeups", "Re-wakeup", "Scanned", "Sync-IO", "ASync-IO");
534 foreach $process_pid (keys %stats) {
535
536 if (!$stats{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE}) {
537 next;
538 }
539
540 $total_kswapd_wake += $stats{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE};
541 $total_kswapd_nr_scanned += $stats{$process_pid}->{HIGH_NR_SCANNED};
542 $total_kswapd_writepage_file_sync += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC};
543 $total_kswapd_writepage_anon_sync += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC};
544 $total_kswapd_writepage_file_async += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC};
545 $total_kswapd_writepage_anon_async += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC};
546
547 printf("%-" . $max_strlen . "s %8d %10d %8u %8i %8u",
548 $process_pid,
549 $stats{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE},
550 $stats{$process_pid}->{HIGH_KSWAPD_REWAKEUP},
551 $stats{$process_pid}->{HIGH_NR_SCANNED},
552 $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC} + $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC},
553 $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC} + $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC});
554
555 if ($stats{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE}) {
556 print " ";
557 for (my $order = 0; $order < 20; $order++) {
558 my $count = $stats{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE_PERORDER}[$order];
559 if ($count != 0) {
560 print "wake-$order=$count ";
561 }
562 }
563 }
564 if ($stats{$process_pid}->{HIGH_KSWAPD_REWAKEUP}) {
565 print " ";
566 for (my $order = 0; $order < 20; $order++) {
567 my $count = $stats{$process_pid}->{HIGH_KSWAPD_REWAKEUP_PERORDER}[$order];
568 if ($count != 0) {
569 print "rewake-$order=$count ";
570 }
571 }
572 }
573 printf("\n");
574 }
575
576 # Print out summaries
577 $total_direct_latency /= 1000;
578 $total_kswapd_latency /= 1000;
579 print "\nSummary\n";
580 print "Direct reclaims: $total_direct_reclaim\n";
581 print "Direct reclaim pages scanned: $total_direct_nr_scanned\n";
582 print "Direct reclaim write file sync I/O: $total_direct_writepage_file_sync\n";
583 print "Direct reclaim write anon sync I/O: $total_direct_writepage_anon_sync\n";
584 print "Direct reclaim write file async I/O: $total_direct_writepage_file_async\n";
585 print "Direct reclaim write anon async I/O: $total_direct_writepage_anon_async\n";
586 print "Wake kswapd requests: $total_wakeup_kswapd\n";
587 printf "Time stalled direct reclaim: %-1.2f seconds\n", $total_direct_latency;
588 print "\n";
589 print "Kswapd wakeups: $total_kswapd_wake\n";
590 print "Kswapd pages scanned: $total_kswapd_nr_scanned\n";
591 print "Kswapd reclaim write file sync I/O: $total_kswapd_writepage_file_sync\n";
592 print "Kswapd reclaim write anon sync I/O: $total_kswapd_writepage_anon_sync\n";
593 print "Kswapd reclaim write file async I/O: $total_kswapd_writepage_file_async\n";
594 print "Kswapd reclaim write anon async I/O: $total_kswapd_writepage_anon_async\n";
595 printf "Time kswapd awake: %-1.2f seconds\n", $total_kswapd_latency;
596}
597
598sub aggregate_perprocesspid() {
599 my $process_pid;
600 my $process;
601 undef %perprocess;
602
603 foreach $process_pid (keys %perprocesspid) {
604 $process = $process_pid;
605 $process =~ s/-([0-9])*$//;
606 if ($process eq '') {
607 $process = "NO_PROCESS_NAME";
608 }
609
610 $perprocess{$process}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN} += $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN};
611 $perprocess{$process}->{MM_VMSCAN_KSWAPD_WAKE} += $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE};
612 $perprocess{$process}->{MM_VMSCAN_WAKEUP_KSWAPD} += $perprocesspid{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD};
613 $perprocess{$process}->{HIGH_KSWAPD_REWAKEUP} += $perprocesspid{$process_pid}->{HIGH_KSWAPD_REWAKEUP};
614 $perprocess{$process}->{HIGH_NR_SCANNED} += $perprocesspid{$process_pid}->{HIGH_NR_SCANNED};
615 $perprocess{$process}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC} += $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC};
616 $perprocess{$process}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC} += $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC};
617 $perprocess{$process}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC} += $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC};
618 $perprocess{$process}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC} += $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC};
619
620 for (my $order = 0; $order < 20; $order++) {
621 $perprocess{$process}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN_PERORDER}[$order] += $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN_PERORDER}[$order];
622 $perprocess{$process}->{MM_VMSCAN_WAKEUP_KSWAPD_PERORDER}[$order] += $perprocesspid{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD_PERORDER}[$order];
623 $perprocess{$process}->{MM_VMSCAN_KSWAPD_WAKE_PERORDER}[$order] += $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE_PERORDER}[$order];
624
625 }
626
627 # Aggregate direct reclaim latencies
628 my $wr_index = $perprocess{$process}->{MM_VMSCAN_DIRECT_RECLAIM_END};
629 my $rd_index = 0;
630 while (defined $perprocesspid{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$rd_index]) {
631 $perprocess{$process}->{HIGH_DIRECT_RECLAIM_LATENCY}[$wr_index] = $perprocesspid{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$rd_index];
632 $rd_index++;
633 $wr_index++;
634 }
635 $perprocess{$process}->{MM_VMSCAN_DIRECT_RECLAIM_END} = $wr_index;
636
637 # Aggregate kswapd latencies
638 my $wr_index = $perprocess{$process}->{MM_VMSCAN_KSWAPD_SLEEP};
639 my $rd_index = 0;
640 while (defined $perprocesspid{$process_pid}->{HIGH_KSWAPD_LATENCY}[$rd_index]) {
641 $perprocess{$process}->{HIGH_KSWAPD_LATENCY}[$wr_index] = $perprocesspid{$process_pid}->{HIGH_KSWAPD_LATENCY}[$rd_index];
642 $rd_index++;
643 $wr_index++;
644 }
645 $perprocess{$process}->{MM_VMSCAN_DIRECT_RECLAIM_END} = $wr_index;
646 }
647}
648
649sub report() {
650 if (!$opt_ignorepid) {
651 dump_stats(\%perprocesspid);
652 } else {
653 aggregate_perprocesspid();
654 dump_stats(\%perprocess);
655 }
656}
657
658# Process events or signals until neither is available
659sub signal_loop() {
660 my $sigint_processed;
661 do {
662 $sigint_processed = 0;
663 process_events();
664
665 # Handle pending signals if any
666 if ($sigint_pending) {
667 my $current_time = time;
668
669 if ($sigint_exit) {
670 print "Received exit signal\n";
671 $sigint_pending = 0;
672 }
673 if ($sigint_report) {
674 if ($current_time >= $sigint_received + 2) {
675 report();
676 $sigint_report = 0;
677 $sigint_pending = 0;
678 $sigint_processed = 1;
679 }
680 }
681 }
682 } while ($sigint_pending || $sigint_processed);
683}
684
685signal_loop();
686report();