Friday, January 17, 2014

AFS Client - better observability

Wouldn't it be nice if fsstat(1M) and fsinfo::: DTrace provider were working with AFS client? It turned out this was trivial to implement - Solaris itself will provide necessary stats for fsstat and register fsinfo::: probes if one extra flag is specified.Thanks to Andrew Deason for implementing it in AFS, and big thanks to Oracle's engineers for providing information on how to do it. See the actual patch to AFS.

Let's see fsstat in action against an AFS mountpount:
$ fsstat /ms 1
new  name   name  attr  attr lookup rddir  read read  write write
file remov  chng   get   set    ops   ops   ops bytes   ops bytes
    0     0     0 10.5K     0   173K   939 20.7K 72.8M     0     0 /ms
    0     0     0     0     0      0     0     0     0     0     0 /ms
    0     0     0     0     0      0     0     0     0     0     0 /ms
    0     0     0    26     0    296     0     9 8.06K     0     0 /ms
    0     0     0     0     0      0     0     0     0     0     0 /ms
    0     0     0     0     0      0     0     0     0     0     0 /ms
    0     0     0     0     0      0     0     0     0     0     0 /ms
    0     0     0   170     0  2.36K    10   106  265K     0     0 /ms
    0     0     0   159     0  1.97K     2    90  261K     0     0 /ms
    0     0     0    25     0    331     0 1.05K 4.15M     0     0 /ms
    0     0     0   138     0  1.80K     0 1.48K 5.37M     0     0 /ms
    0     0     0   360     0  4.72K    12 1.42K 5.35M     0     0 /ms
    0     0     0   122     0  1.63K     0 1.30K 4.68M     0     0 /ms
Now DTrace fsinfo::: provider showing results for AFS related operations:
$ dtrace -q -n fsinfo:::'/args[0]->fi_fs == "afs"/ \
               {printf("%Y %s[%d] %s %s\n", walltimestamp, execname, pid, probename, args[0]->fi_pathname);}'

2014 Jan 16 16:49:07 ifstat[1485] getpage /ms/dist/perl5/PROJ/core/5.8.8-2/.exec/ia32.sunos.5.10/bin/perl
2014 Jan 16 16:49:07 ifstat[1485] lookup /ms/dist
2014 Jan 16 16:49:07 ifstat[1485] lookup /ms/dist/aurora
2014 Jan 16 16:49:07 ifstat[1485] inactive /ms/dist
2014 Jan 16 16:49:07 ifstat[1485] lookup /ms/dist/aurora/bin
2014 Jan 16 16:49:07 ifstat[1485] inactive /ms/dist/aurora
2014 Jan 16 16:49:07 ifstat[1485] inactive /ms/dist/aurora/bin
2014 Jan 16 16:49:07 ifstat[1485] lookup /ms/dist
2014 Jan 16 16:49:07 ifstat[1485] lookup /ms/dist/fsf
2014 Jan 16 16:49:07 ifstat[1485] inactive /ms/dist
2014 Jan 16 16:49:07 ifstat[1485] lookup /ms/dist/fsf/bin
2014 Jan 16 16:49:07 ifstat[1485] inactive /ms/dist/fsf
2014 Jan 16 16:49:07 ifstat[1485] inactive /ms/dist/fsf/bin
2014 Jan 16 16:49:07 ifstat[1485] delmap /ms/dist/perl5/PROJ/core/5.8.8-2/.exec/ia32.sunos.5.10/bin/perl
2014 Jan 16 16:49:07 ifstat[1485] delmap /ms/dist/perl5/PROJ/core/5.8.8-2/.exec/ia32.sunos.5.10/bin/perl
2014 Jan 16 16:49:07 ifstat[1485] delmap /ms/dist/perl5/PROJ/core/5.8.8-2/.exec/ia32.sunos.5.10/lib/perl5/auto/Time/HiRes/HiRes.so
2014 Jan 16 16:49:07 ifstat[1485] delmap /ms/dist/perl5/PROJ/core/5.8.8-2/.exec/ia32.sunos.5.10/lib/perl5/auto/Time/HiRes/HiRes.so
2014 Jan 16 16:49:07 ifstat[1485] close /ms/dist/perl5/PROJ/core/5.8.8-2/.exec/ia32.sunos.5.10/bin/perl
2014 Jan 16 16:49:07 ifstat[964] open /ms/dist/perl5/PROJ/core/5.8.8-2/.exec/ia32.sunos.5.10/bin/perl
2014 Jan 16 16:49:07 ifstat[964] addmap /ms/dist/perl5/PROJ/core/5.8.8-2/.exec/ia32.sunos.5.10/bin/perl
2014 Jan 16 16:49:07 tcpstat[965] open /ms/dist/perl5/PROJ/core/5.8.8-2/.exec/ia32.sunos.5.10/bin/perl
2014 Jan 16 16:49:07 tcpstat[965] addmap /ms/dist/perl5/PROJ/core/5.8.8-2/.exec/ia32.sunos.5.10/bin/perl
2014 Jan 16 16:49:07 tcpstat[965] addmap /ms/dist/perl5/PROJ/core/5.8.8-2/.exec/ia32.sunos.5.10/bin/perl
2014 Jan 16 16:49:07 tcpstat[965] addmap /ms/dist/perl5/PROJ/core/5.8.8-2/.exec/ia32.sunos.5.10/lib/perl5/auto/Time/HiRes/HiRes.so
2014 Jan 16 16:49:07 tcpstat[965] addmap /ms/dist/perl5/PROJ/core/5.8.8-2/.exec/ia32.sunos.5.10/lib/perl5/auto/Time/HiRes/HiRes.so
2014 Jan 16 16:49:07 tcpstat[1484] getpage /ms/dist/perl5/PROJ/core/5.8.8-2/.exec/ia32.sunos.5.10/bin/perl

No comments: