Bug 1305197 - libvirt does not start after installing vdsm
Summary: libvirt does not start after installing vdsm
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: vdsm
Classification: oVirt
Component: General
Version: 4.17.18
Hardware: Unspecified
OS: Unspecified
medium
high
Target Milestone: ovirt-4.0.0-alpha
: 4.17.999
Assignee: Dan Kenigsberg
QA Contact: Petr Kubica
URL:
Whiteboard:
Depends On: 1303355
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-02-06 01:34 UTC by verslyap
Modified: 2016-08-23 07:33 UTC (History)
9 users (show)

Fixed In Version: ovirt 4.0.0 alpha1
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2016-08-23 06:21:41 UTC
oVirt Team: Infra
Embargoed:
rule-engine: ovirt-4.0.0+
rule-engine: planning_ack+
rule-engine: devel_ack+
pstehlik: testing_ack+


Attachments (Terms of Use)
Output from running openssl x509 -in /etc/pki/vdsm/certs/vdsmcert.pem -text (5.83 KB, text/plain)
2016-02-09 11:48 UTC, verslyap
no flags Details
output from running rpm -q vdsm (40 bytes, text/plain)
2016-02-09 11:49 UTC, verslyap
no flags Details
Output of libvirt -v listen (8.33 KB, text/plain)
2016-02-09 11:50 UTC, verslyap
no flags Details
out put from WORKING openssl x509 -in /etc/pki/vdsm/cert/vdsmcert/pem -text (4.44 KB, text/plain)
2016-02-10 23:51 UTC, verslyap
no flags Details

Description verslyap 2016-02-06 01:34:25 UTC
Description of problem:
After installing vdsm, the libvirt service will not start.  journalctl -xe gives the following output:

Feb 05 20:27:43 pine.local audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=supervdsmd comm="systemd" exe="/usr/lib/systemd/systemd" hostnam
Feb 05 20:27:43 pine.local libvirtd[3009]: libvirt version: 1.2.18.2, package: 2.fc23 (Fedora Project, 2016-01-21-00:54:13, buildhw-01-nfs.phx2.fedoraproject.org)
Feb 05 20:27:43 pine.local libvirtd[3009]: Module /usr/lib64/libvirt/connection-driver/libvirt_driver_xen.so not accessible
Feb 05 20:27:43 pine.local libvirtd[3009]: Module /usr/lib64/libvirt/connection-driver/libvirt_driver_libxl.so not accessible
Feb 05 20:27:43 pine.local libvirtd[3009]: Module /usr/lib64/libvirt/connection-driver/libvirt_driver_lxc.so not accessible
Feb 05 20:27:43 pine.local libvirtd[3009]: Module /usr/lib64/libvirt/connection-driver/libvirt_driver_uml.so not accessible
Feb 05 20:27:43 pine.local libvirtd[3009]: Module /usr/lib64/libvirt/connection-driver/libvirt_driver_vbox.so not accessible
Feb 05 20:27:43 pine.local libvirtd[3009]: Certificate /etc/pki/vdsm/certs/vdsmcert.pem usage does not permit key encipherment
Feb 05 20:27:43 pine.local systemd[1]: libvirtd.service: Main process exited, code=exited, status=6/NOTCONFIGURED
Feb 05 20:27:43 pine.local systemd[1]: Failed to start Virtualization daemon.
-- Subject: Unit libvirtd.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit libvirtd.service has failed.
--
-- The result is failed.
Feb 05 20:27:43 pine.local audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=libvirtd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=
Feb 05 20:27:43 pine.local systemd[1]: libvirtd.service: Unit entered failed state.
Feb 05 20:27:43 pine.local systemd[1]: libvirtd.service: Failed with result 'exit-code'.
Feb 05 20:27:43 pine.local systemd[1]: libvirtd.service: Service hold-off time over, scheduling restart.
Feb 05 20:27:43 pine.local audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=libvirtd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=
Feb 05 20:27:43 pine.local systemd[1]: libvirtd.service: Start request repeated too quickly.
Feb 05 20:27:43 pine.local audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=libvirtd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=?
Feb 05 20:27:43 pine.local systemd[1]: Failed to start Virtualization daemon.
-- Subject: Unit libvirtd.service has failed

If I reconfigure vdsm to not use ssl, libvirt starts fine.  I presume that's related to:
Feb 05 20:27:43 pine.local libvirtd[3009]: Certificate /etc/pki/vdsm/certs/vdsmcert.pem usage does not permit key encipherment
in the above output.


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

How reproducible:
with ssl = true on, 100% of the time

Steps to Reproduce:
1. Install vdsm
2. systemctl start(or restart) libvirtd
3.

