Systemtap script to trace various NFS calls

nfs.stp

#! /usr/bin/env stap

global log_nfs_file_open = 1;
global log_nfs_file_read = 1;
global log_nfs_file_write = 1;
global log_nfs_getattr = 1;
global log_nfs_permission = 1;
global log_nfs_opendir = 1;
global log_nfs_lookup = 1;

# set to 1 for logging read/write activities at all positions
global log_all_nfs_read_write_positions = 1;

# workaround to avoid logging activities for the systemtap output filename (without directory!)
global omit_this_filename = ""


function timestamp:long()
{
    return gettimeofday_ms();
}


function datetime:string()
{
    return ctime(gettimeofday_s());
}


probe begin
{
    println("epochmillis;datetime;type;pexecname;execname;ppid;pid;uid;file;inode;root_path;relative_path;i_size;r/w_position");
}

probe module("nfs").function("nfs_file_open")
{
    if(log_nfs_file_open != 1) { next }

    type = "nfs_file_open";

    #dev = __file_dev($filp)
    inode = $inode->i_ino
    #s_id = $inode->i_sb->s_id
    #devname = kernel_string(s_id)

    filename = __file_filename($filp)

    if(omit_this_filename != "" && omit_this_filename == filename) { next }

    #flag = $filp->f_flags

    i_size = $inode->i_size

    relative_path = "";
    root_path = "";
    rw_pos = -1;

    printf("%d;%s;%s;%s;%s;%d;%d;%d;%s;%d;%s;%s;%d;%d\n",
        timestamp(), datetime(), type, pexecname(), execname(), ppid(), pid(), uid(), filename, inode, root_path, relative_path, i_size, rw_pos)
}

probe module("nfs").function("nfs_file_read")
{
    if(log_nfs_file_read != 1) { next }

    type = "nfs_file_read";

    rw_pos = $pos

    if(log_all_nfs_read_write_positions != 1 && rw_pos > 0) { next }

    #dev = __file_dev($filp)
    inode = __file_ino($iocb->ki_filp)
    #s_id = $inode->i_sb->s_id
    #devname = kernel_string(s_id)

    filename = __file_filename($iocb->ki_filp)

    if(omit_this_filename != "" && omit_this_filename == filename) { next }

    #flag = $filp->f_flags

    i_size = -1

    relative_path = "";
    root_path = "";

    printf("%d;%s;%s;%s;%s;%d;%d;%d;%s;%d;%s;%s;%d;%d\n",
        timestamp(), datetime(), type, pexecname(), execname(), ppid(), pid(), uid(), filename, inode, root_path, relative_path, i_size, rw_pos)
}

probe module("nfs").function("nfs_file_write")
{
    if(log_nfs_file_write != 1) { next }

    type = "nfs_file_write";

    rw_pos = $pos

    if(log_all_nfs_read_write_positions != 1 && rw_pos > 0) { next }

    #dev = __file_dev($filp)
    inode = __file_ino($iocb->ki_filp)
    #s_id = $inode->i_sb->s_id
    #devname = kernel_string(s_id)

    filename = __file_filename($iocb->ki_filp)

    if(omit_this_filename != "" && omit_this_filename == filename) { next }

    #flag = $filp->f_flags

    i_size = -1

    relative_path = "";
    root_path = "";

    printf("%d;%s;%s;%s;%s;%d;%d;%d;%s;%d;%s;%s;%d;%d\n",
        timestamp(), datetime(), type, pexecname(), execname(), ppid(), pid(), uid(), filename, inode, root_path, relative_path, i_size, rw_pos)
}

probe module("nfs").function("nfs_getattr")
{
    if(log_nfs_getattr != 1) { next }

    type = "nfs_getattr";

    if (@defined($mnt->mnt_mountpoint)) {
        #relative_path = reverse_path_walk($mnt->mnt_mountpoint);
        relative_path = task_dentry_path(task_current(), $dentry, $mnt);
        root_path = sprintf("%s", reverse_path_walk($mnt->mnt_parent->mnt_mountpoint));
    }else {
        relative_path = "";
        root_path = "";
    }

    filename = d_name($dentry)
    if(omit_this_filename != "" && omit_this_filename == filename) { next }

    #flag = -1
    #dev = -1
    #devname = ""
    i_size = -1
    rw_pos = -1;

    printf("%d;%s;%s;%s;%s;%d;%d;%d;%s;%d;%s;%s;%d;%d\n",
        timestamp(), datetime(), type, pexecname(), execname(), ppid(), pid(), uid(), filename, $dentry->d_inode->i_ino, root_path, relative_path, i_size, rw_pos);
}

probe module("nfs").function("nfs_permission")
{
    if(log_nfs_permission != 1) { next }

    type = "nfs_permission"

    inode = $inode->i_ino

    filename = ""
    root_path = ""
    relative_path = ""
    i_size = -1
    rw_pos = 1

    printf("%d;%s;%s;%s;%s;%d;%d;%d;%s;%d;%s;%s;%d;%d\n",
        timestamp(), datetime(), type, pexecname(), execname(), ppid(), pid(), uid(), filename, inode, root_path, relative_path, i_size, rw_pos);
}

probe module("nfs").function("nfs_opendir")
{
    if(log_nfs_opendir != 1) { next }

    type = "nfs_opendir"

    inode = $inode->i_ino

    filename = ""
    root_path = ""
    relative_path = ""
    i_size = -1
    rw_pos = 1

    printf("%d;%s;%s;%s;%s;%d;%d;%d;%s;%d;%s;%s;%d;%d\n",
        timestamp(), datetime(), type, pexecname(), execname(), ppid(), pid(), uid(), filename, inode, root_path, relative_path, i_size, rw_pos);
}

probe module("nfs").function("nfs_lookup")
{
    if(log_nfs_lookup != 1) { next }

    type = "nfs_lookup"

    inode = $dir->i_ino

    filename = ""
    root_path = ""
    relative_path = ""
    i_size = -1
    rw_pos = 1

    printf("%d;%s;%s;%s;%s;%d;%d;%d;%s;%d;%s;%s;%d;%d\n",
        timestamp(), datetime(), type, pexecname(), execname(), ppid(), pid(), uid(), filename, inode, root_path, relative_path, i_size, rw_pos);
}

To format the first column (epochmillis) in Excel, use this (replace A1 by your field):

=A1/1000/ 86400 + 25569

Then format the cell as custom type:

TT.MM.JJJJ hh:mm:ss,000"