Bug 1164773 - libvirt-1.2.10-2.fc22 fails to connect to hypervisor; error: undefined symbol: virStorageFileCreate
Summary: libvirt-1.2.10-2.fc22 fails to connect to hypervisor; error: undefined symbol...
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: Fedora
Classification: Fedora
Component: libvirt
Version: rawhide
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Libvirt Maintainers
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2014-11-17 12:32 UTC by Kashyap Chamarthy
Modified: 2022-03-21 09:10 UTC (History)
15 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2014-11-20 15:27:01 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
Contextual libvirtd debug logs (799.29 KB, text/plain)
2014-11-17 12:46 UTC, Kashyap Chamarthy
no flags Details
gdb session when libvirt fails to connect to hypervisor (12.80 KB, text/plain)
2014-11-18 08:44 UTC, Kashyap Chamarthy
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Red Hat Bugzilla 1269570 0 unspecified CLOSED Running 'virsh list' with libvirt-0.10.2-54.el6.x86_64 causes "Failed to connect socket to '/var/run/libvirt/libvirt-soc... 2021-06-10 11:00:50 UTC
Red Hat Bugzilla 1314230 0 unspecified CLOSED libvirt fails with undefined symbol 2021-02-22 00:41:40 UTC

Internal Links: 1269570 1314230

Description Kashyap Chamarthy 2014-11-17 12:32:15 UTC
Description of problem
----------------------

libvirtd is unusable with the said version below from Rawhide:

  $ virsh capabilities
  error: failed to connect to the hypervisor
  error: no valid connection
  error: no connection driver available for <null>
  error: Failed to reconnect to the hypervisor

However, libvirtd is running successfully (refer below).

From libvirt debug logs, two things that stand out:

(a) Fails to apply udev rules:

[. . .]
2014-11-17 12:22:20.939+0000: 1046: debug : udevProcessDeviceListEntry:1487 : Failed to create node device for udev device '/sys/devices/virtual/block/dm-1'
2014-11-17 12:22:20.939+0000: 1046: debug : udevProcessDeviceListEntry:1487 : Failed to create node device for udev device '/sys/devices/virtual/block/dm-2'


(b) Fails to load libvirt_driver_qemu.so module for some reason:

[. . .]
2014-11-17 12:22:20.266+0000: 1035: error : virDriverLoadModule:73 : failed to load module /usr/lib64/libvirt/connection-driver/libvirt_driver_qemu.so /usr/lib64/libvirt/connection-driver/libvirt_driver_qemu.so: undefined symbol: virStorageFileCreate
[. . .]

Version:
--------

  $ uname -r; rpm -q qemu-system-x86 libvirt-daemon-kvm
  3.18.0-0.rc4.git2.1.fc22.x86_64
  qemu-system-x86-2.2.0-0.1.rc1.fc22.x86_64
  libvirt-daemon-kvm-1.2.10-2.fc22.x86_64


How reproducible: Consistently.


Steps to Reproduce:
------------------

    $ yum update libvirt* qemu* --enablerepo=rawhide


Actual results 
--------------

  $ sudo virsh list
  error: failed to connect to the hypervisor
  error: no valid connection
  error: no connection driver available for <null>
  error: Failed to reconnect to the hypervisor


Expected results
----------------

libvirt should be functional.


Additional info
---------------

(1) From libvirt debug logs:

$ grep -i error /var/tmp/libvirtd.log 
2014-11-17 12:20:38.124+0000: 669: error : do_open:1165 : no connection driver available for <null>
2014-11-17 12:20:38.124+0000: 669: debug : virNetServerProgramSendError:153 : prog=536903814 ver=1 proc=1 type=1 serial=2 msg=0x7f8188a7b5d0 rerr=0x7f8176998cb0
2014-11-17 12:20:38.126+0000: 661: error : virNetSocketReadWire:1571 : End of file while reading data: Input/output error
2014-11-17 12:20:38.131+0000: 672: error : do_open:1165 : no connection driver available for <null>
2014-11-17 12:20:38.131+0000: 672: debug : virNetServerProgramSendError:153 : prog=536903814 ver=1 proc=1 type=1 serial=2 msg=0x7f8188a7bbc0 rerr=0x7f8175195cb0
2014-11-17 12:20:38.132+0000: 661: error : virNetSocketReadWire:1571 : End of file while reading data: Input/output error
2014-11-17 12:21:51.599+0000: 670: error : do_open:1165 : no connection driver available for <null>
2014-11-17 12:21:51.599+0000: 670: debug : virNetServerProgramSendError:153 : prog=536903814 ver=1 proc=1 type=1 serial=2 msg=0x7f8188a7bbc0 rerr=0x7f8176197cb0
2014-11-17 12:21:51.600+0000: 661: error : virNetSocketReadWire:1571 : End of file while reading data: Input/output error
2014-11-17 12:21:51.606+0000: 673: error : do_open:1165 : no connection driver available for <null>
2014-11-17 12:21:51.606+0000: 673: debug : virNetServerProgramSendError:153 : prog=536903814 ver=1 proc=1 type=1 serial=2 msg=0x7f8188a7bbc0 rerr=0x7f8174994cb0
2014-11-17 12:21:51.607+0000: 661: error : virNetSocketReadWire:1571 : End of file while reading data: Input/output error
2014-11-17 12:22:20.169+0000: 661: debug : virEventPollRunOnce:645 : Poll got error event 4
2014-11-17 12:22:20.264+0000: 1035: error : virDriverLoadModule:73 : failed to load module /usr/lib64/libvirt/connection-driver/libvirt_driver_storage.so /usr/lib64/libvirt/connection-driver/libvirt_driver_storage.so: symbol dm_task_get_info_with_deferred_remove, version Base not defined in file libdevmapper.so.1.02 with link time reference
2014-11-17 12:22:20.266+0000: 1035: error : virDriverLoadModule:73 : failed to load module /usr/lib64/libvirt/connection-driver/libvirt_driver_qemu.so /usr/lib64/libvirt/connection-driver/libvirt_driver_qemu.so: undefined symbol: virStorageFileCreate


(2) libvirt status:

$ systemctl status libvirtd -l
● libvirtd.service - Virtualization daemon
   Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled)
   Active: active (running) since Mon 2014-11-17 07:16:39 EST; 3min 11s ago
     Docs: man:libvirtd(8)
           http://libvirt.org
 Main PID: 661 (libvirtd)
   CGroup: /system.slice/libvirtd.service
           ├─661 /usr/sbin/libvirtd
           ├─720 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/openstackvms.conf --dhcp-script=/usr/libexec/libvirt_leaseshelper
           ├─722 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/openstackvms.conf --dhcp-script=/usr/libexec/libvirt_leaseshelper
           ├─772 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --dhcp-script=/usr/libexec/libvirt_leaseshelper
           └─773 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --dhcp-script=/usr/libexec/libvirt_leaseshelper

Nov 17 07:16:41 intel-sharkbay-dh-07.ml3.eng.bos.redhat.com libvirtd[661]: 2014-11-17 12:16:40.891+0000: 768: debug : virFileClose:99 : Closed fd 23
Nov 17 07:16:41 intel-sharkbay-dh-07.ml3.eng.bos.redhat.com libvirtd[661]: 2014-11-17 12:16:40.891+0000: 768: debug : virFileClose:99 : Closed fd 25
Nov 17 07:16:50 intel-sharkbay-dh-07.ml3.eng.bos.redhat.com dnsmasq[720]: reading /etc/resolv.conf
Nov 17 07:16:50 intel-sharkbay-dh-07.ml3.eng.bos.redhat.com dnsmasq[772]: reading /etc/resolv.conf
Nov 17 07:16:50 intel-sharkbay-dh-07.ml3.eng.bos.redhat.com dnsmasq[720]: using nameserver 10.16.36.29#53
Nov 17 07:16:50 intel-sharkbay-dh-07.ml3.eng.bos.redhat.com dnsmasq[772]: using nameserver 10.16.36.29#53
Nov 17 07:16:50 intel-sharkbay-dh-07.ml3.eng.bos.redhat.com dnsmasq[720]: using nameserver 10.11.5.19#53
Nov 17 07:16:50 intel-sharkbay-dh-07.ml3.eng.bos.redhat.com dnsmasq[772]: using nameserver 10.11.5.19#53
Nov 17 07:16:50 intel-sharkbay-dh-07.ml3.eng.bos.redhat.com dnsmasq[720]: using nameserver 10.5.30.160#53
Nov 17 07:16:50 intel-sharkbay-dh-07.ml3.eng.bos.redhat.com dnsmasq[772]: using nameserver 10.5.30.160#53