Actual results:
libvirtd does not start

Expected results:
libvirtd starts

Additional info:

Comment 1 Dan Kenigsberg 2016-02-06 09:58:48 UTC
Can you share libvirt's rpm version?

Comment 2 verslyap 2016-02-06 14:17:19 UTC
It's:
libvirt.x86_64  1.2.18.2-2.fc23

I had this also occur on a fedora 22 install right before I reinstalled 23 over it.  If you need that information, let me know and I'll throw F22 back on and I'll look that up for you.

Comment 3 verslyap 2016-02-06 14:18:21 UTC
Also, when I run:
sudo openssl verify -CAfile /etc/pki/vdsm/certs/cacert.pem /etc/pki/vdsm/certs/vdsmcert.pem

I get:
/etc/pki/vdsm/certs/vdsmcert.pem: CN = pine.local, O = VDSM Certificate
error 20 at 0 depth lookup:unable to get local issuer certificate

Thanks!

Comment 4 Piotr Kliczewski 2016-02-08 13:45:05 UTC
I performed following steps to reproduce the issue:

    1 Installed f23 on a vm.
    2  dnf -y update
    3  yum install
http://resources.ovirt.org/pub/yum-repo/ovirt-release-master.rpm
    4  dnf -y install make autoconf automake pyflakes logrotate
python-pep8 libvirt-python python-devel  python-nose rpm-build
sanlock-python genisoimage python-odict python-pthreading
libselinux-python python-ethtool m2crypto python-dmidecode
python-netaddr python-inotify python-argparse git  python-cpopen
bridge-utils libguestfs-tools-c pyparted openssl libnl3 libtool
gettext-devel python-ioprocess  policycoreutils-python
python-simplejson python-blivet python-six mom ovirt-vmconsole
    5  git clone http://gerrit.ovirt.org/p/vdsm.git
    7  cd vdsm/
    9  ./autogen.sh --system
   10  make
   12  dnf install python3-nose
   14  dnf install rpm-python
   15  NOSE_EXCLUDE=.* make rpm
   17  cd
   19  cd rpmbuild/RPMS/noarch/
   21  yum install `ls | grep -v hook` `ls | grep vmfex`
   22  vdsm-tool configure --force
   23  service vdsmd start

I used engine built from sources (master) last week. After the host deployment vdsmd and libvirtd were running. I added data domain, created and started a vm.

No issues found.

Please provide more information how to reproduce your issue. I am using:

Name        : libvirt
Arch        : x86_64
Epoch       : 0
Version     : 1.2.18.2
Release     : 2.fc23

Comment 5 verslyap 2016-02-09 00:53:27 UTC
To reach this issue, I took the following steps:
1) Fresh minimal install of fedora 23 (or 22) from the netinst iso
2) install ovirt-release36-003-1.noarch.rpm from the ovirt website
3) when I tried this one fc23, I modified the ovirt36.repo url, replacing $releasever with 22.  On fc22 I left it alone
4) I did a dnf install ovirt-hosted-engine-setup
5) doing a systemctl start vdsm, or a hosted-engine --deploy.  In either case this step fails

It's good to know getting the source and building it works.  I can do that in the meantime.

Comment 6 verslyap 2016-02-09 03:46:39 UTC
After trying the same steps you listed above, I am still encountering the same error.  I also tried doing a dnf install vdsm from ovirt-master-snapshot and encountered the same problem.

Comment 7 verslyap 2016-02-09 04:31:08 UTC
Just on a lark, I reinstalled with fedora server 23 from netinst.  Same issue.

Comment 8 Dan Kenigsberg 2016-02-09 09:03:18 UTC
would you be kind to share your `openssl x509 -in /etc/pki/vdsm/certs/vdsmcert.pem -text`, the output of `rpm -q vdsm`, and that of `libvirtd --listen -v`?

Comment 9 Piotr Kliczewski 2016-02-09 10:31:30 UTC
I followed the steps from comment #5 but I reused f23 vm.

