[RFC PATCH -tip 3/5] perf tools: scripts for pagecache snapshooting

From: Keiichi KII
Date: Mon Jul 18 2011 - 17:37:44 EST


From: Keiichi Kii <k-keiichi@xxxxxxxxxxxxx>

The "pagecache snapshooting" is implemented based on "pagecache object
collections" and the trace stream scripting support in perf tools.

To take pagecache snapshoots,
we can run "perf script pagecache-snapshoot <path of fs> <interval>
ex) perf script pagecache-snapshoot / 600
=> keep taking a snapshoot for "/" filesystem every 10 minutes.

The output consists of 2 parts. The following shows sample outputs.

o One part is to show pagecache usage in a system at a point.

pangecache snapshooting (time: 18501, path: /)
file name cache(B) file(B) ratio ±(B) age
-------------------------------------- -------- -------- ------ ------- ------
/var/lib/rpm/Packages 68.5M 70.0M 97% 60.1M 12
/usr/lib64/thunderbird-3.1/thunderbird 8.8M 19.4M 45% 0 11899
/usr/bin/emacs-23.2 4.3M 10.3M 41% 0 17192
/usr/share/anthy/anthy.dic 3.0M 20.0M 14% 0 18402
/usr/lib64/libgtk-x11-2.0.so.0.2200.0 2.8M 4.5M 63% 0 18485
/usr/lib/locale/locale-archive 1.8M 94.6M 1% 0 18496
/usr/lib64/libpython2.7.so.1.0 1.5M 1.8M 87% 0 18417
/usr/bin/Xorg 1.3M 1.9M 71% 0 18471
/usr/share/fonts/sazanami/mincho/sazan 1.3M 10.1M 12% 0 8634
/var/lib/rpm/__db.003 1.3M 1.3M 100% 0 12
/usr/lib64/perl5/CORE/libperl.so 1.2M 1.5M 82% 0 13415
/lib64/libc-2.13.so 1.2M 1.9M 64% 0 18497
/lib64/libdb-4.8.so 1.2M 1.5M 79% 0 18474
/usr/bin/nautilus 1008.0K 1.9M 53% 0 18418
/usr/lib64/libnss3.so 992.0K 1.2M 78% 0 18491
/lib64/libcrypto.so.1.0.0d 948.0K 1.6M 58% 0 18477
/var/cache/hald/fdi-cache 880.0K 997.5K 88% 0 18479

o the other is to show statistics for pagecache changes between snapshoots
after finishing taking snapshoots.

[stat]
o pagecache max
1: 69.5MB /var/lib/rpm/Packages
2: 37.6MB /var/cache/yum/x86_64/14/fedora/19091941
3: 28.1MB /var/cache/yum/x86_64/14/updates/2d3f230
4: 8.8MB /usr/lib64/thunderbird-3.1/thunderbird-b
5: 7.1MB /var/cache/yum/x86_64/14/fedora-debuginf
6: 6.8MB /var/cache/yum/x86_64/14/updates/updatei
7: 4.3MB /usr/bin/emacs-23.2
8: 3.0MB /usr/share/anthy/anthy.dic
9: 2.8MB /usr/lib64/libgtk-x11-2.0.so.0.2200.0
10: 2.6MB /var/cache/yum/x86_64/14/updates-debugin

o pagecache average
1: 24.4MB/ 69.5MB( 35%) /var/lib/rpm/Packages
2: 8.8MB/ 8.8MB( 100%) /usr/lib64/thunderbird-3.1/thunderbird-b
3: 6.3MB/ 37.6MB( 16%) /var/cache/yum/x86_64/14/fedora/19091941
4: 4.7MB/ 28.1MB( 16%) /var/cache/yum/x86_64/14/updates/2d3f230
5: 4.3MB/ 4.3MB( 100%) /usr/bin/emacs-23.2
6: 3.0MB/ 3.0MB( 100%) /usr/share/anthy/anthy.dic
7: 2.8MB/ 2.8MB( 100%) /usr/lib64/libgtk-x11-2.0.so.0.2200.0
8: 1.8MB/ 1.8MB( 100%) /usr/lib/locale/locale-archive
9: 1.4MB/ 1.5MB( 87%) /usr/lib64/libpython2.7.so.1.0
10: 1.3MB/ 1.3MB( 100%) /usr/bin/Xorg