(3) This looks a similar, old bug:

    https://bugzilla.redhat.com/show_bug.cgi?id=842068 -- libvirt
    completely non-functional in Rawhide: no connection driver available for
    No connection for URI (null)

Comment 1 Kashyap Chamarthy 2014-11-17 12:46:35 UTC
Created attachment 958228 [details]
Contextual libvirtd debug logs

This log was captured was after enabling debug 
logs in /etc/libvirt/libvirtd.conf:

    log_level = 1
    log_outputs="1:file:/var/tmp/libvirtd.log"

And restarting libvirtd:

    systemctl restart libvirtd

Comment 2 Kashyap Chamarthy 2014-11-17 15:42:18 UTC
Strangely, explicitly installing the libvirt RPM (which was missing earlier) and a few deps it brings along,  resovled it:

$ yum install libvirt --enablerepo=rawhide -y
Installing:
 libvirt                                          x86_64                      1.2.10-2.fc22                        rawhide                       42 k
Installing for dependencies:
 libvirt-daemon-driver-libxl                      x86_64                      1.2.10-2.fc22                        rawhide                      147 k
 libvirt-daemon-driver-lxc                        x86_64                      1.2.10-2.fc22                        rawhide                      637 k
 libvirt-daemon-driver-uml                        x86_64                      1.2.10-2.fc22                        rawhide                       94 k
 libvirt-daemon-driver-vbox                       x86_64                      1.2.10-2.fc22                        rawhide                      317 k
 libvirt-daemon-driver-xen          


$ systemctl restart libvirtd
$ virsh nodeinfo
CPU model:           x86_64
CPU(s):              4
CPU frequency:       1726 MHz
CPU socket(s):       1
Core(s) per socket:  4
Thread(s) per core:  1
NUMA cell(s):        1
Memory size:         16154688 KiB

Comment 3 Cole Robinson 2014-11-17 20:54:16 UTC
Does removing those packages again bring back the broken state?
From a broke state, can you show: rpm -qa | grep libvirt

Comment 4 Cole Robinson 2014-11-17 20:56:36 UTC
On Fedora 21 I just updated libvirt\* from rawhide, restarted libvirtd, but virsh works fine FWIW

Updated:
  libvirt-client.x86_64 0:1.2.10-2.fc22                                         
  libvirt-daemon.x86_64 0:1.2.10-2.fc22                                         
  libvirt-daemon-config-network.x86_64 0:1.2.10-2.fc22                          
  libvirt-daemon-config-nwfilter.x86_64 0:1.2.10-2.fc22                         
  libvirt-daemon-driver-interface.x86_64 0:1.2.10-2.fc22                        
  libvirt-daemon-driver-lxc.x86_64 0:1.2.10-2.fc22                              
  libvirt-daemon-driver-network.x86_64 0:1.2.10-2.fc22                          
  libvirt-daemon-driver-nodedev.x86_64 0:1.2.10-2.fc22                          
  libvirt-daemon-driver-nwfilter.x86_64 0:1.2.10-2.fc22                         
  libvirt-daemon-driver-qemu.x86_64 0:1.2.10-2.fc22                             
  libvirt-daemon-driver-secret.x86_64 0:1.2.10-2.fc22                           
  libvirt-daemon-driver-storage.x86_64 0:1.2.10-2.fc22                          
  libvirt-daemon-kvm.x86_64 0:1.2.10-2.fc22                                     
  libvirt-debuginfo.x86_64 0:1.2.10-2.fc22                                      
  libvirt-designer-libs.x86_64 0:0.0.1-10.fc22                                  
  libvirt-devel.x86_64 0:1.2.10-2.fc22                                          
  libvirt-docs.x86_64 0:1.2.10-2.fc22                                           
  libvirt-gconfig.x86_64 0:0.1.9-1.fc22                                         
  libvirt-glib.x86_64 0:0.1.9-1.fc22                                            
  libvirt-gobject.x86_64 0:0.1.9-1.fc22                                         
  libvirt-python.x86_64 0:1.2.10-1.fc22