I installed http://resources.ovirt.org/pub/ovirt-3.6-snapshot-static/rpm/fc23/noarch/ovirt-release36-snapshot-003-1.noarch.rpm and http://resources.ovirt.org/pub/ovirt-3.6-snapshot-static/rpm/fc23/noarch/ovirt-release36-003-1.noarch.rpm. Next I changed urls to point to f22. I installed ovirt-hosted-engine-setup which included:

 vdsm                                                   noarch                         4.17.19-7.gitf5eceaa.fc22                                                  ovirt-3.6-snapshot                         918 k
 vdsm-cli                                               noarch                         4.17.19-7.gitf5eceaa.fc22                                                  ovirt-3.6-snapshot                          70 k
 vdsm-hook-vmfex-dev                                    noarch                         4.17.19-7.gitf5eceaa.fc22                                                  ovirt-3.6-snapshot                          10 k
 vdsm-infra                                             noarch                         4.17.19-7.gitf5eceaa.fc22                                                  ovirt-3.6-snapshot                          15 k
 vdsm-jsonrpc                                           noarch                         4.17.19-7.gitf5eceaa.fc22                                                  ovirt-3.6-snapshot                         104 k
 vdsm-python                                            noarch                         4.17.19-7.gitf5eceaa.fc22                                                  ovirt-3.6-snapshot                         222 k
 vdsm-xmlrpc                                            noarch                         4.17.19-7.gitf5eceaa.fc22                                                  ovirt-3.6-snapshot                          28 k
 vdsm-yajsonrpc                                         noarch                         4.17.19-7.gitf5eceaa.fc22                                                  ovirt-3.6-snapshot                          30 k

When I run hosted-engine --deploy I noticed that vdsm service was started OK. I canceled setup and run systemctl start vdsm to see that it is up.

Now I will do the same with fresh f23.

Comment 10 Piotr Kliczewski 2016-02-09 11:06:20 UTC
When installing on fresh f23 vm I found in the log:

Feb  9 12:00:19 localhost systemd: Starting Virtual Desktop Server Manager...
Feb  9 12:00:19 localhost vdsmd_init_common.sh: vdsm: Running mkdirs
Feb  9 12:00:19 localhost vdsmd_init_common.sh: vdsm: Running configure_coredump
Feb  9 12:00:19 localhost vdsmd_init_common.sh: vdsm: Running configure_vdsm_logs
Feb  9 12:00:19 localhost vdsmd_init_common.sh: vdsm: Running wait_for_network
Feb  9 12:00:19 localhost vdsmd_init_common.sh: vdsm: Running run_init_hooks
Feb  9 12:00:19 localhost vdsmd_init_common.sh: vdsm: Running upgraded_version_check
Feb  9 12:00:19 localhost vdsmd_init_common.sh: vdsm: Running check_is_configured
Feb  9 12:00:19 localhost sasldblistusers2: _sasldb_getkeyhandle has failed
Feb  9 12:00:19 localhost vdsmd_init_common.sh: Error:
Feb  9 12:00:19 localhost vdsmd_init_common.sh: One of the modules is not configured to work with VDSM.
Feb  9 12:00:19 localhost vdsmd_init_common.sh: To configure the module use the following:
Feb  9 12:00:19 localhost vdsmd_init_common.sh: 'vdsm-tool configure [--module module-name]'.
Feb  9 12:00:19 localhost vdsmd_init_common.sh: If all modules are not configured try to use:
Feb  9 12:00:19 localhost vdsmd_init_common.sh: 'vdsm-tool configure --force'
Feb  9 12:00:19 localhost vdsmd_init_common.sh: (The force flag will stop the module's service and start it
Feb  9 12:00:19 localhost vdsmd_init_common.sh: afterwards automatically to load the new configuration.)
Feb  9 12:00:19 localhost vdsmd_init_common.sh: multipath requires configuration
Feb  9 12:00:19 localhost vdsmd_init_common.sh: libvirt is not configured for vdsm yet
Feb  9 12:00:19 localhost vdsmd_init_common.sh: Modules sanlock, sebool, multipath, passwd, certificates, libvirt are not configured
Feb  9 12:00:19 localhost systemd: vdsmd.service: Control process exited, code=exited status=1

Comment 11 Piotr Kliczewski 2016-02-09 11:08:44 UTC
I checked and libvirtd is running even though configuration failed.

Comment 12 Piotr Kliczewski 2016-02-09 11:12:19 UTC
Where can I find more info what exactly failed?

Comment 13 verslyap 2016-02-09 11:48:39 UTC
Created attachment 1122394 [details]
Output from running openssl x509 -in /etc/pki/vdsm/certs/vdsmcert.pem -text

Comment 14 verslyap 2016-02-09 11:49:41 UTC
Created attachment 1122395 [details]
output from running rpm -q vdsm

Comment 15 verslyap 2016-02-09 11:50:18 UTC
Created attachment 1122396 [details]
Output of libvirt -v listen

Comment 16 verslyap 2016-02-09 11:53:49 UTC
Piotr, when I do a journalctl -xe after I attempt to start libvirtd (or vdsmd for that matter), the only error I see in the log is:
Feb 09 06:48:10 cedar.local libvirtd[1968]: Certificate /etc/pki/vdsm/certs/vdsmcert.pem usage does not permit key encipherment

