Bug 1151404

Summary: libvirt fails to display a decent error when qemu-bridge-helper has an error
Product: [Community] Virtualization Tools Reporter: Richard W.M. Jones <rjones>
Component: libvirtAssignee: Libvirt Maintainers <libvirt-maint>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: unspecifiedCC: agedosier, berrange, clalancette, crobinso, gergely, itamar, jforbes, laine, libvirt-maint, pioto, rbalakri, veillard, virt-maint
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-04-10 19:33:26 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:
Bug Depends On:    
Bug Blocks: 910269    
Description Flags
libvirtd.log from failure (xz-compressed) none

Description Richard W.M. Jones 2014-10-10 10:22:28 UTC
Description of problem:

libvirt will not start a guest with an <interface>.  The error is:

Original error from libvirt: failed to retrieve file descriptor for interface: Permission denied [code=38 domain=10]

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


How reproducible:


Steps to Reproduce:
1. guestfish --network -a /dev/null run -v -x

Additional information:

libvirt XML:

<?xml version="1.0"?>\n<domain type="kvm" xmlns:qemu="http://libvirt.org/schemas/domain/qemu/1.0">\n  <name>guestfs-3bxsyfwk7j9gwfoi</name>\n  <memory unit="MiB">500</memory>\n  <currentMemory unit="MiB">500</currentMemory>\n  <cpu mode="host-passthrough">\n    <model fallback="allow"/>\n  </cpu>\n  <vcpu>1</vcpu>\n  <clock offset="utc">\n    <timer name="rtc" tickpolicy="catchup"/>\n    <timer name="pit" tickpolicy="delay"/>\n    <timer name="hpet" present="no"/>\n  </clock>\n  <os>\n    <type>hvm</type>\n    <kernel>/var/tmp/.guestfs-1000/appliance.d/kernel</kernel>\n    <initrd>/var/tmp/.guestfs-1000/appliance.d/initrd</initrd>\n    <cmdline>panic=1 console=ttyS0 udevtimeout=6000 no_timer_check acpi=off printk.time=1 cgroup_disable=memory root=/dev/sdb selinux=0 guestfs_verbose=1 guestfs_network=1 TERM=xterm-256color</cmdline>\n    <bios useserial="yes"/>\n  </os>\n  <on_reboot>destroy</on_reboot>\n  <devices>\n    <controller type="scsi" index="0" model="virtio-scsi"/>\n    <disk device="disk" type="file">\n      <source file="/tmp/libguestfsKRohGj/devnull1"/>\n      <target dev="sda" bus="scsi"/>\n      <driver name="qemu" type="raw" cache="writeback"/>\n      <address type="drive" controller="0" bus="0" target="0" unit="0"/>\n    </disk>\n    <disk type="file" device="disk">\n      <source file="/tmp/libguestfsKRohGj/overlay2"/>\n      <target dev="sdb" bus="scsi"/>\n      <driver name="qemu" type="qcow2" cache="unsafe"/>\n      <address type="drive" controller="0" bus="0" target="1" unit="0"/>\n      <shareable/>\n    </disk>\n    <serial type="unix">\n      <source mode="connect" path="/tmp/libguestfsKRohGj/console.sock"/>\n      <target port="0"/>\n    </serial>\n    <channel type="unix">\n      <source mode="connect" path="/tmp/libguestfsKRohGj/guestfsd.sock"/>\n      <target type="virtio" name="org.libguestfs.channel.0"/>\n    </channel>\n    <interface type="bridge">\n      <source bridge="virbr0"/>\n      <model type="virtio"/>\n    </interface>\n  </devices>\n  <qemu:commandline>\n    <qemu:env name="TMPDIR" value="/var/tmp"/>\n  </qemu:commandline>\n</domain>\n

Comment 1 Richard W.M. Jones 2014-10-10 10:22:59 UTC
It happens whether SELinux is Permissive or Enforcing, so it
does not seem to be an SELinux problem.

Comment 2 Richard W.M. Jones 2014-10-10 10:37:07 UTC
Created attachment 945552 [details]
libvirtd.log from failure (xz-compressed)

The relevant bit seems to be:

2014-10-10 10:34:15.367+0000: 6839: error : qemuCreateInBridgePortWithHelper:267 : failed to retrieve file descriptor for interface: Permission denied
2014-10-10 10:34:15.368+0000: 6839: debug : virProcessAbort:104 : aborting child process 6974

Comment 3 Richard W.M. Jones 2014-10-10 10:42:34 UTC
To give it a bit more context:

2014-10-10 10:34:15.328+0000: 6839: debug : virCommandRunAsync:2265 : About to r
un /usr/libexec/qemu-bridge-helper --use-vnet --br=virbr0 --fd=23
2014-10-10 10:34:15.332+0000: 6839: debug : virFileClose:90 : Closed fd 24
2014-10-10 10:34:15.332+0000: 6839: debug : virCommandRunAsync:2270 : Command re
sult 0, with PID 6974
2014-10-10 10:34:15.332+0000: 6839: debug : virFileClose:90 : Closed fd 23
2014-10-10 10:34:15.367+0000: 6839: error : qemuCreateInBridgePortWithHelper:267 : failed to retrieve file descriptor for interface: Permission denied

$ ll /usr/libexec/qemu-bridge-helper 
-rwsr-xr-x. 1 root root 15344 Sep 26 16:10 /usr/libexec/qemu-bridge-helper

Why would this fail?

Comment 4 Richard W.M. Jones 2014-10-10 13:32:16 UTC
The libvirt bug here is that libvirt hides the underlying
error from qemu-bridge helper.

The underlying error is:

$ /usr/libexec/qemu-bridge-helper --use-vnet --br=virbr0 --fd=1
failed to open /dev/net/tun: Permission denied
$ ll /dev/net/tun 
crw-------. 1 root root 10, 200 Oct 10 10:09 /dev/net/tun

I've not changed the permissions on this file.  The expected
permissions are 0666.

The timestamp on the file is the same (to the nearest second)
as an update of systemd, according to /var/log/yum.log

Oct 10 10:09:21 Updated: systemd-208-22.fc20.x86_64

Comment 5 Richard W.M. Jones 2014-10-10 18:00:12 UTC
The permissions thing is probably

Comment 6 Gergely Polonkai 2014-11-14 23:26:19 UTC
The same happens with me, except my /dev/net/tun has the expected 0666 rights. I failed to produce any logs so far, but I’m on it (any pointers on how to do it are appreciated). The machine was created with GNOME Boxes. If I change the interface to 'user' instead of 'bridge', I can start it with

$ virsh start testrunner

with interface type 'bridge' I get

error: failed to retrieve file descriptor for interface: Permission denied

Comment 7 Gergely Polonkai 2014-11-14 23:44:52 UTC
Some additional information:

SELinux is enabled and enforcing. No relevant lines in audit.log.

Meanwhile I found some info on how to enable logging. However, I failed to set it up correctly (log_outputs="1:file:/var/log/libvirt/libvirtd.log" in libvirtd.conf, service has been restarted afterwards), as there is nothing written to it after libvirtd is started (e.g. when I invoke virsh start testrunner).

Comment 8 Fedora End Of Life 2015-05-29 13:03:40 UTC
This message is a reminder that Fedora 20 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 20. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '20'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 20 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 9 Cole Robinson 2016-04-10 19:33:26 UTC
This was fixed by:

commit db35beaa1d276cc229dcbbc8460ce2fccdda5084
Author: Cole Robinson <crobinso@redhat.com>
Date:   Thu Sep 10 12:35:00 2015 -0400

    qemu: command: Report stderr from qemu-bridge-helper