o increased pagecache total
1: 69.5MB/ 69.5MB( 100%) /var/lib/rpm/Packages
2: 37.6MB/ 37.6MB( 100%) /var/cache/yum/x86_64/14/fedora/19091941
3: 28.1MB/ 28.1MB( 100%) /var/cache/yum/x86_64/14/updates/2d3f230
4: 7.1MB/ 7.1MB( 100%) /var/cache/yum/x86_64/14/fedora-debuginf
5: 6.8MB/ 6.8MB( 100%) /var/cache/yum/x86_64/14/updates/updatei
6: 2.6MB/ 2.6MB( 100%) /var/cache/yum/x86_64/14/updates-debugin
7: 1.5MB/ 1.5MB( 100%) /var/cache/yum/x86_64/14/rpmfusion-free/
8: 1.4MB/ 1.4MB( 100%) /var/cache/yum/x86_64/14/rpmfusion-free-
9: 1.3MB/ 1.3MB( 100%) /var/lib/rpm/__db.003
10: 808.0KB/ 1.2MB( 66%) /lib64/libdb-4.8.so

o decreased pagecache total
1: 69.5MB/ 69.5MB( 100%) /var/lib/rpm/Packages
2: 37.6MB/ 37.6MB( 100%) /var/cache/yum/x86_64/14/fedora/19091941
3: 28.1MB/ 28.1MB( 100%) /var/cache/yum/x86_64/14/updates/2d3f230
4: 7.1MB/ 7.1MB( 100%) /var/cache/yum/x86_64/14/fedora-debuginf
5: 6.8MB/ 6.8MB( 100%) /var/cache/yum/x86_64/14/updates/updatei
6: 2.6MB/ 2.6MB( 100%) /var/cache/yum/x86_64/14/updates-debugin
7: 1.5MB/ 1.5MB( 100%) /var/cache/yum/x86_64/14/rpmfusion-free/
8: 1.4MB/ 1.4MB( 100%) /var/cache/yum/x86_64/14/rpmfusion-free-
9: 1.3MB/ 1.3MB( 100%) /var/lib/rpm/__db.003
10: 808.0KB/ 1.2MB( 66%) /lib64/libdb-4.8.so

Signed-off-by: Keiichi Kii <k-keiichi@xxxxxxxxxxxxx>
---

.../scripts/perl/bin/pagecache-snapshoot-record | 3
.../scripts/perl/bin/pagecache-snapshoot-report | 34 ++++
tools/perf/scripts/perl/pagecache-snapshoot.pl | 188 ++++++++++++++++++++
3 files changed, 225 insertions(+), 0 deletions(-)
create mode 100644 tools/perf/scripts/perl/bin/pagecache-snapshoot-record
create mode 100644 tools/perf/scripts/perl/bin/pagecache-snapshoot-report
create mode 100644 tools/perf/scripts/perl/pagecache-snapshoot.pl


