8:18 a.m.
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