Improved NFS v4 Server logging of client access

SUSE Linux Enterprise Server 15 SP2 and higher
SUSE Linux Enterprise Server 12 SP5

When using NFS v3, it is common for a Linux NFS Server to log messages when a client mounts an NFS share.  For example, the following might appear in /var/log/messages of the NFS server:

2020-11-19T12:57:40.498582-05:00 server1 rpc.mountd[1467]: authenticated mount request from 10.1.2.3:734 for /nfsshare (/nfsshare)

However, no messages of this kind are logged when NFS v4.x is in use.

This has frustrated some administrators who want to see such messages.  However, the lack of these messages in NFS v4 is expected, because there is no "mount protocol" within NFS v4, but there was in v3 and prior.  When a NFS v4 client machine executes a mount operation at its end, there is no specific mount event that can be seen or logged by the NFS Server.  Instead, there are operations that establish the identify of the NFS client and then request access to exported file systems on the server.  Furthermore, these new types of requests happen repeatedly, so long as the NFS client keeps making file system requests of the NFS server.  They are not unique to the client's execution of a mount command.  Therefore, the NFS Server only knows when access occurs (which can be rather constant); not when a specific mount operation occurs.

Linux does have some optional debug messaging for access events in NFS V4.  Initially, these were not very satisfying or consistent.  SUSE has improved the messages and the conditions which trigger them.  This will allow administrators of an NFS Server to track what client systems are using the NFS shares.  However, the logged information looks quite different than the logged messages for NFS v3 events.  See the "Additional Information" section below for an example.  The frequency of log messages will increase as well.  Some administrators may not desire the additional and repetitive logging, so it is not enabled by default.

These enhancements are available in:

SLES 15 SP2
Update the "nfs-kernel-server" package to 2.1.1-10.15 or higher.  Note that another package, "nfs-client", is also built from the same source package as "nfs-kernel-server."  Therefore, on any given machine, both packages typically should be updated at the same time.

SLES 12 SP5
Update the "nfs-kernel-server" package to 1.3.0-34.28 or higher.  Note that another package, "nfs-client", is also built from the same source package as "nfs-kernel-server."  Therefore, on any given machine, both packages typically should be updated at the same time.

With the 2 new packages installed, rpc.mountd will have new logging options available.  More details can be found in the rpc.mountd man page, but here are usage tips and expectations:

The new options can be put into effect by editing /etc/sysconfig/nfs and setting (for example):

MOUNTD_OPTIONS="-l -i -T 3600"

Then put that into effect by restart nfsserver with:   systemctl restart nfsserver

-l (or --log-auth) causes extra logging to be activated for authentication and access events.

-i (or --cache-use-ipaddr) causes individual client information to be logged separately.  Without this, multiple clients could be evaluated within one category of trusted clients (*, netgroups, subnets, etc.) and therefore separate clients might not always trigger separately logged messages.

-T (or --ttl) sets a cache length for the authentication and access information.  At half the cache length (which defaults to 1800 seconds, so half of that is 900 seconds or 15 minutes) information about a client's access to a NFS share may be logged again, if access is still happening.  Logging this information every 15 minutes may be more frequent than desired, so increasing the cache timer will decrease the frequency of the logged messages.  However, with a longer cache timer, the NFS Server will also take longer to detect changes in hostname to IP address mappings.  This could effect how long it takes to start granting or denying access to a changed client.

Example of the messages which are logged:

With the options above in use, when an NFS client at IP address 192.168.1.245 first executes a NFS v4 mount of server1:/export,the following type of messages are logged at server1:

2021-04-11T12:07:39.368937-07:00 server1 rpc.mountd[2337]: granted access to / for 192.168.1.245
2021-04-11T12:07:39.372449-07:00 server1 rpc.mountd[2337]: granted access to /export for 192.168.1.245

Note that the line about access to "/" refers to NFS4's pseudo-root concept, which is the parent of all v4 exports on the nfs server.  It doesn't refer to access to the system's real root directory.

The same client doing another mount later may or may not trigger the same log messages, depending on how soon the client performs the new operation and what is still cached about the previous access.  And even if the client does not perform any additional umount / mount operations, continued access of a previously mounted file system will cause new messages to be logged half way through the cache time.