Subject: [ OST Failure Report ] [ oVirt Master ] [ Jan 15th 2018 ] [ 006_migrations.migrate_vm ]

Wed Jan 17 19:41:36 UTC 2018

Dafna Ron <dron at redhat.com> writes:

> We had a failure in test 006_migrations.migrate_vm
> <http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4842/testReport/junit/%28root%29/006_migrations/migrate_vm/>.
>
> the migration failed with reason "VMExists"

There are two migrations in 006_migrations.migrate_vm.  The first one
succeeded, but if I'm looking correctly into the logs, Engine didn't
send Destroy to the source host after the migration had finished.  Then
the second migration gets rejected by Vdsm, because Vdsm still keeps the
former Vm object instance in Down status.

Since the test succeeds most of the time, it looks like some timing
issue or border case.  Arik, is it a known problem?  If not, would you
like to look into the logs, whether you can see what's happening?

> Seems to be an issue which is caused by connectivity between engine and
> hosts.
> I remember this issue happening before a few weeks ago - is there a
> solution/bug for this issue?

None I'm aware of.

> *Link and headline of suspected patches:
> https://gerrit.ovirt.org/#/c/86114/4 <https://gerrit.ovirt.org/#/c/86114/4>
> - net tests: Fix vlan creation name length in nettestlib Link to Job:*

It's just coincidence that it failed on that patch, so I'm excluding
Edward from the discussion, he is innocent :-).

