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