3:46 a.m.
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.
*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'
9:18 a.m.
On Thu, Mar 16, 2017 at 10:46 AM, Nir Soffer <nsoffer(a)redhat.com> wrote:
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.
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.dbbroker.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.dbbroker.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.executeVDSCommand(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.DefaultVdsCommandExecutor.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.runVdsCommand(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_check-patch-el7-x8...
*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
1:16 p.m.
--Apple-Mail=_99B42EE4-4513-4FE9-8F9A-A1E183AF4102
Content-Transfer-Encoding: quoted-printable
Content-Type: text/plain;
charset=us-ascii
On 16 Mar 2017, at 15:18, Yaniv Kaul <ykaul(a)redhat.com> wrote:
=20
=20
=20
On Thu, Mar 16, 2017 at 10:46 AM, Nir Soffer <nsoffer(a)redhat.com =
<mailto:nsoffer@redhat.com>> wrote:
If found this error in system tests - looks like wrong assert - code
=
should check
if disk is not None before checking state.
=20
I'm not sure who is the owner of this test, so posting here.
=20
Theoretically, perhaps.=20
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
=20
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?
Likely https://gerrit.ovirt.org/#/c/69323 =
<https://gerrit.ovirt.org/#/c/69323> merged 10:33:20 CET today=20
2017-03-16 09:57:57,591-04 INFO =
[org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] =
(DefaultQuartzScheduler1) [5d94233] START, SetVmStatusVDSCommand( =
SetVmStatusVDSCommandParameters:{runAsync=3D'true', =
vmId=3D'00000000-0000-0000-0000-000000000000', status=3D'Down', =
exitStatus=3D'Normal'}), log id: 30ee3299
2017-03-16 09:57:57,593-04 DEBUG =
[org.ovirt.engine.core.dal.dbbroker.PostgresDbEngineDialect$PostgresSimple=
JdbcCall] (DefaultQuartzScheduler1) [5d94233] Compiled stored procedure. =
Call string is [{call getvmdynamicbyvmguid(?)}]
2017-03-16 09:57:57,594-04 DEBUG =
[org.ovirt.engine.core.dal.dbbroker.PostgresDbEngineDialect$PostgresSimple=
JdbcCall] (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=3D'true', =
vmId=3D'00000000-0000-0000-0000-000000000000', status=3D'Down', =
exitStatus=3D'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.executeVDSCommand(Se=
tVmStatusVDSCommand.java:33) [vdsbroker.jar:]
at =
org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBa=
se.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.execut=
e(DefaultVdsCommandExecutor.java:14) [vdsbroker.jar:]
at =
org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceMana=
ger.java:404) [vdsbroker.jar:]
at =
org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.runVdsCommand(VDSBrokerFro=
ntendImpl.java:33) [bll.jar:]
at =
org.ovirt.engine.core.bll.VmHandler.unLockVm(VmHandler.java:377) =
[bll.jar:]
=20
=20
=20
Y.
=20
[1] =
http://jenkins.ovirt.org/job/ovirt-system-tests_master_check-patch-el7-x86=
_64/326/artifact/exported-artifacts/basic_suite_master__logs/test_logs/bas=
ic-suite-master/post-004_basic_sanity.py/lago-basic-suite-master-engine/_v=
ar_log/ovirt-engine/engine.log =
<http://jenkins.ovirt.org/job/ovirt-system-tests_master_check-patch-el7-x8=
6_64/326/artifact/exported-artifacts/basic_suite_master__logs/test_logs/ba=
sic-suite-master/post-004_basic_sanity.py/lago-basic-suite-master-engine/_=
var_log/ovirt-engine/engine.log>
=20
=20
08:28:05 # snapshots_merge:=20
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 =3D func()
08:28:31 File =
"/home/jenkins/workspace/ovirt-system-tests_manual/ovirt-system-tests/basi=
c-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
=
=3D=3D '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/basi=
c-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=3Dallowed_exceptions
08:28:31 File =
"/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 217, in =
assert_equals_within
08:28:31 res =3D func()
08:28:31 File =
"/home/jenkins/workspace/ovirt-system-tests_manual/ovirt-system-tests/basi=
c-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
=
=3D=3D 'ok'
08:28:31 AttributeError: 'NoneType' object has no attribute
'state'
=20
=20
_______________________________________________
Devel mailing list
Devel(a)ovirt.org <mailto:Devel@ovirt.org>
http://lists.ovirt.org/mailman/listinfo/devel =
<http://lists.ovirt.org/mailman/listinfo/devel>
=20
_______________________________________________
Devel mailing list
Devel(a)ovirt.org <mailto:Devel@ovirt.org>
http://lists.ovirt.org/mailman/listinfo/devel =
<http://lists.ovirt.org/mailman/listinfo/devel>
--Apple-Mail=_99B42EE4-4513-4FE9-8F9A-A1E183AF4102
Content-Transfer-Encoding: quoted-printable
Content-Type: text/html;
charset=us-ascii
<html><head><meta http-equiv=3D"Content-Type"
content=3D"text/html =
charset=3Dus-ascii"></head><body style=3D"word-wrap: break-word; =
-webkit-nbsp-mode: space; -webkit-line-break: after-white-space;" =
class=3D""><br class=3D""><div><blockquote
type=3D"cite" class=3D""><div =
class=3D"">On 16 Mar 2017, at 15:18, Yaniv Kaul <<a =
href=3D"mailto:ykaul@redhat.com"
class=3D"">ykaul(a)redhat.com</a>&gt; =
wrote:</div><br class=3D"Apple-interchange-newline"><div
class=3D""><div =
dir=3D"ltr" style=3D"font-family: Helvetica; font-size: 12px; =
font-style: normal; font-variant-caps: normal; font-weight: normal; =
letter-spacing: normal; orphans: auto; text-align: start; text-indent: =
0px; text-transform: none; white-space: normal; widows: auto; =
word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=3D""><div
=
class=3D"gmail_extra"><br
class=3D"Apple-interchange-newline"><br =
class=3D""><div class=3D"gmail_quote">On Thu, Mar 16, 2017 at
10:46 AM, =
Nir Soffer<span
class=3D"Apple-converted-space"> </span><span =
dir=3D"ltr" class=3D""><<a
href=3D"mailto:nsoffer@redhat.com" =
target=3D"_blank"
class=3D"">nsoffer(a)redhat.com</a>&gt;</span><span =
class=3D"Apple-converted-space"> </span>wrote:<br =
class=3D""><blockquote class=3D"gmail_quote"
style=3D"margin: 0px 0px =
0px 0.8ex; border-left-width: 1px; border-left-style: solid; =
border-left-color: rgb(204, 204, 204); padding-left: 1ex;"><div =
dir=3D"ltr" class=3D"">If found this error in system tests - looks
like =
wrong assert - code should check<div class=3D"">if disk is not None =
before checking state.<br class=3D""><div
class=3D""><br =
class=3D""></div><div class=3D"">I'm not sure who
is the owner of this =
test, so posting here.</div></div></div></blockquote><div
class=3D""><br =
class=3D""></div><div class=3D"">Theoretically,
perhaps. </div><div =
class=3D"">Practically, it worked (until yesterday?) and now I'm also =
seeing this failure - it's not a =
coincidence.</div></div></div></div></div></blockquote><blockquote
=
type=3D"cite" class=3D""><div class=3D""><div
dir=3D"ltr" =
style=3D"font-family: Helvetica; font-size: 12px; font-style: normal; =
font-variant-caps: normal; font-weight: normal; letter-spacing: normal; =
orphans: auto; text-align: start; text-indent: 0px; text-transform: =
none; white-space: normal; widows: auto; word-spacing: 0px; =
-webkit-text-stroke-width: 0px;" class=3D""><div =
class=3D"gmail_extra"><div class=3D"gmail_quote"><div
class=3D"">However, =
looking at my failure[1], I'm seeing other nasty stuff, which may =
explain the later on failures</div><div class=3D""><br =
class=3D""></div><div class=3D"">For example, new NPE I
have not seen in =
the past:</div><div class=3D""><div
class=3D"">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.</div></div></div></div></div></div></blockquote><div><br
=
class=3D""></div>Is this IST or which TZ?</div><div>Likely
<a =
href=3D"https://gerrit.ovirt.org/#/c/69323" =
class=3D"">https://gerrit.ovirt.org/#/c/69323</a>&...
10:33:20 =
CET today </div><div><br class=3D""><blockquote
type=3D"cite" =
class=3D""><div class=3D""><div dir=3D"ltr"
style=3D"font-family: =
Helvetica; font-size: 12px; font-style: normal; font-variant-caps: =
normal; font-weight: normal; letter-spacing: normal; orphans: auto; =
text-align: start; text-indent: 0px; text-transform: none; white-space: =
normal; widows: auto; word-spacing: 0px; -webkit-text-stroke-width: =
0px;" class=3D""><div class=3D"gmail_extra"><div =
class=3D"gmail_quote"><div class=3D""><div
class=3D"">2017-03-16 =
09:57:57,591-04 INFO =
[org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] =
(DefaultQuartzScheduler1) [5d94233] START, SetVmStatusVDSCommand( =
SetVmStatusVDSCommandParameters:{runAsync=3D'true', =
vmId=3D'00000000-0000-0000-0000-000000000000', status=3D'Down', =
exitStatus=3D'Normal'}), log id: 30ee3299</div><div
class=3D"">2017-03-16 =
09:57:57,593-04 DEBUG =
[org.ovirt.engine.core.dal.dbbroker.PostgresDbEngineDialect$PostgresSimple=
JdbcCall] (DefaultQuartzScheduler1) [5d94233] Compiled stored procedure. =
Call string is [{call getvmdynamicbyvmguid(?)}]</div><div =
class=3D"">2017-03-16 09:57:57,594-04 DEBUG =
[org.ovirt.engine.core.dal.dbbroker.PostgresDbEngineDialect$PostgresSimple=
JdbcCall] (DefaultQuartzScheduler1) [5d94233] SqlCall for procedure =
[GetVmDynamicByVmGuid] compiled</div><div class=3D"">2017-03-16 =
09:57:57,595-04 ERROR =
[org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] =
(DefaultQuartzScheduler1) [5d94233] Command 'SetVmStatusVDSCommand( =
SetVmStatusVDSCommandParameters:{runAsync=3D'true', =
vmId=3D'00000000-0000-0000-0000-000000000000', status=3D'Down', =
exitStatus=3D'Normal'})' execution failed: null</div><div =
class=3D"">2017-03-16 09:57:57,595-04 DEBUG =
[org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] =
(DefaultQuartzScheduler1) [5d94233] Exception: =
java.lang.NullPointerException</div><div class=3D""><span =
class=3D"gmail-Apple-tab-span" style=3D"white-space: pre;"> =
</span>at =
org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand.executeVDSCommand(Se=
tVmStatusVDSCommand.java:33) [vdsbroker.jar:]</div><div
class=3D""><span =
class=3D"gmail-Apple-tab-span" style=3D"white-space: pre;"> =
</span>at =
org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBa=
se.java:73) [vdsbroker.jar:]</div><div class=3D""><span =
class=3D"gmail-Apple-tab-span" style=3D"white-space: pre;"> =
</span>at =
org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33) =
[dal.jar:]</div><div class=3D""><span
class=3D"gmail-Apple-tab-span" =
style=3D"white-space: pre;"> </span>at =
org.ovirt.engine.core.vdsbroker.vdsbroker.DefaultVdsCommandExecutor.execut=
e(DefaultVdsCommandExecutor.java:14) [vdsbroker.jar:]</div><div =
class=3D""><span class=3D"gmail-Apple-tab-span"
style=3D"white-space: =
pre;"> </span>at =
org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceMana=
ger.java:404) [vdsbroker.jar:]</div><div class=3D""><span =
class=3D"gmail-Apple-tab-span" style=3D"white-space: pre;"> =
</span>at =
org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.runVdsCommand(VDSBrokerFro=
ntendImpl.java:33) [bll.jar:]</div><div class=3D""><span =
class=3D"gmail-Apple-tab-span" style=3D"white-space: pre;"> =
</span>at =
org.ovirt.engine.core.bll.VmHandler.unLockVm(VmHandler.java:377) =
[bll.jar:]</div></div><div class=3D""><br
class=3D""></div><div =
class=3D""><br class=3D""></div><div
class=3D""><br class=3D""></div><div =
class=3D"">Y.</div><div class=3D""><br
class=3D""></div><div =
class=3D"">[1] <a =
href=3D"http://jenkins.ovirt.org/job/ovirt-system-tests_master_check...
-el7-x86_64/326/artifact/exported-artifacts/basic_suite_master__logs/test_=
logs/basic-suite-master/post-004_basic_sanity.py/lago-basic-suite-master-e=
ngine/_var_log/ovirt-engine/engine.log" =
class=3D"">http://jenkins.ovirt.org/job/ovirt-system-tests_m...
tch-el7-x86_64/326/artifact/exported-artifacts/basic_suite_master__logs/te=
st_logs/basic-suite-master/post-004_basic_sanity.py/lago-basic-suite-maste=
r-engine/_var_log/ovirt-engine/engine.log</a></div><div
class=3D""><br =
class=3D""></div><blockquote class=3D"gmail_quote"
style=3D"margin: 0px =
0px 0px 0.8ex; border-left-width: 1px; border-left-style: solid; =
border-left-color: rgb(204, 204, 204); padding-left: 1ex;"><div =
dir=3D"ltr" class=3D""><div class=3D""><div
class=3D""><br =
class=3D""></div><div class=3D""><pre =
class=3D"gmail-m_-3711950224702553848inbox-inbox-console-output" =
style=3D"box-sizing: border-box; white-space: pre-wrap; word-wrap: =
break-word; margin-top: 0px; margin-bottom: 0px; color: rgb(51, 51, 51); =
font-size: 16px;"><span =
class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:05</b> </span><span style=3D"box-sizing:
border-box; =
color: rgb(0, 205, 205);" class=3D""> # snapshots_merge: </span>
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span><span style=3D"box-sizing:
border-box; =
color: rgb(205, 0, 0);" class=3D"">Unhandled exception in
<function =
<lambda> at 0x276a5f0>
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span>Traceback (most recent call
last):
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span> File
"/usr/lib/python2.7/site-<wbr =
class=3D"">packages/ovirtlago/testlib.py"<wbr
class=3D"">, line 217, in =
assert_equals_within
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span> res =3D func()
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span> File
"/home/jenkins/workspace/<wbr =
class=3D"">ovirt-system-tests_manual/<wbr =
class=3D"">ovirt-system-tests/basic-<wbr =
class=3D"">suite-master/test-scenarios/<wbr =
class=3D"">004_basic_sanity.py", line 466, in <lambda>
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span>
api.vms.get(VM0_NAME).disks.<wbr =
class=3D"">get(disk_name).status.state =3D=3D 'ok'
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span>AttributeError: 'NoneType'
object has no =
attribute 'state'</span>
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span><span style=3D"box-sizing:
border-box; =
color: rgb(205, 0, 0);" class=3D"">Error while running thread
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span>Traceback (most recent call
last):
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span> File
"/usr/lib/python2.7/site-<wbr =
class=3D"">packages/lago/utils.py", line 57, in _ret_via_queue
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span> queue.put({'return':
func()})
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span> File
"/home/jenkins/workspace/<wbr =
class=3D"">ovirt-system-tests_manual/<wbr =
class=3D"">ovirt-system-tests/basic-<wbr =
class=3D"">suite-master/test-scenarios/<wbr =
class=3D"">004_basic_sanity.py", line 465, in snapshot_live_merge
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span> lambda:
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span> File
"/usr/lib/python2.7/site-<wbr =
class=3D"">packages/ovirtlago/testlib.py"<wbr
class=3D"">, line 264, in =
assert_true_within_long
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span>
assert_equals_within_long(<wbr =
class=3D"">func, True, allowed_exceptions)
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span> File
"/usr/lib/python2.7/site-<wbr =
class=3D"">packages/ovirtlago/testlib.py"<wbr
class=3D"">, line 251, in =
assert_equals_within_long
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span> func, value, LONG_TIMEOUT, =
allowed_exceptions=3Dallowed_<wbr class=3D"">exceptions
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span> File
"/usr/lib/python2.7/site-<wbr =
class=3D"">packages/ovirtlago/testlib.py"<wbr
class=3D"">, line 217, in =
assert_equals_within
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span> res =3D func()
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span> File
"/home/jenkins/workspace/<wbr =
class=3D"">ovirt-system-tests_manual/<wbr =
class=3D"">ovirt-system-tests/basic-<wbr =
class=3D"">suite-master/test-scenarios/<wbr =
class=3D"">004_basic_sanity.py", line 466, in <lambda>
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span>
api.vms.get(VM0_NAME).disks.<wbr =
class=3D"">get(disk_name).status.state =3D=3D 'ok'
<span class=3D"gmail-m_-3711950224702553848inbox-inbox-timestamp" =
style=3D"box-sizing: border-box;"><b style=3D"box-sizing:
border-box;" =
class=3D"">08:28:31</b> </span>AttributeError: 'NoneType'
object has no =
attribute 'state'</span>
</pre><br =
class=3D"gmail-m_-3711950224702553848inbox-inbox-Apple-interchange-newline=
"></div></div></div><br
class=3D"">______________________________<wbr =
class=3D"">_________________<br class=3D"">Devel mailing
list<br =
class=3D""><a href=3D"mailto:Devel@ovirt.org" =
class=3D"">Devel(a)ovirt.org</a><br class=3D""><a =
href=3D"http://lists.ovirt.org/mailman/listinfo/devel"
rel=3D"noreferrer" =
target=3D"_blank" class=3D"">http://lists.ovirt.org/<wbr =
class=3D"">mailman/listinfo/devel</a><br
class=3D""></blockquote></div><br=
class=3D""></div></div><span style=3D"font-family:
Helvetica; =
font-size: 12px; font-style: normal; font-variant-caps: normal; =
font-weight: normal; letter-spacing: normal; orphans: auto; text-align: =
start; text-indent: 0px; text-transform: none; white-space: normal; =
widows: auto; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: =
none; display: inline !important;" =
class=3D"">_______________________________________________</span><br
=
style=3D"font-family: Helvetica; font-size: 12px; font-style: normal; =
font-variant-caps: normal; font-weight: normal; letter-spacing: normal; =
orphans: auto; text-align: start; text-indent: 0px; text-transform: =
none; white-space: normal; widows: auto; word-spacing: 0px; =
-webkit-text-stroke-width: 0px;" class=3D""><span
style=3D"font-family: =
Helvetica; font-size: 12px; font-style: normal; font-variant-caps: =
normal; font-weight: normal; letter-spacing: normal; orphans: auto; =
text-align: start; text-indent: 0px; text-transform: none; white-space: =
normal; widows: auto; word-spacing: 0px; -webkit-text-stroke-width: 0px; =
float: none; display: inline !important;" class=3D"">Devel mailing =
list</span><br style=3D"font-family: Helvetica; font-size: 12px; =
font-style: normal; font-variant-caps: normal; font-weight: normal; =
letter-spacing: normal; orphans: auto; text-align: start; text-indent: =
0px; text-transform: none; white-space: normal; widows: auto; =
word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=3D""><a =
href=3D"mailto:Devel@ovirt.org" style=3D"font-family: Helvetica; =
font-size: 12px; font-style: normal; font-variant-caps: normal; =
font-weight: normal; letter-spacing: normal; orphans: auto; text-align: =
start; text-indent: 0px; text-transform: none; white-space: normal; =
widows: auto; word-spacing: 0px; -webkit-text-size-adjust: auto; =
-webkit-text-stroke-width: 0px;"
class=3D"">Devel(a)ovirt.org</a><br =
style=3D"font-family: Helvetica; font-size: 12px; font-style: normal; =
font-variant-caps: normal; font-weight: normal; letter-spacing: normal; =
orphans: auto; text-align: start; text-indent: 0px; text-transform: =
none; white-space: normal; widows: auto; word-spacing: 0px; =
-webkit-text-stroke-width: 0px;" class=3D""><a =
href=3D"http://lists.ovirt.org/mailman/listinfo/devel" =
style=3D"font-family: Helvetica; font-size: 12px; font-style: normal; =
font-variant-caps: normal; font-weight: normal; letter-spacing: normal; =
orphans: auto; text-align: start; text-indent: 0px; text-transform: =
none; white-space: normal; widows: auto; word-spacing: 0px; =
-webkit-text-size-adjust: auto; -webkit-text-stroke-width: 0px;" =
class=3D"">http://lists.ovirt.org/mailman/listinfo/devel<...
uote></div><br class=3D""></body></html>=
--Apple-Mail=_99B42EE4-4513-4FE9-8F9A-A1E183AF4102--
2:49 p.m.
On Thu, Mar 16, 2017 at 8:16 PM, Michal Skrivanek <mskrivan(a)redhat.com>
wrote:
On 16 Mar 2017, at 15:18, Yaniv Kaul <ykaul(a)redhat.com> wrote:
On Thu, Mar 16, 2017 at 10:46 AM, Nir Soffer <nsoffer(a)redhat.com> wrote:
> 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?
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.dbbroker.
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.dbbroker.
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.
executeVDSCommand(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.DefaultVdsCommandExecutor.
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.runVdsCommand(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_
check-patch-el7-x86_64/326/artifact/exported-artifacts/
basic_suite_master__logs/test_logs/basic-suite-master/post-
004_basic_sanity.py/lago-basic-suite-master-engine/_
var_log/ovirt-engine/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
4:38 p.m.
On Fri, Mar 17, 2017 at 9:49 PM Yaniv Kaul <ykaul(a)redhat.com> wrote:
On Thu, Mar 16, 2017 at 8:16 PM, Michal Skrivanek
<mskrivan(a)redhat.com>
wrote:
On 16 Mar 2017, at 15:18, Yaniv Kaul <ykaul(a)redhat.com> wrote:
On Thu, Mar 16, 2017 at 10:46 AM, Nir Soffer <nsoffer(a)redhat.com> wrote:
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.
We have offset from UTC - "-04"
Do we have slaves here?
https://time.is/map/UTC-4
Probably machine with incorrect timezone?
Likely https://gerrit.ovirt.org/#/c/69323 merged 10:33:20 CET today
That's the cause or the fix?
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.dbbroker.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.dbbroker.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.executeVDSCommand(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.DefaultVdsCommandExecutor.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.runVdsCommand(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_check-patch-el7-x8...
*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
5:05 p.m.
--Apple-Mail=_FAE55184-0204-4B4B-B082-EFABEC5CA0A7
Content-Transfer-Encoding: quoted-printable
Content-Type: text/plain;
charset=us-ascii
[org.ovirt.engine.core.bll.AddVmTemplateCommand] =
(DefaultQuartzScheduler1) [5d94233] Ending command =
'org.ovirt.engine.core.bll.AddVmTemplateCommand' successfully.
"/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 217, in =
assert_equals_within
<http://lists.ovirt.org/mailman/listinfo/devel>
On 17 Mar 2017, at 20:49, Yaniv Kaul <ykaul(a)redhat.com> wrote:
=20
=20
=20
On Thu, Mar 16, 2017 at 8:16 PM, Michal Skrivanek <mskrivan(a)redhat.com =
<mailto:mskrivan@redhat.com>> wrote:
=20
> On 16 Mar 2017, at 15:18, Yaniv Kaul <ykaul(a)redhat.com =
<mailto:ykaul@redhat.com>> wrote:
<mailto:nsoffer@redhat.com>> wrote:
> If found this error in system tests - looks like wrong assert -
code =
should check
> if disk is not None before checking state.
this
failure - it's not a coincidence.
=20
> I'm not sure who is the owner of this test, so
posting here.
=20
> Theoretically, perhaps.=20
> Practically, it worked (until yesterday?) and now I'm also seeing = > However, looking at my failure[1], I'm seeing other nasty
stuff, =
which may explain the later on failures
=20
> For example, new NPE I have
not seen in the past:
> 2017-03-16 09:57:57,581-04 INFO =
=20
Is this IST or which TZ?
=20
Interesting question - I guess that's why we need the offset from UTC =
or use
UTC in the logs.
=20
Likely https://gerrit.ovirt.org/#/c/69323 =
<https://gerrit.ovirt.org/#/c/69323> merged 10:33:20 CET today=20
=20
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
Y.
=20
=20
> 2017-03-16 09:57:57,591-04 INFO =
[org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] =
(DefaultQuartzScheduler1) [5d94233] START, SetVmStatusVDSCommand( =
SetVmStatusVDSCommandParameters:{runAsync=3D'true', =
vmId=3D'00000000-0000-0000-0000-000000000000', status=3D'Down', =
exitStatus=3D'Normal'}), log id: 30ee3299
> 2017-03-16 09:57:57,593-04 DEBUG =
[org.ovirt.engine.core.dal.dbbroker.PostgresDbEngineDialect$PostgresSimple=
JdbcCall] (DefaultQuartzScheduler1) [5d94233] Compiled stored procedure. =
Call string is [{call getvmdynamicbyvmguid(?)}]
> 2017-03-16 09:57:57,594-04 DEBUG =
[org.ovirt.engine.core.dal.dbbroker.PostgresDbEngineDialect$PostgresSimple=
JdbcCall] (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=3D'true', =
vmId=3D'00000000-0000-0000-0000-000000000000', status=3D'Down', =
exitStatus=3D'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.executeVDSCommand(Se=
tVmStatusVDSCommand.java:33) [vdsbroker.jar:]
> at =
org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBa=
se.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.execut=
e(DefaultVdsCommandExecutor.java:14) [vdsbroker.jar:]
> at =
org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceMana=
ger.java:404) [vdsbroker.jar:]
> at =
org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.runVdsCommand(VDSBrokerFro=
ntendImpl.java:33) [bll.jar:]
> at =
org.ovirt.engine.core.bll.VmHandler.unLockVm(VmHandler.java:377) =
[bll.jar:]
http://jenkins.ovirt.org/job/ovirt-system-tests_master_check-patch-el7-x86=
_64/326/artifact/exported-artifacts/basic_suite_master__logs/test_logs/bas=
ic-suite-master/post-004_basic_sanity.py/lago-basic-suite-master-engine/_v=
ar_log/ovirt-engine/engine.log =
<http://jenkins.ovirt.org/job/ovirt-system-tests_master_check-patch-el7-x8=
6_64/326/artifact/exported-artifacts/basic_suite_master__logs/test_logs/ba=
sic-suite-master/post-004_basic_sanity.py/lago-basic-suite-master-engine/_=
var_log/ovirt-engine/engine.log>
=20
=20
>
08:28:05 # snapshots_merge:=20
> 08:28:31 Unhandled exception in <function <lambda> at 0x276a5f0>
> 08:28:31 Traceback (most recent call last):
> 08:28:31 File =
> 08:28:31 res =3D func()
> 08:28:31 File =
"/home/jenkins/workspace/ovirt-system-tests_manual/ovirt-system-tests/basi=
c-suite-master/test-scenarios/004_basic_sanity.py", line 466, in =
<lambda>
> 08:28:31 api.vms.get(VM0_NAME).disks.ge =
<http://disks.ge/>t(disk_name).status.state =3D=3D '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/basi=
c-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=3Dallowed_exceptions
> 08:28:31 File =
"/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 217, in =
assert_equals_within
> 08:28:31 res =3D func()
> 08:28:31 File =
"/home/jenkins/workspace/ovirt-system-tests_manual/ovirt-system-tests/basi=
c-suite-master/test-scenarios/004_basic_sanity.py", line 466, in =
<lambda>
> 08:28:31 api.vms.get(VM0_NAME).disks.ge =
<http://disks.ge/>t(disk_name).status.state =3D=3D 'ok'
> 08:28:31 AttributeError: 'NoneType' object has no
attribute 'state'
<http://lists.ovirt.org/mailman/listinfo/devel>
=20
=20
>
_______________________________________________
> Devel mailing list
> Devel(a)ovirt.org <mailto:Devel@ovirt.org>
> http://lists.ovirt.org/mailman/listinfo/devel =
=20
>
_______________________________________________
> Devel mailing list
> Devel(a)ovirt.org <mailto:Devel@ovirt.org>
> http://lists.ovirt.org/mailman/listinfo/devel =
=20
--Apple-Mail=_FAE55184-0204-4B4B-B082-EFABEC5CA0A7
Content-Transfer-Encoding: quoted-printable
Content-Type: text/html;
charset=us-ascii
<html><head><meta http-equiv=3D"Content-Type"
content=3D"text/html =
charset=3Dus-ascii"></head><body style=3D"word-wrap: break-word; =
-webkit-nbsp-mode: space; -webkit-line-break: after-white-space;" =
class=3D""><br class=3D""><div><blockquote
type=3D"cite" class=3D""><div =
class=3D"">On 17 Mar 2017, at 20:49, Yaniv Kaul <<a =
href=3D"mailto:ykaul@redhat.com"
class=3D"">ykaul(a)redhat.com</a>&gt; =
wrote:</div><br class=3D"Apple-interchange-newline"><div
class=3D""><div =
dir=3D"ltr" class=3D""><br class=3D""><div
class=3D"gmail_extra"><br =
class=3D""><div class=3D"gmail_quote">On Thu, Mar 16, 2017 at
8:16 PM, =
Michal Skrivanek <span dir=3D"ltr" class=3D""><<a =
href=3D"mailto:mskrivan@redhat.com" target=3D"_blank" =
class=3D"">mskrivan(a)redhat.com</a>&gt;</span> wrote:<br =
class=3D""><blockquote class=3D"gmail_quote"
style=3D"margin:0 0 0 =
.8ex;border-left:1px #ccc solid;padding-left:1ex"><div =
style=3D"word-wrap:break-word" class=3D""><br
class=3D""><div =
class=3D""><span class=3D""><blockquote
type=3D"cite" class=3D""><div =
class=3D"">On 16 Mar 2017, at 15:18, Yaniv Kaul <<a =
href=3D"mailto:ykaul@redhat.com" target=3D"_blank" =
class=3D"">ykaul(a)redhat.com</a>&gt; wrote:</div><br =
class=3D"m_-2867758101781581971Apple-interchange-newline"><div =
class=3D""><div dir=3D"ltr" =
style=3D"font-family:Helvetica;font-size:12px;font-style:normal;font-varia=
nt-caps:normal;font-weight:normal;letter-spacing:normal;text-align:start;t=
ext-indent:0px;text-transform:none;white-space:normal;word-spacing:0px" =
class=3D""><div class=3D"gmail_extra"><br =
class=3D"m_-2867758101781581971Apple-interchange-newline"><br =
class=3D""><div class=3D"gmail_quote">On Thu, Mar 16, 2017 at
10:46 AM, =
Nir Soffer<span =
class=3D"m_-2867758101781581971Apple-converted-space"> </span><span
=
dir=3D"ltr" class=3D""><<a
href=3D"mailto:nsoffer@redhat.com" =
target=3D"_blank"
class=3D"">nsoffer(a)redhat.com</a>&gt;</span><span =
class=3D"m_-2867758101781581971Apple-converted-space"> </span>wr<wbr
=
class=3D"">ote:<br class=3D""><blockquote
class=3D"gmail_quote" =
style=3D"margin:0px 0px 0px =
0.8ex;border-left-width:1px;border-left-style:solid;border-left-color:rgb(=
204,204,204);padding-left:1ex"><div dir=3D"ltr"
class=3D"">If found this =
error in system tests - looks like wrong assert - code should check<div =
class=3D"">if disk is not None before checking state.<br
class=3D""><div =
class=3D""><br class=3D""></div><div
class=3D"">I'm not sure who is the =
owner of this test, so posting
here.</div></div></div></blockquote><div =
class=3D""><br class=3D""></div><div
class=3D"">Theoretically, =
perhaps. </div><div class=3D"">Practically, it worked
(until =
yesterday?) and now I'm also seeing this failure - it's not a =
coincidence.</div></div></div></div></div></blockquote><blockquote
=
type=3D"cite" class=3D""><div class=3D""><div
dir=3D"ltr" =
style=3D"font-family:Helvetica;font-size:12px;font-style:normal;font-varia=
nt-caps:normal;font-weight:normal;letter-spacing:normal;text-align:start;t=
ext-indent:0px;text-transform:none;white-space:normal;word-spacing:0px" =
class=3D""><div class=3D"gmail_extra"><div
class=3D"gmail_quote"><div =
class=3D"">However, looking at my failure[1], I'm seeing other nasty =
stuff, which may explain the later on failures</div><div
class=3D""><br =
class=3D""></div><div class=3D"">For example, new NPE I
have not seen in =
the past:</div><div class=3D""><div
class=3D"">2017-03-16 =
09:57:57,581-04 INFO [org.ovirt.engine.core.bll.<wbr =
class=3D"">AddVmTemplateCommand] (DefaultQuartzScheduler1) [5d94233] =
Ending command 'org.ovirt.engine.core.bll.<wbr =
class=3D"">AddVmTemplateCommand' =
successfully.</div></div></div></div></div></div></blockquote><div
=
class=3D""><br class=3D""></div></span>Is this
IST or which =
TZ?</div></div></blockquote><div class=3D""><br
class=3D""></div><div =
class=3D"">Interesting question - I guess that's why we need the offset
=
from UTC or use UTC in the logs.</div><div =
class=3D""> </div><blockquote
class=3D"gmail_quote" style=3D"margin:0=
0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div =
style=3D"word-wrap:break-word" class=3D""><div
class=3D"">Likely <a =
href=3D"https://gerrit.ovirt.org/#/c/69323" target=3D"_blank" =
class=3D"">https://gerrit.ovirt.org/#/c/<wbr =
class=3D"">69323</a> merged 10:33:20 CET =
today </div></div></blockquote><div
class=3D""><br =
class=3D""></div><div class=3D"">That's the cause
or the =
fix?</div></div></div></div></div></blockquote><div><br
=
class=3D""></div>oh, sorry, the cause.</div><div>we were
not able to =
find anyone to confirm and resolve it today unfortunately</div><div><br =
class=3D""><blockquote type=3D"cite"
class=3D""><div class=3D""><div =
dir=3D"ltr" class=3D""><div
class=3D"gmail_extra"><div =
class=3D"gmail_quote"><div class=3D"">Y.</div><div
=
class=3D""> </div><blockquote
class=3D"gmail_quote" style=3D"margin:0=
0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div =
style=3D"word-wrap:break-word" class=3D""><div
class=3D""><div =
class=3D"h5"><div class=3D""><br
class=3D""><blockquote type=3D"cite" =
class=3D""><div class=3D""><div dir=3D"ltr" =
style=3D"font-family:Helvetica;font-size:12px;font-style:normal;font-varia=
nt-caps:normal;font-weight:normal;letter-spacing:normal;text-align:start;t=
ext-indent:0px;text-transform:none;white-space:normal;word-spacing:0px" =
class=3D""><div class=3D"gmail_extra"><div
class=3D"gmail_quote"><div =
class=3D""><div class=3D"">2017-03-16 09:57:57,591-04 INFO =
[org.ovirt.engine.core.<wbr class=3D"">vdsbroker.<wbr =
class=3D"">SetVmStatusVDSCommand] (DefaultQuartzScheduler1) [5d94233] =
START, SetVmStatusVDSCommand( SetVmStatusVDSCommandParameter<wbr =
class=3D"">s:{runAsync=3D'true',
vmId=3D'00000000-0000-0000-0000-<wbr =
class=3D"">000000000000', status=3D'Down',
exitStatus=3D'Normal'}), log =
id: 30ee3299</div><div class=3D"">2017-03-16 09:57:57,593-04 DEBUG
=
[org.ovirt.engine.core.dal.<wbr class=3D"">dbbroker.<wbr =
class=3D"">PostgresDbEngineDialect$<wbr
class=3D"">PostgresSimpleJdbcCall]=
(DefaultQuartzScheduler1) [5d94233] Compiled stored procedure. Call =
string is [{call getvmdynamicbyvmguid(?)}]</div><div
class=3D"">2017-03-16=
09:57:57,594-04 DEBUG [org.ovirt.engine.core.dal.<wbr =
class=3D"">dbbroker.<wbr
class=3D"">PostgresDbEngineDialect$<wbr =
class=3D"">PostgresSimpleJdbcCall] (DefaultQuartzScheduler1) [5d94233] =
SqlCall for procedure [GetVmDynamicByVmGuid] compiled</div><div =
class=3D"">2017-03-16 09:57:57,595-04 ERROR [org.ovirt.engine.core.<wbr =
class=3D"">vdsbroker.<wbr class=3D"">SetVmStatusVDSCommand]
=
(DefaultQuartzScheduler1) [5d94233] Command 'SetVmStatusVDSCommand( =
SetVmStatusVDSCommandParameter<wbr
class=3D"">s:{runAsync=3D'true', =
vmId=3D'00000000-0000-0000-0000-<wbr class=3D"">000000000000', =
status=3D'Down', exitStatus=3D'Normal'})' execution failed: =
null</div><div class=3D"">2017-03-16 09:57:57,595-04 DEBUG =
[org.ovirt.engine.core.<wbr class=3D"">vdsbroker.<wbr =
class=3D"">SetVmStatusVDSCommand] (DefaultQuartzScheduler1) [5d94233] =
Exception: java.lang.NullPointerException</div><div
class=3D""><span =
class=3D"m_-2867758101781581971gmail-Apple-tab-span" =
style=3D"white-space:pre-wrap"> </span>at org.ovirt.engine.core.<wbr
=
class=3D"">vdsbroker.<wbr
class=3D"">SetVmStatusVDSCommand.<wbr =
class=3D"">executeVDSCommand(<wbr =
class=3D"">SetVmStatusVDSCommand.java:33) [vdsbroker.jar:]</div><div
=
class=3D""><span
class=3D"m_-2867758101781581971gmail-Apple-tab-span" =
style=3D"white-space:pre-wrap"> </span>at org.ovirt.engine.core.<wbr
=
class=3D"">vdsbroker.VDSCommandBase.<wbr =
class=3D"">executeCommand(VDSCommandBase.<wbr
class=3D"">java:73) =
[vdsbroker.jar:]</div><div class=3D""><span =
class=3D"m_-2867758101781581971gmail-Apple-tab-span" =
style=3D"white-space:pre-wrap"> </span>at
org.ovirt.engine.core.dal.<wbr =
class=3D"">VdcCommandBase.execute(<wbr
class=3D"">VdcCommandBase.java:33) =
[dal.jar:]</div><div class=3D""><span =
class=3D"m_-2867758101781581971gmail-Apple-tab-span" =
style=3D"white-space:pre-wrap"> </span>at org.ovirt.engine.core.<wbr
=
class=3D"">vdsbroker.vdsbroker.<wbr =
class=3D"">DefaultVdsCommandExecutor.<wbr
class=3D"">execute(<wbr =
class=3D"">DefaultVdsCommandExecutor.<wbr class=3D"">java:14)
=
[vdsbroker.jar:]</div><div class=3D""><span =
class=3D"m_-2867758101781581971gmail-Apple-tab-span" =
style=3D"white-space:pre-wrap"> </span>at org.ovirt.engine.core.<wbr
=
class=3D"">vdsbroker.ResourceManager.<wbr =
class=3D"">runVdsCommand(ResourceManager.<wbr
class=3D"">java:404) =
[vdsbroker.jar:]</div><div class=3D""><span =
class=3D"m_-2867758101781581971gmail-Apple-tab-span" =
style=3D"white-space:pre-wrap"> </span>at
org.ovirt.engine.core.bll.<wbr =
class=3D"">VDSBrokerFrontendImpl.<wbr
class=3D"">runVdsCommand(<wbr =
class=3D"">VDSBrokerFrontendImpl.java:33) [bll.jar:]</div><div =
class=3D""><span
class=3D"m_-2867758101781581971gmail-Apple-tab-span" =
style=3D"white-space:pre-wrap"> </span>at
org.ovirt.engine.core.bll.<wbr =
class=3D"">VmHandler.unLockVm(VmHandler.<wbr
class=3D"">java:377) =
[bll.jar:]</div></div><div class=3D""><br
class=3D""></div><div =
class=3D""><br class=3D""></div><div
class=3D""><br class=3D""></div><div =
class=3D"">Y.</div><div class=3D""><br
class=3D""></div><div =
class=3D"">[1] <a =
href=3D"http://jenkins.ovirt.org/job/ovirt-system-tests_master_check...
-el7-x86_64/326/artifact/exported-artifacts/basic_suite_master__logs/test_=
logs/basic-suite-master/post-004_basic_sanity.py/lago-basic-suite-master-e=
ngine/_var_log/ovirt-engine/engine.log" target=3D"_blank" =
class=3D"">http://jenkins.ovirt.org/job/<wbr =
class=3D"">ovirt-system-tests_master_<wbr =
class=3D"">check-patch-el7-x86_64/326/<wbr =
class=3D"">artifact/exported-artifacts/<wbr =
class=3D"">basic_suite_master__logs/test_<wbr =
class=3D"">logs/basic-suite-master/post-<wbr =
class=3D"">004_basic_sanity.py/lago-<wbr =
class=3D"">basic-suite-master-engine/_<wbr =
class=3D"">var_log/ovirt-engine/engine.<wbr
class=3D"">log</a></div><div =
class=3D""><br class=3D""></div><blockquote
class=3D"gmail_quote" =
style=3D"margin:0px 0px 0px =
0.8ex;border-left-width:1px;border-left-style:solid;border-left-color:rgb(=
204,204,204);padding-left:1ex"><div dir=3D"ltr"
class=3D""><div =
class=3D""><div class=3D""><br
class=3D""></div><div class=3D""><pre =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-con=
sole-output" =
style=3D"box-sizing:border-box;white-space:pre-wrap;word-wrap:break-word;m=
argin-top:0px;margin-bottom:0px;color:rgb(51,51,51);font-size:16px"><span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:05</b> </span><span =
style=3D"box-sizing:border-box;color:rgb(0,205,205)" class=3D""> #
=
snapshots_merge: </span>
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span><span =
style=3D"box-sizing:border-box;color:rgb(205,0,0)"
class=3D"">Unhandled =
exception in <function <lambda> at 0x276a5f0>
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span>Traceback (most recent call
last):
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span> File =
"/usr/lib/python2.7/site-packa<wbr
class=3D"">ges/ovirtlago/testlib.py", =
line 217, in assert_equals_within
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span> res =3D func()
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span> File =
"/home/jenkins/workspace/ovirt<wbr =
class=3D"">-system-tests_manual/ovirt-<wbr =
class=3D"">system-tests/basic-suite-<wbr =
class=3D"">master/test-scenarios/004_<wbr
class=3D"">basic_sanity.py", =
line 466, in <lambda>
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span> api.vms.get(VM0_NAME).<a
=
href=3D"http://disks.ge/" class=3D"">disks.ge</a><wbr =
class=3D"">t(disk_name).status.state =3D=3D 'ok'
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span>AttributeError:
'NoneType' object has no =
attribute 'state'</span>
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span><span =
style=3D"box-sizing:border-box;color:rgb(205,0,0)" class=3D"">Error
=
while running thread
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span>Traceback (most recent call
last):
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span> File =
"/usr/lib/python2.7/site-packa<wbr
class=3D"">ges/lago/utils.py", line =
57, in _ret_via_queue
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span> queue.put({'return':
func()})
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span> File =
"/home/jenkins/workspace/ovirt<wbr =
class=3D"">-system-tests_manual/ovirt-<wbr =
class=3D"">system-tests/basic-suite-<wbr =
class=3D"">master/test-scenarios/004_<wbr
class=3D"">basic_sanity.py", =
line 465, in snapshot_live_merge
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span> lambda:
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span> File =
"/usr/lib/python2.7/site-packa<wbr
class=3D"">ges/ovirtlago/testlib.py", =
line 264, in assert_true_within_long
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span>
assert_equals_within_long(func<wbr =
class=3D"">, True, allowed_exceptions)
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span> File =
"/usr/lib/python2.7/site-packa<wbr
class=3D"">ges/ovirtlago/testlib.py", =
line 251, in assert_equals_within_long
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span> func, value, LONG_TIMEOUT, =
allowed_exceptions=3Dallowed_exc<wbr class=3D"">eptions
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span> File =
"/usr/lib/python2.7/site-packa<wbr
class=3D"">ges/ovirtlago/testlib.py", =
line 217, in assert_equals_within
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span> res =3D func()
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span> File =
"/home/jenkins/workspace/ovirt<wbr =
class=3D"">-system-tests_manual/ovirt-<wbr =
class=3D"">system-tests/basic-suite-<wbr =
class=3D"">master/test-scenarios/004_<wbr
class=3D"">basic_sanity.py", =
line 466, in <lambda>
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span> api.vms.get(VM0_NAME).<a
=
href=3D"http://disks.ge/" class=3D"">disks.ge</a><wbr =
class=3D"">t(disk_name).status.state =3D=3D 'ok'
<span =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-tim=
estamp" style=3D"box-sizing:border-box"><b
style=3D"box-sizing:border-box"=
class=3D"">08:28:31</b> </span>AttributeError:
'NoneType' object has no =
attribute 'state'</span>
</pre><br =
class=3D"m_-2867758101781581971gmail-m_-3711950224702553848inbox-inbox-App=
le-interchange-newline"></div></div></div><br =
class=3D"">______________________________<wbr =
class=3D"">_________________<br class=3D"">Devel mailing
list<br =
class=3D""><a href=3D"mailto:Devel@ovirt.org"
target=3D"_blank" =
class=3D"">Devel(a)ovirt.org</a><br class=3D""><a =
href=3D"http://lists.ovirt.org/mailman/listinfo/devel"
rel=3D"noreferrer" =
target=3D"_blank" class=3D"">http://lists.ovirt.org/mailman<wbr
=
class=3D"">/listinfo/devel</a><br
class=3D""></blockquote></div><br =
class=3D""></div></div><span =
style=3D"font-family:Helvetica;font-size:12px;font-style:normal;font-varia=
nt-caps:normal;font-weight:normal;letter-spacing:normal;text-align:start;t=
ext-indent:0px;text-transform:none;white-space:normal;word-spacing:0px;flo=
at:none;display:inline!important" =
class=3D"">______________________________<wbr =
class=3D"">_________________</span><br =
style=3D"font-family:Helvetica;font-size:12px;font-style:normal;font-varia=
nt-caps:normal;font-weight:normal;letter-spacing:normal;text-align:start;t=
ext-indent:0px;text-transform:none;white-space:normal;word-spacing:0px" =
class=3D""><span =
style=3D"font-family:Helvetica;font-size:12px;font-style:normal;font-varia=
nt-caps:normal;font-weight:normal;letter-spacing:normal;text-align:start;t=
ext-indent:0px;text-transform:none;white-space:normal;word-spacing:0px;flo=
at:none;display:inline!important" class=3D"">Devel mailing =
list</span><br =
style=3D"font-family:Helvetica;font-size:12px;font-style:normal;font-varia=
nt-caps:normal;font-weight:normal;letter-spacing:normal;text-align:start;t=
ext-indent:0px;text-transform:none;white-space:normal;word-spacing:0px" =
class=3D""><a href=3D"mailto:Devel@ovirt.org" =
style=3D"font-family:Helvetica;font-size:12px;font-style:normal;font-varia=
nt-caps:normal;font-weight:normal;letter-spacing:normal;text-align:start;t=
ext-indent:0px;text-transform:none;white-space:normal;word-spacing:0px" =
target=3D"_blank" class=3D"">Devel(a)ovirt.org</a><br =
style=3D"font-family:Helvetica;font-size:12px;font-style:normal;font-varia=
nt-caps:normal;font-weight:normal;letter-spacing:normal;text-align:start;t=
ext-indent:0px;text-transform:none;white-space:normal;word-spacing:0px" =
class=3D""><a
href=3D"http://lists.ovirt.org/mailman/listinfo/devel" =
style=3D"font-family:Helvetica;font-size:12px;font-style:normal;font-varia=
nt-caps:normal;font-weight:normal;letter-spacing:normal;text-align:start;t=
ext-indent:0px;text-transform:none;white-space:normal;word-spacing:0px" =
target=3D"_blank" class=3D"">http://lists.ovirt.org/<wbr =
class=3D"">mailman/listinfo/devel</a></div></blockquote></div><br
=
class=3D""></div></div></div></blockquote></div><br
=
class=3D""></div></div>
</div></blockquote></div><br
class=3D""></body></html>=
--Apple-Mail=_FAE55184-0204-4B4B-B082-EFABEC5CA0A7--
5:57 a.m.
On Sat, Mar 18, 2017 at 12:05 AM, Michal Skrivanek <mskrivan(a)redhat.com>
wrote:
On 17 Mar 2017, at 20:49, Yaniv Kaul <ykaul(a)redhat.com> wrote:
On Thu, Mar 16, 2017 at 8:16 PM, Michal Skrivanek <mskrivan(a)redhat.com>
wrote:
>
> On 16 Mar 2017, at 15:18, Yaniv Kaul <ykaul(a)redhat.com> wrote:
>
>
>
> On Thu, Mar 16, 2017 at 10:46 AM, Nir Soffer <nsoffer(a)redhat.com> wrote:
>
>> 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 secondary bug is that it fails every 10 seconds or so, continuously.
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_
> suite_master__logs/test_logs/basic-suite-master/post-004_
> basic_sanity.py/lago-basic-suite-master-engine/_var_log/
> ovirt-engine/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
>
>
>
5:14 a.m.
On Sat, Mar 18, 2017 at 12:57 PM, Yaniv Kaul <ykaul(a)redhat.com> wrote:
On Sat, Mar 18, 2017 at 12:05 AM, Michal Skrivanek <mskrivan(a)redhat.com>
wrote:
>
> On 17 Mar 2017, at 20:49, Yaniv Kaul <ykaul(a)redhat.com> wrote:
>
>
>
> On Thu, Mar 16, 2017 at 8:16 PM, Michal Skrivanek <mskrivan(a)redhat.com>
> wrote:
>
>>
>> On 16 Mar 2017, at 15:18, Yaniv Kaul <ykaul(a)redhat.com> wrote:
>>
>>
>>
>> On Thu, Mar 16, 2017 at 10:46 AM, Nir Soffer <nsoffer(a)redhat.com> wrote:
>>
>>> 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.
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.
[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.
>
> 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-
>> engine/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
7:09 a.m.
On Sun, Mar 19, 2017 at 12:14 PM, Arik Hadas <ahadas(a)redhat.com> wrote:
On Sat, Mar 18, 2017 at 12:57 PM, Yaniv Kaul <ykaul(a)redhat.com> wrote:
>
>
> On Sat, Mar 18, 2017 at 12:05 AM, Michal Skrivanek <mskrivan(a)redhat.com>
> wrote:
>
>>
>> On 17 Mar 2017, at 20:49, Yaniv Kaul <ykaul(a)redhat.com> wrote:
>>
>>
>>
>> On Thu, Mar 16, 2017 at 8:16 PM, Michal Skrivanek <mskrivan(a)redhat.com>
>> wrote:
>>
>>>
>>> On 16 Mar 2017, at 15:18, Yaniv Kaul <ykaul(a)redhat.com> wrote:
>>>
>>>
>>>
>>> On Thu, Mar 16, 2017 at 10:46 AM, Nir Soffer <nsoffer(a)redhat.com> 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
>
7:41 a.m.
On Sun, Mar 19, 2017 at 2:09 PM, Yaniv Kaul <ykaul(a)redhat.com> wrote:
On Sun, Mar 19, 2017 at 12:14 PM, Arik Hadas <ahadas(a)redhat.com> wrote:
>
>
> On Sat, Mar 18, 2017 at 12:57 PM, Yaniv Kaul <ykaul(a)redhat.com> wrote:
>
>>
>>
>> On Sat, Mar 18, 2017 at 12:05 AM, Michal Skrivanek <mskrivan(a)redhat.com>
>> wrote:
>>
>>>
>>> On 17 Mar 2017, at 20:49, Yaniv Kaul <ykaul(a)redhat.com> wrote:
>>>
>>>
>>>
>>> On Thu, Mar 16, 2017 at 8:16 PM, Michal Skrivanek
<mskrivan(a)redhat.com>
>>> wrote:
>>>
>>>>
>>>> On 16 Mar 2017, at 15:18, Yaniv Kaul <ykaul(a)redhat.com> wrote:
>>>>
>>>>
>>>>
>>>> On Thu, Mar 16, 2017 at 10:46 AM, Nir Soffer <nsoffer(a)redhat.com>
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.
>
Merged.
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?
Well, we had such intentions but these things are always the first
candidates to postpone. We should.
>
> [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?
For the most part, chances are extremely low for a command to fail in its
end-action phase. Generally, commands either fail in their validation phase
or execution phase or when their async tasks/jobs fail. In those case, we
don't have/need a mechanism for periodic retry. On the other hand, the
end-action phase is relatively short and simple and is really not expected
to fail (unless there is a bug, like in this case), but if it does fail -
we have to retry and the user will probably experience more acute issues
than a flood of audit messages (e.g., inability to connect to the
database). AFAIK there is no limit to the number of retry attempts in this
case.
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
>>
>
>
2593
days inactive
2596
days old
9 comments
4 participants
participants (4)
-
Arik Hadas -
Michal Skrivanek -
Nir Soffer -
Yaniv Kaul