Bug 1185850 - internal error: could not get interface XML description: File operation failed - Failed to read (null)
internal error: could not get interface XML description: File operation faile...
Status: CLOSED ERRATA
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: netcf (Show other bugs)
7.1
Unspecified Unspecified
high Severity unspecified
: rc
: ---
Assigned To: Laine Stump
Virtualization Bugs
: Regression
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2015-01-26 07:40 EST by Lukáš Nykrýn
Modified: 2015-03-05 03:51 EST (History)
13 users (show)

See Also:
Fixed In Version: netcf-0.2.6-3.el7
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2015-03-05 03:51:24 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
journalctl -b -u libvirtd.service (212.43 KB, text/x-vhdl)
2015-01-26 07:41 EST, Lukáš Nykrýn
no flags Details

  None (edit)
Description Lukáš Nykrýn 2015-01-26 07:40:51 EST
Description of problem:
Virtmanager and libvirtd currently does not work for me

Version-Release number of selected component (if applicable):
libvirt-1.2.8-15.el7.x86_64
virt-manager-1.1.0-12.el7.noarch

From virtmanager:
Error polling connection 'qemu:///system': internal error: could not get interface XML description: File operation failed - Failed to read (null)

Traceback (most recent call last):
  File "/usr/share/virt-manager/virtManager/engine.py", line 341, in _handle_tick_queue
    conn.tick(**kwargs)
  File "/usr/share/virt-manager/virtManager/connection.py", line 1136, in tick
    raise e  # pylint: disable=raising-bad-type
libvirtError: internal error: could not get interface XML description: File operation failed - Failed to read (null)
Comment 1 Lukáš Nykrýn 2015-01-26 07:41:24 EST
Created attachment 984203 [details]
journalctl -b -u  libvirtd.service
Comment 3 Ján Tomko 2015-01-26 08:57:43 EST
The error message comes from netcf.

The only case of that error being reported with path already freed is here:
https://git.fedorahosted.org/cgit/netcf.git/tree/src/dutil_linux.c#n1080
when accessing:
"/sys/class/net/%s/operstate", ifname

Can you check if that file is readable for all interfaces?
Comment 4 Laine Stump 2015-01-26 14:32:23 EST
I wonder if it's possible for operstate to not exist for any particular net driver, or possibly is is 0 length. Can you also do "cd /sys/class/net; ls -ld * */operstate" so we can check for the presence of any net device that doesn't have operstate.

If you do find such a device, you should try running 

virsh nodedev-dumpxml $(virsh nodedev-list | grep $devicename | sort | tail -)

My guess is that command will fail for the same device.

If there are net devices lacking operstate then both libvirt's nodedevice driver and netcf will need to be more forgiving in the face of failure.
Comment 5 Laine Stump 2015-01-26 14:35:54 EST
Oops - that command should be:

virsh nodedev-dumpxml $(virsh nodedev-list | grep $devicename | sort | tail -1 )

(the "1" missed the cut-paste somehow)
Comment 6 Laine Stump 2015-01-26 14:47:54 EST
Here is a command to list all the interfaces that netcf recognizes and attempt to get their status XML (which I believe is what virt-manager is doing):

  virsh iface-list --all | tail -n +3 | cut -f2 -d' ' \
   | while read intf; do if [ "$intf" != "" ]; then \
   echo ++++ $intf ++++; virsh iface-dumpxml $intf; fi; done

The iface-dumpxml command should fail for the interface that is giving the problem.
Comment 7 Laine Stump 2015-01-26 16:58:59 EST
If nothing else, netcf should do a better job of reporting the error. In addition to keeping around the path until after we've finished with it (so we log the actual path instead of "(null)", the macro used to record the error already turns errno into a string in the local named errbuf, so we should be including that in the log message.

I just posted this to the upstream netcf-devel mailing list. It won't fix the root cause, but should make the error log much more informative:

  https://lists.fedorahosted.org/pipermail/netcf-devel/2015-January/000920.html
Comment 10 Lukáš Nykrýn 2015-01-27 07:07:01 EST
Thanks! Much better.
It looks that this was my fault:
Error polling connection 'qemu:///system': internal error: could not get interface XML description: File operation failed - Failed to read /sys/class/net/lo:0/operstate : No  such file or directory

