Bug 1389248

Summary: [RGW:NFS]:- NFS mount fails for unknown parameter in config file
Product: Red Hat Ceph Storage Reporter: Ramakrishnan Periyasamy <rperiyas>
Component: RGWAssignee: Matt Benjamin (redhat) <mbenjamin>
Status: CLOSED NOTABUG QA Contact: ceph-qe-bugs <ceph-qe-bugs>
Severity: urgent Docs Contact:
Priority: urgent    
Version: 2.1CC: cbodley, ceph-eng-bugs, ceph-qe-bugs, hnallurv, kbader, kdreyer, kurs, mbenjamin, owasserm, rperiyas, sweil
Target Milestone: rc   
Target Release: 2.1   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-11-04 05:18:29 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Ramakrishnan Periyasamy 2016-10-27 09:35:01 UTC
Description of problem:
Unable to Mount NFS with RGW, After adding EXPORT and RGW information in nfs config file, nfs service restart command passes but log reports unknown parameters in conf file.
==============================
Oct 27 08:55:52 magna105 nfs-ganesha[18836]: [main] main :MAIN :EVENT :ganesha.nfsd Starting: Ganesha Version /builddir/build/BUILD/nfs-ganesha-2.4.0/src, built at Oct 21 2016 12:28:26 on
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] nfs_set_param_from_conf :NFS STARTUP :EVENT :Configuration file successfully parsed
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] init_server_pkgs :NFS STARTUP :EVENT :Initializing ID Mapper.
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] init_server_pkgs :NFS STARTUP :EVENT :ID Mapper successfully initialized.
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] create_export :FSAL :CRIT :RGW module: librgw init failed (-5)
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] fsal_cfg_commit :CONFIG :CRIT :Could not create export for (/) to (/)
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] main :NFS STARTUP :WARN :No export entries found in configuration file !!!
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] config_errs_to_log :CONFIG :CRIT :Config File (/etc/ganesha/ganesha.conf:69): 1 validation errors in block FSAL
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] config_errs_to_log :CONFIG :CRIT :Config File (/etc/ganesha/ganesha.conf:69): Errors processing block (FSAL)
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] config_errs_to_log :CONFIG :CRIT :Config File (/etc/ganesha/ganesha.conf:66): Unknown parameter (NFS_Protocols)
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] config_errs_to_log :CONFIG :CRIT :Config File (/etc/ganesha/ganesha.conf:67): Unknown parameter (Transport_Protocols)
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] config_errs_to_log :CONFIG :CRIT :Config File (/etc/ganesha/ganesha.conf:60): 2 errors while processing parameters for EXPORT
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] config_errs_to_log :CONFIG :CRIT :Config File (/etc/ganesha/ganesha.conf:60): Errors processing block (EXPORT)
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] lower_my_caps :NFS STARTUP :EVENT :CAP_SYS_RESOURCE was successfully removed for proper quota management in FSAL
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] lower_my_caps :NFS STARTUP :EVENT :currenty set capabilities are: = cap_chown,cap_dac_override,cap_dac_read_search,cap_fowner,cap_fsetid,cap_kill,cap_setgid,cap_setuid,cap_setpcap,cap_linux_immutable,cap_net_bind_service,cap_net_broadcast,cap_net_admin,cap_net_raw,cap_ipc_lock,cap_ipc_owner,cap_sys_module,cap_sys_rawio,cap_sys_chroot,cap_sys_ptrace,cap_sys_pacct,cap_sys_admin,cap_sys_boot,cap_sys_nice,cap_sys_time,cap_sys_tty_config,cap_mknod,cap_lease,cap_audit_write,cap_audit_control,cap_setfcap+ep
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] nfs_Init_svc :DISP :CRIT :Cannot acquire credentials for principal nfs
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] nfs_Init_admin_thread :NFS CB :EVENT :Admin thread initialized
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] nfs4_start_grace :STATE :EVENT :NFS Server Now IN GRACE, duration 90
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] nfs_rpc_cb_init_ccache :NFS STARTUP :EVENT :Callback creds directory (/var/run/ganesha) already exists
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] nfs_rpc_cb_init_ccache :NFS STARTUP :WARN :gssd_refresh_krb5_machine_credential failed (-1765328160:0)
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] nfs_Start_threads :THREAD :EVENT :Starting delayed executor.
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] nfs_Start_threads :THREAD :EVENT :gsh_dbusthread was started successfully
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] nfs_Start_threads :THREAD :EVENT :admin thread was started successfully
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] nfs_Start_threads :THREAD :EVENT :reaper thread was started successfully
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] nfs_Start_threads :THREAD :EVENT :General fridge was started successfully
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [reaper] nfs_in_grace :STATE :EVENT :NFS Server Now IN GRACE
Oct 27 08:55:52 magna105 rpc.statd[13249]: Received SM_UNMON_ALL request from magna105 while not monitoring any hosts
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] nfs_start :NFS STARTUP :EVENT :-------------------------------------------------
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] nfs_start :NFS STARTUP :EVENT :             NFS SERVER INITIALIZED
Oct 27 08:55:52 magna105 nfs-ganesha[18837]: [main] nfs_start :NFS STARTUP :EVENT :-------------------------------------------------
^[:QOct 27 08:57:22 magna105 nfs-ganesha[18837]: [reaper] nfs_in_grace :STATE :EVENT :NFS Server Now NOT IN GRACE
Oct 27 08:57:57 magna105 systemd-logind: New session 378 of user ubuntu.
Oct 27 08:57:57 magna105 systemd: Started Session 378 of user ubuntu.
==============================

Removed the unknown parameters in conf file and restarted the nfs service, got below errors in nfs logs.
=============================
agna105 nfs-ganesha[26958]: [main] nfs_set_param_from_conf :NFS STARTUP :EVENT :Configuration file successfully parsed
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] init_server_pkgs :NFS STARTUP :EVENT :Initializing ID Mapper.
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] init_server_pkgs :NFS STARTUP :EVENT :ID Mapper successfully initialized.
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] create_export :FSAL :CRIT :RGW module: librgw init failed (-5)
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] fsal_cfg_commit :CONFIG :CRIT :Could not create export for (/) to (/)
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] export_commit_common :EXPORT :CRIT :Clients = (0x7f24e8125ef8,0x7f24e8125ef8) next = (0x7f24e8125ef8, 0x7f24e8125ef8)
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] main :NFS STARTUP :WARN :No export entries found in configuration file !!!
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] config_errs_to_log :CONFIG :CRIT :Config File (/etc/ganesha/ganesha.conf:69): 1 validation errors in block FSAL
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] config_errs_to_log :CONFIG :CRIT :Config File (/etc/ganesha/ganesha.conf:69): Errors processing block (FSAL)
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] config_errs_to_log :CONFIG :CRIT :Config File (/etc/ganesha/ganesha.conf:60): 1 validation errors in block EXPORT
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] config_errs_to_log :CONFIG :CRIT :Config File (/etc/ganesha/ganesha.conf:60): Errors processing block (EXPORT)
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] lower_my_caps :NFS STARTUP :EVENT :CAP_SYS_RESOURCE was successfully removed for proper quota management in FSAL
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] lower_my_caps :NFS STARTUP :EVENT :currenty set capabilities are: = cap_chown,cap_dac_override,cap_dac_read_search,cap_fowner,cap_fsetid,cap_kill,cap_setgid,cap_setuid,cap_setpcap,cap_linux_immutable,cap_net_bind_service,cap_net_broadcast,cap_net_admin,cap_net_raw,cap_ipc_lock,cap_ipc_owner,cap_sys_module,cap_sys_rawio,cap_sys_chroot,cap_sys_ptrace,cap_sys_pacct,cap_sys_admin,cap_sys_boot,cap_sys_nice,cap_sys_time,cap_sys_tty_config,cap_mknod,cap_lease,cap_audit_write,cap_audit_control,cap_setfcap+ep
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] nfs_Init_svc :DISP :CRIT :Cannot acquire credentials for principal nfs
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] nfs_Init_admin_thread :NFS CB :EVENT :Admin thread initialized
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] nfs4_start_grace :STATE :EVENT :NFS Server Now IN GRACE, duration 90
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] nfs_rpc_cb_init_ccache :NFS STARTUP :EVENT :Callback creds directory (/var/run/ganesha) already exists
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] nfs_rpc_cb_init_ccache :NFS STARTUP :WARN :gssd_refresh_krb5_machine_credential failed (-1765328160:0)
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] nfs_Start_threads :THREAD :EVENT :Starting delayed executor.
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] nfs_Start_threads :THREAD :EVENT :gsh_dbusthread was started successfully
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] nfs_Start_threads :THREAD :EVENT :admin thread was started successfully
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] nfs_Start_threads :THREAD :EVENT :reaper thread was started successfully
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] nfs_Start_threads :THREAD :EVENT :General fridge was started successfully
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [reaper] nfs_in_grace :STATE :EVENT :NFS Server Now IN GRACE
Oct 27 09:00:58 magna105 rpc.statd[13249]: Received SM_UNMON_ALL request from magna105 while not monitoring any hosts
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] nfs_start :NFS STARTUP :EVENT :-------------------------------------------------
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] nfs_start :NFS STARTUP :EVENT :             NFS SERVER INITIALIZED
Oct 27 09:00:58 magna105 nfs-ganesha[26958]: [main] nfs_start :NFS STARTUP :EVENT :-------------------------------------------------
Oct 27 09:01:01 magna105 systemd: Created slice user-0.slice.
=============================

