[Engine-devel] ovirt live 1.1: 'local_vm' stuck in Wait For Launch

[Dan Kenigsberg]

On Sun, Nov 03, 2013 at 12:01:28PM -0500, Einav Cohen wrote:
> Hi All,
> 
> In my ovirt live 1.1 system (ran as-is, done no alterations to the system once "installed"), 
> after attempting to run the default 'local_vm' VM, it is getting stuck on 'Wait For Launch'.
> I tried running the ovirt live 1.1 system for ~5 times, only in one of these times the VM 
> has actually moved to the Powering Up / Up state when attempting to run it.
> Any ideas?
> 
> [attached engine.log, vdsm.log]
> 
> Many thanks in advance!
> 
> ----
> Regards, 
> Einav

snip

> 
> libvirtEventLoop::DEBUG::2013-11-03 11:52:26,383::vm::4724::vm.Vm::(_onLibvirtLifecycleEvent) vmId=`1f0a2763-5c40-4fa3-a51c-ed98276b8e6d`::event Started detail 0 opaque None
> Thread-126::DEBUG::2013-11-03 11:52:26,465::sampling::285::vm.Vm::(start) vmId=`1f0a2763-5c40-4fa3-a51c-ed98276b8e6d`::Start statistics collection
> Thread-128::DEBUG::2013-11-03 11:52:26,479::sampling::314::vm.Vm::(run) vmId=`1f0a2763-5c40-4fa3-a51c-ed98276b8e6d`::Stats thread started
> Thread-128::DEBUG::2013-11-03 11:52:26,480::task::579::TaskManager.Task::(_updateState) Task=`06de0c6d-28e6-4c20-9139-90c3f440dc6b`::moving from state init -> state preparing
> Thread-128::INFO::2013-11-03 11:52:26,480::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='5b5e5322-df22-4516-860b-361f00c46233', spUUID='9b476274-7c1c-4762-8cb4-699c2729b152', imgUUID='a544c2c3-cf3a-42c7-8e20-371344ad22da', volUUID='bcabc2ba-b7e1-47f9-9098-bbe19b096ad5', options=None)
> Thread-128::DEBUG::2013-11-03 11:52:26,483::fileVolume::520::Storage.Volume::(validateVolumePath) validate path for bcabc2ba-b7e1-47f9-9098-bbe19b096ad5
> Thread-128::INFO::2013-11-03 11:52:26,485::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '139264', 'apparentsize': '262144'}
> Thread-128::DEBUG::2013-11-03 11:52:26,485::task::1168::TaskManager.Task::(prepare) Task=`06de0c6d-28e6-4c20-9139-90c3f440dc6b`::finished: {'truesize': '139264', 'apparentsize': '262144'}
> Thread-128::DEBUG::2013-11-03 11:52:26,485::task::579::TaskManager.Task::(_updateState) Task=`06de0c6d-28e6-4c20-9139-90c3f440dc6b`::moving from state preparing -> state finished
> Thread-128::DEBUG::2013-11-03 11:52:26,485::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
> Thread-128::DEBUG::2013-11-03 11:52:26,485::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
> Thread-128::DEBUG::2013-11-03 11:52:26,491::task::974::TaskManager.Task::(_decref) Task=`06de0c6d-28e6-4c20-9139-90c3f440dc6b`::ref 0 aborting False
> Thread-126::DEBUG::2013-11-03 11:52:26,507::vmChannels::194::vds::(register) Add fileno 45 to listener's channels.
> Thread-126::WARNING::2013-11-03 11:52:26,522::vm::3326::vm.Vm::(_readPauseCode) vmId=`1f0a2763-5c40-4fa3-a51c-ed98276b8e6d`::_readPauseCode unsupported by libvirt vm
> Thread-126::DEBUG::2013-11-03 11:52:26,552::vm::2036::vm.Vm::(_startUnderlyingVm) vmId=`1f0a2763-5c40-4fa3-a51c-ed98276b8e6d`::_ongoingCreations released

Is this a log of a successful or of a failed attempt? "_ongoingCreations
released" (should) mean that the Vm is "Up" as much as Vdsm concerns.

Could you verify that Vdsm reports "Wait For Launch" via vdsClient?
Could you attach libvirtd.log from a failed attempt?
Which kernel and qemu-kvm are you using?