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