Bug 1120209

I don't think this is a regression. I have seen this error in users logs in the past in the mailing list.

Please prove that this is a regression by testing again with:

1. RHEL 6.5
2. RHEV 3.4.0

Please also specify exactly which RHEL 7.0 image you used, and which repositories were used to install vdsm. I tried to add a RHEL 7.0 host to engine yesterday, and the deployment fails when trying to install vdsm, I surprised that you reached a state where you can run vdsm.

When you test, make sure you start with clean image, the same image a customer would start with.

Also lowering severity, this does not look like urgent issue, as this happens only on the first time you deploy on a clean image.

This look like this issue on the mailing list:
http://lists.ovirt.org/pipermail/users/2014-February/021904.html

Which seems to be caused by this change:
http://gerrit.ovirt.org/17487 fixing bug 988995

This change is available rhev-3.3:

$ git log --grep I57583eb8931411d40bcce8f6a676621f6ee1eebd
commit 620343d6317c849fc985a5083cebb68c995f7c15
Author: Yeela Kaplan <ykaplan>
Date:   Tue Jul 30 16:27:07 2013 +0300

    multipath: Reload multipathd instead of restart on setup
    
    Multipathd is required by vdsmd.
    We should not take care of starting it, but only reloading
    new configuration.
    
    Change-Id: I57583eb8931411d40bcce8f6a676621f6ee1eebd
    Bug-Url: https://bugzilla.redhat.com/show_bug.cgi?id=988995
    Signed-off-by: Yeela Kaplan <ykaplan>
    Reviewed-on: http://gerrit.ovirt.org/17487
    Reviewed-by: Dan Kenigsberg <danken>

So this may be a regression in rhev-3.3, but not in 3.4.

I think that what happens here is this:

1. vdsm requires multipathd, so multipathd is installed
2. When installing multipathd, it is not started
3. When vdsm change multipath configuration, it used to restart multipathd,
   but since rhev-3.3 it is reloaded instead.
4. Because multipath is not running, reload fails, exposing the issue that
   multipathd is not running when vdsm is installed.

It seems that the right way to handle this is to ensure that multipathd
is running before installing vdsm.

Alon, how do you suggest to solve this deployment issue?