There was a leftover from a testing of an initscript bug.
[root@notas network-scripts]# cat ifcfg-lo:0
DEVICE=lo:0
ONBOOT=yes
IPV6INIT=yes
IPV6ADDR=abc::1/128
NM_CONTROLLED="no"
Comment 12 Laine Stump 2015-01-27 12:02:29 EST
I'm actually concerned about the results of this - "lo:0" is an "alias interface", which is a deprecated (but likely still used) method of putting multiple IP addresses on a single physical interface. If any customer has an alias interface, virt-manager will refuse to work. I think we need to make this not an error condition.
Comment 13 Laine Stump 2015-01-27 12:14:15 EST
I've checked and the code that adds operstate (and speed) to the interface status was added in netcf-0.2.5 and wasn't in RHEL7.0, so this behavior is a regression from RHEL7.0 I'm adding the Regression keyword.
Comment 16 Laine Stump 2015-01-27 13:19:16 EST
Here is the patch (along with the previously mentioned short patch) to solve this problem:

https://lists.fedorahosted.org/pipermail/netcf-devel/2015-January/000924.html

All it does is to turn an error condition into an "add empty/0 placeholders" condition. Because it only changes an error condition into an innocuous non-error condition, the chance of further regression is very low.

To test it, you just need to add an ifcfg file for an alias interface to /etc/sysconfig/network-scripts. The ifcfg file in Comment 10 would be adequate (or you could take any existing ifcfg file for an ethernet device that has a static IP address, eg "ifcfg-enp9s0", copy it to e.g. "ifcfg-enp9s0:0", then edit the copy to change the following lines:

  DEVICE="enp9s0:0"
  IPADDR="some other IP address"

then finally run "ifup enp9s0:0". After this is done, without the patch above virt-manager will refuse to run and "ncftool dumpxml enp9s0:0" will return an error. With the patch, virt-manager will run, and ncftool will complete successfully (although the produced xml will be nearly empty).

Again - without this patch every user who has an alias interface defined will be unable to run virt-manager once they upgrade from rhel 7.0 to rhel 7.1.
Comment 17 tingting zheng 2015-01-28 00:12:07 EST
I can reproduce it by add config file:
# cat ifcfg-lo:0
DEVICE=lo:0
ONBOOT=yes
IPV6INIT=yes
IPV6ADDR=abc::1/128
NM_CONTROLLED="no"

# ifup lo:0

# virt-manager
error shows as description:
Error polling connection 'qemu:///system': internal error: could not get interface XML description: File operation failed - Failed to read (null)
Comment 19 Lukáš Nykrýn 2015-01-28 03:21:17 EST
Just a small note, using configuration file from comment 10 will result to error in our rhel7 initscripts. So don't be surprised if you see some error message.
(upstream fix: https://git.fedorahosted.org/cgit/initscripts.git/commit/?id=a9c3e6924fc8b39ee6c7a7ba93bc392d1bc40a95 )
Comment 22 Hu Jianwei 2015-01-28 21:43:15 EST
I can reproduce it on below version.
[root@localhost network-scripts]# rpm -q netcf
netcf-0.2.6-2.el7.x86_64
libvirt-1.2.8-15.el7.x86_64

[root@localhost network-scripts]# cat /etc/sysconfig/network-scripts/ifcfg-eno1:0
DEVICE=eno1:0
ONBOOT=yes
IPADDR=192.168.1.8
NETMASK=255.255.255.0

[root@localhost network-scripts]# ncftool dumpxml eno1:0 --live
error: File operation failed
error: Failed to read (null)

[root@localhost network-scripts]# virsh iface-dumpxml eno1:0
error: internal error: could not get interface XML description: File operation failed - Failed to read (null)


Verified as below:
[root@localhost ~]# rpm -q netcf libvirt
netcf-0.2.6-3.el7.x86_64
libvirt-1.2.8-15.el7.x86_64

[root@localhost ~]# cat /etc/sysconfig/network-scripts/ifcfg-eno1:0
DEVICE=eno1:0
ONBOOT=yes
IPADDR=192.168.1.8
NETMASK=255.255.255.0

[root@localhost ~]# ncftool dumpxml eno1:0 --live
<?xml version="1.0"?>
<interface name="eno1:0" type="ethernet">
  <link state="" speed="0"/>
</interface>

[root@localhost ~]# ncftool dumpxml eno1:0 
<?xml version="1.0"?>
<interface type="ethernet" name="eno1:0">
  <start mode="onboot"/>
  <protocol family="ipv4">
    <ip address="192.168.1.8" prefix="24"/>
  </protocol>
</interface>

[root@localhost ~]# virsh iface-dumpxml eno1:0
<interface type='ethernet' name='eno1:0'>
</interface>

Using virt-manager, it can be started, no error occurred.
[root@localhost ~]# virt-manager --debug
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (cli:208) Launched with command line: /usr/share/virt-manager/virt-manager --debug
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (virt-manager:147) virt-manager version: 1.1.0
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (virt-manager:148) virtManager import: <module 'virtManager' from '/usr/share/virt-manager/virtManager/__init__.pyc'>

** (virt-manager:17859): WARNING **: Couldn't connect to accessibility bus: Failed to connect to socket /tmp/dbus-RHbCj0CgHO: Connection refused
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (virt-manager:206) GTK version: 3.8.8
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] ERROR (importer:51) Could not find any typelib for AppIndicator3
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (engine:455) libguestfs inspection support: False
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (systray:150) Showing systray: False
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (engine:229) About to connect to uris ['qemu:///system']
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (manager:208) Showing manager
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (engine:356) window counter incremented to 1
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:947) Scheduling background open thread for qemu:///system
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:961) Background 'open connection' thread is running
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1012) Background open thread complete, scheduling notify
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1017) Notifying open result
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1023) libvirt version=1002008
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1025) daemon version=1002008
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1026) conn version=2001002
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1028) qemu:///system capabilities:
<capabilities>

  <host>
    <uuid>00c1fcdb-9fd8-e111-852c-24be051881ce</uuid>
    <cpu>
 ...(clipped)
