Re: [ovirt-devel] System tests failure (wrong test code?)

On Sun, Mar 19, 2017 at 12:14 PM, Arik Hadas <ahadas(a)redhat.com&gt; wrote: > > > On Sat, Mar 18, 2017 at 12:57 PM, Yaniv Kaul <ykaul(a)redhat.com&gt; wrote: > >> >> >> On Sat, Mar 18, 2017 at 12:05 AM, Michal Skrivanek <mskrivan(a)redhat.com&gt; >> wrote: >> >>> >>> On 17 Mar 2017, at 20:49, Yaniv Kaul <ykaul(a)redhat.com&gt; wrote: >>> >>> >>> >>> On Thu, Mar 16, 2017 at 8:16 PM, Michal Skrivanek <mskrivan(a)redhat.com&gt; >>> wrote: >>> >>>> >>>> On 16 Mar 2017, at 15:18, Yaniv Kaul <ykaul(a)redhat.com&gt; wrote: >>>> >>>> >>>> >>>> On Thu, Mar 16, 2017 at 10:46 AM, Nir Soffer <nsoffer(a)redhat.com&gt; wr >>>> ote: >>>> >>>>> If found this error in system tests - looks like wrong assert - code >>>>> should check >>>>> if disk is not None before checking state. >>>>> >>>>> I'm not sure who is the owner of this test, so posting here. >>>>> >>>> >>>> Theoretically, perhaps. >>>> Practically, it worked (until yesterday?) and now I'm also seeing this >>>> failure - it's not a coincidence. >>>> >>>> However, looking at my failure[1], I'm seeing other nasty stuff, which >>>> may explain the later on failures >>>> >>>> For example, new NPE I have not seen in the past: >>>> 2017-03-16 09:57:57,581-04 INFO [org.ovirt.engine.core.bll.AddVmTemplateCommand] >>>> (DefaultQuartzScheduler1) [5d94233] Ending command >>>> 'org.ovirt.engine.core.bll.AddVmTemplateCommand' successfully. >>>> >>>> >>>> Is this IST or which TZ? >>>> >>> >>> Interesting question - I guess that's why we need the offset from UTC >>> or use UTC in the logs. >>> >>> >>>> Likely https://gerrit.ovirt.org/#/c/69323 merged 10:33:20 CET today >>>> >>> >>> That's the cause or the fix? >>> >>> >>> oh, sorry, the cause. >>> we were not able to find anyone to confirm and resolve it today >>> unfortunately >>> >> > A fix is posted: https://gerrit.ovirt.org/#/c/74276/ > The cause is explained in the commit message. >

Thanks. > In our defense I'll say that somehow the system tests passed when we ran > them ([1]) and that the command for adding a template became way too > complicated than it is supposed to be with the introduction of import from > glance and instance-types. > Do we have intentions to simplify it?

> > [1] http://jenkins.ovirt.org/job/ovirt-system-tests_manual/129/ > > >> >> A secondary bug is that it fails every 10 seconds or so, continuously. >> Y. >> > > Right, because it fails in the end-action phase of the command and we > have a retry mechanism that attempts to end the command (unless stated > otherwise) periodically. > But the end user experience is an event every few seconds (10?) that we fail an operation. When does it give up?

