Hello All,
A customer reported that same client (part of netgroup) gets access allowed for 1 request and access denied for another request. I found that due to race conditions, only one thread will get success for adding particular client/hosts to the netgroup cache and others will get error.
Here is the log snippet ...
================
    10  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] worker_run :DISP :DEBUG :NFS protocol request, reqdata=0x7f0a940537c0 xprt=0x7f0c54116450 requests=1
    12  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] worker_run :DISP :DEBUG :NFS protocol request, reqdata=0x7f0a94356d90 xprt=0x7f0c54116450 requests=2
    13  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] export_check_access :EXPORT :M_DBG :EXPORT_DEFAULTS (options=42102002root_squash   , ----, 3--, ---, TCP, ----, Manage_Gids   ,         , anon_uid=    -2, anon_gid=    -2, sys)
    14  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] export_check_access :EXPORT :M_DBG :EXPORT_DEFAULTS (options=42102002root_squash   , ----, 3--, ---, TCP, ----, Manage_Gids   ,         , anon_uid=    -2, anon_gid=    -2, sys)
    15  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] export_check_access :EXPORT :M_DBG :default options (options=03303002root_squash   , ----, 34-, UDP, TCP, ----, No Manage_Gids, -- Deleg, anon_uid=    -2, anon_gid=    -2, none, sys)
    16  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] export_check_access :EXPORT :M_DBG :default options (options=03303002root_squash   , ----, 34-, UDP, TCP, ----, No Manage_Gids, -- Deleg, anon_uid=    -2, anon_gid=    -2, none, sys)
    17  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] export_check_access :EXPORT :M_DBG :Final options   (options=42102002root_squash   , ----, 3--, ---, TCP, ----, Manage_Gids   , -- Deleg, anon_uid=    -2, anon_gid=    -2, sys)
    18  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] export_check_access :EXPORT :M_DBG :Final options   (options=42102002root_squash   , ----, 3--, ---, TCP, ----, Manage_Gids   , -- Deleg, anon_uid=    -2, anon_gid=    -2, sys)
    19  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] nfs_rpc_execute :DISP :DEBUG :Request from ::ffff:53.55.134.154 for Program 100003, Version 3, Function 1 has xid=2073167330
    20  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] nfs_rpc_execute :DISP :DEBUG :Request from ::ffff:53.55.134.154 for Program 100003, Version 3, Function 1 has xid=2056390114
    21  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] get_gsh_export :HT CACHE :DEBUG :export_mgr cache hit slot 1
    22  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] get_gsh_export :HT CACHE :DEBUG :export_mgr cache hit slot 1
    23  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] nfs_rpc_execute :EXPORT :M_DBG :EXPORT: MID DEBUG: Found export entry for path=/net/gpfsm/fs1 as exportid=1
    24  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] nfs_rpc_execute :EXPORT :M_DBG :EXPORT: MID DEBUG: nfs_rpc_execute about to call nfs_export_check_access for client ::ffff:53.55.134.154
    25  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] nfs_rpc_execute :EXPORT :M_DBG :EXPORT: MID DEBUG: Found export entry for path=/net/gpfsm/fs1 as exportid=1
    26  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] convert_ipv6_to_ipv4 :EXPORT :M_DBG :Converting IPv6 encapsulated IPv4 address ::ffff:53.55.134.154 to IPv4 53.55.134.154
    27  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] nfs_rpc_execute :EXPORT :M_DBG :EXPORT: MID DEBUG: nfs_rpc_execute about to call nfs_export_check_access for client ::ffff:53.55.134.154
    28  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] export_check_access :EXPORT :M_DBG :Check for address 53.55.134.154 for export id 1 path /net/gpfsm/fs1
    29  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] client_match :EXPORT :M_DBG :Match V4: 0x1486fe0 NETGROUP_CLIENT: sea (options=421021e2root_squash   , RWrw, 3--, ---, TCP, ----, Manage_Gids   , -- Deleg, anon_uid=    -2, anon_gid=    -2, sys)
    30  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] convert_ipv6_to_ipv4 :EXPORT :M_DBG :Converting IPv6 encapsulated IPv4 address ::ffff:53.55.134.154 to IPv4 53.55.134.154
    31  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] export_check_access :EXPORT :M_DBG :Check for address 53.55.134.154 for export id 1 path /net/gpfsm/fs1
    32  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] client_match :EXPORT :M_DBG :Match V4: 0x1486fe0 NETGROUP_CLIENT: sea (options=421021e2root_squash   , RWrw, 3--, ---, TCP, ----, Manage_Gids   , -- Deleg, anon_uid=    -2, anon_gid=    -2, sys)
    33  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] nfs_ip_name_add :DISP :DEBUG :Inserting 53.55.134.154->SMTCAC2064.rd.corpintra.net to addr cache
    34  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] nfs_ip_name_add :DISP :DEBUG :Inserting 53.55.134.154->SMTCAC2064.rd.corpintra.net to addr cache
    35  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] client_match :EXPORT :M_DBG :Match V4: 0x148d320 NETGROUP_CLIENT: ep-gf01 (options=421021e2root_squash   , RWrw, 3--, ---, TCP, ----, Manage_Gids   , -- Deleg, anon_uid=    -2, anon_gid=    -2, sys)
    36  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] export_check_access :EXPORT :M_DBG :CLIENT          (options=421021e2root_squash   , RWrw, 3--, ---, TCP, ----, Manage_Gids   , -- Deleg, anon_uid=    -2, anon_gid=    -2, sys)
    37  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] export_check_access :EXPORT :M_DBG :EXPORT          (options=03303002              ,     ,    ,               ,               , -- Deleg,                ,                )
    38  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] export_check_access :EXPORT :M_DBG :EXPORT_DEFAULTS (options=42102002root_squash   , ----, 3--, ---, TCP, ----, Manage_Gids   ,         , anon_uid=    -2, anon_gid=    -2, sys)
    39  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] export_check_access :EXPORT :M_DBG :default options (options=03303002root_squash   , ----, 34-, UDP, TCP, ----, No Manage_Gids, -- Deleg, anon_uid=    -2, anon_gid=    -2, none, sys)
    40  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] export_check_access :EXPORT :M_DBG :Final options   (options=421021e2root_squash   , RWrw, 3--, ---, TCP, ----, Manage_Gids   , -- Deleg, anon_uid=    -2, anon_gid=    -2, sys)
    41  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] nfs_req_creds :EXPORT :M_DBG :EXPORT: MID DEBUG: AUTH_SYS creds mapped to uid=26112, gid=50161, glen=14 (managed)
    42  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] nfs3_getattr :NFS3 :DEBUG :REQUEST PROCESSING: Calling nfs3_getattr handle: File Handle V3: Len=56 430000013030000a00020028000a0001055aa937f902000002000000000300f008000000000000000001000100fefe040000000000000000
    43  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] cih_get_by_key_latch :HT CACHE :DEBUG :cih cache hit slot 16168
    44  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] fsal_get_xstat_by_handle :FSAL :DEBUG :gpfs_ganesha: GET_XSTAT returned, fd 6 rc 0 fh_size 48
    45  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-80] gpfsfsal_xstat_2_fsal_attributes :FSAL :DEBUG :inode 149946371
