Bug 484028 – app-emulation/libvirt fails to start VMs with error virCommandHandshakeWait:2465 : Child quit during startup handshake: Input/output error while selinux is enforcing

• Product: Gentoo Linux
• Status: RESOLVED NEEDINFO

[Description Kristopher Henry Kram 2013-09-06 17:33:28 UTC]

Attempting to start a VM using libvirt(1.1.1-r5,1.1.2) with virsh or virt-manager while selinux is in enforcing cause libvirt-1.1.1 to crash and not start the VM. In 1.1.2 libvirt does not crash but does not start the VM. When i disable selinux everything works as it should.

Reproducible: Always

Steps to Reproduce:
1. Enforce selinux
2. Start a libvirt VM
3. Get error
Actual Results:  
Got error : virCommandHandshakeWait:2465 : Child quit during startup handshake: Input/output error in both virsh,virt-manager and in the libvirtd.log. Then libvirt crashes if 1.1.1 or doesn't in 1.1.2. It dosen't star the VM in either.

Expected Results:  
The VM starts.

emerge_info.txt

Portage 2.1.12.2 (hardened/linux/amd64/selinux, gcc-4.6.3, glibc-2.15-r3, 3.2.50-hardened-r4-KHD24 x86_64)
=================================================================
System uname: Linux-3.2.50-hardened-r4-KHD24-x86_64-Intel-R-_Core-TM-_i5-2410M_CPU_@_2.30GHz-with-gentoo-2.2
KiB Mem:     3958268 total,    588820 free
KiB Swap:   20479996 total,  20479864 free
Timestamp of tree: Fri, 06 Sep 2013 15:45:01 +0000
ld GNU ld (GNU Binutils) 2.23.1
app-shells/bash:          4.2_p45
dev-lang/python:          2.7.5-r2, 3.2.5-r2
dev-util/cmake:           2.8.10.2-r2
dev-util/pkgconfig:       0.28
sys-apps/baselayout:      2.2
sys-apps/openrc:          0.11.8
sys-apps/sandbox:         2.6-r1
sys-devel/autoconf:       2.13, 2.69
sys-devel/automake:       1.10.3, 1.12.6, 1.13.4
sys-devel/binutils:       2.23.1
sys-devel/gcc:            4.6.3
sys-devel/gcc-config:     1.7.3
sys-devel/libtool:        2.4-r1
sys-devel/make:           3.82-r4
sys-kernel/linux-headers: 3.9 (virtual/os-headers)
sys-libs/glibc:           2.15-r3
Repositories: gentoo
ACCEPT_KEYWORDS="amd64"
ACCEPT_LICENSE="* -@EULA"
CBUILD="x86_64-pc-linux-gnu"
CFLAGS="-march=native -O2 -pipe"
CHOST="x86_64-pc-linux-gnu"
CONFIG_PROTECT="/etc /usr/share/config /usr/share/gnupg/qualified.txt"
CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/dconf /etc/env.d /etc/fonts/fonts.conf /etc/gconf /etc/gentoo-release /etc/revdep-rebuild /etc/sandbox.d /etc/terminfo"
CXXFLAGS="-march=native -O2 -pipe"
DISTDIR="/usr/portage/distfiles"
FCFLAGS="-O2 -pipe"
FEATURES="assume-digests binpkg-logs config-protect-if-modified distlocks ebuild-locks fixlafiles merge-sync news parallel-fetch preserve-libs protect-owned sandbox selinux sesandbox sfperms strict unknown-features-warn unmerge-logs unmerge-orphans userfetch xattr"
FFLAGS="-O2 -pipe"
GENTOO_MIRRORS="http://lug.mtu.edu/gentoo/ http://portage.org.ua/ http://mirror.mcs.anl.gov/pub/gentoo/ http://mirror.datapipe.net/gentoo http://gentoo.mirrors.easynews.com/linux/gentoo/ http://chi-10g-1-mirror.fastsoft.net/pub/linux/gentoo/gentoo-distfiles/ http://gentoo.mirrors.hoobly.com/ http://gentoo.netnitco.net"
LDFLAGS="-Wl,-O1 -Wl,--as-needed"
MAKEOPTS="-j5"
PKGDIR="/usr/portage/packages"
PORTAGE_CONFIGROOT="/"
PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --compress --force --whole-file --delete --stats --human-readable --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages"
PORTAGE_TMPDIR="/var/tmp"
PORTDIR="/usr/portage"
PORTDIR_OVERLAY=""
SYNC="rsync://rsync.us.gentoo.org/gentoo-portage"
USE="X acpi alsa amd64 apm apng audit berkdb bzip2 cli consolekit cpuload cracklib crypt cryptsetup cxx dbus device-mapper dri gdbm gif gmp gpm gtk gtk3 gudev gui hardened hwdb iconv imlib ipv6 iso jpeg jpg justify libcanberra libnotify lm_sensors lvm lzma lzo mem-scramble mmx modules mudflap multilib multislot ncurses networkmonitor nls nptl ogg open_perms opengl openmp osmesa pam pax_kernel pcre pmu png policykit python qt qt3support qt4 razor readline screensaver sdl secure-delete selinux sensord sensors session sna spell spice sqlite sse sse2 sse3 sse4 ssl startup-notification systemtap tcpd threads tiff truetype udev unicode urandom usb usbredir vde virt-network virtfs vorbis xattr xml zlib" ABI_X86="64" ALSA_CARDS="ali5451 als4000 atiixp atiixp-modem bt87x ca0106 cmipci emu10k1x ens1370 ens1371 es1938 es1968 fm801 hda-intel intel8x0 intel8x0m maestro3 trident usb-audio via82xx via82xx-modem ymfpci" APACHE2_MODULES="authn_core authz_core socache_shmcb unixd actions alias auth_basic authn_alias authn_anon authn_dbm authn_default authn_file authz_dbm authz_default authz_groupfile authz_host authz_owner authz_user autoindex cache cgi cgid dav dav_fs dav_lock deflate dir disk_cache env expires ext_filter file_cache filter headers include info log_config logio mem_cache mime mime_magic negotiation rewrite setenvif speling status unique_id userdir usertrack vhost_alias" CALLIGRA_FEATURES="kexi words flow plan sheets stage tables krita karbon braindump author" CAMERAS="ptp2" COLLECTD_PLUGINS="df interface irq load memory rrdtool swap syslog" ELIBC="glibc" GPSD_PROTOCOLS="ashtech aivdm earthmate evermore fv18 garmin garmintxt gpsclock itrax mtk3301 nmea ntrip navcom oceanserver oldstyle oncore rtcm104v2 rtcm104v3 sirf superstar2 timing tsip tripmate tnt ubx" GRUB_PLATFORMS="pc multiboot" INPUT_DEVICES="keyboard mouse evdev" KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 lcdm001 mtxorb ncurses text" LIBREOFFICE_EXTENSIONS="presenter-console presenter-minimizer" LINGUAS="en en_US en_GB" OFFICE_IMPLEMENTATION="libreoffice" PHP_TARGETS="php5-5" PYTHON_SINGLE_TARGET="python2_7" PYTHON_TARGETS="python2_7 python3_2" RUBY_TARGETS="ruby19 ruby18" USERLAND="GNU" VIDEO_CARDS="nouveau intel" XTABLES_ADDONS="quota2 psd pknock lscan length2 ipv4options ipset ipp2p iface geoip fuzzy condition tee tarpit sysrq steal rawnat logmark ipmark dhcpmac delude chaos account"
Unset:  CPPFLAGS, CTARGET, EMERGE_DEFAULT_OPTS, INSTALL_MASK, LANG, LC_ALL, PORTAGE_BUNZIP2_COMMAND, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS, USE_PYTHON

