[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 08:38:17 UTC 2016
[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.getConstraintValidatorInstanceForAutomaticUnwrapping(ConstraintTree.java:266)
> [hibernate-validator-5.2.4.Final.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.MetaConstraint.
> validateConstraint(MetaConstraint.java:73) [hibernate-validator-5.2.4.
> Final.jar:5.2.4.Final]
> at org.hibernate.validator.internal.engine.ValidatorImpl.
> validateConstraintsForGroup(ValidatorImpl.java:1488)
> [hibernate-validator-5.2.4.Final.jar:5.2.4.Final]
> at org.hibernate.validator.internal.engine.ValidatorImpl.
> validateReturnValueForSingleGroup(ValidatorImpl.java:1459)
> [hibernate-validator-5.2.4.Final.jar:5.2.4.Final]
> at org.hibernate.validator.internal.engine.ValidatorImpl.
> validateReturnValueForGroup(ValidatorImpl.java:1422)
> [hibernate-validator-5.2.4.Final.jar:5.2.4.Final]
> at org.hibernate.validator.internal.engine.ValidatorImpl.
> validateReturnValueInContext(ValidatorImpl.java:1338)
> [hibernate-validator-5.2.4.Final.jar:5.2.4.Final]
> at org.hibernate.validator.internal.engine.ValidatorImpl.
> validateReturnValue(ValidatorImpl.java:317) [hibernate-validator-5.2.4.
> Final.jar:5.2.4.Final]
> at org.hibernate.validator.internal.engine.ValidatorImpl.
> validateReturnValue(ValidatorImpl.java:277) [hibernate-validator-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.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$
> 976505265$Proxy$_$$_WeldClientProxy.validateReturnValue(Unknown Source)
> at org.hibernate.validator.internal.cdi.interceptor.
> ValidationInterceptor.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.SimpleInterceptorInvocation$
> SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:74)
> [weld-core-impl-2.3.5.Final.jar:2.3.5.Final]
> at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.
> executeAroundInvoke(InterceptorMethodHandler.java:84)
> [weld-core-impl-2.3.5.Final.jar:2.3.5.Final]
> at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.
> executeInterception(InterceptorMethodHandler.java:72)
> [weld-core-impl-2.3.5.Final.jar:2.3.5.Final]
> at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.
> invoke(InterceptorMethodHandler.java:56) [weld-core-impl-2.3.5.Final.
> jar:2.3.5.Final]
> at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecorato
> rStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79)
> [weld-core-impl-2.3.5.Final.jar:2.3.5.Final]
> at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecorato
> rStackMethodHandler.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/e8d80780/attachment.html>
More information about the Infra
mailing list