kern/59452: Move NFS wcc data messages to debug or control them via sysctl.

[drixter%e-utp.net@localhost]

>Number:         59452
>Category:       kern
>Synopsis:       Move NFS wcc data messages to debug or control them via sysctl.
>Confidential:   no
>Severity:       non-critical
>Priority:       low
>Responsible:    kern-bug-people
>State:          open
>Class:          change-request
>Submitter-Id:   net
>Arrival-Date:   Sun Jun 01 10:55:00 +0000 2025
>Originator:     Marcin Gondek
>Release:        NetBSD current
>Organization:
e-utp.net
>Environment:
NetBSD devil.e-utp.net 10.99.14 NetBSD 10.99.14 (DEVIL) #43: Wed May 21 21:43:55 CEST 2025  root%devil.e-utp.net@localhost:/usr/obj/sys/arch/amd64/compile/DEVIL amd64

>Description:
Hi.

I know that such messages should not generally appear if the NFS server is working properly. But unfortunately it is not repairable everywhere -> Synology NFS, hence the question about the possibility of moving these messages to the DEBUG variant or maybe make it controlable via sysctl.

[    54.639309] diskstation6.e-utp.net:/volume1/homes/drixter: inaccurate wcc data (ctime) detected, disabling wcc (ctime 1747860168.846777829 1747860168.846777829, mtime 1747860168.846777829 1747860168.846777829)
[  8290.061715] diskstation6.e-utp.net:/volume1/Applications/html: inaccurate wcc data (ctime) detected, disabling wcc (ctime 1747868404.268648787 1747868404.268648787, mtime 1747868404.268648787 1747868404.268648787)
[ 37999.556765] diskstation6.e-utp.net:/volume1/Applications/NetBSD: inaccurate wcc data (ctime) detected, disabling wcc (ctime 1747898113.761877738 1747898113.761877738, mtime 1747898113.761877738 1747898113.761877738)
[ 129985.269256] diskstation6.e-utp.net:/volume1/homes/drixter: inaccurate wcc data (ctime) detected, disabling wcc (ctime 1747990099.474778485 1747990099.474778485, mtime 1747990099.474778485 1747990099.474778485)
[ 271086.518951] diskstation6.e-utp.net:/volume1/Applications/NetBSD: re-enabling wcc
[ 346441.968607] diskstation6.e-utp.net:/volume1/Applications/NetBSD: inaccurate wcc data (ctime) detected, disabling wcc (ctime 1748206556.173615162 1748206556.173615162, mtime 1748206556.173615162 1748206556.172615149)
[ 514378.384585] diskstation6.e-utp.net:/volume1/Applications/NetBSD: re-enabling wcc
[ 514557.066122] diskstation6.e-utp.net:/volume1/Applications/NetBSD: inaccurate wcc data (ctime) detected, disabling wcc (ctime 1748374671.270579777 1748374671.270579777, mtime 1748374671.270579777 1748374671.270579777)
[ 515971.888284] diskstation6.e-utp.net:/volume1/homes/drixter: re-enabling wcc
[ 515971.888284] diskstation6.e-utp.net:/volume1/homes/drixter: inaccurate wcc data (ctime) detected, disabling wcc (ctime 1748376086.092195755 1748376086.092195755, mtime 1748376086.092195755 1748376086.092195755)
[ 660108.808665] diskstation6.e-utp.net:/volume1/homes/drixter: re-enabling wcc
[ 660108.958666] diskstation6.e-utp.net:/volume1/homes/drixter: inaccurate wcc data (ctime) detected, disabling wcc (ctime 1748520223.159904837 1748520223.159904837, mtime 1748520223.159904837 1748520223.159904837)
[ 850685.043667] diskstation6.e-utp.net:/volume1/Applications/NetBSD: re-enabling wcc
[ 850838.054987] diskstation6.e-utp.net:/volume1/Applications/NetBSD: inaccurate wcc data (ctime) detected, disabling wcc (ctime 1748710952.261138867 1748710952.261138867, mtime 1748710952.261138867 1748710952.261138867)
[ 851717.862621] diskstation6.e-utp.net:/volume1/homes/drixter: re-enabling wcc
[ 851717.942624] diskstation6.e-utp.net:/volume1/homes/drixter: inaccurate wcc data (ctime) detected, disabling wcc (ctime 1748711832.146387487 1748711832.146387487, mtime 1748711832.146387487 1748711832.146387487)

>How-To-Repeat:
Make some load on NFS share.
>Fix:
Probably define DEBUG option for printf.

The patch is not tested, just to idea how this can be covered, if possible.

As far now I have no clue how to handle it via sysctl option.

==cut==
*** nfs_clntsubs.c      Sun Jun  1 12:41:04 2025
--- nfs_clntsubs-IFDEF.c        Sun Jun  1 12:43:24 2025
***************
*** 424,429 ****
--- 424,430 ----

                        mutex_enter(&nmp->nm_lock);
                        if (!NFS_WCCKLUDGE(nmp, now)) {
+ #ifdef DEBUG
                                printf("%s: inaccurate wcc data (%s) detected,"
                                    " disabling wcc"
                                    " (ctime %u.%09u %u.%09u,"
***************
*** 438,443 ****
--- 439,445 ----
                                    (unsigned int)omtime->tv_nsec,
                                    (unsigned int)mtime->tv_sec,
                                    (unsigned int)mtime->tv_nsec);
+ #endif
                        }
                        nmp->nm_iflag |= NFSMNT_WCCKLUDGE;
                        nmp->nm_wcckludgetime = now;
***************
*** 447,454 ****
--- 449,458 ----
                } else if (nmp->nm_iflag & NFSMNT_WCCKLUDGE) {
                        mutex_enter(&nmp->nm_lock);
                        if (nmp->nm_iflag & NFSMNT_WCCKLUDGE) {
+ #ifdef DEBUG
                                printf("%s: re-enabling wcc\n",
                                    vp->v_mount->mnt_stat.f_mntfromname);
+ #endif
                                nmp->nm_iflag &= ~NFSMNT_WCCKLUDGE;
                        }
                        mutex_exit(&nmp->nm_lock);
==cut==

Thanks,