My vdsm.log file is empty.

Comment 17 Piotr Kliczewski 2016-02-09 11:59:12 UTC
It looks like we have any vdsm-tool issue so we need more info from Yaniv.

Comment 18 Dan Kenigsberg 2016-02-09 21:55:40 UTC
(In reply to verslyap from comment #13)
> Created attachment 1122394 [details]
> Output from running openssl x509 -in /etc/pki/vdsm/certs/vdsmcert.pem -text

2016-02-09 11:45:04.688+0000: 1866: error : virNetTLSContextCheckCertKeyUsage:276 : Certificate /etc/pki/vdsm/certs/vdsmcert.pem usage does not permit key encipherment

Martin, can you tell why libvirt does not accept our certificate?

Comment 19 verslyap 2016-02-10 03:19:50 UTC
I reinstalled fedora using standard media and it worked.  Just for good measure I retried with the netinst installer again and that reproduced the problem.  So there's got to be some difference between the standard install and the netinst install.

Comment 20 Martin Kletzander 2016-02-10 10:49:52 UTC
(In reply to Dan Kenigsberg from comment #18)
My guess would be that there's newer gnutls which is more strict about what that particular certificate can (not) do.  I wanted to suggest running:

certtool --certificate-info </etc/pki/vdsm/certs/vdsmcert.pem

But now I went through the discussion and found out there's corresponding output from openssl, so that's enough.  You can see in the output of openssl that the Key usage is only for digital signature, so I'm guessing that is only the CA certificate.  Or your certificates worked earlier and do not work now.  That would be because that certificate is badly created and newer gnutls just started enforcing that.  It also could've been libvirt, but we did not have that many changes WRT this scenario, I believe.

Comment 21 Dan Kenigsberg 2016-02-10 11:50:51 UTC
Thanks, Martin.

verslyap, could you share your now-working certificate (-text thereof)?
Can you spot any difference in version of gnutls, openssl, or libvirt?

Comment 22 verslyap 2016-02-10 13:06:33 UTC
Yes.  I'll do it when I get home from work.

Comment 23 verslyap 2016-02-10 23:51:07 UTC
Created attachment 1123011 [details]
out put from WORKING openssl x509 -in /etc/pki/vdsm/cert/vdsmcert/pem -text

Comment 24 verslyap 2016-02-11 01:05:20 UTC
Dan,

I did a dnf upgrade, and that did an upgrade of gnutls and openssl.  Although vdsm has continued to work.  Checking out the fedora 23 repos, I can see that a base install of fedora 23 delivers:
gnutls-3.4.5-2.fc23.x86_64.rpm
openssl-1.0.2d-2.fc23.x86_64.rpm
libvirt-daemon-1.2.18.1-2.fc23.x86_64.rpm

The latest versions of these packages (which would be delivered with a netinst) are:
gnutls-3.4.8-1.fc23.x86_64.rpm
openssl-1.0.2f-1.fc23.x86_64.rpm
libvirt-daemon-1.2.18.2-2.fc23.x86_64.rpm

Sorry to say, I don't really know very much about how to investigate rpm files.  My linux skills are at about 4.5 out of 10.  Just enough to be dangerous o_O

Comment 25 verslyap 2016-02-12 04:04:09 UTC
I just found this out tonight.  When I do a dnf upgrade before I've installed vdsm, I encounter this issue.  When I install and configure vdsm on a fresh install, then do a dnf upgrade, vdsm works fine.

Comment 26 verslyap 2016-02-12 04:16:10 UTC
I found this bug open in Fedora, pertaining to gnutls:
https://bugzilla.redhat.com/show_bug.cgi?id=1303355
As related from here:
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=813243

Notice that the newest version gnutls available in Fedora 23 is somewhat newer than the "found in" line on the second link, but still older than the "fixed in" line.  A fix for this issue is currently in testing for Fedora 22.  I'm not really sure how these things work, but I'm presuming Fedora 23 is next.  Probably just need wait until that package gets updated.

Comment 27 Sandro Bonazzola 2016-04-05 14:08:15 UTC
No reference to the fixing patch, monving on_qa based on TestOnly keyword and state.

Comment 28 Pavel Stehlik 2016-08-23 06:21:41 UTC
Closing this bug based on comments & fix of bug 813243 in F23. If still exists, please reopen.

Comment 29 Pavel Stehlik 2016-08-23 07:33:25 UTC
(In reply to Pavel Stehlik from comment #28)
> Closing this bug based on comments & fix of bug 813243 in F23. If still
> exists, please reopen.

The fix is in bug 1303355 - the above is copy/paste error.


Note You need to log in before you can comment on or make changes to this bug.