Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1154672

Summary: [hosted-engine] [selinux] Unknown libvirterror: ecode: 38 edom: 0 level: 2 message: Child quit during startup handshake: Input/output error
Product: Red Hat Enterprise Virtualization Manager Reporter: Jiri Belka <jbelka>
Component: vdsmAssignee: Nobody <nobody>
Status: CLOSED CURRENTRELEASE QA Contact: meital avital <mavital>
Severity: urgent Docs Contact:
Priority: urgent    
Version: 3.5.0CC: bazulay, danken, didi, ecohen, gklein, iheim, jbelka, lpeer, lsurette, lveyde, michal.skrivanek, sbonazzo, stirabos, yeylon
Target Milestone: ---Keywords: Regression
Target Release: 3.5.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard: virt
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-10-31 14:41:28 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:
Embargoed:
Attachments:
Description Flags
/var/log/vdsm logs
none
logs none

Description Jiri Belka 2014-10-20 13:29:24 UTC
Created attachment 948557 [details]
/var/log/vdsm logs

Description of problem:

# hosted-engine --deploy on rhel6.6 and latest d/s build.
...
[ INFO  ] Creating VM
[ ERROR ] Failed to execute stage 'Closing up': Cannot set temporary password for console connection. The VM may not have been created: please check VDSM logs
[ INFO  ] Stage: Clean up
[ INFO  ] Generating answer file '/etc/ovirt-hosted-engine/answers.conf'
[ INFO  ] Answer file '/etc/ovirt-hosted-engine/answers.conf' has been updated
[ INFO  ] Stage: Pre-termination
[ INFO  ] Stage: Termination

...
Thread-90::DEBUG::2014-10-20 15:06:09,183::BindingXMLRPC::1132::vds::(wrapper) client [127.0.0.1]::call vmSetTicket with ('b438d986-e670-4c00-ae7c-5b5a10aefd94', '1346ChDi', '10800', 'disconnect', {}) {}
Thread-90::ERROR::2014-10-20 15:06:09,183::BindingXMLRPC::1151::vds::(wrapper) unexpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/rpc/BindingXMLRPC.py", line 1135, in wrapper
    res = f(*args, **kwargs)
  File "/usr/share/vdsm/rpc/BindingXMLRPC.py", line 383, in vmSetTicket
    return vm.setTicket(password, ttl, existingConnAction, params)
  File "/usr/share/vdsm/API.py", line 634, in setTicket
    return v.setTicket(password, ttl, existingConnAction, params)
  File "/usr/share/vdsm/virt/vm.py", line 4721, in setTicket
    graphics = _domParseStr(self._dom.XMLDesc(0)).childNodes[0]. \
AttributeError: 'NoneType' object has no attribute 'XMLDesc'

Version-Release number of selected component (if applicable):
vdsm-4.16.7-1.el6ev.x86_64
ovirt-hosted-engine-setup-1.2.1-1.el6ev.noarch

How reproducible:
100%

Steps to Reproduce:
1. hosted-engine --deploy on rhel6.6
2.
3.

Actual results:
failure

Expected results:
should work

Additional info:
- re-running hosted-engine --deploy ends in other error :D

...
[ ERROR ] The following VMs has been found: b438d986-e670-4c00-ae7c-5b5a10aefd94
[ ERROR ] Failed to execute stage 'Environment setup': Cannot setup Hosted Engine with other VMs running
[ INFO  ] Stage: Clean up
[ INFO  ] Generating answer file '/etc/ovirt-hosted-engine/answers.conf'
[ INFO  ] Answer file '/etc/ovirt-hosted-engine/answers.conf' has been updated
[ INFO  ] Stage: Pre-termination
[ INFO  ] Stage: Termination

Comment 1 Sandro Bonazzola 2014-10-20 14:36:25 UTC
Original error while starting the VM was:

