Tracing NFSv4 Read and Writer Requests Using nfsv4rwsnoop.d

This DTrace script traces NFS version 4 reads and writes:

#!/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");
}

nfsv4:::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);
}

nfsv4:::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_len,
            args[1]->noi_curpath);
}

This output shows a few files were read, and one was written:

# ./nfsv4rwsnoop.d 
TIME(us)         CLIENT             OP OFFSET    BYTES PATHNAME
156889725960     192.0.2.14       R 0          4096 /export/share/bin/nawk
156889735515     192.0.2.14       R 4         28672 /export/share/bin/nawk
156889736298     192.0.2.14       R 32        32768 /export/share/bin/nawk
156889736544     192.0.2.14       R 96        32768 /export/share/bin/nawk
156889736902     192.0.2.14       R 64        32768 /export/share/bin/nawk
156916061653     192.0.2.14       R 0          4096 /export/share/bin/ssh
156916069375     192.0.2.14       R 4         28672 /export/share/bin/ssh
156916070098     192.0.2.14       R 32        32768 /export/share/bin/ssh
156916070435     192.0.2.14       R 96        32768 /export/share/bin/ssh
156916070758     192.0.2.14       R 64        32768 /export/share/bin/ssh
156916071036     192.0.2.14       R 128       32768 /export/share/bin/ssh
156916071352     192.0.2.14       R 160       32768 /export/share/bin/ssh
156916071582     192.0.2.14       R 192       32768 /export/share/bin/ssh
156916071696     192.0.2.14       R 72         4096 /export/share/bin/ssh
156916080508     192.0.2.14       R 224        4096 /export/share/bin/ssh
156916080844     192.0.2.14       R 228       28672 /export/share/bin/ssh
156916081566     192.0.2.14       R 256       32768 /export/share/bin/ssh
156916081833     192.0.2.14       R 288       32768 /export/share/bin/ssh
156916082237     192.0.2.14       R 320       20480 /export/share/bin/ssh
156933373074     192.0.2.14       W 0         32768 /export/share/words
156933373351     192.0.2.14       W 32        32768 /export/share/words
156933373855     192.0.2.14       W 64        32768 /export/share/words
156933374185     192.0.2.14       W 96        32768 /export/share/words
156933375442     192.0.2.14       W 128       32768 /export/share/words
156933375864     192.0.2.14       W 160       32768 /export/share/words
156933376105     192.0.2.14       W 192       10055 /export/share/words

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

Bytes of I/O

PATHNAME

Path name of file, if known