gentoostart_selinux_enforcing.txt

type=VIRT_MACHINE_ID msg=audit(1378486954.790:46266): user pid=8156 uid=0 auid=1000 ses=2 subj=system_u:system_r:virtd_t msg='virt=kvm vm="gentootest" uuid=bf91af38-4eda-51f6-1e62-aada8c9fe1b8 vm-ctx=system_u:system_r:svirt_t:s0:c188,c729 img-ctx=system_u:object_r:svirt_image_t:s0:c188,c729 model=selinux: exe="/usr/sbin/libvirtd" hostname=? addr=? terminal=? res=success'
type=VIRT_MACHINE_ID msg=audit(1378486954.790:46267): user pid=8156 uid=0 auid=1000 ses=2 subj=system_u:system_r:virtd_t msg='virt=kvm vm="gentootest" uuid=bf91af38-4eda-51f6-1e62-aada8c9fe1b8 vm-ctx=77:102 img-ctx=77:102 model=dac: exe="/usr/sbin/libvirtd" hostname=? addr=? terminal=? res=success'
type=VIRT_RESOURCE msg=audit(1378486954.790:46268): user pid=8156 uid=0 auid=1000 ses=2 subj=system_u:system_r:virtd_t msg='virt=kvm resrc=mem reason=start vm="gentootest" uuid=bf91af38-4eda-51f6-1e62-aada8c9fe1b8 old-mem=0 new-mem=1127424: exe="/usr/sbin/libvirtd" hostname=? addr=? terminal=? res=success'
type=VIRT_RESOURCE msg=audit(1378486954.790:46269): user pid=8156 uid=0 auid=1000 ses=2 subj=system_u:system_r:virtd_t msg='virt=kvm resrc=vcpu reason=start vm="gentootest" uuid=bf91af38-4eda-51f6-1e62-aada8c9fe1b8 old-vcpu=0 new-vcpu=4: exe="/usr/sbin/libvirtd" hostname=? addr=? terminal=? res=success'
type=VIRT_CONTROL msg=audit(1378486954.790:46270): user pid=8156 uid=0 auid=1000 ses=2 subj=system_u:system_r:virtd_t msg='virt=kvm op=start reason=booted vm="gentootest" uuid=bf91af38-4eda-51f6-1e62-aada8c9fe1b8 vm-pid=-1: exe="/usr/sbin/libvirtd" hostname=? addr=? terminal=? res=failed'


