in trace/postprocess/trace-vmscan-postprocess.pl [267:461]
sub process_events {
my $traceevent;
my $process_pid;
my $cpus;
my $timestamp;
my $tracepoint;
my $details;
my $statline;
# Read each line of the event log
EVENT_PROCESS:
while ($traceevent = <STDIN>) {
if ($traceevent =~ /$regex_traceevent/o) {
$process_pid = $1;
$timestamp = $4;
$tracepoint = $5;
$process_pid =~ /(.*)-([0-9]*)$/;
my $process = $1;
my $pid = $2;
if ($process eq "") {
$process = $last_procmap{$pid};
$process_pid = "$process-$pid";
}
$last_procmap{$pid} = $process;
if ($opt_read_procstat) {
$statline = read_statline($pid);
if ($opt_read_procstat && $process eq '') {
$process_pid = guess_process_pid($pid, $statline);
}
}
} else {
next;
}
# Perl Switch() sucks majorly
if ($tracepoint eq "mm_vmscan_direct_reclaim_begin") {
$timestamp = timestamp_to_ms($timestamp);
$perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN}++;
$perprocesspid{$process_pid}->{STATE_DIRECT_BEGIN} = $timestamp;
$details = $6;
if ($details !~ /$regex_direct_begin/o) {
print "WARNING: Failed to parse mm_vmscan_direct_reclaim_begin as expected\n";
print " $details\n";
print " $regex_direct_begin\n";
next;
}
my $order = $1;
$perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN_PERORDER}[$order]++;
$perprocesspid{$process_pid}->{STATE_DIRECT_ORDER} = $order;
} elsif ($tracepoint eq "mm_vmscan_direct_reclaim_end") {
# Count the event itself
my $index = $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_END};
$perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_END}++;
# Record how long direct reclaim took this time
if (defined $perprocesspid{$process_pid}->{STATE_DIRECT_BEGIN}) {
$timestamp = timestamp_to_ms($timestamp);
my $order = $perprocesspid{$process_pid}->{STATE_DIRECT_ORDER};
my $latency = ($timestamp - $perprocesspid{$process_pid}->{STATE_DIRECT_BEGIN});
$perprocesspid{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index] = "$order-$latency";
}
} elsif ($tracepoint eq "mm_vmscan_kswapd_wake") {
$details = $6;
if ($details !~ /$regex_kswapd_wake/o) {
print "WARNING: Failed to parse mm_vmscan_kswapd_wake as expected\n";
print " $details\n";
print " $regex_kswapd_wake\n";
next;
}
my $order = $2;
$perprocesspid{$process_pid}->{STATE_KSWAPD_ORDER} = $order;
if (!$perprocesspid{$process_pid}->{STATE_KSWAPD_BEGIN}) {
$timestamp = timestamp_to_ms($timestamp);
$perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE}++;
$perprocesspid{$process_pid}->{STATE_KSWAPD_BEGIN} = $timestamp;
$perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE_PERORDER}[$order]++;
} else {
$perprocesspid{$process_pid}->{HIGH_KSWAPD_REWAKEUP}++;
$perprocesspid{$process_pid}->{HIGH_KSWAPD_REWAKEUP_PERORDER}[$order]++;
}
} elsif ($tracepoint eq "mm_vmscan_kswapd_sleep") {
# Count the event itself
my $index = $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_SLEEP};
$perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_SLEEP}++;
# Record how long kswapd was awake
$timestamp = timestamp_to_ms($timestamp);
my $order = $perprocesspid{$process_pid}->{STATE_KSWAPD_ORDER};
my $latency = ($timestamp - $perprocesspid{$process_pid}->{STATE_KSWAPD_BEGIN});
$perprocesspid{$process_pid}->{HIGH_KSWAPD_LATENCY}[$index] = "$order-$latency";
$perprocesspid{$process_pid}->{STATE_KSWAPD_BEGIN} = 0;
} elsif ($tracepoint eq "mm_vmscan_wakeup_kswapd") {
$perprocesspid{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD}++;
$details = $6;
if ($details !~ /$regex_wakeup_kswapd/o) {
print "WARNING: Failed to parse mm_vmscan_wakeup_kswapd as expected\n";
print " $details\n";
print " $regex_wakeup_kswapd\n";
next;
}
my $order = $3;
$perprocesspid{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD_PERORDER}[$order]++;
} elsif ($tracepoint eq "mm_vmscan_lru_isolate") {
$details = $6;
if ($details !~ /$regex_lru_isolate/o) {
print "WARNING: Failed to parse mm_vmscan_lru_isolate as expected\n";
print " $details\n";
print " $regex_lru_isolate/o\n";
next;
}
my $isolate_mode = $1;
my $nr_scanned = $5;
my $file = $8;
# To closer match vmstat scanning statistics, only count isolate_both
# and isolate_inactive as scanning. isolate_active is rotation
# isolate_inactive == 1
# isolate_active == 2
# isolate_both == 3
if ($isolate_mode != 2) {
$perprocesspid{$process_pid}->{HIGH_NR_SCANNED} += $nr_scanned;
if ($file =~ /_file/) {
$perprocesspid{$process_pid}->{HIGH_NR_FILE_SCANNED} += $nr_scanned;
} else {
$perprocesspid{$process_pid}->{HIGH_NR_ANON_SCANNED} += $nr_scanned;
}
}
} elsif ($tracepoint eq "mm_vmscan_lru_shrink_inactive") {
$details = $6;
if ($details !~ /$regex_lru_shrink_inactive/o) {
print "WARNING: Failed to parse mm_vmscan_lru_shrink_inactive as expected\n";
print " $details\n";
print " $regex_lru_shrink_inactive/o\n";
next;
}
my $nr_reclaimed = $3;
my $flags = $13;
my $file = 0;
if ($flags =~ /RECLAIM_WB_FILE/) {
$file = 1;
}
$perprocesspid{$process_pid}->{HIGH_NR_RECLAIMED} += $nr_reclaimed;
if ($file) {
$perprocesspid{$process_pid}->{HIGH_NR_FILE_RECLAIMED} += $nr_reclaimed;
} else {
$perprocesspid{$process_pid}->{HIGH_NR_ANON_RECLAIMED} += $nr_reclaimed;
}
} elsif ($tracepoint eq "mm_vmscan_writepage") {
$details = $6;
if ($details !~ /$regex_writepage/o) {
print "WARNING: Failed to parse mm_vmscan_writepage as expected\n";
print " $details\n";
print " $regex_writepage\n";
next;
}
my $flags = $3;
my $file = 0;
my $sync_io = 0;
if ($flags =~ /RECLAIM_WB_FILE/) {
$file = 1;
}
if ($flags =~ /RECLAIM_WB_SYNC/) {
$sync_io = 1;
}
if ($sync_io) {
if ($file) {
$perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC}++;
} else {
$perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC}++;
}
} else {
if ($file) {
$perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC}++;
} else {
$perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC}++;
}
}
} else {
$perprocesspid{$process_pid}->{EVENT_UNKNOWN}++;
}
if ($sigint_pending) {
last EVENT_PROCESS;
}
}
}