Comment 5 Richard W.M. Jones 2014-11-17 21:09:47 UTC
I've seen 'error: failed to connect to the hypervisor' as well.
It's infuriatingly hard to reproduce however, which is why I didn't
file a bug about it.  Also I suspect it has several underlying causes,
and the undefined symbol in this bug is just one of them.

Comment 6 Cole Robinson 2014-11-17 21:15:41 UTC
Rich, are you running rawhide host?

Also, does it reproduce with 1.2.10-1 ? The patches added in the -2 update are pretty minor and don't use the StorageCreateFile API. Maybe this is rawhide brokenness

Comment 7 Richard W.M. Jones 2014-11-17 21:27:05 UTC
(In reply to Cole Robinson from comment #6)
> Rich, are you running rawhide host?
> 
> Also, does it reproduce with 1.2.10-1 ? The patches added in the -2 update
> are pretty minor and don't use the StorageCreateFile API. Maybe this is
> rawhide brokenness

As I recall it has happened with recent upgrades to F21 and Rawhide.
In neither case was it easy to reproduce, and both went away after
rebooting.

Comment 8 Kashyap Chamarthy 2014-11-18 08:01:36 UTC
(In reply to Cole Robinson from comment #3)
> Does removing those packages again bring back the broken state?

Yes, I can. (Sorry, I forgot to note this in my initial description.)

$ yum remove libvirt -y
Dependencies resolved.
[. . .]
Removing:
 libvirt                                         x86_64                      1.2.10-2.fc22                         @System                        0  
 libvirt-daemon-driver-lxc                       x86_64                      1.2.10-2.fc22                         @System                      1.6 M
 libvirt-daemon-driver-uml                       x86_64                      1.2.10-2.fc22                         @System                      130 k
 libvirt-daemon-driver-vbox                      x86_64                      1.2.10-2.fc22                         @System                      1.7 M
 libvirt-daemon-driver-xen                       x86_64                      1.2.10-2.fc22                         @System                      234 k

Transaction Summary
======================================================================================================================================================
[. . .]
Removed:
  libvirt.x86_64 1.2.10-2.fc22                      libvirt-daemon-driver-lxc.x86_64 1.2.10-2.fc22   libvirt-daemon-driver-uml.x86_64 1.2.10-2.fc22  
  libvirt-daemon-driver-vbox.x86_64 1.2.10-2.fc22   libvirt-daemon-driver-xen.x86_64 1.2.10-2.fc22  


$ systemctl restart libvirtd

$  systemctl status libvirtd | grep Active
   Active: active (running) since Tue 2014-11-18 02:58:05 EST; 2min 1s ago

$ virsh nodeinfo
error: failed to connect to the hypervisor
error: no valid connection
error: no connection driver available for <null>
error: Failed to reconnect to the hypervisor


> From a broke state, can you show: rpm -qa | grep libvirt

There we go:
-----
$ rpm -qa | grep libvirt
libvirt-daemon-driver-storage-1.2.10-2.fc22.x86_64
libvirt-docs-1.2.10-2.fc22.x86_64
libvirt-daemon-qemu-1.2.10-2.fc22.x86_64
libvirt-devel-1.2.10-2.fc22.x86_64
libvirt-daemon-driver-interface-1.2.10-2.fc22.x86_64
libvirt-daemon-config-nwfilter-1.2.10-2.fc22.x86_64
libvirt-daemon-driver-libxl-1.2.10-2.fc22.x86_64
libvirt-client-1.2.10-2.fc22.x86_64
libvirt-daemon-driver-nodedev-1.2.10-2.fc22.x86_64
libvirt-daemon-driver-nwfilter-1.2.10-2.fc22.x86_64
libvirt-daemon-kvm-1.2.10-2.fc22.x86_64
libvirt-python-1.2.10-1.fc22.x86_64
libvirt-daemon-config-network-1.2.10-2.fc22.x86_64
libvirt-daemon-1.2.10-2.fc22.x86_64
libvirt-daemon-driver-qemu-1.2.10-2.fc22.x86_64
libvirt-daemon-driver-secret-1.2.10-2.fc22.x86_64
libvirt-daemon-driver-network-1.2.10-2.fc22.x86_64
-----

Comment 9 Kashyap Chamarthy 2014-11-18 08:44:32 UTC
Created attachment 958464 [details]
gdb session when libvirt fails to connect to hypervisor

That's exactly how I tried:

  $ ps -C libvirtd
    PID TTY          TIME CMD
   1360 ?        00:00:00 libvirtd

  $ gdb libvirtd 1360
  (gdb)
  [. . .]
  (gdb) set logging on
  Copying output to gdb.txt.
  (gdb) cont
  Continuing.

Perform the test: 

  $ virsh nodeinfo
  error: failed to connect to the hypervisor
  error: no valid connection
  error: no connection driver available for <null>
  error: Failed to reconnect to the hypervisor

Then on the `gdb` instance:

  (gdb) ^C
  (gdb) thread apply all bt
  (gdb) quit

Output in gdb.txt.

Comment 10 Kashyap Chamarthy 2014-11-18 11:22:43 UTC
Another point I should note here is, one oddity with this machine's default libvirt URI somehow ended up being LXC:

$ virsh uri
lxc:///

It wasn't set in any of the libvirt config files either:

$ cat /etc/libvirt/libvirtd.conf /etc/libvirt/libvirt.conf \
  | grep -i uri | grep -v ^# | grep -v ^$
$ echo $?
1

And, as noted in this bug[*], epxlicitly setting

  export LIBVIRT_DEFAULT_URI=qemu:///system

didn't help either:


  $ virsh uri
  error: failed to connect to the hypervisor
  error: no valid connection
  error: no connection driver available for qemu:///system
  error: Failed to reconnect to the hypervisor

(However, an you can notice from comment#8, libvirt-daemon-driver-qemu, libvirt-daemon-qemu RPMs are installed on the host.)


[*] https://bugzilla.redhat.com/show_bug.cgi?id=1165068 --  libvirt-1.2.10-2.fc22: fails to define KVM guest XML - internal error: unexpected domain type kvm, expecting lxc

Comment 11 Kashyap Chamarthy 2014-11-18 12:12:39 UTC
Okay, we found (thanks to DanPB for the hint to take a look at`journalctl` libvirt logs ) the root cause : device-mapper RPM version should be this: device-mapper-1.02.90-1.fc21.x86_64 (instead of: device-mapper-1.02.88-2.fc21.x86_64)

From `journalctl`:

$ journalctl -u libvirtd --since=yesterday -p err
[. . .] failed to load module /usr/lib64/libvirt/connection-driver/libvirt_driver_storage.so /usr/lib64/libvirt/connection-driver/libvirt_driver_storage.so: symbol dm_task_get_info_with_deferred_remove, version Base not defined in file libdevmapper.so.1.02 with link time reference
.
.
[. . .] failed to load module /usr/lib64/libvirt/connection-driver/libvirt_driver_qemu.so /usr/lib64/libvirt/connection-driver/libvirt_driver_qemu.so: undefined symbol: virStorageFileCreate


Updating to device-mapper-1.02.90-1.fc21.x86_64 solved the issue:

$ virsh uri
qemu:///system

$ virsh nodeinfo
CPU model:           x86_64
CPU(s):              4
CPU frequency:       1568 MHz
CPU socket(s):       1
Core(s) per socket:  4
Thread(s) per core:  1
NUMA cell(s):        1
Memory size:         16154688 KiB

Comment 12 Michal Privoznik 2014-11-20 13:37:35 UTC
(In reply to Kashyap Chamarthy from comment #11)
> Okay, we found (thanks to DanPB for the hint to take a look at`journalctl`
> libvirt logs ) the root cause : device-mapper RPM version should be this:
> device-mapper-1.02.90-1.fc21.x86_64 (instead of:
> device-mapper-1.02.88-2.fc21.x86_64)
> 
> From `journalctl`:
> 
> $ journalctl -u libvirtd --since=yesterday -p err
> [. . .] failed to load module
> /usr/lib64/libvirt/connection-driver/libvirt_driver_storage.so
> /usr/lib64/libvirt/connection-driver/libvirt_driver_storage.so: symbol
> dm_task_get_info_with_deferred_remove, version Base not defined in file
> libdevmapper.so.1.02 with link time reference

So libdevmapper.so (from device-mapper-libs) hasn't provided the symbol. Hence, storage driver has failed to load.

> .
> .
> [. . .] failed to load module
> /usr/lib64/libvirt/connection-driver/libvirt_driver_qemu.so
> /usr/lib64/libvirt/connection-driver/libvirt_driver_qemu.so: undefined
> symbol: virStorageFileCreate
> 

And subsequently did qemu driver, which needs some symbols (e.g. virStorageFileCreate) from storage driver. Therefore, the default URI is not qemu:///system but lxc:///

> 
> Updating to device-mapper-1.02.90-1.fc21.x86_64 solved the issue:

Exactly! this is a device-mapper-libs bug where they just didn't export some symbol(s) for a several versions. I think this can be closed as NOTABUG, can't it?

Comment 13 Kashyap Chamarthy 2014-11-20 15:27:01 UTC
(In reply to Michal Privoznik from comment #12)
> (In reply to Kashyap Chamarthy from comment #11)
> > Okay, we found (thanks to DanPB for the hint to take a look at`journalctl`
> > libvirt logs ) the root cause : device-mapper RPM version should be this:
> > device-mapper-1.02.90-1.fc21.x86_64 (instead of:
> > device-mapper-1.02.88-2.fc21.x86_64)
> > 
> > From `journalctl`:
> > 
> > $ journalctl -u libvirtd --since=yesterday -p err
> > [. . .] failed to load module
> > /usr/lib64/libvirt/connection-driver/libvirt_driver_storage.so
> > /usr/lib64/libvirt/connection-driver/libvirt_driver_storage.so: symbol
> > dm_task_get_info_with_deferred_remove, version Base not defined in file
> > libdevmapper.so.1.02 with link time reference
> 
> So libdevmapper.so (from device-mapper-libs) hasn't provided the symbol.
> Hence, storage driver has failed to load.
> 
> > .
> > .
> > [. . .] failed to load module
> > /usr/lib64/libvirt/connection-driver/libvirt_driver_qemu.so
> > /usr/lib64/libvirt/connection-driver/libvirt_driver_qemu.so: undefined
> > symbol: virStorageFileCreate
> > 
> 
> And subsequently did qemu driver, which needs some symbols (e.g.
> virStorageFileCreate) from storage driver. Therefore, the default URI is not
> qemu:///system but lxc:///
> 
> > 
> > Updating to device-mapper-1.02.90-1.fc21.x86_64 solved the issue:
> 
> Exactly! this is a device-mapper-libs bug where they just didn't export some
> symbol(s) for a several versions. 

Yes, and the Fixed-In-Version  	device-mapper-libs-1.02.90-1.fc21.x86_64.rpm (provided as part of lvm2-2.02.111-1.fc21) is in Fedora-21 stable:

  $ bodhi -L lvm2  | grep f21
    [. . .]
         f21-updates-testing  lvm2-2.02.111-1.fc21
                         f21  lvm2-2.02.111-1.fc21
       f21-updates-candidate  lvm2-2.02.111-1.fc21


> I think this can be closed as NOTABUG,
> can't it?

Yes, this is not a libvirt bug, so, closing the bug per rationale noted above.

Comment 14 Richard W.M. Jones 2015-08-10 20:58:40 UTC
FWIW I just hit this error on a fresh F22 @Core install.

The cause was because I didn't have 'qemu' & 'libvirt-daemon-kvm'
installed.

The error was in no way obvious.


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