1c25ce589SFinn Behrens#!/usr/bin/env perl 2b898cc70SMel Gorman# This is a POC for reading the text representation of trace output related to 3b898cc70SMel Gorman# page reclaim. It makes an attempt to extract some high-level information on 4b898cc70SMel Gorman# what is going on. The accuracy of the parser may vary 5b898cc70SMel Gorman# 62abfcd29SRoss Zwisler# Example usage: trace-vmscan-postprocess.pl < /sys/kernel/tracing/trace_pipe 7b898cc70SMel Gorman# other options 8b898cc70SMel Gorman# --read-procstat If the trace lacks process info, get it from /proc 9b898cc70SMel Gorman# --ignore-pid Aggregate processes of the same name together 10b898cc70SMel Gorman# 11b898cc70SMel Gorman# Copyright (c) IBM Corporation 2009 12b898cc70SMel Gorman# Author: Mel Gorman <mel@csn.ul.ie> 13b898cc70SMel Gormanuse strict; 14b898cc70SMel Gormanuse Getopt::Long; 15b898cc70SMel Gorman 16b898cc70SMel Gorman# Tracepoint events 17b898cc70SMel Gormanuse constant MM_VMSCAN_DIRECT_RECLAIM_BEGIN => 1; 18b898cc70SMel Gormanuse constant MM_VMSCAN_DIRECT_RECLAIM_END => 2; 19b898cc70SMel Gormanuse constant MM_VMSCAN_KSWAPD_WAKE => 3; 20b898cc70SMel Gormanuse constant MM_VMSCAN_KSWAPD_SLEEP => 4; 21b898cc70SMel Gormanuse constant MM_VMSCAN_LRU_SHRINK_ACTIVE => 5; 22b898cc70SMel Gormanuse constant MM_VMSCAN_LRU_SHRINK_INACTIVE => 6; 23b898cc70SMel Gormanuse constant MM_VMSCAN_LRU_ISOLATE => 7; 24b898cc70SMel Gormanuse constant MM_VMSCAN_WRITEPAGE_FILE_SYNC => 8; 25b898cc70SMel Gormanuse constant MM_VMSCAN_WRITEPAGE_ANON_SYNC => 9; 26b898cc70SMel Gormanuse constant MM_VMSCAN_WRITEPAGE_FILE_ASYNC => 10; 27b898cc70SMel Gormanuse constant MM_VMSCAN_WRITEPAGE_ANON_ASYNC => 11; 28b898cc70SMel Gormanuse constant MM_VMSCAN_WRITEPAGE_ASYNC => 12; 29b898cc70SMel Gormanuse constant EVENT_UNKNOWN => 13; 30b898cc70SMel Gorman 31b898cc70SMel Gorman# Per-order events 32b898cc70SMel Gormanuse constant MM_VMSCAN_DIRECT_RECLAIM_BEGIN_PERORDER => 11; 33b898cc70SMel Gormanuse constant MM_VMSCAN_WAKEUP_KSWAPD_PERORDER => 12; 34b898cc70SMel Gormanuse constant MM_VMSCAN_KSWAPD_WAKE_PERORDER => 13; 35b898cc70SMel Gormanuse constant HIGH_KSWAPD_REWAKEUP_PERORDER => 14; 36b898cc70SMel Gorman 37b898cc70SMel Gorman# Constants used to track state 38b898cc70SMel Gormanuse constant STATE_DIRECT_BEGIN => 15; 39b898cc70SMel Gormanuse constant STATE_DIRECT_ORDER => 16; 40b898cc70SMel Gormanuse constant STATE_KSWAPD_BEGIN => 17; 41b898cc70SMel Gormanuse constant STATE_KSWAPD_ORDER => 18; 42b898cc70SMel Gorman 43b898cc70SMel Gorman# High-level events extrapolated from tracepoints 44b898cc70SMel Gormanuse constant HIGH_DIRECT_RECLAIM_LATENCY => 19; 45b898cc70SMel Gormanuse constant HIGH_KSWAPD_LATENCY => 20; 46b898cc70SMel Gormanuse constant HIGH_KSWAPD_REWAKEUP => 21; 47b898cc70SMel Gormanuse constant HIGH_NR_SCANNED => 22; 48b898cc70SMel Gormanuse constant HIGH_NR_TAKEN => 23; 49e11da5b4SMel Gormanuse constant HIGH_NR_RECLAIMED => 24; 502c51856cSChen Yuconguse constant HIGH_NR_FILE_SCANNED => 25; 512c51856cSChen Yuconguse constant HIGH_NR_ANON_SCANNED => 26; 522c51856cSChen Yuconguse constant HIGH_NR_FILE_RECLAIMED => 27; 532c51856cSChen Yuconguse constant HIGH_NR_ANON_RECLAIMED => 28; 54b898cc70SMel Gorman 55b898cc70SMel Gormanmy %perprocesspid; 56b898cc70SMel Gormanmy %perprocess; 57b898cc70SMel Gormanmy %last_procmap; 58b898cc70SMel Gormanmy $opt_ignorepid; 59b898cc70SMel Gormanmy $opt_read_procstat; 60b898cc70SMel Gorman 61b898cc70SMel Gormanmy $total_wakeup_kswapd; 62b898cc70SMel Gormanmy ($total_direct_reclaim, $total_direct_nr_scanned); 632c51856cSChen Yucongmy ($total_direct_nr_file_scanned, $total_direct_nr_anon_scanned); 64b898cc70SMel Gormanmy ($total_direct_latency, $total_kswapd_latency); 65e11da5b4SMel Gormanmy ($total_direct_nr_reclaimed); 662c51856cSChen Yucongmy ($total_direct_nr_file_reclaimed, $total_direct_nr_anon_reclaimed); 67b898cc70SMel Gormanmy ($total_direct_writepage_file_sync, $total_direct_writepage_file_async); 68b898cc70SMel Gormanmy ($total_direct_writepage_anon_sync, $total_direct_writepage_anon_async); 69b898cc70SMel Gormanmy ($total_kswapd_nr_scanned, $total_kswapd_wake); 702c51856cSChen Yucongmy ($total_kswapd_nr_file_scanned, $total_kswapd_nr_anon_scanned); 71b898cc70SMel Gormanmy ($total_kswapd_writepage_file_sync, $total_kswapd_writepage_file_async); 72b898cc70SMel Gormanmy ($total_kswapd_writepage_anon_sync, $total_kswapd_writepage_anon_async); 73e11da5b4SMel Gormanmy ($total_kswapd_nr_reclaimed); 742c51856cSChen Yucongmy ($total_kswapd_nr_file_reclaimed, $total_kswapd_nr_anon_reclaimed); 75b898cc70SMel Gorman 76b898cc70SMel Gorman# Catch sigint and exit on request 77b898cc70SMel Gormanmy $sigint_report = 0; 78b898cc70SMel Gormanmy $sigint_exit = 0; 79b898cc70SMel Gormanmy $sigint_pending = 0; 80b898cc70SMel Gormanmy $sigint_received = 0; 81b898cc70SMel Gormansub sigint_handler { 82b898cc70SMel Gorman my $current_time = time; 83b898cc70SMel Gorman if ($current_time - 2 > $sigint_received) { 84b898cc70SMel Gorman print "SIGINT received, report pending. Hit ctrl-c again to exit\n"; 85b898cc70SMel Gorman $sigint_report = 1; 86b898cc70SMel Gorman } else { 87b898cc70SMel Gorman if (!$sigint_exit) { 88b898cc70SMel Gorman print "Second SIGINT received quickly, exiting\n"; 89b898cc70SMel Gorman } 90b898cc70SMel Gorman $sigint_exit++; 91b898cc70SMel Gorman } 92b898cc70SMel Gorman 93b898cc70SMel Gorman if ($sigint_exit > 3) { 94b898cc70SMel Gorman print "Many SIGINTs received, exiting now without report\n"; 95b898cc70SMel Gorman exit; 96b898cc70SMel Gorman } 97b898cc70SMel Gorman 98b898cc70SMel Gorman $sigint_received = $current_time; 99b898cc70SMel Gorman $sigint_pending = 1; 100b898cc70SMel Gorman} 101b898cc70SMel Gorman$SIG{INT} = "sigint_handler"; 102b898cc70SMel Gorman 103b898cc70SMel Gorman# Parse command line options 104b898cc70SMel GormanGetOptions( 105b898cc70SMel Gorman 'ignore-pid' => \$opt_ignorepid, 106b898cc70SMel Gorman 'read-procstat' => \$opt_read_procstat, 107b898cc70SMel Gorman); 108b898cc70SMel Gorman 109b898cc70SMel Gorman# Defaults for dynamically discovered regex's 11083121580SVlastimil Babkamy $regex_direct_begin_default = 'order=([0-9]*) gfp_flags=([A-Z_|]*)'; 111b898cc70SMel Gormanmy $regex_direct_end_default = 'nr_reclaimed=([0-9]*)'; 112b898cc70SMel Gormanmy $regex_kswapd_wake_default = 'nid=([0-9]*) order=([0-9]*)'; 113b898cc70SMel Gormanmy $regex_kswapd_sleep_default = 'nid=([0-9]*)'; 11483121580SVlastimil Babkamy $regex_wakeup_kswapd_default = 'nid=([0-9]*) order=([0-9]*) gfp_flags=([A-Z_|]*)'; 115*3dfbb555SVlastimil Babkamy $regex_lru_isolate_default = 'classzone=([0-9]*) order=([0-9]*) nr_requested=([0-9]*) nr_scanned=([0-9]*) nr_skipped=([0-9]*) nr_taken=([0-9]*) lru=([a-z_]*)'; 116886cf190SKirill Tkhaimy $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_|]*)'; 11783121580SVlastimil Babkamy $regex_lru_shrink_active_default = 'lru=([A-Z_]*) nr_taken=([0-9]*) nr_active=([0-9]*) nr_deactivated=([0-9]*) nr_referenced=([0-9]*) priority=([0-9]*) flags=([A-Z_|]*)' ; 118b898cc70SMel Gormanmy $regex_writepage_default = 'page=([0-9a-f]*) pfn=([0-9]*) flags=([A-Z_|]*)'; 119b898cc70SMel Gorman 120b898cc70SMel Gorman# Dyanically discovered regex 121b898cc70SMel Gormanmy $regex_direct_begin; 122b898cc70SMel Gormanmy $regex_direct_end; 123b898cc70SMel Gormanmy $regex_kswapd_wake; 124b898cc70SMel Gormanmy $regex_kswapd_sleep; 125b898cc70SMel Gormanmy $regex_wakeup_kswapd; 126b898cc70SMel Gormanmy $regex_lru_isolate; 127b898cc70SMel Gormanmy $regex_lru_shrink_inactive; 128b898cc70SMel Gormanmy $regex_lru_shrink_active; 129b898cc70SMel Gormanmy $regex_writepage; 130b898cc70SMel Gorman 131b898cc70SMel Gorman# Static regex used. Specified like this for readability and for use with /o 132b898cc70SMel Gorman# (process_pid) (cpus ) ( time ) (tpoint ) (details) 133bd727816SVinayak Menonmy $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*(.*)'; 134b898cc70SMel Gormanmy $regex_statname = '[-0-9]*\s\((.*)\).*'; 135b898cc70SMel Gormanmy $regex_statppid = '[-0-9]*\s\(.*\)\s[A-Za-z]\s([0-9]*).*'; 136b898cc70SMel Gorman 137b898cc70SMel Gormansub generate_traceevent_regex { 138b898cc70SMel Gorman my $event = shift; 139b898cc70SMel Gorman my $default = shift; 140b898cc70SMel Gorman my $regex; 141b898cc70SMel Gorman 142b898cc70SMel Gorman # Read the event format or use the default 1432abfcd29SRoss Zwisler if (!open (FORMAT, "/sys/kernel/tracing/events/$event/format")) { 144b898cc70SMel Gorman print("WARNING: Event $event format string not found\n"); 145b898cc70SMel Gorman return $default; 146b898cc70SMel Gorman } else { 147b898cc70SMel Gorman my $line; 148b898cc70SMel Gorman while (!eof(FORMAT)) { 149b898cc70SMel Gorman $line = <FORMAT>; 150b898cc70SMel Gorman $line =~ s/, REC->.*//; 151b898cc70SMel Gorman if ($line =~ /^print fmt:\s"(.*)".*/) { 152b898cc70SMel Gorman $regex = $1; 153b898cc70SMel Gorman $regex =~ s/%s/\([0-9a-zA-Z|_]*\)/g; 154b898cc70SMel Gorman $regex =~ s/%p/\([0-9a-f]*\)/g; 155b898cc70SMel Gorman $regex =~ s/%d/\([-0-9]*\)/g; 156b898cc70SMel Gorman $regex =~ s/%ld/\([-0-9]*\)/g; 157b898cc70SMel Gorman $regex =~ s/%lu/\([0-9]*\)/g; 158b898cc70SMel Gorman } 159b898cc70SMel Gorman } 160b898cc70SMel Gorman } 161b898cc70SMel Gorman 162b898cc70SMel Gorman # Can't handle the print_flags stuff but in the context of this 163b898cc70SMel Gorman # script, it really doesn't matter 164b898cc70SMel Gorman $regex =~ s/\(REC.*\) \? __print_flags.*//; 165b898cc70SMel Gorman 166b898cc70SMel Gorman # Verify fields are in the right order 167b898cc70SMel Gorman my $tuple; 168b898cc70SMel Gorman foreach $tuple (split /\s/, $regex) { 169b898cc70SMel Gorman my ($key, $value) = split(/=/, $tuple); 170b898cc70SMel Gorman my $expected = shift; 171b898cc70SMel Gorman if ($key ne $expected) { 172b898cc70SMel Gorman print("WARNING: Format not as expected for event $event '$key' != '$expected'\n"); 173b898cc70SMel Gorman $regex =~ s/$key=\((.*)\)/$key=$1/; 174b898cc70SMel Gorman } 175b898cc70SMel Gorman } 176b898cc70SMel Gorman 177b898cc70SMel Gorman if (defined shift) { 178b898cc70SMel Gorman die("Fewer fields than expected in format"); 179b898cc70SMel Gorman } 180b898cc70SMel Gorman 181b898cc70SMel Gorman return $regex; 182b898cc70SMel Gorman} 183b898cc70SMel Gorman 184b898cc70SMel Gorman$regex_direct_begin = generate_traceevent_regex( 185b898cc70SMel Gorman "vmscan/mm_vmscan_direct_reclaim_begin", 186b898cc70SMel Gorman $regex_direct_begin_default, 18783121580SVlastimil Babka "order", "gfp_flags"); 188b898cc70SMel Gorman$regex_direct_end = generate_traceevent_regex( 189b898cc70SMel Gorman "vmscan/mm_vmscan_direct_reclaim_end", 190b898cc70SMel Gorman $regex_direct_end_default, 191b898cc70SMel Gorman "nr_reclaimed"); 192b898cc70SMel Gorman$regex_kswapd_wake = generate_traceevent_regex( 193b898cc70SMel Gorman "vmscan/mm_vmscan_kswapd_wake", 194b898cc70SMel Gorman $regex_kswapd_wake_default, 195b898cc70SMel Gorman "nid", "order"); 196b898cc70SMel Gorman$regex_kswapd_sleep = generate_traceevent_regex( 197b898cc70SMel Gorman "vmscan/mm_vmscan_kswapd_sleep", 198b898cc70SMel Gorman $regex_kswapd_sleep_default, 199b898cc70SMel Gorman "nid"); 200b898cc70SMel Gorman$regex_wakeup_kswapd = generate_traceevent_regex( 201b898cc70SMel Gorman "vmscan/mm_vmscan_wakeup_kswapd", 202b898cc70SMel Gorman $regex_wakeup_kswapd_default, 20383121580SVlastimil Babka "nid", "order", "gfp_flags"); 204b898cc70SMel Gorman$regex_lru_isolate = generate_traceevent_regex( 205b898cc70SMel Gorman "vmscan/mm_vmscan_lru_isolate", 206b898cc70SMel Gorman $regex_lru_isolate_default, 207*3dfbb555SVlastimil Babka "classzone", "order", 20893607e5aSMichal Hocko "nr_requested", "nr_scanned", "nr_skipped", "nr_taken", 20993607e5aSMichal Hocko "lru"); 210b898cc70SMel Gorman$regex_lru_shrink_inactive = generate_traceevent_regex( 211b898cc70SMel Gorman "vmscan/mm_vmscan_lru_shrink_inactive", 212b898cc70SMel Gorman $regex_lru_shrink_inactive_default, 21393607e5aSMichal Hocko "nid", "nr_scanned", "nr_reclaimed", "nr_dirty", "nr_writeback", 214886cf190SKirill Tkhai "nr_congested", "nr_immediate", "nr_activate_anon", 215886cf190SKirill Tkhai "nr_activate_file", "nr_ref_keep", 21693607e5aSMichal Hocko "nr_unmap_fail", "priority", "flags"); 217b898cc70SMel Gorman$regex_lru_shrink_active = generate_traceevent_regex( 218b898cc70SMel Gorman "vmscan/mm_vmscan_lru_shrink_active", 219b898cc70SMel Gorman $regex_lru_shrink_active_default, 22083121580SVlastimil Babka "nid", "nr_taken", "nr_active", "nr_deactivated", "nr_referenced", 22183121580SVlastimil Babka "priority", "flags"); 222b898cc70SMel Gorman$regex_writepage = generate_traceevent_regex( 22383121580SVlastimil Babka "vmscan/mm_vmscan_write_folio", 224b898cc70SMel Gorman $regex_writepage_default, 225b898cc70SMel Gorman "page", "pfn", "flags"); 226b898cc70SMel Gorman 227b898cc70SMel Gormansub read_statline($) { 228b898cc70SMel Gorman my $pid = $_[0]; 229b898cc70SMel Gorman my $statline; 230b898cc70SMel Gorman 231b898cc70SMel Gorman if (open(STAT, "/proc/$pid/stat")) { 232b898cc70SMel Gorman $statline = <STAT>; 233b898cc70SMel Gorman close(STAT); 234b898cc70SMel Gorman } 235b898cc70SMel Gorman 236b898cc70SMel Gorman if ($statline eq '') { 237b898cc70SMel Gorman $statline = "-1 (UNKNOWN_PROCESS_NAME) R 0"; 238b898cc70SMel Gorman } 239b898cc70SMel Gorman 240b898cc70SMel Gorman return $statline; 241b898cc70SMel Gorman} 242b898cc70SMel Gorman 243b898cc70SMel Gormansub guess_process_pid($$) { 244b898cc70SMel Gorman my $pid = $_[0]; 245b898cc70SMel Gorman my $statline = $_[1]; 246b898cc70SMel Gorman 247b898cc70SMel Gorman if ($pid == 0) { 248b898cc70SMel Gorman return "swapper-0"; 249b898cc70SMel Gorman } 250b898cc70SMel Gorman 251b898cc70SMel Gorman if ($statline !~ /$regex_statname/o) { 252b898cc70SMel Gorman die("Failed to math stat line for process name :: $statline"); 253b898cc70SMel Gorman } 254b898cc70SMel Gorman return "$1-$pid"; 255b898cc70SMel Gorman} 256b898cc70SMel Gorman 257b898cc70SMel Gorman# Convert sec.usec timestamp format 258b898cc70SMel Gormansub timestamp_to_ms($) { 259b898cc70SMel Gorman my $timestamp = $_[0]; 260b898cc70SMel Gorman 261b898cc70SMel Gorman my ($sec, $usec) = split (/\./, $timestamp); 262b898cc70SMel Gorman return ($sec * 1000) + ($usec / 1000); 263b898cc70SMel Gorman} 264b898cc70SMel Gorman 265b898cc70SMel Gormansub process_events { 266b898cc70SMel Gorman my $traceevent; 267b898cc70SMel Gorman my $process_pid; 268b898cc70SMel Gorman my $cpus; 269b898cc70SMel Gorman my $timestamp; 270b898cc70SMel Gorman my $tracepoint; 271b898cc70SMel Gorman my $details; 272b898cc70SMel Gorman my $statline; 273b898cc70SMel Gorman 274b898cc70SMel Gorman # Read each line of the event log 275b898cc70SMel GormanEVENT_PROCESS: 276b898cc70SMel Gorman while ($traceevent = <STDIN>) { 277b898cc70SMel Gorman if ($traceevent =~ /$regex_traceevent/o) { 278b898cc70SMel Gorman $process_pid = $1; 279bd727816SVinayak Menon $timestamp = $4; 280bd727816SVinayak Menon $tracepoint = $5; 281b898cc70SMel Gorman 282b898cc70SMel Gorman $process_pid =~ /(.*)-([0-9]*)$/; 283b898cc70SMel Gorman my $process = $1; 284b898cc70SMel Gorman my $pid = $2; 285b898cc70SMel Gorman 286b898cc70SMel Gorman if ($process eq "") { 287b898cc70SMel Gorman $process = $last_procmap{$pid}; 288b898cc70SMel Gorman $process_pid = "$process-$pid"; 289b898cc70SMel Gorman } 290b898cc70SMel Gorman $last_procmap{$pid} = $process; 291b898cc70SMel Gorman 292b898cc70SMel Gorman if ($opt_read_procstat) { 293b898cc70SMel Gorman $statline = read_statline($pid); 294b898cc70SMel Gorman if ($opt_read_procstat && $process eq '') { 295b898cc70SMel Gorman $process_pid = guess_process_pid($pid, $statline); 296b898cc70SMel Gorman } 297b898cc70SMel Gorman } 298b898cc70SMel Gorman } else { 299b898cc70SMel Gorman next; 300b898cc70SMel Gorman } 301b898cc70SMel Gorman 302b898cc70SMel Gorman # Perl Switch() sucks majorly 303b898cc70SMel Gorman if ($tracepoint eq "mm_vmscan_direct_reclaim_begin") { 304b898cc70SMel Gorman $timestamp = timestamp_to_ms($timestamp); 305b898cc70SMel Gorman $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN}++; 306b898cc70SMel Gorman $perprocesspid{$process_pid}->{STATE_DIRECT_BEGIN} = $timestamp; 307b898cc70SMel Gorman 308bd727816SVinayak Menon $details = $6; 309b898cc70SMel Gorman if ($details !~ /$regex_direct_begin/o) { 310b898cc70SMel Gorman print "WARNING: Failed to parse mm_vmscan_direct_reclaim_begin as expected\n"; 311b898cc70SMel Gorman print " $details\n"; 312b898cc70SMel Gorman print " $regex_direct_begin\n"; 313b898cc70SMel Gorman next; 314b898cc70SMel Gorman } 315b898cc70SMel Gorman my $order = $1; 316b898cc70SMel Gorman $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN_PERORDER}[$order]++; 317b898cc70SMel Gorman $perprocesspid{$process_pid}->{STATE_DIRECT_ORDER} = $order; 318b898cc70SMel Gorman } elsif ($tracepoint eq "mm_vmscan_direct_reclaim_end") { 319b898cc70SMel Gorman # Count the event itself 320b898cc70SMel Gorman my $index = $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_END}; 321b898cc70SMel Gorman $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_END}++; 322b898cc70SMel Gorman 323b898cc70SMel Gorman # Record how long direct reclaim took this time 324b898cc70SMel Gorman if (defined $perprocesspid{$process_pid}->{STATE_DIRECT_BEGIN}) { 325b898cc70SMel Gorman $timestamp = timestamp_to_ms($timestamp); 326b898cc70SMel Gorman my $order = $perprocesspid{$process_pid}->{STATE_DIRECT_ORDER}; 327b898cc70SMel Gorman my $latency = ($timestamp - $perprocesspid{$process_pid}->{STATE_DIRECT_BEGIN}); 328b898cc70SMel Gorman $perprocesspid{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index] = "$order-$latency"; 329b898cc70SMel Gorman } 330b898cc70SMel Gorman } elsif ($tracepoint eq "mm_vmscan_kswapd_wake") { 331bd727816SVinayak Menon $details = $6; 332b898cc70SMel Gorman if ($details !~ /$regex_kswapd_wake/o) { 333b898cc70SMel Gorman print "WARNING: Failed to parse mm_vmscan_kswapd_wake as expected\n"; 334b898cc70SMel Gorman print " $details\n"; 335b898cc70SMel Gorman print " $regex_kswapd_wake\n"; 336b898cc70SMel Gorman next; 337b898cc70SMel Gorman } 338b898cc70SMel Gorman 339b898cc70SMel Gorman my $order = $2; 340b898cc70SMel Gorman $perprocesspid{$process_pid}->{STATE_KSWAPD_ORDER} = $order; 341b898cc70SMel Gorman if (!$perprocesspid{$process_pid}->{STATE_KSWAPD_BEGIN}) { 342b898cc70SMel Gorman $timestamp = timestamp_to_ms($timestamp); 343b898cc70SMel Gorman $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE}++; 344b898cc70SMel Gorman $perprocesspid{$process_pid}->{STATE_KSWAPD_BEGIN} = $timestamp; 345b898cc70SMel Gorman $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE_PERORDER}[$order]++; 346b898cc70SMel Gorman } else { 347b898cc70SMel Gorman $perprocesspid{$process_pid}->{HIGH_KSWAPD_REWAKEUP}++; 348b898cc70SMel Gorman $perprocesspid{$process_pid}->{HIGH_KSWAPD_REWAKEUP_PERORDER}[$order]++; 349b898cc70SMel Gorman } 350b898cc70SMel Gorman } elsif ($tracepoint eq "mm_vmscan_kswapd_sleep") { 351b898cc70SMel Gorman 352b898cc70SMel Gorman # Count the event itself 353b898cc70SMel Gorman my $index = $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_SLEEP}; 354b898cc70SMel Gorman $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_SLEEP}++; 355b898cc70SMel Gorman 356b898cc70SMel Gorman # Record how long kswapd was awake 357b898cc70SMel Gorman $timestamp = timestamp_to_ms($timestamp); 358b898cc70SMel Gorman my $order = $perprocesspid{$process_pid}->{STATE_KSWAPD_ORDER}; 359b898cc70SMel Gorman my $latency = ($timestamp - $perprocesspid{$process_pid}->{STATE_KSWAPD_BEGIN}); 360b898cc70SMel Gorman $perprocesspid{$process_pid}->{HIGH_KSWAPD_LATENCY}[$index] = "$order-$latency"; 361b898cc70SMel Gorman $perprocesspid{$process_pid}->{STATE_KSWAPD_BEGIN} = 0; 362b898cc70SMel Gorman } elsif ($tracepoint eq "mm_vmscan_wakeup_kswapd") { 363b898cc70SMel Gorman $perprocesspid{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD}++; 364b898cc70SMel Gorman 365bd727816SVinayak Menon $details = $6; 366b898cc70SMel Gorman if ($details !~ /$regex_wakeup_kswapd/o) { 367b898cc70SMel Gorman print "WARNING: Failed to parse mm_vmscan_wakeup_kswapd as expected\n"; 368b898cc70SMel Gorman print " $details\n"; 369b898cc70SMel Gorman print " $regex_wakeup_kswapd\n"; 370b898cc70SMel Gorman next; 371b898cc70SMel Gorman } 37283121580SVlastimil Babka my $order = $2; 373b898cc70SMel Gorman $perprocesspid{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD_PERORDER}[$order]++; 374b898cc70SMel Gorman } elsif ($tracepoint eq "mm_vmscan_lru_isolate") { 375bd727816SVinayak Menon $details = $6; 376b898cc70SMel Gorman if ($details !~ /$regex_lru_isolate/o) { 377b898cc70SMel Gorman print "WARNING: Failed to parse mm_vmscan_lru_isolate as expected\n"; 378b898cc70SMel Gorman print " $details\n"; 379b898cc70SMel Gorman print " $regex_lru_isolate/o\n"; 380b898cc70SMel Gorman next; 381b898cc70SMel Gorman } 382*3dfbb555SVlastimil Babka my $nr_scanned = $4; 383*3dfbb555SVlastimil Babka my $lru = $7; 3847a2d19bcSMel Gorman 38583121580SVlastimil Babka # To closer match vmstat scanning statistics, only count 38683121580SVlastimil Babka # inactive lru as scanning 38783121580SVlastimil Babka if ($lru =~ /inactive_/) { 388b898cc70SMel Gorman $perprocesspid{$process_pid}->{HIGH_NR_SCANNED} += $nr_scanned; 38983121580SVlastimil Babka if ($lru =~ /_file/) { 3902c51856cSChen Yucong $perprocesspid{$process_pid}->{HIGH_NR_FILE_SCANNED} += $nr_scanned; 3912c51856cSChen Yucong } else { 3922c51856cSChen Yucong $perprocesspid{$process_pid}->{HIGH_NR_ANON_SCANNED} += $nr_scanned; 3932c51856cSChen Yucong } 3947a2d19bcSMel Gorman } 395e11da5b4SMel Gorman } elsif ($tracepoint eq "mm_vmscan_lru_shrink_inactive") { 396bd727816SVinayak Menon $details = $6; 397e11da5b4SMel Gorman if ($details !~ /$regex_lru_shrink_inactive/o) { 398e11da5b4SMel Gorman print "WARNING: Failed to parse mm_vmscan_lru_shrink_inactive as expected\n"; 399e11da5b4SMel Gorman print " $details\n"; 400e11da5b4SMel Gorman print " $regex_lru_shrink_inactive/o\n"; 401e11da5b4SMel Gorman next; 402e11da5b4SMel Gorman } 4032c51856cSChen Yucong 40493607e5aSMichal Hocko my $nr_reclaimed = $3; 405886cf190SKirill Tkhai my $flags = $13; 4062c51856cSChen Yucong my $file = 0; 4072c51856cSChen Yucong if ($flags =~ /RECLAIM_WB_FILE/) { 4082c51856cSChen Yucong $file = 1; 4092c51856cSChen Yucong } 410e11da5b4SMel Gorman $perprocesspid{$process_pid}->{HIGH_NR_RECLAIMED} += $nr_reclaimed; 4112c51856cSChen Yucong if ($file) { 4122c51856cSChen Yucong $perprocesspid{$process_pid}->{HIGH_NR_FILE_RECLAIMED} += $nr_reclaimed; 4132c51856cSChen Yucong } else { 4142c51856cSChen Yucong $perprocesspid{$process_pid}->{HIGH_NR_ANON_RECLAIMED} += $nr_reclaimed; 4152c51856cSChen Yucong } 416b898cc70SMel Gorman } elsif ($tracepoint eq "mm_vmscan_writepage") { 417bd727816SVinayak Menon $details = $6; 418b898cc70SMel Gorman if ($details !~ /$regex_writepage/o) { 419b898cc70SMel Gorman print "WARNING: Failed to parse mm_vmscan_writepage as expected\n"; 420b898cc70SMel Gorman print " $details\n"; 421b898cc70SMel Gorman print " $regex_writepage\n"; 422b898cc70SMel Gorman next; 423b898cc70SMel Gorman } 424b898cc70SMel Gorman 425b898cc70SMel Gorman my $flags = $3; 426b898cc70SMel Gorman my $file = 0; 427b898cc70SMel Gorman my $sync_io = 0; 428b898cc70SMel Gorman if ($flags =~ /RECLAIM_WB_FILE/) { 429b898cc70SMel Gorman $file = 1; 430b898cc70SMel Gorman } 431b898cc70SMel Gorman if ($flags =~ /RECLAIM_WB_SYNC/) { 432b898cc70SMel Gorman $sync_io = 1; 433b898cc70SMel Gorman } 434b898cc70SMel Gorman if ($sync_io) { 435b898cc70SMel Gorman if ($file) { 436b898cc70SMel Gorman $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC}++; 437b898cc70SMel Gorman } else { 438b898cc70SMel Gorman $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC}++; 439b898cc70SMel Gorman } 440b898cc70SMel Gorman } else { 441b898cc70SMel Gorman if ($file) { 442b898cc70SMel Gorman $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC}++; 443b898cc70SMel Gorman } else { 444b898cc70SMel Gorman $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC}++; 445b898cc70SMel Gorman } 446b898cc70SMel Gorman } 447b898cc70SMel Gorman } else { 448b898cc70SMel Gorman $perprocesspid{$process_pid}->{EVENT_UNKNOWN}++; 449b898cc70SMel Gorman } 450b898cc70SMel Gorman 451b898cc70SMel Gorman if ($sigint_pending) { 452b898cc70SMel Gorman last EVENT_PROCESS; 453b898cc70SMel Gorman } 454b898cc70SMel Gorman } 455b898cc70SMel Gorman} 456b898cc70SMel Gorman 457b898cc70SMel Gormansub dump_stats { 458b898cc70SMel Gorman my $hashref = shift; 459b898cc70SMel Gorman my %stats = %$hashref; 460b898cc70SMel Gorman 461b898cc70SMel Gorman # Dump per-process stats 462b898cc70SMel Gorman my $process_pid; 463b898cc70SMel Gorman my $max_strlen = 0; 464b898cc70SMel Gorman 465b898cc70SMel Gorman # Get the maximum process name 466b898cc70SMel Gorman foreach $process_pid (keys %perprocesspid) { 467b898cc70SMel Gorman my $len = length($process_pid); 468b898cc70SMel Gorman if ($len > $max_strlen) { 469b898cc70SMel Gorman $max_strlen = $len; 470b898cc70SMel Gorman } 471b898cc70SMel Gorman } 472b898cc70SMel Gorman $max_strlen += 2; 473b898cc70SMel Gorman 474b898cc70SMel Gorman # Work out latencies 475b898cc70SMel Gorman printf("\n") if !$opt_ignorepid; 476b898cc70SMel Gorman printf("Reclaim latencies expressed as order-latency_in_ms\n") if !$opt_ignorepid; 477b898cc70SMel Gorman foreach $process_pid (keys %stats) { 478b898cc70SMel Gorman 479b898cc70SMel Gorman if (!$stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[0] && 480b898cc70SMel Gorman !$stats{$process_pid}->{HIGH_KSWAPD_LATENCY}[0]) { 481b898cc70SMel Gorman next; 482b898cc70SMel Gorman } 483b898cc70SMel Gorman 484b898cc70SMel Gorman printf "%-" . $max_strlen . "s ", $process_pid if !$opt_ignorepid; 485b898cc70SMel Gorman my $index = 0; 486b898cc70SMel Gorman while (defined $stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index] || 487b898cc70SMel Gorman defined $stats{$process_pid}->{HIGH_KSWAPD_LATENCY}[$index]) { 488b898cc70SMel Gorman 489b898cc70SMel Gorman if ($stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index]) { 490b898cc70SMel Gorman printf("%s ", $stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index]) if !$opt_ignorepid; 491b898cc70SMel Gorman my ($dummy, $latency) = split(/-/, $stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index]); 492b898cc70SMel Gorman $total_direct_latency += $latency; 493b898cc70SMel Gorman } else { 494b898cc70SMel Gorman printf("%s ", $stats{$process_pid}->{HIGH_KSWAPD_LATENCY}[$index]) if !$opt_ignorepid; 495b898cc70SMel Gorman my ($dummy, $latency) = split(/-/, $stats{$process_pid}->{HIGH_KSWAPD_LATENCY}[$index]); 496b898cc70SMel Gorman $total_kswapd_latency += $latency; 497b898cc70SMel Gorman } 498b898cc70SMel Gorman $index++; 499b898cc70SMel Gorman } 500b898cc70SMel Gorman print "\n" if !$opt_ignorepid; 501b898cc70SMel Gorman } 502b898cc70SMel Gorman 503b898cc70SMel Gorman # Print out process activity 504b898cc70SMel Gorman printf("\n"); 505e11da5b4SMel Gorman printf("%-" . $max_strlen . "s %8s %10s %8s %8s %8s %8s %8s %8s\n", "Process", "Direct", "Wokeup", "Pages", "Pages", "Pages", "Pages", "Time"); 506e11da5b4SMel Gorman printf("%-" . $max_strlen . "s %8s %10s %8s %8s %8s %8s %8s %8s\n", "details", "Rclms", "Kswapd", "Scanned", "Rclmed", "Sync-IO", "ASync-IO", "Stalled"); 507b898cc70SMel Gorman foreach $process_pid (keys %stats) { 508b898cc70SMel Gorman 509b898cc70SMel Gorman if (!$stats{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN}) { 510b898cc70SMel Gorman next; 511b898cc70SMel Gorman } 512b898cc70SMel Gorman 513b898cc70SMel Gorman $total_direct_reclaim += $stats{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN}; 514b898cc70SMel Gorman $total_wakeup_kswapd += $stats{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD}; 515b898cc70SMel Gorman $total_direct_nr_scanned += $stats{$process_pid}->{HIGH_NR_SCANNED}; 5162c51856cSChen Yucong $total_direct_nr_file_scanned += $stats{$process_pid}->{HIGH_NR_FILE_SCANNED}; 5172c51856cSChen Yucong $total_direct_nr_anon_scanned += $stats{$process_pid}->{HIGH_NR_ANON_SCANNED}; 518e11da5b4SMel Gorman $total_direct_nr_reclaimed += $stats{$process_pid}->{HIGH_NR_RECLAIMED}; 5192c51856cSChen Yucong $total_direct_nr_file_reclaimed += $stats{$process_pid}->{HIGH_NR_FILE_RECLAIMED}; 5202c51856cSChen Yucong $total_direct_nr_anon_reclaimed += $stats{$process_pid}->{HIGH_NR_ANON_RECLAIMED}; 521b898cc70SMel Gorman $total_direct_writepage_file_sync += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC}; 522b898cc70SMel Gorman $total_direct_writepage_anon_sync += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC}; 523b898cc70SMel Gorman $total_direct_writepage_file_async += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC}; 524b898cc70SMel Gorman 525b898cc70SMel Gorman $total_direct_writepage_anon_async += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC}; 526b898cc70SMel Gorman 527b898cc70SMel Gorman my $index = 0; 528b898cc70SMel Gorman my $this_reclaim_delay = 0; 529b898cc70SMel Gorman while (defined $stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index]) { 530b898cc70SMel Gorman my ($dummy, $latency) = split(/-/, $stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index]); 531b898cc70SMel Gorman $this_reclaim_delay += $latency; 532b898cc70SMel Gorman $index++; 533b898cc70SMel Gorman } 534b898cc70SMel Gorman 535e11da5b4SMel Gorman printf("%-" . $max_strlen . "s %8d %10d %8u %8u %8u %8u %8.3f", 536b898cc70SMel Gorman $process_pid, 537b898cc70SMel Gorman $stats{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN}, 538b898cc70SMel Gorman $stats{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD}, 539b898cc70SMel Gorman $stats{$process_pid}->{HIGH_NR_SCANNED}, 5402c51856cSChen Yucong $stats{$process_pid}->{HIGH_NR_FILE_SCANNED}, 5412c51856cSChen Yucong $stats{$process_pid}->{HIGH_NR_ANON_SCANNED}, 542e11da5b4SMel Gorman $stats{$process_pid}->{HIGH_NR_RECLAIMED}, 5432c51856cSChen Yucong $stats{$process_pid}->{HIGH_NR_FILE_RECLAIMED}, 5442c51856cSChen Yucong $stats{$process_pid}->{HIGH_NR_ANON_RECLAIMED}, 545b898cc70SMel Gorman $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC} + $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC}, 546b898cc70SMel Gorman $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC} + $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC}, 547b898cc70SMel Gorman $this_reclaim_delay / 1000); 548b898cc70SMel Gorman 549b898cc70SMel Gorman if ($stats{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN}) { 550b898cc70SMel Gorman print " "; 551b898cc70SMel Gorman for (my $order = 0; $order < 20; $order++) { 552b898cc70SMel Gorman my $count = $stats{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN_PERORDER}[$order]; 553b898cc70SMel Gorman if ($count != 0) { 554b898cc70SMel Gorman print "direct-$order=$count "; 555b898cc70SMel Gorman } 556b898cc70SMel Gorman } 557b898cc70SMel Gorman } 558b898cc70SMel Gorman if ($stats{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD}) { 559b898cc70SMel Gorman print " "; 560b898cc70SMel Gorman for (my $order = 0; $order < 20; $order++) { 561b898cc70SMel Gorman my $count = $stats{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD_PERORDER}[$order]; 562b898cc70SMel Gorman if ($count != 0) { 563b898cc70SMel Gorman print "wakeup-$order=$count "; 564b898cc70SMel Gorman } 565b898cc70SMel Gorman } 566b898cc70SMel Gorman } 567b898cc70SMel Gorman 568b898cc70SMel Gorman print "\n"; 569b898cc70SMel Gorman } 570b898cc70SMel Gorman 571b898cc70SMel Gorman # Print out kswapd activity 572b898cc70SMel Gorman printf("\n"); 573e11da5b4SMel Gorman printf("%-" . $max_strlen . "s %8s %10s %8s %8s %8s %8s\n", "Kswapd", "Kswapd", "Order", "Pages", "Pages", "Pages", "Pages"); 574e11da5b4SMel Gorman printf("%-" . $max_strlen . "s %8s %10s %8s %8s %8s %8s\n", "Instance", "Wakeups", "Re-wakeup", "Scanned", "Rclmed", "Sync-IO", "ASync-IO"); 575b898cc70SMel Gorman foreach $process_pid (keys %stats) { 576b898cc70SMel Gorman 577b898cc70SMel Gorman if (!$stats{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE}) { 578b898cc70SMel Gorman next; 579b898cc70SMel Gorman } 580b898cc70SMel Gorman 581b898cc70SMel Gorman $total_kswapd_wake += $stats{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE}; 582b898cc70SMel Gorman $total_kswapd_nr_scanned += $stats{$process_pid}->{HIGH_NR_SCANNED}; 5832c51856cSChen Yucong $total_kswapd_nr_file_scanned += $stats{$process_pid}->{HIGH_NR_FILE_SCANNED}; 5842c51856cSChen Yucong $total_kswapd_nr_anon_scanned += $stats{$process_pid}->{HIGH_NR_ANON_SCANNED}; 585e11da5b4SMel Gorman $total_kswapd_nr_reclaimed += $stats{$process_pid}->{HIGH_NR_RECLAIMED}; 5862c51856cSChen Yucong $total_kswapd_nr_file_reclaimed += $stats{$process_pid}->{HIGH_NR_FILE_RECLAIMED}; 5872c51856cSChen Yucong $total_kswapd_nr_anon_reclaimed += $stats{$process_pid}->{HIGH_NR_ANON_RECLAIMED}; 588b898cc70SMel Gorman $total_kswapd_writepage_file_sync += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC}; 589b898cc70SMel Gorman $total_kswapd_writepage_anon_sync += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC}; 590b898cc70SMel Gorman $total_kswapd_writepage_file_async += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC}; 591b898cc70SMel Gorman $total_kswapd_writepage_anon_async += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC}; 592b898cc70SMel Gorman 593e11da5b4SMel Gorman printf("%-" . $max_strlen . "s %8d %10d %8u %8u %8i %8u", 594b898cc70SMel Gorman $process_pid, 595b898cc70SMel Gorman $stats{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE}, 596b898cc70SMel Gorman $stats{$process_pid}->{HIGH_KSWAPD_REWAKEUP}, 597b898cc70SMel Gorman $stats{$process_pid}->{HIGH_NR_SCANNED}, 5982c51856cSChen Yucong $stats{$process_pid}->{HIGH_NR_FILE_SCANNED}, 5992c51856cSChen Yucong $stats{$process_pid}->{HIGH_NR_ANON_SCANNED}, 600e11da5b4SMel Gorman $stats{$process_pid}->{HIGH_NR_RECLAIMED}, 6012c51856cSChen Yucong $stats{$process_pid}->{HIGH_NR_FILE_RECLAIMED}, 6022c51856cSChen Yucong $stats{$process_pid}->{HIGH_NR_ANON_RECLAIMED}, 603b898cc70SMel Gorman $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC} + $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC}, 604b898cc70SMel Gorman $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC} + $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC}); 605b898cc70SMel Gorman 606b898cc70SMel Gorman if ($stats{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE}) { 607b898cc70SMel Gorman print " "; 608b898cc70SMel Gorman for (my $order = 0; $order < 20; $order++) { 609b898cc70SMel Gorman my $count = $stats{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE_PERORDER}[$order]; 610b898cc70SMel Gorman if ($count != 0) { 611b898cc70SMel Gorman print "wake-$order=$count "; 612b898cc70SMel Gorman } 613b898cc70SMel Gorman } 614b898cc70SMel Gorman } 615b898cc70SMel Gorman if ($stats{$process_pid}->{HIGH_KSWAPD_REWAKEUP}) { 616b898cc70SMel Gorman print " "; 617b898cc70SMel Gorman for (my $order = 0; $order < 20; $order++) { 618b898cc70SMel Gorman my $count = $stats{$process_pid}->{HIGH_KSWAPD_REWAKEUP_PERORDER}[$order]; 619b898cc70SMel Gorman if ($count != 0) { 620b898cc70SMel Gorman print "rewake-$order=$count "; 621b898cc70SMel Gorman } 622b898cc70SMel Gorman } 623b898cc70SMel Gorman } 624b898cc70SMel Gorman printf("\n"); 625b898cc70SMel Gorman } 626b898cc70SMel Gorman 627b898cc70SMel Gorman # Print out summaries 628b898cc70SMel Gorman $total_direct_latency /= 1000; 629b898cc70SMel Gorman $total_kswapd_latency /= 1000; 630b898cc70SMel Gorman print "\nSummary\n"; 631b898cc70SMel Gorman print "Direct reclaims: $total_direct_reclaim\n"; 632b898cc70SMel Gorman print "Direct reclaim pages scanned: $total_direct_nr_scanned\n"; 6332c51856cSChen Yucong print "Direct reclaim file pages scanned: $total_direct_nr_file_scanned\n"; 6342c51856cSChen Yucong print "Direct reclaim anon pages scanned: $total_direct_nr_anon_scanned\n"; 635e11da5b4SMel Gorman print "Direct reclaim pages reclaimed: $total_direct_nr_reclaimed\n"; 6362c51856cSChen Yucong print "Direct reclaim file pages reclaimed: $total_direct_nr_file_reclaimed\n"; 6372c51856cSChen Yucong print "Direct reclaim anon pages reclaimed: $total_direct_nr_anon_reclaimed\n"; 638b898cc70SMel Gorman print "Direct reclaim write file sync I/O: $total_direct_writepage_file_sync\n"; 639b898cc70SMel Gorman print "Direct reclaim write anon sync I/O: $total_direct_writepage_anon_sync\n"; 640b898cc70SMel Gorman print "Direct reclaim write file async I/O: $total_direct_writepage_file_async\n"; 641b898cc70SMel Gorman print "Direct reclaim write anon async I/O: $total_direct_writepage_anon_async\n"; 642b898cc70SMel Gorman print "Wake kswapd requests: $total_wakeup_kswapd\n"; 643b898cc70SMel Gorman printf "Time stalled direct reclaim: %-1.2f seconds\n", $total_direct_latency; 644b898cc70SMel Gorman print "\n"; 645b898cc70SMel Gorman print "Kswapd wakeups: $total_kswapd_wake\n"; 646b898cc70SMel Gorman print "Kswapd pages scanned: $total_kswapd_nr_scanned\n"; 6472c51856cSChen Yucong print "Kswapd file pages scanned: $total_kswapd_nr_file_scanned\n"; 6482c51856cSChen Yucong print "Kswapd anon pages scanned: $total_kswapd_nr_anon_scanned\n"; 649e11da5b4SMel Gorman print "Kswapd pages reclaimed: $total_kswapd_nr_reclaimed\n"; 6502c51856cSChen Yucong print "Kswapd file pages reclaimed: $total_kswapd_nr_file_reclaimed\n"; 6512c51856cSChen Yucong print "Kswapd anon pages reclaimed: $total_kswapd_nr_anon_reclaimed\n"; 652b898cc70SMel Gorman print "Kswapd reclaim write file sync I/O: $total_kswapd_writepage_file_sync\n"; 653b898cc70SMel Gorman print "Kswapd reclaim write anon sync I/O: $total_kswapd_writepage_anon_sync\n"; 654b898cc70SMel Gorman print "Kswapd reclaim write file async I/O: $total_kswapd_writepage_file_async\n"; 655b898cc70SMel Gorman print "Kswapd reclaim write anon async I/O: $total_kswapd_writepage_anon_async\n"; 656b898cc70SMel Gorman printf "Time kswapd awake: %-1.2f seconds\n", $total_kswapd_latency; 657b898cc70SMel Gorman} 658b898cc70SMel Gorman 659b898cc70SMel Gormansub aggregate_perprocesspid() { 660b898cc70SMel Gorman my $process_pid; 661b898cc70SMel Gorman my $process; 662b898cc70SMel Gorman undef %perprocess; 663b898cc70SMel Gorman 664b898cc70SMel Gorman foreach $process_pid (keys %perprocesspid) { 665b898cc70SMel Gorman $process = $process_pid; 666b898cc70SMel Gorman $process =~ s/-([0-9])*$//; 667b898cc70SMel Gorman if ($process eq '') { 668b898cc70SMel Gorman $process = "NO_PROCESS_NAME"; 669b898cc70SMel Gorman } 670b898cc70SMel Gorman 671b898cc70SMel Gorman $perprocess{$process}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN} += $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN}; 672b898cc70SMel Gorman $perprocess{$process}->{MM_VMSCAN_KSWAPD_WAKE} += $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE}; 673b898cc70SMel Gorman $perprocess{$process}->{MM_VMSCAN_WAKEUP_KSWAPD} += $perprocesspid{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD}; 674b898cc70SMel Gorman $perprocess{$process}->{HIGH_KSWAPD_REWAKEUP} += $perprocesspid{$process_pid}->{HIGH_KSWAPD_REWAKEUP}; 675b898cc70SMel Gorman $perprocess{$process}->{HIGH_NR_SCANNED} += $perprocesspid{$process_pid}->{HIGH_NR_SCANNED}; 6762c51856cSChen Yucong $perprocess{$process}->{HIGH_NR_FILE_SCANNED} += $perprocesspid{$process_pid}->{HIGH_NR_FILE_SCANNED}; 6772c51856cSChen Yucong $perprocess{$process}->{HIGH_NR_ANON_SCANNED} += $perprocesspid{$process_pid}->{HIGH_NR_ANON_SCANNED}; 678e11da5b4SMel Gorman $perprocess{$process}->{HIGH_NR_RECLAIMED} += $perprocesspid{$process_pid}->{HIGH_NR_RECLAIMED}; 6792c51856cSChen Yucong $perprocess{$process}->{HIGH_NR_FILE_RECLAIMED} += $perprocesspid{$process_pid}->{HIGH_NR_FILE_RECLAIMED}; 6802c51856cSChen Yucong $perprocess{$process}->{HIGH_NR_ANON_RECLAIMED} += $perprocesspid{$process_pid}->{HIGH_NR_ANON_RECLAIMED}; 681b898cc70SMel Gorman $perprocess{$process}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC} += $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC}; 682b898cc70SMel Gorman $perprocess{$process}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC} += $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC}; 683b898cc70SMel Gorman $perprocess{$process}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC} += $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC}; 684b898cc70SMel Gorman $perprocess{$process}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC} += $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC}; 685b898cc70SMel Gorman 686b898cc70SMel Gorman for (my $order = 0; $order < 20; $order++) { 687b898cc70SMel Gorman $perprocess{$process}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN_PERORDER}[$order] += $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN_PERORDER}[$order]; 688b898cc70SMel Gorman $perprocess{$process}->{MM_VMSCAN_WAKEUP_KSWAPD_PERORDER}[$order] += $perprocesspid{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD_PERORDER}[$order]; 689b898cc70SMel Gorman $perprocess{$process}->{MM_VMSCAN_KSWAPD_WAKE_PERORDER}[$order] += $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE_PERORDER}[$order]; 690b898cc70SMel Gorman 691b898cc70SMel Gorman } 692b898cc70SMel Gorman 693b898cc70SMel Gorman # Aggregate direct reclaim latencies 694b898cc70SMel Gorman my $wr_index = $perprocess{$process}->{MM_VMSCAN_DIRECT_RECLAIM_END}; 695b898cc70SMel Gorman my $rd_index = 0; 696b898cc70SMel Gorman while (defined $perprocesspid{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$rd_index]) { 697b898cc70SMel Gorman $perprocess{$process}->{HIGH_DIRECT_RECLAIM_LATENCY}[$wr_index] = $perprocesspid{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$rd_index]; 698b898cc70SMel Gorman $rd_index++; 699b898cc70SMel Gorman $wr_index++; 700b898cc70SMel Gorman } 701b898cc70SMel Gorman $perprocess{$process}->{MM_VMSCAN_DIRECT_RECLAIM_END} = $wr_index; 702b898cc70SMel Gorman 703b898cc70SMel Gorman # Aggregate kswapd latencies 704b898cc70SMel Gorman my $wr_index = $perprocess{$process}->{MM_VMSCAN_KSWAPD_SLEEP}; 705b898cc70SMel Gorman my $rd_index = 0; 706b898cc70SMel Gorman while (defined $perprocesspid{$process_pid}->{HIGH_KSWAPD_LATENCY}[$rd_index]) { 707b898cc70SMel Gorman $perprocess{$process}->{HIGH_KSWAPD_LATENCY}[$wr_index] = $perprocesspid{$process_pid}->{HIGH_KSWAPD_LATENCY}[$rd_index]; 708b898cc70SMel Gorman $rd_index++; 709b898cc70SMel Gorman $wr_index++; 710b898cc70SMel Gorman } 711b898cc70SMel Gorman $perprocess{$process}->{MM_VMSCAN_DIRECT_RECLAIM_END} = $wr_index; 712b898cc70SMel Gorman } 713b898cc70SMel Gorman} 714b898cc70SMel Gorman 715b898cc70SMel Gormansub report() { 716b898cc70SMel Gorman if (!$opt_ignorepid) { 717b898cc70SMel Gorman dump_stats(\%perprocesspid); 718b898cc70SMel Gorman } else { 719b898cc70SMel Gorman aggregate_perprocesspid(); 720b898cc70SMel Gorman dump_stats(\%perprocess); 721b898cc70SMel Gorman } 722b898cc70SMel Gorman} 723b898cc70SMel Gorman 724b898cc70SMel Gorman# Process events or signals until neither is available 725b898cc70SMel Gormansub signal_loop() { 726b898cc70SMel Gorman my $sigint_processed; 727b898cc70SMel Gorman do { 728b898cc70SMel Gorman $sigint_processed = 0; 729b898cc70SMel Gorman process_events(); 730b898cc70SMel Gorman 731b898cc70SMel Gorman # Handle pending signals if any 732b898cc70SMel Gorman if ($sigint_pending) { 733b898cc70SMel Gorman my $current_time = time; 734b898cc70SMel Gorman 735b898cc70SMel Gorman if ($sigint_exit) { 736b898cc70SMel Gorman print "Received exit signal\n"; 737b898cc70SMel Gorman $sigint_pending = 0; 738b898cc70SMel Gorman } 739b898cc70SMel Gorman if ($sigint_report) { 740b898cc70SMel Gorman if ($current_time >= $sigint_received + 2) { 741b898cc70SMel Gorman report(); 742b898cc70SMel Gorman $sigint_report = 0; 743b898cc70SMel Gorman $sigint_pending = 0; 744b898cc70SMel Gorman $sigint_processed = 1; 745b898cc70SMel Gorman } 746b898cc70SMel Gorman } 747b898cc70SMel Gorman } 748b898cc70SMel Gorman } while ($sigint_pending || $sigint_processed); 749b898cc70SMel Gorman} 750b898cc70SMel Gorman 751b898cc70SMel Gormansignal_loop(); 752b898cc70SMel Gormanreport(); 753