Bug 1371934

Summary: Continuous vdsm service failure related messages seen in /var/log/messages.
Product: Red Hat Gluster Storage Reporter: Shashank Raj <sraj>
Component: vdsmAssignee: Sahina Bose <sabose>
Status: CLOSED NOTABUG QA Contact: Sachin <sashinde>
Severity: high Docs Contact:
Priority: unspecified    
Version: rhgs-3.1CC: mzywusko, rhs-bugs, rhsc-qe-bugs, rnachimu, sashinde, sraj, storage-qa-internal
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-09-01 10:10:54 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:
Attachments:
Description Flags
/var/log/messages none

Description Shashank Raj 2016-08-31 13:10:32 UTC
Description of problem:

Continuous vdsm service failure related messages seen in /var/log/messages.

Version-Release number of selected component (if applicable):

3.7.9-10 and 3.7.9-12

How reproducible:

Twice

Steps to Reproduce:
1.Download RHEL 7 based 3.1.3 ISO from customer portal. 
2.Install RHGS using the ISO with nfs-ganesha packages.
3.Observe once the installtion is done, continuous vdsm service failed messages are seen in /var/log/messages:


Aug 31 03:40:49 localhost systemd: vdsmd.service holdoff time over, scheduling restart.
Aug 31 03:40:49 localhost systemd: Starting Virtual Desktop Server Manager...
Aug 31 03:40:49 localhost vdsmd_init_common.sh: vdsm: Running mkdirs
Aug 31 03:40:49 localhost vdsmd_init_common.sh: vdsm: Running configure_coredump
Aug 31 03:40:49 localhost vdsmd_init_common.sh: vdsm: Running configure_vdsm_logs
Aug 31 03:40:49 localhost vdsmd_init_common.sh: vdsm: Running wait_for_network
Aug 31 03:40:49 localhost vdsmd_init_common.sh: vdsm: Running run_init_hooks
Aug 31 03:40:50 localhost vdsmd_init_common.sh: vdsm: Running upgraded_version_check
Aug 31 03:40:50 localhost vdsmd_init_common.sh: vdsm: Running check_is_configured
Aug 31 03:40:53 localhost vdsmd_init_common.sh: Error:
Aug 31 03:40:53 localhost vdsmd_init_common.sh: One of the modules is not configured to work with VDSM.
Aug 31 03:40:53 localhost vdsmd_init_common.sh: To configure the module use the following:
Aug 31 03:40:53 localhost vdsmd_init_common.sh: 'vdsm-tool configure [--module module-name]'.
Aug 31 03:40:53 localhost vdsmd_init_common.sh: If all modules are not configured try to use:
Aug 31 03:40:53 localhost vdsmd_init_common.sh: 'vdsm-tool configure --force'
Aug 31 03:40:53 localhost vdsmd_init_common.sh: (The force flag will stop the module's service and start it
Aug 31 03:40:53 localhost vdsmd_init_common.sh: afterwards automatically to load the new configuration.)
Aug 31 03:40:53 localhost vdsmd_init_common.sh: Manual override for multipath.conf detected - preserving current configuration
Aug 31 03:40:53 localhost vdsmd_init_common.sh: This manual override for multipath.conf was based on downrevved template. You are strongly advised to contact your support representatives
Aug 31 03:40:53 localhost vdsmd_init_common.sh: libvirt is already configured for vdsm
Aug 31 03:40:53 localhost vdsmd_init_common.sh: Modules sebool are not configured
Aug 31 03:40:53 localhost vdsmd_init_common.sh: vdsm: stopped during execute check_is_configured task (task returned with error code 1).
Aug 31 03:40:53 localhost systemd: vdsmd.service: control process exited, code=exited status=1
Aug 31 03:40:53 localhost systemd: Failed to start Virtual Desktop Server Manager.
Aug 31 03:40:53 localhost systemd: Dependency failed for MOM instance configured for VDSM purposes.
Aug 31 03:40:53 localhost systemd: Job mom-vdsm.service/start failed with result 'dependency'.
Aug 31 03:40:53 localhost systemd: Unit vdsmd.service entered failed state.
Aug 31 03:40:53 localhost systemd: vdsmd.service failed.
Aug 31 03:40:53 localhost systemd: vdsmd.service holdoff time over, scheduling restart.
Aug 31 03:40:53 localhost systemd: Starting Virtual Desktop Server Manager

4. Subscribe to live channels and do a yum update.

5. Reboot the system.

6. Observe that after the reboot, vdsm service stays in activating (start-pre) state and again following messages are seen in /var/log/messages:

[root@dhcp43-205 ~]# systemctl status vdsmd
● vdsmd.service - Virtual Desktop Server Manager
   Loaded: loaded (/usr/lib/systemd/system/vdsmd.service; enabled; vendor preset: enabled)
   Active: activating (start-pre) since Wed 2016-08-31 05:09:14 EDT; 2s ago
  Control: 26036 (vdsmd_init_comm)
   CGroup: /system.slice/vdsmd.service
           └─control
             ├─26036 /bin/sh /usr/libexec/vdsm/vdsmd_init_common.sh --pre-start
             └─26064 /usr/bin/python /usr/bin/vdsm-tool is-configured