diff --git a/tools/perf/scripts/perl/bin/pagecache-snapshoot-record b/tools/perf/scripts/perl/bin/pagecache-snapshoot-record
new file mode 100644
index 0000000..7ece9c9
--- /dev/null
+++ b/tools/perf/scripts/perl/bin/pagecache-snapshoot-record
@@ -0,0 +1,3 @@
+#!/bin/bash
+
+perf record -D -e mm:dump_inode --filter "nrpages>20" -e mm:dump_header $@
diff --git a/tools/perf/scripts/perl/bin/pagecache-snapshoot-report b/tools/perf/scripts/perl/bin/pagecache-snapshoot-report
new file mode 100644
index 0000000..228c9d2
--- /dev/null
+++ b/tools/perf/scripts/perl/bin/pagecache-snapshoot-report
@@ -0,0 +1,34 @@
+#!/bin/bash
+# description: snapshoot pagecache usage
+# args: <path> <interval>
+
+function find_debugfs_path {
+ echo `cat /proc/mounts | grep debugfs | awk 'NR == 1 {print $2}'`
+}
+
+for i in "$@"
+do
+ if expr match "$i" "-" > /dev/null; then
+ break
+ fi
+ n_args=$(( $n_args + 1 ))
+done
+
+if [ "$n_args" -eq 2 ]; then
+ path=$1
+ interval=$2
+ shift 2
+else
+ echo "usage: pagecache-snapshoot <path> <interval>"
+ exit
+fi
+
+CUR_PID=$$
+while true;
+do
+ test `ps -e | grep $CUR_PID | wc -l` = 0 && break;
+ echo $path > `find_debugfs_path`/tracing/objects/mm/pages/walk-fs
+ sleep $interval
+done&
+
+perf script $@ -s "$PERF_EXEC_PATH"/scripts/perl/pagecache-snapshoot.pl
diff --git a/tools/perf/scripts/perl/pagecache-snapshoot.pl b/tools/perf/scripts/perl/pagecache-snapshoot.pl
new file mode 100644
index 0000000..f87f3fc
--- /dev/null
+++ b/tools/perf/scripts/perl/pagecache-snapshoot.pl
@@ -0,0 +1,188 @@
+#!/usr/bin/perl -w
+# (C) 2011, Keiichi Kii <k-keiichi@xxxxxxxxxxxxx>
+# Licensed under the terms of the GNU GPL License version 2
+
+# Take pagecache snapshoot in system.
+
+use lib "$ENV{'PERF_EXEC_PATH'}/scripts/perl/Perf-Trace-Util/lib";
+use lib "./Perf-Trace-Util/lib";
+use Perf::Trace::Core;
+use Perf::Trace::Context;
+use Perf::Trace::Util;
+use File::Basename qw/basename/;
+use threads;
+use Getopt::Std;
+
+my $interval;
+my $cur_mode = $ARGV[0];
+my $cur_record;
+my $limit = 17;
+my @records;
+my @stats;
+
+sub trace_end {
+ clear_term();
+ analyze();
+ print_stats();
+}
+
+sub mm::dump_header
+{
+ my ($event_name, $context, $common_cpu, $common_secs, $common_nsecs,
+ $common_pid, $common_comm,
+ $object_name, $input_data) = @_;
+
+ clear_term();
+ print_files($cur_record);
+ switch_record($input_data, $common_secs);
+}
+
+sub switch_record() {
+ my ($path, $time) = @_;
+ my %new_record = ();
+
+ $$cur_record{complete} = 1;
+ $new_record{path} = $path;
+ $new_record{time} = $time;
+ $new_record{files} = ();
+ $new_record{complete} = 0;
+
+ if (@records > 0) {
+ foreach my $f (keys %{$$cur_record{files}}) {
+ if ($$cur_record{files}{$f}{pages} == 0) {
+ $new_record{files}{$f} = {cached => 0, pages => 0};
+ } else {
+ %{$new_record{files}{$f}} = %{$$cur_record{files}{$f}};
+ $new_record{files}{$f}{cached} = 1;
+ $new_record{files}{$f}{pages} = 0;
+ $new_record{files}{$f}{change} =
+ -$$cur_record{files}{$f}{pages};
+ }
+ }
+ }
+ $cur_record = \%new_record;
+ push(@records, \%new_record);
+}
+
+sub mm::dump_inode
+{
+ my ($event_name, $context, $common_cpu, $common_secs, $common_nsecs,
+ $common_pid, $common_comm,
+ $ino, $size, $nrpages, $age,
+ $state, $dev, $file) = @_;
+
+ if ($file =~ /$$cur_record{path}/ and $nrpages != 0) {
+ if (defined($$cur_record{files}{$dev.":".$ino})) {
+ $$cur_record{files}{$dev.":".$ino}{path} = $file;
+ $$cur_record{files}{$dev.":".$ino}{size} = $size;
+ $$cur_record{files}{$dev.":".$ino}{pages} = $nrpages;
+ $$cur_record{files}{$dev.":".$ino}{change} += $nrpages;
+ $$cur_record{files}{$dev.":".$ino}{cached} = 1;
+ $$cur_record{files}{$dev.":".$ino}{age} = $age;
+ } else {
+ $$cur_record{files}{$dev.":".$ino} =
+ {cached => 1, path => $file, size => $size, pages => $nrpages,
+ change => (@records == 1) ? 0 : $nrpages, age => $age};
+ }
+ }
+}
+
+sub print_files() {
+ my $record = shift;
+ my $i = 0;
+ my $file_name ="";
+
+ printf("pagecache snapshooting (time: %d, path: %s)\n",
+ $$record{time}, $$record{path});
+ printf("%38s %8s %8s %6s %7s %6s\n",
+ "file name", "cache(B)", "file(B)", "ratio", "+/-(B)", "age");
+ printf("%38s %8s %8s %6s %7s %6s\n",
+ '-'x38, '-'x8, '-'x8, '-'x6, '-'x7, '-'x6);
+ foreach my $f (sort {$$b{pages} <=> $$a{pages}} values %{$$record{files}}) {
+ next if $$f{cached} == 0;
+ $i++;
+ printf("%-38s %8s %8s %5d%% %7s %6d\n", get_file_name($$f{path}, 38),
+ convert_unit($$f{pages} * 4096), convert_unit($$f{size}),
+ ($$f{size} == 0) ? 0 : ($$f{pages} * 4096) / $$f{size} * 100,
+ convert_unit($$f{change} * 4096),
+ $$f{age} / 1000);
+ last if $i >= $limit;
+ }
+}
+
+sub analyze() {
+ foreach my $key (keys %{$records[$#records]{files}}) {
+ my (@result, $total);
+ my %stat = (max => 0, increase => 0, decrease => 0, average => 0);
+
+ @result = grep $$_{files}{$key}{cached} == 1 &&
+ $$_{complete} == 1, @records;
+ $total = grep $$_{complete} == 1, @records;
+ $stat{max} = 0;
+ foreach my $r (@result) {
+ $stat{path} = $$r{files}{$key}{path};
+ if ($stat{max} < $$r{files}{$key}{pages}) {
+ $stat{max} = $$r{files}{$key}{pages};
+ }
+ $stat{average} += $$r{files}{$key}{pages} / $total;
+ if ($$r{files}{$key}{change} > 0) {
+ $stat{increase} += $$r{files}{$key}{change};
+ } else {
+ $stat{decrease} += -$$r{files}{$key}{change};
+ }
+ }
+ $stats{files}{$key} = \%stat;
+ }
+}
+
+sub print_stats() {
+ print "[stat]\n";
+ print "o pagecache max\n";
+ print_stats_elem("max", 10);
+ print "o pagecache average\n";
+ print_stats_elem("average", 10);
+ print "o increased pagecache total\n";
+ print_stats_elem("increase", 10);
+ print "o decreased pagecache total\n";
+ print_stats_elem("decrease", 10);
+}
+
+sub print_stats_elem() {
+ my ($type, $num) = @_;
+ my $i = 1;
+
+ foreach my $s (sort {$$b{$type} <=> $$a{$type}} values %{$stats{files}}) {
+ next if $$s{$type} == 0;
+ if ($type eq "max") {
+ printf("%3d: %8sB %-40s\n", $i, convert_unit($$s{$type} * 4096),
+ get_file_name($$s{path}, 40));
+ } else {
+ printf("%3d: %8sB/%8sB(%4d%%) %-40s\n", $i,
+ convert_unit($$s{$type} * 4096),
+ convert_unit($$s{max} * 4096),
+ $$s{$type} / $$s{max} * 100, get_file_name($$s{path}, 40));
+ }
+ $i++;
+ last if $i > $num;
+ }
+ print "\n";
+}
+
+@unit = ("K", "M", "G", "T");
+sub convert_unit() {
+ my $size = shift;
+
+ for (my $i=$#unit; $i >= 0; $i--) {
+ if (abs($size) >= 1024 ** ($i+1)) {
+ return sprintf("%.1f%s", $size/1024 ** ($i+1) , $unit[$i]);
+ }
+ }
+ return $size
+}
+
+
+sub get_file_name() {
+ my ($f, $length) = @_;
+
+ return substr($f, 0, $length);
+}


--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/