...
...
    70  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] export_check_access :EXPORT :M_DBG :EXPORT          (options=03303002              ,     ,    ,               ,               , -- Deleg,                ,                )
    71  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] export_check_access :EXPORT :M_DBG :EXPORT_DEFAULTS (options=42102002root_squash   , ----, 3--, ---, TCP, ----, Manage_Gids   ,         , anon_uid=    -2, anon_gid=    -2, sys)
    72  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] export_check_access :EXPORT :M_DBG :default options (options=03303002root_squash   , ----, 34-, UDP, TCP, ----, No Manage_Gids, -- Deleg, anon_uid=    -2, anon_gid=    -2, none, sys)
    73  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] export_check_access :EXPORT :M_DBG :Final options   (options=42102002root_squash   , ----, 3--, ---, TCP, ----, Manage_Gids   , -- Deleg, anon_uid=    -2, anon_gid=    -2, sys)
    74  2018-12-19 16:09:54 : epoch 00080092 : smtcfc0203 : gpfs.ganesha.nfsd-408410[work-62] nfs_rpc_execute :DISP :INFO :DISP: INFO: Client ::ffff:53.55.134.154 is not allowed to access Export_Id 1 /net/gpfsm/fs1, vers=3, proc=1

================
I have uploaded patch to fix this kind of access errors:
https://review.gerrithub.io/c/ffilz/nfs-ganesha/+/438804
--
with regards,
Sachin Punadikar