gentoostart_selinux_permissive.txt

type=MAC_STATUS msg=audit(1378487076.850:46273): enforcing=0 old_enforcing=1 auid=1000 ses=2
type=VIRT_MACHINE_ID msg=audit(1378487096.530:46274): user pid=8156 uid=0 auid=1000 ses=2 subj=system_u:system_r:virtd_t msg='virt=kvm vm="gentootest" uuid=bf91af38-4eda-51f6-1e62-aada8c9fe1b8 vm-ctx=system_u:system_r:svirt_t:s0:c270,c277 img-ctx=system_u:object_r:svirt_image_t:s0:c270,c277 model=selinux: exe="/usr/sbin/libvirtd" hostname=? addr=? terminal=? res=success'
type=VIRT_MACHINE_ID msg=audit(1378487096.530:46275): user pid=8156 uid=0 auid=1000 ses=2 subj=system_u:system_r:virtd_t msg='virt=kvm vm="gentootest" uuid=bf91af38-4eda-51f6-1e62-aada8c9fe1b8 vm-ctx=77:102 img-ctx=77:102 model=dac: exe="/usr/sbin/libvirtd" hostname=? addr=? terminal=? res=success'
type=VIRT_RESOURCE msg=audit(1378487103.830:46276): user pid=8156 uid=0 auid=1000 ses=2 subj=system_u:system_r:virtd_t msg='virt=kvm resrc=mem reason=start vm="gentootest" uuid=bf91af38-4eda-51f6-1e62-aada8c9fe1b8 old-mem=0 new-mem=1127424: exe="/usr/sbin/libvirtd" hostname=? addr=? terminal=? res=success'
type=VIRT_RESOURCE msg=audit(1378487103.830:46277): user pid=8156 uid=0 auid=1000 ses=2 subj=system_u:system_r:virtd_t msg='virt=kvm resrc=vcpu reason=start vm="gentootest" uuid=bf91af38-4eda-51f6-1e62-aada8c9fe1b8 old-vcpu=0 new-vcpu=4: exe="/usr/sbin/libvirtd" hostname=? addr=? terminal=? res=success'
type=VIRT_CONTROL msg=audit(1378487103.830:46278): user pid=8156 uid=0 auid=1000 ses=2 subj=system_u:system_r:virtd_t msg='virt=kvm op=start reason=booted vm="gentootest" uuid=bf91af38-4eda-51f6-1e62-aada8c9fe1b8 vm-pid=8782: exe="/usr/sbin/libvirtd" hostname=? addr=? terminal=? res=success'
type=VIRT_CONTROL msg=audit(1378487111.900:46279): user pid=8156 uid=0 auid=1000 ses=2 subj=system_u:system_r:virtd_t msg='virt=kvm op=stop reason=destroyed vm="gentootest" uuid=bf91af38-4eda-51f6-1e62-aada8c9fe1b8 vm-pid=-1: exe="/usr/sbin/libvirtd" hostname=? addr=? terminal=? res=success'