Version-Release number of selected component (if applicable):
ceph version: 10.2.3-10.el7cp
NFS version: 
[ubuntu@magna105 ~]$ rpm -qa | grep nfs
nfs-ganesha-2.4.0-3.el7cp.x86_64
nfs-utils-1.3.0-0.33.el7.x86_64
nfs-ganesha-rgw-2.4.0-3.el7cp.x86_64
libnfsidmap-0.25-15.el7.x86_64

How reproducible:
6/6

Steps to Reproduce:
1. Configure ceph cluster and rgw
2. Install NFS ganesha packages and follow document
https://access-qa-redhat-com.vserver.qa.ext.phx1.redhat.com/documentation/en/red-hat-ceph-storage/2/single/object-gateway-guide-for-red-hat-enterprise-linux#exporting_the_namespace_to_nfs_ganesha_tech_preview
3. Update NFS config with s3 user, secret and access key.
4. Start NFS service.

Actual results:
NFS mount is failing

Expected results:
Service should start properly and NFS mount should succeed

Additional info:
N/A

Comment 7 Matt Benjamin (redhat) 2016-11-02 14:26:00 UTC
(In reply to Ramakrishnan Periyasamy from comment #0)
Running ganesha.nfsd in the foreground (-F), I see:

[root@magna105 ganesha]# /usr/bin/ganesha.nfsd -f /etc/ganesha/ganesha.conf -F
2016-11-02 14:12:19.516992 7ffb60f880c0 -1 auth: unable to find a keyring on /var/lib/ceph/radosgw/ceph-rgw.magna104/keyring: (2) No such file or directory
2016-11-02 14:12:19.519479 7ffb60f880c0 -1 monclient(hunting): authenticate NOTE: no keyring found; disabled cephx authentication
2016-11-02 14:12:19.520188 7ffb60f880c0 -1 Couldn't init storage provider (RADOS)

I think this is likely the root cause of the inability to use the cluster, because although the ganesha.conf is messy (has a lot of commented-out sections from a prior glusterfs setup), it looks clear that the RGW FSAL has initialized.

I switched to using a config file based on my own template (ganesha.conf.matt), which among other things has:

1. settings to bypass the idmapper (new in 2.4.0):

    Allow_Numeric_Owners = true;
    Only_Numeric_Owners = true;

2. moves logging to /tmp/ganesha-rgw.log (not for production)

Reviewing the log, I now see:

1. the RGW fsal is found and nfs-ganesha tries to intialize it
2. the RGW module init function fails (due to the aforementioned lack of a keyring, or at any rate, failure to init RADOS, which almost certainly is due to misconfiguration of ceph.conf or related files on the host
3. the subsequent report of now export entries found is actually a side-effect of problem #2--i.e., it is telling us that we failed to initialize the FSAL driver for the single configured export entry

02/11/2016 14:18:00 : epoch 5819f597 : magna105 : ganesha.nfsd-29798[main] load\
_fsal :NFS STARTUP :DEBUG :Loading FSAL RGW with /usr/lib64/ganesha/libfsalrgw.\
so
02/11/2016 14:18:00 : epoch 5819f597 : magna105 : ganesha.nfsd-29798[main] init\
 :FSAL :DEBUG :RGW module registering.
02/11/2016 14:18:00 : epoch 5819f597 : magna105 : ganesha.nfsd-29798[main] init\
_config :FSAL :DEBUG :RGW module setup.
02/11/2016 14:18:00 : epoch 5819f597 : magna105 : ganesha.nfsd-29798[main] crea\
te_export :FSAL :CRIT :RGW module: librgw init failed (-5)
02/11/2016 14:18:00 : epoch 5819f597 : magna105 : ganesha.nfsd-29798[main] fsal\
_put :FSAL :INFO :FSAL RGW now unused
02/11/2016 14:18:00 : epoch 5819f597 : magna105 : ganesha.nfsd-29798[main] pseu\
dofs_create_export :FSAL :DEBUG :Created exp 0x7f7eeb7056d0 - /
02/11/2016 14:18:00 : epoch 5819f597 : magna105 : ganesha.nfsd-29798[main] main\
 :NFS STARTUP :WARN :No export entries found in configuration file !!!
02/11/2016 14:18:00 : epoch 5819f597 : magna105 : ganesha.nfsd-29798[main] conf\
ig_errs_to_log :CONFIG :CRIT :Config Fi

In fine:
I'll try to fix the Ceph setup.  But as background, the nfs-ganesha running the RGW fsal contains an embedded instance of Ceph's radosgw--and for that reason, it needs all of the supporting configuration (ceph.conf, keyrings, etc) that are needed on an radosgw node.  (One easy way to test, therefore, is to set up nfs-ganesha with FSAL RGW on an existing, and already tested radosgw instance in the cluster, rather than on a separate node.)

Comment 12 Ramakrishnan Periyasamy 2016-11-04 05:18:29 UTC
I can configure the NFS with rgw without any issues, Because of config and setup related issues above problem observed in setup.

Moving this to NOTABUG and CLOSED state.