Jon Haslam's Weblog

The other day, Erik O'Shaughnessy wrote a nice blog on extracting some new statistics that fsflush makes available to us in Solaris 10 . Any new insight that can be gathered into the operation of the mysterious fsflush has to be a good thing and goodness abounds with Eriks fsfstat tool.

However, it wouldn't be right if we didn't knock a quick version up in D now would it? The script below just takes advantage of the fact that we can reference symbols in the kernel using the backquote character (`) which is the symbol scoping operator.

#!/usr/sbin/dtrace -s

#pragma D option quiet

BEGIN
{
    lexam = 0; lscan = 0; llock = 0; lmod = 0; lcoal = 0; lrel = 0; ltime = 0;
    printf("%10s %10s %10s %10s %10s %10s %10s\n", "SCANNED", "EXAMINED",
        "LOCKED", "MODIFIED", "COALESCE", "RELEASES", "TIME(ns)");
}

tick-1s
/lexam/
{
    printf("%10d %10d %10d %10d %10d %10d %10d\n", `fsf_total.fsf_scan - lscan,
        `fsf_total.fsf_examined - lexam, `fsf_total.fsf_locked - llock,
        `fsf_total.fsf_modified - lmod, `fsf_total.fsf_coalesce - lcoal,
        `fsf_total.fsf_releases - lrel, `fsf_total.fsf_time - ltime);
    lexam = `fsf_total.fsf_examined;
    lscan = `fsf_total.fsf_scan;
    llock = `fsf_total.fsf_locked;
    lmod = `fsf_total.fsf_modified;
    lcoal = `fsf_total.fsf_coalesce;
    lrel = `fsf_total.fsf_releases;
    ltime = `fsf_total.fsf_time;
}

/*
 * First time through
 */

tick-1s
/!lexam/
{
    lexam = `fsf_total.fsf_examined;
    lscan = `fsf_total.fsf_scan;
    llock = `fsf_total.fsf_locked;
    lmod = `fsf_total.fsf_modified;
    lcoal = `fsf_total.fsf_coalesce;
    ltime = `fsf_total.fsf_time;
    lrel = `fsf_total.fsf_releases;
}

On my lowly laptop with 768MB of memory things look like:

   SCANNED   EXAMINED     LOCKED   MODIFIED   COALESCE   RELEASES   TIME(ns)
      6355       6356        222          2          0          0     576918
      6355       6356        506          1          0          0     593640
      6355       6356        946          0          0          0     635839
      6355       6356        560          2          0          0     621283
      6355       6356        348          5          0          0     612733
      6355       6356        636          3          0          0     642727
      6355       6356       1005          3          0          0     673983
      6355       6356        783          4          0          0     674637
      6355       5138        309          0          0          0     492221
      6355       5333          0          0          0          0     441155
      6355       6140          2          0          0          0     491863
      6355          7          0          0          0          0       4859
      6355          7          0          0          0          0       4618
      6355          7          1          0          0          0       4588
      6355       5333        619          0          0          0     508046
      6355       6356        350          1          0          0     685573
      6355       6356        343          0          0          0     585538
      6355       6356          0          0          0          0     506531
      6355       6356         18          0          0          0     508688
      6355       6356        415          1          0          0     711370
      6355       6356        542          0          0          0     619117
      6355       6356        377          0          0          0     578586

Sure, Eriks looks nicer and I do like his percentage column but for 15 minutes of my time I'm not complaining!