libvirtd.log

2013-09-06 16:57:54.939+0000: 8167: info : libvirt version: 1.1.2
2013-09-06 16:57:54.939+0000: 8167: error : udevGetDMIData:1558 : Failed to get udev device for syspath '/sys/devices/virtual/dmi/id' or '/sys/class/dmi/id'
2013-09-06 16:57:55.074+0000: 8167: error : virCommandWait:2348 : internal error: Child process (/bin/sh -c 'EBT="/sbin/ebtables"
cmd='\''$EBT -t nat -L'\''
eval res=\$\("${cmd} 2>&1"\)
if [ $? -ne 0 ]; then  echo "Failure to execute command '\''${cmd}'\'' : '\''${res}'\''.";  exit 1;fi
') unexpected exit status 1
2013-09-06 16:57:55.075+0000: 8167: error : ebiptablesDriverTestCLITools:4274 : Testing of ebtables command failed: Failure to execute command '$EBT -t nat -L' : 'The kernel doesn't support the ebtables 'nat' table.'.

2013-09-06 16:58:36.818+0000: 8157: error : virCommandHandshakeWait:2465 : Child quit during startup handshake: Input/output error
2013-09-06 16:59:30.710+0000: 8159: warning : qemuOpenVhostNet:495 : Unable to open vhost-net. Opened so far 0, requested 1
2013-09-06 16:59:30.769+0000: 8159: error : virCommandHandshakeWait:2465 : Child quit during startup handshake: Input/output error
2013-09-06 16:59:45.530+0000: 8159: error : virCommandHandshakeWait:2465 : Child quit during startup handshake: Input/output error
2013-09-06 17:00:52.449+0000: 8160: error : virCommandHandshakeWait:2465 : Child quit during startup handshake: Input/output error
2013-09-06 17:00:56.073+0000: 8160: error : virCommandHandshakeWait:2465 : Child quit during startup handshake: Input/output error
2013-09-06 17:01:35.200+0000: 8157: warning : qemuOpenVhostNet:495 : Unable to open vhost-net. Opened so far 0, requested 1
2013-09-06 17:01:35.259+0000: 8157: error : virCommandHandshakeWait:2465 : Child quit during startup handshake: Input/output error
2013-09-06 17:01:49.989+0000: 8159: warning : qemuOpenVhostNet:495 : Unable to open vhost-net. Opened so far 0, requested 1
2013-09-06 17:01:50.109+0000: 8159: error : virCommandHandshakeWait:2465 : Child quit during startup handshake: Input/output error
2013-09-06 17:02:34.809+0000: 8158: error : virCommandHandshakeWait:2465 : Child quit during startup handshake: Input/output error

[Comment 1 Kristopher Henry Kram 2013-09-06 17:35:27 UTC]

Created attachment 358094 [details]
libvirtd.log

[Comment 2 Kristopher Henry Kram 2013-09-06 17:36:07 UTC]

Created attachment 358096 [details]
emerge_info.txt

[Comment 3 Kristopher Henry Kram 2013-09-06 17:36:28 UTC]

Created attachment 358098 [details]
gentoostart_selinux_enforcing.txt

[Comment 4 Kristopher Henry Kram 2013-09-06 17:36:45 UTC]

Created attachment 358100 [details]
gentoostart_selinux_permissive.txt

[Comment 5 Sven Vermeulen (RETIRED) 2013-10-27 18:30:50 UTC]

When you say "When i disable selinux everything works as it should." do you mean run with SELinux in permissive mode? Or really disabled?

The logs you show show no AVC denials (which does not surprise me as libvirt is SELinux-aware, so it changes its behavior when SELinux is enabled and might just query the policy to decide on its actions - as a result, libvirt never really tries something, so no denials are logged). Just to make sure, if things do work in permissive mode (but not in enforcing), care to disable the dontaudits?

You can do so using "semodule -DB".

Don't forget to re-enable them (semodule -B) afterwards, otherwise your audit logs will be cluttered with (useless) denials.