> *http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4842/
> <http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4842/>Link
> to all
> logs:http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4842/artifact/
> <http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4842/artifact/>(Relevant)
> error snippet from the log: <error>*
>
>
>
>
>
>
>
>
>
> *vdsm dst:2018-01-15 06:47:03,355-0500 ERROR (jsonrpc/0) [api] FINISH
> create error=Virtual machine already exists (api:124)Traceback (most recent
> call last):  File "/usr/lib/python2.7/site-packages/vdsm/common/api.py",
> line 117, in method    ret = func(*args, **kwargs)  File
> "/usr/lib/python2.7/site-packages/vdsm/API.py", line 180, in create
> raise exception.VMExists()VMExists: Virtual machine already exists*
>
>
> *vdsm src: 2018-01-15 06:47:03,359-0500 ERROR (migsrc/d17a2482)
> [virt.vm] *(vmId='d17a2482-4904-4cbc-8d13-3a3b7840782d')
> migration destination error: Virtual machine already exists (migration:290
>
>
> *)*
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
> *Engine: 2018-01-15 06:45:30,169-05 ERROR
> [org.ovirt.engine.core.vdsbroker.monitoring.HostMonitoring]
> (EE-ManagedThreadFactory-engineScheduled-Thread-34) [] Failure to refresh
> host 'lago-basic-suite-master-host-0' runtime info:
> java.net.ConnectException: Connection refused2018-01-15 06:45:30,169-05
> DEBUG [org.ovirt.engine.core.vdsbroker.monitoring.HostMonitoring]
> (EE-ManagedThreadFactory-engineScheduled-Thread-34) [] Exception:
> org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException:
> java.net.ConnectException: Connection refused        at
> org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createNetworkException(VdsBrokerCommand.java:159)
> [vdsbroker.jar:]        at
> org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:122)
> [vdsbroker.jar:]        at
> org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:73)
> [vdsbroker.jar:]        at
> org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33)
> [dal.jar:]        at
> org.ovirt.engine.core.vdsbroker.vdsbroker.DefaultVdsCommandExecutor.execute(DefaultVdsCommandExecutor.java:14)
> [vdsbroker.jar:]        at
> org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:387)
> [vdsbroker.jar:]        at
> org.ovirt.engine.core.vdsbroker.ResourceManager$Proxy$_$$_WeldSubclass.runVdsCommand$$super(Unknown
> Source) [vdsbroker.jar:]        at
> sun.reflect.GeneratedMethodAccessor234.invoke(Unknown Source)
> [:1.8.0_151]        at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> [rt.jar:1.8.0_151]        at
> java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_151]
> at
> org.jboss.weld.interceptor.proxy.TerminalAroundInvokeInvocationContext.proceedInternal(TerminalAroundInvokeInvocationContext.java:49)
> [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]        at
> org.jboss.weld.interceptor.proxy.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:77)
> [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]        at
> org.ovirt.engine.core.common.di.interceptor.LoggingInterceptor.apply(LoggingInterceptor.java:12)
> [common.jar:]        at
> sun.reflect.GeneratedMethodAccessor69.invoke(Unknown Source)
> [:1.8.0_151]        at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> [rt.jar:1.8.0_151]        at
> java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_151]
> at
> org.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:73)
> [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]        at
> org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeAroundInvoke(InterceptorMethodHandler.java:84)
> [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]        at
> org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeInterception(InterceptorMethodHandler.java:72)
> [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]        at
> org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(InterceptorMethodHandler.java:56)
> [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]        at
> org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79)
> [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]        at
> org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:68)
> [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]        at
> org.ovirt.engine.core.vdsbroker.ResourceManager$Proxy$_$$_WeldSubclass.runVdsCommand(Unknown
> Source) [vdsbroker.jar:]        at
> org.ovirt.engine.core.vdsbroker.VdsManager.refreshCapabilities(VdsManager.java:647)
> [vdsbroker.jar:]        at
> org.ovirt.engine.core.vdsbroker.monitoring.HostMonitoring.refreshVdsRunTimeInfo(HostMonitoring.java:118)
> [vdsbroker.jar:]        at
> org.ovirt.engine.core.vdsbroker.monitoring.HostMonitoring.refresh(HostMonitoring.java:85)
> [vdsbroker.jar:]        at
> org.ovirt.engine.core.vdsbroker.VdsManager.refresh(VdsManager.java:267)
> [vdsbroker.jar:]        at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> [rt.jar:1.8.0_151]        at
> java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
> [rt.jar:1.8.0_151]        at
> org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.access$201(ManagedScheduledThreadPoolExecutor.java:383)
> [javax.enterprise.concurrent-1.0.jar:]        at
> org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.run(ManagedScheduledThreadPoolExecutor.java:534)
> [javax.enterprise.concurrent-1.0.jar:]        at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [rt.jar:1.8.0_151]        at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [rt.jar:1.8.0_151]        at java.lang.Thread.run(Thread.java:748)
> [rt.jar:1.8.0_151]        at
> org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread.run(ManagedThreadFactoryImpl.java:250)
> [javax.enterprise.concurrent-1.0.jar:]        at
> org.jboss.as.ee.concurrent.service.ElytronManagedThreadFactory$ElytronManagedThread.run(ElytronManagedThreadFactory.java:78)Caused
> by: java.net.ConnectException: Connection refused        at
> sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
> [rt.jar:1.8.0_151]        at
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
> [rt.jar:1.8.0_151]        at
> org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient.connect(ReactorClient.java:118)
> [vdsm-jsonrpc-java-client.jar:]        at
> org.ovirt.vdsm.jsonrpc.client.JsonRpcClient.getClient(JsonRpcClient.java:160)
> [vdsm-jsonrpc-java-client.jar:]        at
> org.ovirt.vdsm.jsonrpc.client.JsonRpcClient.call(JsonRpcClient.java:93)
> [vdsm-jsonrpc-java-client.jar:]        at
> org.ovirt.engine.core.vdsbroker.jsonrpc.FutureMap.<init>(FutureMap.java:70)
> [vdsbroker.jar:]        at
> org.ovirt.engine.core.vdsbroker.jsonrpc.JsonRpcVdsServer.getCapabilities(JsonRpcVdsServer.java:314)
> [vdsbroker.jar:]        at
> org.ovirt.engine.core.vdsbroker.vdsbroker.GetCapabilitiesVDSCommand.executeVdsBrokerCommand(GetCapabilitiesVDSCommand.java:22)
> [vdsbroker.jar:]        at
> org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:112)
> [vdsbroker.jar:]        ... 34 more2018-01-15 06:45:30,170-05 DEBUG
> [org.ovirt.engine.core.vdsbroker.VdsManager]
> (EE-ManagedThreadFactory-engineScheduled-Thread-34) [] Failed to refresh
> VDS, network error, continuing,
> vds='lago-basic-suite-master-host-0'(31f09289-ec6c-42ff-a745-e82e8ac8e6b9):
> java.net.ConnectException: Connection refused*
>
> *</error>*
> _______________________________________________
> Devel mailing list
> Devel at ovirt.org
> http://lists.ovirt.org/mailman/listinfo/devel