Hi,
We have a failure that seems to be random and happening in several projects.
from what I can see, we are failing due to a timing issue in the test itself because we are querying the vm after its been destroyed in engine.
looking at engine, I can see that the vm was actually shut down,
I would like to disable this test until we can fix the issue since it already failed about 7 different patches from different projects.
engine:
018-03-23 14:44:14,156-04 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-5) [] Failed to destroy VM '7020944f-cd26-4c31-b381-0ce6be733fd7' because VM does not exist, ignoring
2018-03-23 14:44:14,156-04 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-5) [] FINISH, DestroyVDSCommand, log id: 646766a
2018-03-23 14:44:14,156-04 DEBUG [org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor] (ForkJoinPool-1-worker-5) [] method: runVdsCommand, params: [Destroy, DestroyVmVDSCommandParameters:{hostId='c40b11df-7053-437e-8acc-c5
e91c1694bc', vmId='7020944f-cd26-4c31-b381-0ce6be733fd7', secondsToWait='0', gracefully='false', reason='', ignoreNoVm='true'}], timeElapsed: 14ms
2018-03-23 14:44:14,156-04 DEBUG [org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor] (ForkJoinPool-1-worker-5) [] method: getVmManager, params: [7020944f-cd26-4c31-b381-0ce6be733fd7], timeElapsed: 0ms
2018-03-23 14:44:14,156-04 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (ForkJoinPool-1-worker-5) [] VM '7020944f-cd26-4c31-b381-0ce6be733fd7'(vm2) moved from 'Up' --> 'Down'
2018-03-23 14:44:14,156-04 DEBUG [org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor] (ForkJoinPool-1-worker-5) [] method: getVmManager, params: [7020944f-cd26-4c31-b381-0ce6be733fd7], timeElapsed: 0ms
2018-03-23 14:44:14,177-04 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-4) [a463501f-f01a-4048-93ca-02647308394b] EVENT_ID: USER_STOP_VM(33), VM vm2 powered off by admin@internal-authz (Host:
lago-basic-suite-master-host-0).
vdsm:
2018-03-23 14:44:14,024-0400 INFO (libvirt/events) [virt.vm] (vmId='7020944f-cd26-4c31-b381-0ce6be733fd7') Changed state to Down: Admin shut down from the engine (code=6) (vm:1684)
2018-03-23 14:44:14,028-0400 INFO (jsonrpc/1) [api.virt] FINISH destroy return={'status': {'message': 'Machine destroyed', 'code': 0}} from=::ffff:192.168.201.4,53454, flow_id=a463501f-f01a-4048-93ca-02647308394b, vmId=7020944f-cd26-4c31
-b381-0ce6be733fd7 (api:52)
2018-03-23 14:44:14,028-0400 INFO (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC call VM.destroy succeeded in 1.72 seconds (__init__:311)
2018-03-23 14:44:14,031-0400 INFO (periodic/2) [Executor] Worker was discarded (executor:305)
2018-03-23 14:44:14,033-0400 INFO (libvirt/events) [virt.vm] (vmId='7020944f-cd26-4c31-b381-0ce6be733fd7') Stopping connection (guestagent:440)
2018-03-23 14:44:14,033-0400 ERROR (libvirt/events) [vds] Error running VM callback (clientIF:666)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/clientIF.py", line 629, in dispatchLibvirtEvents
v.onLibvirtLifecycleEvent(event, detail, None)
AttributeError: 'NoneType' object has no attribute 'onLibvirtLifecycleEvent'
2018-03-23 14:44:14,078-0400 INFO (jsonrpc/4) [api.virt] START destroy(gracefulAttempts=1) from=::ffff:192.168.201.4,53454, vmId=7020944f-cd26-4c31-b381-0ce6be733fd7 (api:46)
2018-03-23 14:44:14,078-0400 INFO (jsonrpc/4) [api] FINISH destroy error=Virtual machine does not exist: {'vmId': u'7020944f-cd26-4c31-b381-0ce6be733fd7'} (api:127)
2018-03-23 14:44:14,079-0400 INFO (jsonrpc/4) [api.virt] FINISH destroy return={'status': {'message': "Virtual machine does not exist: {'vmId': u'7020944f-cd26-4c31-b381-0ce6be733fd7'}", 'code': 1}} from=::ffff:192.168.201.4,53454, vmId=
7020944f-cd26-4c31-b381-0ce6be733fd7 (api:52)