Tracing NFSv3 Read and Writer Requests Using nfsv3rwsnoop.d

This DTrace script traces NFS version 3 read and write requests, showing details of each operation.

#!/usr/sbin/dtrace -s

#pragma D option quiet
#pragma D option switchrate=10hz

dtrace:::BEGIN
{
        printf("%-16s %-18s %2s %-8s %6s %s\n", "TIME(us)",
            "CLIENT", "OP", "OFFSET", "BYTES", "PATHNAME");
}

nfsv3:::op-read-start
{
        printf("%-16d %-18s %2s %-8d %6d %s\n", timestamp / 1000,
            args[0]->ci_remote, "R", args[2]->offset / 1024, args[2]->count,
            args[1]->noi_curpath);
}

nfsv3:::op-write-start
{
        printf("%-16d %-18s %2s %-8d %6d %s\n", timestamp / 1000,
            args[0]->ci_remote, "W", args[2]->offset / 1024,
            args[2]->data.data_len, args[1]->noi_curpath);
}

The following output shows a read of /export/stuff/bin/ghex2, then a read of /export/stuff/bin/gksu, and finally a write of /export/stuff/words12:

# ./nfsv3iosnoop.d
TIME(us)         CLIENT             OP OFFSET    BYTES PATHNAME 
4299383207       192.0.2.75       R 0          4096 /export/stuff/bin/ghex2
4299391813       192.0.2.75       R 4         28672 /export/stuff/bin/ghex2
4299395700       192.0.2.75       R 32        32768 /export/stuff/bin/ghex2
4299396038       192.0.2.75       R 96        32768 /export/stuff/bin/ghex2
4299396462       192.0.2.75       R 128        8192 /export/stuff/bin/ghex2
4299396550       192.0.2.75       R 64        32768 /export/stuff/bin/ghex2
4320233417       192.0.2.75       R 0          4096 /export/stuff/bin/gksu
4320240902       192.0.2.75       R 4         28672 /export/stuff/bin/gksu
4320242434       192.0.2.75       R 32        32768 /export/stuff/bin/gksu
4320242730       192.0.2.75       R 64        24576 /export/stuff/bin/gksu
4333460565       192.0.2.75       W 0         32768 /export/stuff/words12
4333461477       192.0.2.75       W 32        32768 /export/stuff/words12
4333463264       192.0.2.75       W 64        32768 /export/stuff/words12
4333463567       192.0.2.75       W 96        32768 /export/stuff/words12
4333463893       192.0.2.75       W 128       32768 /export/stuff/words12
4333464202       192.0.2.75       W 160       32768 /export/stuff/words12
4333464451       192.0.2.75       W 192       10055 /export/stuff/words12

The fields printed are:

Field	Description
TIME(us)	Time of event in microseconds
CLIENT	Remote client IP address
OP	R == read, W == write
OFFSET	File offset of I/O, in Kbytes
BYTES	Tbytes of I/O
PATHNAME	Path name of file, if known

Note:

The output may be shuffled slightly on multi-CPU servers due to DTrace per-CPU buffering; post sort the TIME column if needed.