How to configure debug kernel logging for a Linux NFS client

Document created by wade on Feb 27, 2016
Version 1Show Document
  • View in full screen mode

Author: Nabeel Moidu, last modified by Jonathan Bubier on December 3, 2014

 

Original Publication Date: December 2, 2014

 

NFS Client Debugging

This article describes how to enable client side debugging for RPC tracing in NFS. For example, if you mount a MapR NFS export, and hit an issue with file permissions enabling client side debugging can help a lot.

 

The procedure to enable debug logging for the NFS client is simple . You need to set the kernel parameter sunrpc.nfs_debug to a value ranging from 0 to 1023. This can also be set to the values 2^x - 1 Eg. 31,63,127,255,511 etc. This value is a bit mask that indicates which types of events you'd like to see traced. For information on the flag values, look in include/linux/nfs_fs.h, include/linux/lockd/debug.h, include/linux/sunrpc/debug.h, or include/linux/nfsd/debug.h in the kernel source code.

If you are root on a node run the following command:

$ sysctl -w sunrpc.nfs_debug=1023

If you require sudo run the following command:

$ sudo sysctl -w sunrpc.nfs_debug=1023

To verify the setting run the following command:

$ sysctl -a  | grep sunrpc.nfs_debug

To turn off debugging run the following command:

$ sysctl -w sunrpc.nfs_debug=0

If you require sudo run the following command:

$ sudo sysctl -w sunrpc.nfs_debug=0

With NFS debugging enabled the debug messages are printed on the console and in /var/log/messages as the client processes any request over NFS.

 

Sample output:

$ ls dir1

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: permission(0:16/921994000), mask=0x1, res=0

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: nfs_lookup_revalidate(dumps/dir1) is valid

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: dentry_delete(dumps/dir1, 8)

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: permission(0:16/921994000), mask=0x1, res=0

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: revalidating (0:16/922126323)

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS call getattr

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS reply getattr: 0

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: nfs_update_inode(0:16/922126323 ct=1 info=0x7e7f)

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: (0:16/922126323) revalidation complete

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: nfs_lookup_revalidate(dumps/dir1) is valid

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS call access

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: nfs_update_inode(0:16/922126323 ct=1 info=0x7e7f)

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS reply access: 0

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: permission(0:16/922126323), mask=0x24, res=0

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: open dir(dumps/dir1)

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: readdir(dumps/dir1) starting at cookie 0

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS call readdirplus 0

10-Aug-14

$ Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: nfs_update_inode(0:16/922126323 ct=1 info=0x7e7f)

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS reply readdirplus: 448

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: nfs_fhget(0:16/922126324 ct=1)

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: dentry_delete(dir1/10-Aug-14, 0)

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: nfs_do_filldir() filling ended @ cookie 18446744073709551615; returning = 0

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: readdir(dumps/dir1) returns 0

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: permission(0:16/921994000), mask=0x1, res=0

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: nfs_lookup_revalidate(dumps/dir1) is valid

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: permission(0:16/922126323), mask=0x1, res=0

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: nfs_lookup_revalidate(dir1/10-Aug-14) is valid

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: dentry_delete(dir1/10-Aug-14, 8)

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: readdir(dumps/dir1) starting at cookie 3

Dec 2 05:00:37 nmk-centos-60-1 kernel: NFS: readdir(dumps/dir1) returns 0

Uses:

1) Analyze performance issues between the NFS client and NFS server. Use the debug settings to identify exact system calls that take time and debug them individually.
2) Permission issues

 

Note:

This can cause heavy logging on the nodes with significant NFS activity, so please use it with caution. You can easily fill up your system partitions and cause instability on your node. Use the commands as described above to disable the NFS client debug logging when it is no longer required to avoid filling the system logs.

Attachments

    Outcomes