(In reply to Nir Soffer from comment #9)
> It seems that the right way to handle this is to ensure that multipathd
> is running before installing vdsm.
> 
> Alon, how do you suggest to solve this deployment issue?

what do you mean ensure? if user installs vdsm manually? if that is required vdsmd should start multipathd when it tries to start up.

Proof that this is not a rhev-3.4.1 regression:
https://bugzilla.redhat.com/show_bug.cgi?id=1079707#c7

That comment show same problem when rhev-3.4.0 was tested. Unfortunately the issue was ignored. Probably nobody tried to install on a clean image.

Dan, can we solve this on systemd using a proper unit configuration as you suggest in https://bugzilla.redhat.com/show_bug.cgi?id=988995#c1 ?

In my opinion, the proper fix is to avoid messing up with multipath.conf while Vdsm is running (a la http://gerrit.ovirt.org/#/c/26123/).

We have an explicit Requires=multipathd.service, so the service should have been running when we call reload. I do not have another guess why reload failed.

Nikolay, could you attach the output of `journalctl` and /var/log/messages, which may have hints on which service was running when?

(In reply to Dan Kenigsberg from comment #13)
> In my opinion, the proper fix is to avoid messing up with multipath.conf
> while Vdsm is running (a la http://gerrit.ovirt.org/#/c/26123/).
> 
> We have an explicit Requires=multipathd.service, so the service should have
> been running when we call reload. I do not have another guess why reload
> failed.

I don't have logs from this case, but in the mailing list post in comment 9, we can see that the service was inactive:

Feb 26 01:21:32 test-101022114 systemd[1]: Unit multipathd.service cannot be reloaded because it is inactive.
Feb 26 01:21:32 test-101022114 python[2866]: detected unhandled Python exception in '/usr/bin/vdsm-tool'
Feb 26 01:21:33 test-101022114 dbus-daemon[572]: dbus[572]: [system] Activating service name='org.freedesktop.problems' (using servicehelper)
Feb 26 01:21:33 test-101022114 dbus[572]: [system] Activating service name='org.freedesktop.problems' (using servicehelper)
Feb 26 01:21:33 test-101022114 dbus-daemon[572]: dbus[572]: [system] Successfully activated service 'org.freedesktop.problems'
Feb 26 01:21:33 test-101022114 dbus[572]: [system] Successfully activated service 'org.freedesktop.problems'
Feb 26 01:21:33 test-101022114 vdsm vds ERROR Error initializing IRS#012Traceback (most recent call last):#012  File "/usr/share/vdsm/clientIF.py", line 258, in _initIRS#012    self.irs = Dispatcher(HSM())#012  File "/usr/share/vdsm/storage/hsm.py", line 352, in __init__#012    multipath.setupMultipath()#012  File "/usr/share/vdsm/storage/multipath.py", line 182, in setupMultipath#012    raise se.MultipathReloadError()#012MultipathReloadError: Multipath service reload error: ()

Maybe systemd is starting the service but does not wait until the service is up?

Yes, apparently you were right. systemd.unit(5):

  If a unit foo.service requires a unit bar.service as configured
  with Requires= and no ordering is configured with After= or Before=,
  then both units will be started simultaneously and without any
  delay between them if foo.service is activated.

The issue here is not required services order. We can see during startup that multipathd
is started before vdsm, however, during the first time vdsm is being run, we change
the network configuration (unified_network_persistence_upgrade, restore_nets). These
network configuration probably cause multipathd to fail and exit, so when the network
changes are finished, and vdsm start to initialize, multipathd is not running.

I tested this with master - once with master (see messages-before.log(, and once
with the attached patch (see messages-after.log). In both of them we get the same
results.

It seems that vdsm init script cannot change netowrk configuration since vdsm
required services depend on the the network. So the long term fix is to separate
the network configuration from vdsm startup.

For short term fix, we can check in setupMultipath if multipath is running,
and if start it instead of reloading, but this check is racy.

Antoni, can you look at this?

Created attachment 920652 [details]
log from fresh fedora 20 installation using master from Jul 23

Created attachment 920653 [details]
log from fresh fedora 20 installation using attach patch

The attached patch is correct but does not fix this issue.

This is caused by missing multipath.conf file on a fresh install on Fedora 20
and RHEL 7. When the file does not exists, multipathd service will fail to
start silently, leading to failure to reload multipathd configuration in vdsm.

    [root@reserved-0-247 ~]# systemctl start multipathd
    [root@reserved-0-247 ~]# systemctl status multipathd
    multipathd.service - Device-Mapper Multipath Device Controller
       Loaded: loaded (/usr/lib/systemd/system/multipathd.service; enabled)
       Active: inactive (dead) since Fri 2014-07-25 13:55:48 IDT; 14min ago
               start condition failed at Fri 2014-07-25 14:10:04 IDT; 2s ago
               ConditionPathExists=/etc/multipath.conf was not met
      Process: 11908 ExecStart=/sbin/multipathd (code=exited, status=0/SUCCESS)

The first run of vdsm, vdsm installs a new multipath.conf file but will fail to 
reload multipathd service (because it was started but exited silently) and exit.
The second run of vdsm will succeed as multipathd will start normally using the
new configuration installed by vdsm.

Actually there is also no multipath.conf file in fresh install of device-mapper-multipath on
RHEL 6.5, but multipathd does not exit, and can be reconfigured later.

When running without multipath.conf, multipathd log this to syslog:

Jul 25 15:25:28 dhcp-1-210 multipathd: /etc/multipath.conf does not exist, blacklisting all devices.
Jul 25 15:25:28 dhcp-1-210 multipathd: A sample multipath.conf file is located at
Jul 25 15:25:28 dhcp-1-210 multipathd: /usr/share/doc/device-mapper-multipath-0.4.9/multipath.conf
Jul 25 15:25:28 dhcp-1-210 multipathd: You can run /sbin/mpathconf to create or modify /etc/multipath.conf
Jul 25 15:25:28 dhcp-1-210 multipathd: path checkers start up

So this bug is caused by change in behavior in multipathd, requiring /etc/multipath.conf as
as start condition.

verified on vt3.1