Thread-81::DEBUG::2014-10-20 15:25:13,010::libvirtconnection::143::root::(wrapper) Unknown libvirterror: ecode: 38 edom: 0 level: 2 message: Child quit during startup handshake: Input/output error
Thread-81::DEBUG::2014-10-20 15:25:13,010::vm::2289::vm.Vm::(_startUnderlyingVm) vmId=`c3cd8c5d-40ec-482b-a29d-1c33f980e635`::_ongoingCreations released
Thread-81::ERROR::2014-10-20 15:25:13,011::vm::2326::vm.Vm::(_startUnderlyingVm) vmId=`c3cd8c5d-40ec-482b-a29d-1c33f980e635`::The vm start process failed

without libvirt logs I can't say what happened.
Can you provide libvirt logs?

Comment 2 Jiri Belka 2014-10-21 14:33:43 UTC
Created attachment 948991 [details]
logs

Comment 3 Michal Skrivanek 2014-10-21 15:00:14 UTC
check for SELinux denials. Anything?

Comment 4 Michal Skrivanek 2014-10-21 15:03:50 UTC
the attachment is missing libvirtd.log. Please include.

Comment 5 Jiri Belka 2014-10-22 14:58:36 UTC
[root@dell-r210ii-13 log]# find /var/log -type f -name 'libvirtd.log'
[root@dell-r210ii-13 log]# find /var/log -type f -name 'libvirt*.log'
[root@dell-r210ii-13 log]#

apologize, no libvirtd.log

...
type=AVC msg=audit(1413987296.075:1106): avc:  denied  { search } for  pid=2305 comm="sanlock" name="" dev=0:1b ino=278 scontext=unconfined_u:system_r:sanlock_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
type=AVC msg=audit(1413987296.075:1106): avc:  denied  { open } for  pid=2305 comm="sanlock" name="ids" dev=0:1b ino=426 scontext=unconfined_u:system_r:sanlock_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
type=AVC msg=audit(1413987345.051:1127): avc:  denied  { search } for  pid=7618 comm="sanlock" name="" dev=0:1b ino=278 scontext=unconfined_u:system_r:sanlock_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
type=AVC msg=audit(1413987345.051:1127): avc:  denied  { open } for  pid=7618 comm="sanlock" name="2419b5be-8159-40de-a285-08c2739fb687" dev=0:1b ino=805 scontext=unconfined_u:system_r:sanlock_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
type=AVC msg=audit(1413987390.067:1156): avc:  denied  { connectto } for  pid=2699 comm="libvirtd" path="/var/run/sanlock/sanlock.sock" scontext=system_u:system_r:svirt_t:s0:c38,c274 tcontext=unconfined_u:system_r:sanlock_t:s0-s0:c0.c1023 tclass=unix_stream_socket
type=AVC msg=audit(1413987390.068:1157): avc:  denied  { connectto } for  pid=2699 comm="libvirtd" path="/var/run/sanlock/sanlock.sock" scontext=system_u:system_r:svirt_t:s0:c38,c274 tcontext=unconfined_u:system_r:sanlock_t:s0-s0:c0.c1023 tclass=unix_stream_socket

it's selinux issue, tried again after `setenforce 0' and installer passed problematic part.

Comment 6 Michal Skrivanek 2014-10-22 15:03:00 UTC
then this indeed looks like a duplicate of the selinux-policy issues. Which version do you have?

Comment 7 Jiri Belka 2014-10-23 07:21:22 UTC
selinux-policy-3.7.19-260.el6.noarch

Comment 8 Michal Skrivanek 2014-10-30 15:13:53 UTC
sorry, can you confirm  policycoreutils-2.0.83-19.47.el6_6.1 or newer?

Comment 9 Michal Skrivanek 2014-10-30 15:15:22 UTC
also make sure restorecon was run or box was reinstalled

Comment 10 Jiri Belka 2014-10-31 13:43:12 UTC
works ok with policycoreutils-2.0.83-19.47.el6_6.1.x86_64 and vt8

Comment 11 Michal Skrivanek 2014-10-31 14:41:28 UTC
resolved in RHEL 6.6