</capabilities>

[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:800) Using domain events
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:834) Using network events
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:210) Using libvirt API for mediadev enumeration
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1199) domain=virt-tests-vm1 status=Shutoff added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1199) domain=r7a status=Shutoff added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1199) domain=win7 status=Shutoff added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1199) domain=libvirt_test_api status=Running added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1199) domain=r71 status=Running added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1208) network=vepa-net added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1208) network=passthrough-net added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1208) network=hostdev-net added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1208) network=default added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1208) network=route-net added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1208) network=bridge-net added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1208) network=private-net added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1221) pool=default added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1221) pool=root added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1221) pool=images-5 added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1221) pool=images added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1221) pool=images-4 added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1221) pool=images-7 added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1221) pool=images-6 added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1221) pool=images-1 added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1221) pool=images-3 added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1221) pool=images-2 added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1234) interface=enp2s0 added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1234) interface=lo:0 added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1234) interface=lo added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1234) interface=eno1 added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1234) interface=eno1:0 added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:1234) interface=eth1 added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:856) mediadev=block_sr0_hp_DVD_RAM_GH82N_228CD038950 added
[Thu, 29 Jan 2015 10:34:48 virt-manager 17859] DEBUG (connection:856) mediadev=block_sr0_hp_DVD_RAM_GH82N_228CD038950 added

[Thu, 29 Jan 2015 10:34:53 virt-manager 17859] DEBUG (manager:219) Closing manager
[Thu, 29 Jan 2015 10:34:53 virt-manager 17859] DEBUG (engine:360) window counter decremented to 0
[Thu, 29 Jan 2015 10:34:53 virt-manager 17859] DEBUG (connection:883) conn.close() uri=qemu:///system
[Thu, 29 Jan 2015 10:34:53 virt-manager 17859] DEBUG (engine:442) Exiting app normally.

So move to Verified.
Comment 24 errata-xmlrpc 2015-03-05 03:51:24 EST
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHBA-2015-0363.html

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