Lines Matching +full:a +full:- +full:za +full:- +full:z
2 # This is a POC for reading the text representation of trace output related to
3 # page reclaim. It makes an attempt to extract some high-level information on
6 # Example usage: trace-vmscan-postprocess.pl < /sys/kernel/tracing/trace_pipe
8 # --read-procstat If the trace lacks process info, get it from /proc
9 # --ignore-pid Aggregate processes of the same name together
31 # Per-order events
43 # High-level events extrapolated from tracepoints
83 if ($current_time - 2 > $sigint_received) {
84 print "SIGINT received, report pending. Hit ctrl-c again to exit\n";
105 'ignore-pid' => \$opt_ignorepid,
106 'read-procstat' => \$opt_read_procstat,
110 my $regex_direct_begin_default = 'order=([0-9]*) gfp_flags=([A-Z_|]*)';
111 my $regex_direct_end_default = 'nr_reclaimed=([0-9]*)';
112 my $regex_kswapd_wake_default = 'nid=([0-9]*) order=([0-9]*)';
113 my $regex_kswapd_sleep_default = 'nid=([0-9]*)';
114 my $regex_wakeup_kswapd_default = 'nid=([0-9]*) order=([0-9]*) gfp_flags=([A-Z_|]*)';
115 …fault = 'classzone=([0-9]*) order=([0-9]*) nr_requested=([0-9]*) nr_scanned=([0-9]*) nr_skipped=([…
116 …-9]*) nr_scanned=([0-9]*) nr_reclaimed=([0-9]*) nr_dirty=([0-9]*) nr_writeback=([0-9]*) nr_congest…
117 …efault = 'lru=([A-Z_]*) nr_taken=([0-9]*) nr_active=([0-9]*) nr_deactivated=([0-9]*) nr_referenced…
118 my $regex_writepage_default = 'page=([0-9a-f]*) pfn=([0-9]*) flags=([A-Z_|]*)';
133 my $regex_traceevent = '\s*([a-zA-Z0-9-]*)\s*(\[[0-9]*\])(\s*[dX.][Nnp.][Hhs.][0-9a-fA-F.]*|)\s*([0…
134 my $regex_statname = '[-0-9]*\s\((.*)\).*';
135 my $regex_statppid = '[-0-9]*\s\(.*\)\s[A-Za-z]\s([0-9]*).*';
150 $line =~ s/, REC->.*//;
153 $regex =~ s/%s/\([0-9a-zA-Z|_]*\)/g;
154 $regex =~ s/%p/\([0-9a-f]*\)/g;
155 $regex =~ s/%d/\([-0-9]*\)/g;
156 $regex =~ s/%ld/\([-0-9]*\)/g;
157 $regex =~ s/%lu/\([0-9]*\)/g;
237 $statline = "-1 (UNKNOWN_PROCESS_NAME) R 0";
248 return "swapper-0";
254 return "$1-$pid";
282 $process_pid =~ /(.*)-([0-9]*)$/;
288 $process_pid = "$process-$pid";
305 $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN}++;
306 $perprocesspid{$process_pid}->{STATE_DIRECT_BEGIN} = $timestamp;
316 $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN_PERORDER}[$order]++;
317 $perprocesspid{$process_pid}->{STATE_DIRECT_ORDER} = $order;
320 my $index = $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_END};
321 $perprocesspid{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_END}++;
324 if (defined $perprocesspid{$process_pid}->{STATE_DIRECT_BEGIN}) {
326 my $order = $perprocesspid{$process_pid}->{STATE_DIRECT_ORDER};
327 my $latency = ($timestamp - $perprocesspid{$process_pid}->{STATE_DIRECT_BEGIN});
328 $perprocesspid{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index] = "$order-$latency";
340 $perprocesspid{$process_pid}->{STATE_KSWAPD_ORDER} = $order;
341 if (!$perprocesspid{$process_pid}->{STATE_KSWAPD_BEGIN}) {
343 $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE}++;
344 $perprocesspid{$process_pid}->{STATE_KSWAPD_BEGIN} = $timestamp;
345 $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE_PERORDER}[$order]++;
347 $perprocesspid{$process_pid}->{HIGH_KSWAPD_REWAKEUP}++;
348 $perprocesspid{$process_pid}->{HIGH_KSWAPD_REWAKEUP_PERORDER}[$order]++;
353 my $index = $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_SLEEP};
354 $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_SLEEP}++;
358 my $order = $perprocesspid{$process_pid}->{STATE_KSWAPD_ORDER};
359 my $latency = ($timestamp - $perprocesspid{$process_pid}->{STATE_KSWAPD_BEGIN});
360 $perprocesspid{$process_pid}->{HIGH_KSWAPD_LATENCY}[$index] = "$order-$latency";
361 $perprocesspid{$process_pid}->{STATE_KSWAPD_BEGIN} = 0;
363 $perprocesspid{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD}++;
373 $perprocesspid{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD_PERORDER}[$order]++;
388 $perprocesspid{$process_pid}->{HIGH_NR_SCANNED} += $nr_scanned;
390 $perprocesspid{$process_pid}->{HIGH_NR_FILE_SCANNED} += $nr_scanned;
392 $perprocesspid{$process_pid}->{HIGH_NR_ANON_SCANNED} += $nr_scanned;
410 $perprocesspid{$process_pid}->{HIGH_NR_RECLAIMED} += $nr_reclaimed;
412 $perprocesspid{$process_pid}->{HIGH_NR_FILE_RECLAIMED} += $nr_reclaimed;
414 $perprocesspid{$process_pid}->{HIGH_NR_ANON_RECLAIMED} += $nr_reclaimed;
436 $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC}++;
438 $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC}++;
442 $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC}++;
444 $perprocesspid{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC}++;
448 $perprocesspid{$process_pid}->{EVENT_UNKNOWN}++;
461 # Dump per-process stats
476 printf("Reclaim latencies expressed as order-latency_in_ms\n") if !$opt_ignorepid;
479 if (!$stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[0] &&
480 !$stats{$process_pid}->{HIGH_KSWAPD_LATENCY}[0]) {
484 printf "%-" . $max_strlen . "s ", $process_pid if !$opt_ignorepid;
486 while (defined $stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index] ||
487 defined $stats{$process_pid}->{HIGH_KSWAPD_LATENCY}[$index]) {
489 if ($stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index]) {
490 printf("%s ", $stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index]) if !$opt_ignorepid;
491 my ($dummy, $latency) = split(/-/, $stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index]);
494 printf("%s ", $stats{$process_pid}->{HIGH_KSWAPD_LATENCY}[$index]) if !$opt_ignorepid;
495 my ($dummy, $latency) = split(/-/, $stats{$process_pid}->{HIGH_KSWAPD_LATENCY}[$index]);
505 …printf("%-" . $max_strlen . "s %8s %10s %8s %8s %8s %8s %8s %8s\n", "Process", "Direct", "Woke…
506 …printf("%-" . $max_strlen . "s %8s %10s %8s %8s %8s %8s %8s %8s\n", "details", "Rclms", "Kswa…
509 if (!$stats{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN}) {
513 $total_direct_reclaim += $stats{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN};
514 $total_wakeup_kswapd += $stats{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD};
515 $total_direct_nr_scanned += $stats{$process_pid}->{HIGH_NR_SCANNED};
516 $total_direct_nr_file_scanned += $stats{$process_pid}->{HIGH_NR_FILE_SCANNED};
517 $total_direct_nr_anon_scanned += $stats{$process_pid}->{HIGH_NR_ANON_SCANNED};
518 $total_direct_nr_reclaimed += $stats{$process_pid}->{HIGH_NR_RECLAIMED};
519 $total_direct_nr_file_reclaimed += $stats{$process_pid}->{HIGH_NR_FILE_RECLAIMED};
520 $total_direct_nr_anon_reclaimed += $stats{$process_pid}->{HIGH_NR_ANON_RECLAIMED};
521 $total_direct_writepage_file_sync += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC};
522 $total_direct_writepage_anon_sync += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC};
523 $total_direct_writepage_file_async += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC};
525 $total_direct_writepage_anon_async += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC};
529 while (defined $stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index]) {
530 my ($dummy, $latency) = split(/-/, $stats{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$index]);
535 printf("%-" . $max_strlen . "s %8d %10d %8u %8u %8u %8u %8.3f",
537 $stats{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN},
538 $stats{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD},
539 $stats{$process_pid}->{HIGH_NR_SCANNED},
540 $stats{$process_pid}->{HIGH_NR_FILE_SCANNED},
541 $stats{$process_pid}->{HIGH_NR_ANON_SCANNED},
542 $stats{$process_pid}->{HIGH_NR_RECLAIMED},
543 $stats{$process_pid}->{HIGH_NR_FILE_RECLAIMED},
544 $stats{$process_pid}->{HIGH_NR_ANON_RECLAIMED},
545 …$stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC} + $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE…
546 …$stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC} + $stats{$process_pid}->{MM_VMSCAN_WRITEPAG…
549 if ($stats{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN}) {
552 my $count = $stats{$process_pid}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN_PERORDER}[$order];
554 print "direct-$order=$count ";
558 if ($stats{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD}) {
561 my $count = $stats{$process_pid}->{MM_VMSCAN_WAKEUP_KSWAPD_PERORDER}[$order];
563 print "wakeup-$order=$count ";
573 …printf("%-" . $max_strlen . "s %8s %10s %8s %8s %8s %8s\n", "Kswapd", "Kswapd", "Order", …
574 …printf("%-" . $max_strlen . "s %8s %10s %8s %8s %8s %8s\n", "Instance", "Wakeups", "Re-wakeup"…
577 if (!$stats{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE}) {
581 $total_kswapd_wake += $stats{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE};
582 $total_kswapd_nr_scanned += $stats{$process_pid}->{HIGH_NR_SCANNED};
583 $total_kswapd_nr_file_scanned += $stats{$process_pid}->{HIGH_NR_FILE_SCANNED};
584 $total_kswapd_nr_anon_scanned += $stats{$process_pid}->{HIGH_NR_ANON_SCANNED};
585 $total_kswapd_nr_reclaimed += $stats{$process_pid}->{HIGH_NR_RECLAIMED};
586 $total_kswapd_nr_file_reclaimed += $stats{$process_pid}->{HIGH_NR_FILE_RECLAIMED};
587 $total_kswapd_nr_anon_reclaimed += $stats{$process_pid}->{HIGH_NR_ANON_RECLAIMED};
588 $total_kswapd_writepage_file_sync += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC};
589 $total_kswapd_writepage_anon_sync += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC};
590 $total_kswapd_writepage_file_async += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC};
591 $total_kswapd_writepage_anon_async += $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC};
593 printf("%-" . $max_strlen . "s %8d %10d %8u %8u %8i %8u",
595 $stats{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE},
596 $stats{$process_pid}->{HIGH_KSWAPD_REWAKEUP},
597 $stats{$process_pid}->{HIGH_NR_SCANNED},
598 $stats{$process_pid}->{HIGH_NR_FILE_SCANNED},
599 $stats{$process_pid}->{HIGH_NR_ANON_SCANNED},
600 $stats{$process_pid}->{HIGH_NR_RECLAIMED},
601 $stats{$process_pid}->{HIGH_NR_FILE_RECLAIMED},
602 $stats{$process_pid}->{HIGH_NR_ANON_RECLAIMED},
603 …$stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC} + $stats{$process_pid}->{MM_VMSCAN_WRITEPAGE…
604 …$stats{$process_pid}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC} + $stats{$process_pid}->{MM_VMSCAN_WRITEPAG…
606 if ($stats{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE}) {
609 my $count = $stats{$process_pid}->{MM_VMSCAN_KSWAPD_WAKE_PERORDER}[$order];
611 print "wake-$order=$count ";
615 if ($stats{$process_pid}->{HIGH_KSWAPD_REWAKEUP}) {
618 my $count = $stats{$process_pid}->{HIGH_KSWAPD_REWAKEUP_PERORDER}[$order];
620 print "rewake-$order=$count ";
643 printf "Time stalled direct reclaim: %-1.2f seconds\n", $total_direct_latency;
656 printf "Time kswapd awake: %-1.2f seconds\n", $total_kswapd_latency;
666 $process =~ s/-([0-9])*$//;
671 …$perprocess{$process}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN} += $perprocesspid{$process_pid}->{MM_VMSCA…
672 …$perprocess{$process}->{MM_VMSCAN_KSWAPD_WAKE} += $perprocesspid{$process_pid}->{MM_VMSCAN_KSWAPD_…
673 …$perprocess{$process}->{MM_VMSCAN_WAKEUP_KSWAPD} += $perprocesspid{$process_pid}->{MM_VMSCAN_WAKEU…
674 …$perprocess{$process}->{HIGH_KSWAPD_REWAKEUP} += $perprocesspid{$process_pid}->{HIGH_KSWAPD_REWAKE…
675 $perprocess{$process}->{HIGH_NR_SCANNED} += $perprocesspid{$process_pid}->{HIGH_NR_SCANNED};
676 …$perprocess{$process}->{HIGH_NR_FILE_SCANNED} += $perprocesspid{$process_pid}->{HIGH_NR_FILE_SCANN…
677 …$perprocess{$process}->{HIGH_NR_ANON_SCANNED} += $perprocesspid{$process_pid}->{HIGH_NR_ANON_SCANN…
678 $perprocess{$process}->{HIGH_NR_RECLAIMED} += $perprocesspid{$process_pid}->{HIGH_NR_RECLAIMED};
679 …$perprocess{$process}->{HIGH_NR_FILE_RECLAIMED} += $perprocesspid{$process_pid}->{HIGH_NR_FILE_REC…
680 …$perprocess{$process}->{HIGH_NR_ANON_RECLAIMED} += $perprocesspid{$process_pid}->{HIGH_NR_ANON_REC…
681 …$perprocess{$process}->{MM_VMSCAN_WRITEPAGE_FILE_SYNC} += $perprocesspid{$process_pid}->{MM_VMSCAN…
682 …$perprocess{$process}->{MM_VMSCAN_WRITEPAGE_ANON_SYNC} += $perprocesspid{$process_pid}->{MM_VMSCAN…
683 …$perprocess{$process}->{MM_VMSCAN_WRITEPAGE_FILE_ASYNC} += $perprocesspid{$process_pid}->{MM_VMSCA…
684 …$perprocess{$process}->{MM_VMSCAN_WRITEPAGE_ANON_ASYNC} += $perprocesspid{$process_pid}->{MM_VMSCA…
687 …$perprocess{$process}->{MM_VMSCAN_DIRECT_RECLAIM_BEGIN_PERORDER}[$order] += $perprocesspid{$proces…
688 …$perprocess{$process}->{MM_VMSCAN_WAKEUP_KSWAPD_PERORDER}[$order] += $perprocesspid{$process_pid}-…
689 …$perprocess{$process}->{MM_VMSCAN_KSWAPD_WAKE_PERORDER}[$order] += $perprocesspid{$process_pid}->{…
694 my $wr_index = $perprocess{$process}->{MM_VMSCAN_DIRECT_RECLAIM_END};
696 while (defined $perprocesspid{$process_pid}->{HIGH_DIRECT_RECLAIM_LATENCY}[$rd_index]) {
697 …$perprocess{$process}->{HIGH_DIRECT_RECLAIM_LATENCY}[$wr_index] = $perprocesspid{$process_pid}->{H…
701 $perprocess{$process}->{MM_VMSCAN_DIRECT_RECLAIM_END} = $wr_index;
704 my $wr_index = $perprocess{$process}->{MM_VMSCAN_KSWAPD_SLEEP};
706 while (defined $perprocesspid{$process_pid}->{HIGH_KSWAPD_LATENCY}[$rd_index]) {
707 …$perprocess{$process}->{HIGH_KSWAPD_LATENCY}[$wr_index] = $perprocesspid{$process_pid}->{HIGH_KSWA…
711 $perprocess{$process}->{MM_VMSCAN_DIRECT_RECLAIM_END} = $wr_index;