Y. > > >> >> >> >>> >>> Y. >>> >>> >>>> >>>> 2017-03-16 09:57:57,591-04 INFO [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] >>>> (DefaultQuartzScheduler1) [5d94233] START, SetVmStatusVDSCommand( >>>> SetVmStatusVDSCommandParameters:{runAsync='true', >>>> vmId='00000000-0000-0000-0000-000000000000', status='Down', >>>> exitStatus='Normal'}), log id: 30ee3299 >>>> 2017-03-16 09:57:57,593-04 DEBUG [org.ovirt.engine.core.dal.dbb >>>> roker.PostgresDbEngineDialect$PostgresSimpleJdbcCall] >>>> (DefaultQuartzScheduler1) [5d94233] Compiled stored procedure. Call string >>>> is [{call getvmdynamicbyvmguid(?)}] >>>> 2017-03-16 09:57:57,594-04 DEBUG [org.ovirt.engine.core.dal.dbb >>>> roker.PostgresDbEngineDialect$PostgresSimpleJdbcCall] >>>> (DefaultQuartzScheduler1) [5d94233] SqlCall for procedure >>>> [GetVmDynamicByVmGuid] compiled >>>> 2017-03-16 09:57:57,595-04 ERROR [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] >>>> (DefaultQuartzScheduler1) [5d94233] Command 'SetVmStatusVDSCommand( >>>> SetVmStatusVDSCommandParameters:{runAsync='true', >>>> vmId='00000000-0000-0000-0000-000000000000', status='Down', >>>> exitStatus='Normal'})' execution failed: null >>>> 2017-03-16 09:57:57,595-04 DEBUG [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] >>>> (DefaultQuartzScheduler1) [5d94233] Exception: >>>> java.lang.NullPointerException >>>> at org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand.execut >>>> eVDSCommand(SetVmStatusVDSCommand.java:33) [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.DefaultVdsCommandE >>>> xecutor.execute(DefaultVdsCommandExecutor.java:14) [vdsbroker.jar:] >>>> at org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:404) >>>> [vdsbroker.jar:] >>>> at org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.runVdsComman >>>> d(VDSBrokerFrontendImpl.java:33) [bll.jar:] >>>> at org.ovirt.engine.core.bll.VmHandler.unLockVm(VmHandler.java:377) >>>> [bll.jar:] >>>> >>>> >>>> >>>> Y. >>>> >>>> [1] http://jenkins.ovirt.org/job/ovirt-system-tests_master_chec >>>> k-patch-el7-x86_64/326/artifact/exported-artifacts/basic_sui >>>> te_master__logs/test_logs/basic-suite-master/post-004_basic_ >>>> sanity.py/lago-basic-suite-master-engine/_var_log/ovirt-engi >>>> ne/engine.log >>>> >>>> >>>>> *08:28:05* # snapshots_merge: *08:28:31* Unhandled exception in <function <lambda> at 0x276a5f0>*08:28:31* Traceback (most recent call last):*08:28:31* File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 217, in assert_equals_within*08:28:31* res = func()*08:28:31* File "/home/jenkins/workspace/ovirt-system-tests_manual/ovirt-system-tests/basic-suite-master/test-scenarios/004_basic_sanity.py", line 466, in <lambda>*08:28:31* api.vms.get(VM0_NAME).disks.get(disk_name).status.state == 'ok'*08:28:31* AttributeError: 'NoneType' object has no attribute 'state'*08:28:31* Error while running thread*08:28:31* Traceback (most recent call last):*08:28:31* File "/usr/lib/python2.7/site-packages/lago/utils.py", line 57, in _ret_via_queue*08:28:31* queue.put({'return': func()})*08:28:31* File "/home/jenkins/workspace/ovirt-system-tests_manual/ovirt-system-tests/basic-suite-master/test-scenarios/004_basic_sanity.py", line 465, in snapshot_live_merge*08:28:31* lambda:*08:28:31* File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 264, in assert_true_within_long*08:28:31* assert_equals_within_long(func, True, allowed_exceptions)*08:28:31* File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 251, in assert_equals_within_long*08:28:31* func, value, LONG_TIMEOUT, allowed_exceptions=allowed_exceptions*08:28:31* File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 217, in assert_equals_within*08:28:31* res = func()*08:28:31* File "/home/jenkins/workspace/ovirt-system-tests_manual/ovirt-system-tests/basic-suite-master/test-scenarios/004_basic_sanity.py", line 466, in <lambda>*08:28:31* api.vms.get(VM0_NAME).disks.get(disk_name).status.state == 'ok'*08:28:31* AttributeError: 'NoneType' object has no attribute 'state' >>>>> >>>>> >>>>> >>>>> _______________________________________________ >>>>> Devel mailing list >>>>> Devel(a)ovirt.org >>>>> http://lists.ovirt.org/mailman/listinfo/devel >>>>> >>>> >>>> _______________________________________________ >>>> Devel mailing list >>>> Devel(a)ovirt.org >>>> http://lists.ovirt.org/mailman/listinfo/devel >>>> >>>> >>>> >>> >>> >> >> _______________________________________________ >> Devel mailing list >> Devel(a)ovirt.org >> http://lists.ovirt.org/mailman/listinfo/devel >> > >