Aug 31 05:09:14 dhcp43-205.lab.eng.blr.redhat.com systemd[1]: Starting Virtual D...
Aug 31 05:09:14 dhcp43-205.lab.eng.blr.redhat.com vdsmd_init_common.sh[26036]: v...
Aug 31 05:09:15 dhcp43-205.lab.eng.blr.redhat.com vdsmd_init_common.sh[26036]: v...
Aug 31 05:09:15 dhcp43-205.lab.eng.blr.redhat.com vdsmd_init_common.sh[26036]: v...
Aug 31 05:09:15 dhcp43-205.lab.eng.blr.redhat.com vdsmd_init_common.sh[26036]: v...
Aug 31 05:09:15 dhcp43-205.lab.eng.blr.redhat.com vdsmd_init_common.sh[26036]: v...
Aug 31 05:09:16 dhcp43-205.lab.eng.blr.redhat.com vdsmd_init_common.sh[26036]: v...
Aug 31 05:09:16 dhcp43-205.lab.eng.blr.redhat.com vdsmd_init_common.sh[26036]: v...
Hint: Some lines were ellipsized, use -l to show in full.




Aug 31 03:40:49 localhost systemd: vdsmd.service holdoff time over, scheduling restart.
Aug 31 03:40:49 localhost systemd: Starting Virtual Desktop Server Manager...
Aug 31 03:40:49 localhost vdsmd_init_common.sh: vdsm: Running mkdirs
Aug 31 03:40:49 localhost vdsmd_init_common.sh: vdsm: Running configure_coredump
Aug 31 03:40:49 localhost vdsmd_init_common.sh: vdsm: Running configure_vdsm_logs
Aug 31 03:40:49 localhost vdsmd_init_common.sh: vdsm: Running wait_for_network
Aug 31 03:40:49 localhost vdsmd_init_common.sh: vdsm: Running run_init_hooks
Aug 31 03:40:50 localhost vdsmd_init_common.sh: vdsm: Running upgraded_version_check
Aug 31 03:40:50 localhost vdsmd_init_common.sh: vdsm: Running check_is_configured
Aug 31 03:40:53 localhost vdsmd_init_common.sh: Error:
Aug 31 03:40:53 localhost vdsmd_init_common.sh: One of the modules is not configured to work with VDSM.
Aug 31 03:40:53 localhost vdsmd_init_common.sh: To configure the module use the following:
Aug 31 03:40:53 localhost vdsmd_init_common.sh: 'vdsm-tool configure [--module module-name]'.
Aug 31 03:40:53 localhost vdsmd_init_common.sh: If all modules are not configured try to use:
Aug 31 03:40:53 localhost vdsmd_init_common.sh: 'vdsm-tool configure --force'
Aug 31 03:40:53 localhost vdsmd_init_common.sh: (The force flag will stop the module's service and start it
Aug 31 03:40:53 localhost vdsmd_init_common.sh: afterwards automatically to load the new configuration.)
Aug 31 03:40:53 localhost vdsmd_init_common.sh: Manual override for multipath.conf detected - preserving current configuration
Aug 31 03:40:53 localhost vdsmd_init_common.sh: This manual override for multipath.conf was based on downrevved template. You are strongly advised to contact your support representatives
Aug 31 03:40:53 localhost vdsmd_init_common.sh: libvirt is already configured for vdsm
Aug 31 03:40:53 localhost vdsmd_init_common.sh: Modules sebool are not configured
Aug 31 03:40:53 localhost vdsmd_init_common.sh: vdsm: stopped during execute check_is_configured task (task returned with error code 1).
Aug 31 03:40:53 localhost systemd: vdsmd.service: control process exited, code=exited status=1
Aug 31 03:40:53 localhost systemd: Failed to start Virtual Desktop Server Manager.
Aug 31 03:40:53 localhost systemd: Dependency failed for MOM instance configured for VDSM purposes.
Aug 31 03:40:53 localhost systemd: Job mom-vdsm.service/start failed with result 'dependency'.
Aug 31 03:40:53 localhost systemd: Unit vdsmd.service entered failed state.
Aug 31 03:40:53 localhost systemd: vdsmd.service failed.
Aug 31 03:40:53 localhost systemd: vdsmd.service holdoff time over, scheduling restart.
Aug 31 03:40:53 localhost systemd: Starting Virtual Desktop Server Manager


7. Sometimes on machines if the vdsm service is in failed state, below messages are also seen:


Aug 31 03:34:55 localhost daemonAdapter: libvirt: XML-RPC error : authentication failed: authentication failed
Aug 31 03:34:56 localhost journal: authentication failed: Failed to start SASL negotiation: -20 (SASL(-13): user not found: unable to canonify user and get auxprops)
Aug 31 03:34:56 localhost journal: authentication failed: authentication failed
Aug 31 03:34:56 localhost journal: End of file while reading data: Input/output error
Aug 31 03:34:56 localhost daemonAdapter: libvirt: XML-RPC error : authentication failed: authentication failed
Aug 31 03:34:56 localhost journal: authentication failed: Failed to start SASL negotiation: -20 (SASL(-13): user not found: unable to canonify user and get auxprops)
Aug 31 03:34:56 localhost journal: authentication failed: authentication failed
Aug 31 03:34:56 localhost journal: End of file while reading data: Input/output error

Actual results:


Expected results:

There should not be any errors seen.

Additional info:

Comment 2 Shashank Raj 2016-08-31 13:11:26 UTC
Created attachment 1196361 [details]
/var/log/messages

Comment 3 Ramesh N 2016-08-31 13:47:24 UTC
I tried re-producing this issue using RHGS 3.1.3 ISO without nfs-ganesha packages. But I could not re-produce. Can you confirm that it happens only with nfs-ganesha pacakges?.

Comment 4 Shashank Raj 2016-09-01 10:10:54 UTC
Looks like there is some problem with the hyper-visor i am using. Everytime i create a new VM on this hyper-visor with 3.1.3 ISO, i get these continuous vdsm failure related messages.

But when i tried the same on another hyper-visor, i am not able to reproduce the issue.

Since its not seen on different hype-visor, closing this as not a bug.