[ovirt-devel] Failure on start VM in ovirt-system-tests from patches merged to master on the 25/10/2016
Allon Mureinik
amureini at redhat.com
Thu Oct 27 12:13:42 UTC 2016
Now I also see it in the CI.
I merged the patch so we can squeeze in as many CI runs as possible before
the weekend.
On Thu, Oct 27, 2016 at 11:38 AM, Allon Mureinik <amureini at redhat.com>
wrote:
> [Adding Martin Sivak.]
>
> That reproduces on my setup too, but didn't see it in CI, and is not
> related to the recent injection issues.
>
> Martin - This issue seems to have been introduced in your patch 0e4ae6b.
> I'm not sure eaxctly why java doesn't like the @NotNull annotation on
> schedule, but ampyrically it does, as removing it solves the issue.
> I've posted https://gerrit.ovirt.org/65784 to do so - please review (or
> suggest a better solution, of course :-))
>
> Thanks,
> Allon
>
> On Thu, Oct 27, 2016 at 9:12 AM, Yaniv Kaul <ykaul at redhat.com> wrote:
>
>> I still fail to run a VM:
>> 2016-10-27 02:01:02,849 ERROR [org.ovirt.engine.core.bll.RunVmOnceCommand]
>> (default task-17) [78897d21] Command 'org.ovirt.engine.core.bll.RunVmOnceCommand'
>> failed: HV000186: The constraint of type 'javax.valida
>> tion.constraints.NotNull' defined on 'schedule.<return value>' has
>> multiple matching constraint validators which is due to an additional value
>> handler of type 'org.hibernate.validator.internal.engine.valuehandli
>> ng.OptionalValueUnwrapper'. It is unclear which value needs validating.
>> Clarify configuration via @UnwrapValidatedValue.
>> 2016-10-27 02:01:02,849 ERROR [org.ovirt.engine.core.bll.RunVmOnceCommand]
>> (default task-17) [78897d21] Exception: javax.validation.UnexpectedTypeException:
>> HV000186: The constraint of type 'javax.validation.con
>> straints.NotNull' defined on 'schedule.<return value>' has multiple
>> matching constraint validators which is due to an additional value handler
>> of type 'org.hibernate.validator.internal.engine.valuehandling.Optio
>> nalValueUnwrapper'. It is unclear which value needs validating. Clarify
>> configuration via @UnwrapValidatedValue.
>> at org.hibernate.validator.internal.engine.constraintvalidation
>> .ConstraintTree.getConstraintValidatorInstanceForAutomaticUn
>> wrapping(ConstraintTree.java:266) [hibernate-validator-5.2.4.Fin
>> al.jar:5.2.4.Fin
>> al]
>> at org.hibernate.validator.internal.engine.constraintvalidation
>> .ConstraintTree.getInitializedConstraintValidator(ConstraintTree.java:163)
>> [hibernate-validator-5.2.4.Final.jar:5.2.4.Final]
>> at org.hibernate.validator.internal.engine.constraintvalidation
>> .ConstraintTree.validateConstraints(ConstraintTree.java:116)
>> [hibernate-validator-5.2.4.Final.jar:5.2.4.Final]
>> at org.hibernate.validator.internal.engine.constraintvalidation
>> .ConstraintTree.validateConstraints(ConstraintTree.java:87)
>> [hibernate-validator-5.2.4.Final.jar:5.2.4.Final]
>> at org.hibernate.validator.internal.metadata.core.MetaConstrain
>> t.validateConstraint(MetaConstraint.java:73)
>> [hibernate-validator-5.2.4.Final.jar:5.2.4.Final]
>> at org.hibernate.validator.internal.engine.ValidatorImpl.valida
>> teConstraintsForGroup(ValidatorImpl.java:1488)
>> [hibernate-validator-5.2.4.Final.jar:5.2.4.Final]
>> at org.hibernate.validator.internal.engine.ValidatorImpl.valida
>> teReturnValueForSingleGroup(ValidatorImpl.java:1459)
>> [hibernate-validator-5.2.4.Final.jar:5.2.4.Final]
>> at org.hibernate.validator.internal.engine.ValidatorImpl.valida
>> teReturnValueForGroup(ValidatorImpl.java:1422)
>> [hibernate-validator-5.2.4.Final.jar:5.2.4.Final]
>> at org.hibernate.validator.internal.engine.ValidatorImpl.valida
>> teReturnValueInContext(ValidatorImpl.java:1338)
>> [hibernate-validator-5.2.4.Final.jar:5.2.4.Final]
>> at org.hibernate.validator.internal.engine.ValidatorImpl.valida
>> teReturnValue(ValidatorImpl.java:317) [hibernate-validator-5.2.4.Fin
>> al.jar:5.2.4.Final]
>> at org.hibernate.validator.internal.engine.ValidatorImpl.valida
>> teReturnValue(ValidatorImpl.java:277) [hibernate-validator-5.2.4.Fin
>> al.jar:5.2.4.Final]
>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>> [rt.jar:1.8.0_111]
>> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
>> [rt.jar:1.8.0_111]
>> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>> [rt.jar:1.8.0_111]
>> at java.lang.reflect.Method.invoke(Method.java:498)
>> [rt.jar:1.8.0_111]
>> at org.jboss.weld.bean.proxy.AbstractBeanInstance.invoke(AbstractBeanInstance.java:38)
>> [weld-core-impl-2.3.5.Final.jar:2.3.5.Final]
>> at org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:100)
>> [weld-core-impl-2.3.5.Final.jar:2.3.5.Final]
>> at org.jboss.weldx.validation.ExecutableValidator$Validator$976
>> 505265$Proxy$_$$_WeldClientProxy.validateReturnValue(Unknown Source)
>> at org.hibernate.validator.internal.cdi.interceptor.ValidationI
>> nterceptor.validateMethodInvocation(ValidationInterceptor.java:80)
>> [hibernate-validator-cdi-5.2.4.Final.jar:5.2.4.Final]
>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>> [rt.jar:1.8.0_111]
>> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
>> [rt.jar:1.8.0_111]
>> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>> [rt.jar:1.8.0_111]
>> at java.lang.reflect.Method.invoke(Method.java:498)
>> [rt.jar:1.8.0_111]
>> at org.jboss.weld.interceptor.reader.SimpleInterceptorInvocatio
>> n$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:74)
>> [weld-core-impl-2.3.5.Final.jar:2.3.5.Final]
>> at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.ex
>> ecuteAroundInvoke(InterceptorMethodHandler.java:84)
>> [weld-core-impl-2.3.5.Final.jar:2.3.5.Final]
>> at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.ex
>> ecuteInterception(InterceptorMethodHandler.java:72)
>> [weld-core-impl-2.3.5.Final.jar:2.3.5.Final]
>> at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.in
>> voke(InterceptorMethodHandler.java:56) [weld-core-impl-2.3.5.Final.ja
>> r:2.3.5.Final]
>> at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorSta
>> ckMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79)
>> [weld-core-impl-2.3.5.Final.jar:2.3.5.Final]
>> at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorSta
>> ckMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:68)
>> [weld-core-impl-2.3.5.Final.jar:2.3.5.Final]
>> at org.ovirt.engine.core.bll.scheduling.SchedulingManager$Proxy
>> $_$$_WeldSubclass.schedule(Unknown Source) [bll.jar:]
>> at org.ovirt.engine.core.bll.RunVmCommand.getVdsToRunOn(RunVmCommand.java:818)
>> [bll.jar:]
>> at org.ovirt.engine.core.bll.RunVmCommand.runVm(RunVmCommand.java:231)
>> [bll.jar:]
>> at org.ovirt.engine.core.bll.RunVmCommand.perform(RunVmCommand.java:414)
>> [bll.jar:]
>> at org.ovirt.engine.core.bll.RunVmCommand.executeVmCommand(RunVmCommand.java:339)
>> [bll.jar:]
>> at org.ovirt.engine.core.bll.VmCommand.executeCommand(VmCommand.java:106)
>> [bll.jar:]
>>
>>
>> On Thu, Oct 27, 2016 at 5:12 AM, Allon Mureinik <amureini at redhat.com>
>> wrote:
>>
>>> Seems like we cleared up the engine issues related to the recent
>>> injection changes.
>>>
>>> I am now seeing stop errors, e.g.:
>>>
>>> {"jsonrpc": "2.0", "id": "ea0c564f-bc17-4fc2-8f1b-67c4d28257c6", "result": {"cpuStatistics": {"1": {"cpuUser": "3.07", "nodeIndex": 0, "cpuSys": "3.00", "cpuIdle": "93.93"}, "0": {"cpuUser": "1.67", "nodeIndex": 0, "cpuSys": "2.07", "cpuIdle": "96.26"}}, "numaNodeMemFree": {"0": {"memPercent": 83, "memFree": "359"}}, "memShared": 0, "thpState": "always", "ksmMergeAcrossNodes": true, "vmCount": 0, "memUsed": "20", "storageDomains": {"b2bb3220-1eb3-426a-90c2-5e236aefbe1a": {"code": 0, "actual": true, "version": 0, "acquired": true, "delay": "0.000840117", "lastCheck": "7.1", "valid": true}, "3130195a-73f9-4490-b554-98a9205cead6": {"code": 0, "actual": true, "version": 4, "acquired": true, "delay": "0.00150771", "lastCheck": "7.5", "valid": true}, "1a9e202b-83b7-4bdc-9b0c-e76b83676068": {"code": 0, "actual": true, "version": 4, "acquired": true, "delay": "0.000590956",
>>> 2016-10-26 21:51:09,878 DEBUG [org.ovirt.engine.core.utils.timer.FixedDelayJobListener] (DefaultQuartzScheduler7) [6d206bd1] Rescheduling DEFAULT.org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.invokeCallbackMethods#-9223372036854775783 as there is no unfired trigger.
>>> 2016-10-26 21:51:28,705 DEBUG [org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp Reactor) [383dd6a0] Heartbeat exceeded. Closing channel
>>> 2016-10-26 21:51:28,708 DEBUG [org.ovirt.vdsm.jsonrpc.client.reactors.Reactor] (SSL Stomp Reactor) [383dd6a0] Internal server error: null: java.lang.NullPointerException
>>> at org.ovirt.vdsm.jsonrpc.client.reactors.SSLClient.write(SSLClient.java:102) [vdsm-jsonrpc-java-client.jar:]
>>> at org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient.processOutgoing(ReactorClient.java:245) [vdsm-jsonrpc-java-client.jar:]
>>> at org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient.process(ReactorClient.java:208) [vdsm-jsonrpc-java-client.jar:]
>>> at org.ovirt.vdsm.jsonrpc.client.reactors.SSLClient.process(SSLClient.java:125) [vdsm-jsonrpc-java-client.jar:]
>>> at org.ovirt.vdsm.jsonrpc.client.reactors.Reactor.processChannels(Reactor.java:89) [vdsm-jsonrpc-java-client.jar:]
>>> at org.ovirt.vdsm.jsonrpc.client.reactors.Reactor.run(Reactor.java:65) [vdsm-jsonrpc-java-client.jar:]
>>>
>>>
>>> Piotr - any idea?
>>>
>>>
>>> On Wed, Oct 26, 2016 at 9:34 PM, Nadav Goldin <ngoldin at redhat.com>
>>> wrote:
>>>
>>>> Its running now:
>>>> http://jenkins.ovirt.org/job/ovirt-engine_master_build-artif
>>>> acts-fc24-x86_64/1037/,
>>>> when it finishes it will trigger the deploy job which will trigger the
>>>> experimental job. The build_artifacts job is triggered approximately
>>>> every 2 hours(depends on the load).
>>>> Inside the build-artifacts job you can see the last
>>>> commit(https://gerrit.ovirt.org/65776, which is already after your
>>>> commit)
>>>>
>>>>
>>>> On Wed, Oct 26, 2016 at 9:26 PM, Allon Mureinik <amureini at redhat.com>
>>>> wrote:
>>>> > @Infra - the last experimental job I saw was from ~17:30 local Israel
>>>> time.
>>>> > Any idea why another one isn't being triggered (or am I just being
>>>> daft)?
>>>> >
>>>> > On Wed, Oct 26, 2016 at 6:27 PM, Allon Mureinik <amureini at redhat.com>
>>>> wrote:
>>>> >>
>>>> >> Yipes.
>>>> >> [1] should fix that, waiting for the CI to run to merge.
>>>> >>
>>>> >> [1] https://gerrit.ovirt.org/#/c/65768/
>>>> >>
>>>> >> On Wed, Oct 26, 2016 at 3:42 PM, Nadav Goldin <ngoldin at redhat.com>
>>>> wrote:
>>>> >>>
>>>> >>> Unfortunately it is still failing, see[1], the repository used was
>>>> >>> built from commit [2]. If you want to check the logs same links
>>>> >>> apply(just replace build number 2759->2782)
>>>> >>>
>>>> >>>
>>>> >>>
>>>> >>> [1] http://jenkins.ovirt.org/job/test-repo_ovirt_experimental_ma
>>>> ster/2782
>>>> >>> [2] https://gerrit.ovirt.org/#/c/65740/
>>>> >>>
>>>> >>> On Wed, Oct 26, 2016 at 11:33 AM, Tal Nisan <tnisan at redhat.com>
>>>> wrote:
>>>> >>> > Should be fixed now on master as those patches were just merged:
>>>> >>> >
>>>> >>> > https://gerrit.ovirt.org/#/c/65738/ - "Move InjectorRule to
>>>> VdsBroker":
>>>> >>> > aligns the InjectorRule's package with the Injector so it can
>>>> >>> > essentially be
>>>> >>> > used wherever the Injector is used [+12, -4]
>>>> >>> > https://gerrit.ovirt.org/#/c/65739 - "InjectorRule: override
>>>> injector
>>>> >>> > anyway": Fixes a bug in InjectorRule where the Injector is only
>>>> mocked
>>>> >>> > if
>>>> >>> > you call InjectorRule.bind [+6, -1]
>>>> >>> > https://gerrit.ovirt.org/#/c/65740 - "core: InjectorRule for
>>>> injecting
>>>> >>> > members": Fixes a bug in InjectorRule to allow using
>>>> >>> > Injector.injectMembers
>>>> >>> > when using it [+18, -5]
>>>> >>> > https://gerrit.ovirt.org/#/c/65725 - "core: Fix AuditLogging":
>>>> The
>>>> >>> > actual
>>>> >>> > fix. Basically, goes over all the places that create an
>>>> >>> > AuditLoggableBase
>>>> >>> > that needs injecting and take care of it [+155, -160]
>>>> >>> >
>>>> >>> >
>>>> >>> > On Wed, Oct 26, 2016 at 10:04 AM, Nadav Goldin <
>>>> ngoldin at redhat.com>
>>>> >>> > wrote:
>>>> >>> >>
>>>> >>> >> Hi,
>>>> >>> >> We have new failure on OST from patches merged to master
>>>> yesterday,
>>>> >>> >> the failure started after the merge of [1], but as there were
>>>> quite a
>>>> >>> >> few patches merged quickly I can't make sure it is the one
>>>> causing
>>>> >>> >> it(OST aren't ran per-patch).
>>>> >>> >> The test that fails is [2] when attempting to start the VM.
>>>> >>> >>
>>>> >>> >> The error from the API side:
>>>> >>> >>
>>>> >>> >> RequestError:
>>>> >>> >> status: 500
>>>> >>> >> reason: Internal Server Error
>>>> >>> >> detail: javax.ejb.EJBException: java.lang.NullPointerException
>>>> >>> >> at
>>>> >>> >>
>>>> >>> >> org.jboss.as.ejb3.tx.CMTTxInterceptor.handleExceptionInNoTx(
>>>> CMTTxInterceptor.java:213)
>>>> >>> >> at
>>>> >>> >>
>>>> >>> >> org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInte
>>>> rceptor.java:265)
>>>> >>> >> at
>>>> >>> >>
>>>> >>> >> org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxIntercep
>>>> tor.java:374)
>>>> >>> >> at
>>>> >>> >>
>>>> >>> >> org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTT
>>>> xInterceptor.java:243)
>>>> >>> >> at
>>>> >>> >>
>>>> >>> >> org.jboss.invocation.InterceptorContext.proceed(InterceptorC
>>>> ontext.java:340)
>>>> >>> >> ....
>>>> >>> >>
>>>> >>> >> In the engine logs there are a few 'java.lang.NullPointerExceptio
>>>> n'
>>>> >>> >> errors:
>>>> >>> >>
>>>> >>> >> 2016-10-25 11:53:52,845 INFO
>>>> >>> >> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLo
>>>> gableBase]
>>>> >>> >> (org.ovirt.thread.pool-6-thread-2) [5e6a88be] Failed to get vds
>>>> >>> >> 'd60db21f-95f0-487b-9f17-44861e2610a7', error: null
>>>> >>> >> 2016-10-25 11:53:52,864 DEBUG
>>>> >>> >> [org.ovirt.engine.core.utils.timer.FixedDelayJobListener]
>>>> >>> >> (DefaultQuartzScheduler5) [] Rescheduling
>>>> >>> >>
>>>> >>> >>
>>>> >>> >> DEFAULT.org.ovirt.engine.core.bll.tasks.AsyncTaskManager.tim
>>>> erElapsed#-9223372036854775787
>>>> >>> >> as there is no unfired trigger.
>>>> >>> >> ...
>>>> >>> >> 2016-10-25 11:53:52,845 DEBUG
>>>> >>> >> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLo
>>>> gableBase]
>>>> >>> >> (org.ovirt.thread.pool-6-thread-2) [5e6a88be] Exception:
>>>> >>> >> java.lang.NullPointerException
>>>> >>> >> at
>>>> >>> >>
>>>> >>> >> org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLog
>>>> ableBase.getVdsStatic(AuditLogableBase.java:633)
>>>> >>> >> [dal.jar:]
>>>> >>> >> at
>>>> >>> >>
>>>> >>> >> org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLog
>>>> ableBase.getVdsName(AuditLogableBase.java:504)
>>>> >>> >> [dal.jar:]
>>>> >>> >> ...
>>>> >>> >> 2016-10-25 11:53:52,837 INFO
>>>> >>> >> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLo
>>>> gableBase]
>>>> >>> >> (org.ovirt.thread.pool-6-thread-2) [5e6a88be] Failed to get vds
>>>> >>> >> 'd60db21f-95f0-487b-9f17-44861e2610a7', error: null
>>>> >>> >> 2016-10-25 11:53:52,837 DEBUG
>>>> >>> >> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLo
>>>> gableBase]
>>>> >>> >> (org.ovirt.thread.pool-6-thread-2) [5e6a88be] Exception:
>>>> >>> >> java.lang.NullPointerException
>>>> >>> >> at
>>>> >>> >>
>>>> >>> >> org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLog
>>>> ableBase.getVdsStatic(AuditLogableBase.java:633)
>>>> >>> >> [dal.jar:]
>>>> >>> >> at
>>>> >>> >>
>>>> >>> >> org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLog
>>>> ableBase.getVdsName(AuditLogableBase.java:504)
>>>> >>> >> [dal.jar:]
>>>> >>> >> ...
>>>> >>> >>
>>>> >>> >> The full engine logs can be found here[3] and the entire test
>>>> suite
>>>> >>> >> logs here[4].
>>>> >>> >>
>>>> >>> >> Can anyone have a look?
>>>> >>> >>
>>>> >>> >> Thanks,
>>>> >>> >> Nadav.
>>>> >>> >>
>>>> >>> >>
>>>> >>> >> [1] https://gerrit.ovirt.org/#/c/65198/
>>>> >>> >> [2]
>>>> >>> >>
>>>> >>> >> https://github.com/oVirt/ovirt-system-tests/blob/master/basi
>>>> c_suite_master/test-scenarios/004_basic_sanity.py#L322
>>>> >>> >> [3]
>>>> >>> >>
>>>> >>> >> http://jenkins.ovirt.org/job/test-repo_ovirt_experimental_ma
>>>> ster/2759/artifact/exported-artifacts/basic_suite_master.sh-
>>>> fc24/exported-artifacts/test_logs/basic_suite_master/post-00
>>>> 4_basic_sanity.py/*zip*/post-004_basic_sanity.py.zip
>>>> >>> >> [4]
>>>> >>> >>
>>>> >>> >> http://jenkins.ovirt.org/job/test-repo_ovirt_experimental_ma
>>>> ster/2759/artifact/exported-artifacts/basic_suite_master.sh-
>>>> fc24/exported-artifacts/
>>>> >>> >> _______________________________________________
>>>> >>> >> Devel mailing list
>>>> >>> >> Devel at ovirt.org
>>>> >>> >> http://lists.ovirt.org/mailman/listinfo/devel
>>>> >>> >
>>>> >>> >
>>>> >>
>>>> >>
>>>> >
>>>>
>>>
>>>
>>> _______________________________________________
>>> Devel mailing list
>>> Devel at ovirt.org
>>> http://lists.ovirt.org/mailman/listinfo/devel
>>>
>>
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ovirt.org/pipermail/infra/attachments/20161027/2d27f0c6/attachment.html>
More information about the Infra
mailing list