<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=utf-8">
</head>
<body text="#000000" bgcolor="#FFFFFF">
<div class="moz-cite-prefix">I opened a bug on the error:
<a class="moz-txt-link-freetext" href="https://bugzilla.redhat.com/show_bug.cgi?id=1516780">https://bugzilla.redhat.com/show_bug.cgi?id=1516780</a><br>
<br>
This test seems to be catching something since we are failing on
it randomly so I will review the logs today to see if I can find
the true cause of failure and update my findings. <br>
<br>
On 11/22/2017 07:05 PM, Yaniv Kaul wrote:<br>
</div>
<blockquote type="cite"
cite="mid:CAJgorsYjf+Z-31PeUrOY+oT1QFRWmzoGQM0djJDS0+Ef+OOqJQ@mail.gmail.com">
<div dir="ltr"><br>
<div class="gmail_extra"><br>
<div class="gmail_quote">On Wed, Nov 22, 2017 at 7:55 PM, Nir
Soffer <span dir="ltr"><<a
href="mailto:nsoffer@redhat.com" target="_blank"
moz-do-not-send="true">nsoffer@redhat.com</a>></span>
wrote:<br>
<blockquote class="gmail_quote" style="margin:0px 0px 0px
0.8ex;border-left:1px solid
rgb(204,204,204);padding-left:1ex">
<div dir="ltr"><br>
<br>
<div class="gmail_quote">
<div>
<div class="gmail-h5">
<div dir="ltr">On Wed, Nov 22, 2017 at 7:15 PM
Dafna Ron <<a href="mailto:dron@redhat.com"
target="_blank" moz-do-not-send="true">dron@redhat.com</a>>
wrote:<br>
</div>
<blockquote class="gmail_quote" style="margin:0px
0px 0px 0.8ex;border-left:1px solid
rgb(204,204,204);padding-left:1ex">
<div bgcolor="#FFFFFF">
<p>Hi, <br>
</p>
<p>we have a failure in
004_basic_sanity.verify_add_<wbr>vm_template.
<br>
</p>
<p>The error seems to be a failure from the
api request since although I am seeing
errors in the logs I am not sure they are
the cause. <br>
</p>
<p><br>
</p>
<p><b style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25">
</b></p>
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt"><b
style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25"><span style="font-size:11pt;font-family:Arial;color:rgb(0,0,0);background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap">Link and headline ofto suspected patches:
</span></b></p>
<b style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25">
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt"><span style="font-size:11pt;font-family:Arial;color:rgb(0,0,0);background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap">
</span></p>
core: Cleanup BaseImagesCommand code - <a
class="gmail-m_5033699571211795255m_-8160106625429842286moz-txt-link-freetext"
href="https://gerrit.ovirt.org/#/c/83812/"
target="_blank" moz-do-not-send="true">https://gerrit.ovirt.org/#/c/<wbr>83812/</a></b>
<p><b style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25"><br>
</b></p>
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt"><b
style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25"><span style="font-size:11pt;font-family:Arial;color:rgb(0,0,0);background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap">Link to Job:</span></b></p>
<b style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25"><a
class="gmail-m_5033699571211795255m_-8160106625429842286moz-txt-link-freetext"
href="http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3989"
target="_blank" moz-do-not-send="true">http://jenkins.ovirt.org/job/<wbr>ovirt-master_change-queue-<wbr>tester/3989</a></b>
<p><b style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25"><br>
</b></p>
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt"><b
style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25"><span style="font-size:11pt;font-family:Arial;color:rgb(0,0,0);background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap">Link to all logs:</span></b></p>
<b style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25"><a
class="gmail-m_5033699571211795255m_-8160106625429842286moz-txt-link-freetext"
href="http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3989/artifact"
target="_blank" moz-do-not-send="true">http://jenkins.ovirt.org/job/<wbr>ovirt-master_change-queue-<wbr>tester/3989/artifact</a></b></div>
</blockquote>
</div>
</div>
</div>
</div>
</blockquote>
<div><br>
</div>
<div><br>
</div>
<div>Relevant logs start here - <a
href="http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3989/artifact/exported-artifacts/basic-suit-master-el7/test_logs/basic-suite-master/post-004_basic_sanity.py/"
moz-do-not-send="true">http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3989/artifact/exported-artifacts/basic-suit-master-el7/test_logs/basic-suite-master/post-004_basic_sanity.py/</a></div>
<div><br>
</div>
<div>Specifically, server.log (<a
href="http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3989/artifact/exported-artifacts/basic-suit-master-el7/test_logs/basic-suite-master/post-004_basic_sanity.py/lago-basic-suite-master-engine/_var_log/ovirt-engine/server.log"
moz-do-not-send="true">http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/3989/artifact/exported-artifacts/basic-suit-master-el7/test_logs/basic-suite-master/post-004_basic_sanity.py/lago-basic-suite-master-engine/_var_log/ovirt-engine/server.log</a>
):</div>
<div><br>
</div>
<div>
<div>2017-11-22 10:40:14,334-05 ERROR
[org.jboss.as.ejb3.invocation]
(EE-ManagedThreadFactory-engineScheduled-Thread-29)
WFLYEJB0034: EJB Invocation failed on component Backend
for method public abstract
org.ovirt.engine.core.common.action.ActionReturnValue
org.ovirt.engine.core.bll.interfaces.BackendInternal.endAction(org.ovirt.engine.core.common.action.ActionType,org.ovirt.engine.core.common.action.ActionParametersBase,org.ovirt.engine.core.bll.context.CommandContext):
javax.ejb.EJBTransactionRolledbackException</div>
<div><span style="white-space:pre"> </span>at
org.jboss.as.ejb3.tx.CMTTxInterceptor.handleInCallerTx(CMTTxInterceptor.java:160)
[wildfly-ejb3-11.0.0.Final.jar:11.0.0.Final]</div>
<div><span style="white-space:pre"> </span>at
org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:257)
[wildfly-ejb3-11.0.0.Final.jar:11.0.0.Final]</div>
<div><span style="white-space:pre"> </span>at
org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:381)
[wildfly-ejb3-11.0.0.Final.jar:11.0.0.Final]</div>
<div><span style="white-space:pre"> </span>at
org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:244)
[wildfly-ejb3-11.0.0.Final.jar:11.0.0.Final]</div>
<div><span style="white-space:pre"> </span>at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)</div>
<div><span style="white-space:pre"> </span>at
org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)</div>
<div><span style="white-space:pre"> </span>at
org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:73)
[weld-core-impl-2.4.3.Final.jar:2.4.3.Final]</div>
<div><span style="white-space:pre"> </span>at
org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)</div>
<div><span style="white-space:pre"> </span>at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)</div>
<div><span style="white-space:pre"> </span>at
org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
[wildfly-ejb3-11.0.0.Final.jar:11.0.0.Final]</div>
<div><span style="white-space:pre"> </span>at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)</div>
<div><span style="white-space:pre"> </span>at
org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47)
[wildfly-ejb3-11.0.0.Final.jar:11.0.0.Final]</div>
<div><span style="white-space:pre"> </span>at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)</div>
<div><span style="white-space:pre"> </span>at
org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
[wildfly-ejb3-11.0.0.Final.jar:11.0.0.Final]</div>
<div><span style="white-space:pre"> </span>at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)</div>
<div><span style="white-space:pre"> </span>at
org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22)
[wildfly-ejb3-11.0.0.Final.jar:11.0.0.Final]</div>
<div><span style="white-space:pre"> </span>at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)</div>
</div>
<div><br>
</div>
<div>...</div>
<div>
<pre style="color:rgb(0,0,0)">Caused by: java.lang.NullPointerException
at java.util.Objects.requireNonNull(Objects.java:203) [rt.jar:1.8.0_151]
at java.util.Optional.<init>(Optional.java:96) [rt.jar:1.8.0_151]
at java.util.Optional.of(Optional.java:108) [rt.jar:1.8.0_151]
at java.util.stream.FindOps$FindSink$OfRef.get(FindOps.java:193) [rt.jar:1.8.0_151]
at java.util.stream.FindOps$FindSink$OfRef.get(FindOps.java:190) [rt.jar:1.8.0_151]
at java.util.stream.FindOps$FindOp.evaluateSequential(FindOps.java:152) [rt.jar:1.8.0_151]
at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) [rt.jar:1.8.0_151]
at java.util.stream.ReferencePipeline.findFirst(ReferencePipeline.java:464) [rt.jar:1.8.0_151]
at org.ovirt.engine.core.bll.storage.disk.image.BaseImagesCommand.setQcowCompatByQemuImageInfo(BaseImagesCommand.java:432) [bll.jar:]
at org.ovirt.engine.core.bll.storage.disk.image.BaseImagesCommand.endSuccessfully(BaseImagesCommand.java:393) [bll.jar:]
at org.ovirt.engine.core.bll.CommandBase.internalEndSuccessfully(CommandBase.java:751) [bll.jar:]
at org.ovirt.engine.core.bll.CommandBase.endActionInTransactionScope(CommandBase.java:709) [bll.jar:]
at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1989) [bll.jar:]
at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInRequired(TransactionSupport.java:139) [utils.jar:]
at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:105) [utils.jar:]
at org.ovirt.engine.core.bll.CommandBase.endAction(CommandBase.java:574) [bll.jar:]
at org.ovirt.engine.core.bll.Backend.endAction(Backend.java:536) [bll.jar:]</pre>
<pre style="color:rgb(0,0,0)">
</pre>
<pre style="color:rgb(0,0,0)">
</pre>
<pre style="color:rgb(0,0,0)">Y.</pre>
<pre style="color:rgb(0,0,0)">
</pre>
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px
0.8ex;border-left:1px solid
rgb(204,204,204);padding-left:1ex">
<div dir="ltr">
<div class="gmail_quote">
<div>
<div class="gmail-h5">
<blockquote class="gmail_quote" style="margin:0px
0px 0px 0.8ex;border-left:1px solid
rgb(204,204,204);padding-left:1ex">
<div bgcolor="#FFFFFF">
<p><b style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25"><br>
</b></p>
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt"><b
style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25"><span style="font-size:11pt;font-family:Arial;color:rgb(0,0,0);background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap">(Relevant) error snippet from the log: </span></b></p>
<b style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25">
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt"><span style="font-size:11pt;font-family:Arial;color:rgb(0,0,0);background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap"><error></span></p>
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt"><span style="font-size:11pt;font-family:Arial;color:rgb(0,0,0);background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap">
</span></p>
</b><b style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25">
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt"><span style="font-size:11pt;font-family:Arial;color:rgb(0,0,0);background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap">lago log: </span></p>
</b></div>
</blockquote>
</div>
</div>
</div>
</div>
</blockquote>
<div><br>
</div>
<div> </div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px
0.8ex;border-left:1px solid
rgb(204,204,204);padding-left:1ex">
<div dir="ltr">
<div class="gmail_quote">
<div>
<div class="gmail-h5">
<blockquote class="gmail_quote" style="margin:0px
0px 0px 0.8ex;border-left:1px solid
rgb(204,204,204);padding-left:1ex">
<div bgcolor="#FFFFFF"><b
style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25">
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt"><span style="font-size:11pt;font-family:Arial;color:rgb(0,0,0);background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap">
</span></p>
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt"><span style="font-size:11pt;font-family:Arial;color:rgb(0,0,0);background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap">
</span></p>
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt"><br>
</p>
</b>
<pre style="box-sizing:border-box;white-space:pre-wrap;word-wrap:break-word;margin:0px;color:rgb(51,51,51);font-size:14px;font-style:normal;font-variant-ligatures:normal;font-variant-caps:normal;font-weight:normal;letter-spacing:normal;text-align:start;text-indent:0px;text-transform:none;word-spacing:0px;text-decoration-style:initial;text-decoration-color:initial"> File "/usr/lib64/python2.7/<wbr>unittest/case.py", line 369, in run
testMethod()
File "/usr/lib/python2.7/site-<wbr>packages/nose/case.py", line 197, in runTest
self.test(*self.arg)
File "/usr/lib/python2.7/site-<wbr>packages/ovirtlago/testlib.py"<wbr>, line 129, in wrapped_test
test()
File "/usr/lib/python2.7/site-<wbr>packages/ovirtlago/testlib.py"<wbr>, line 59, in wrapper
return func(get_test_prefix(), *args, **kwargs)
File "/usr/lib/python2.7/site-<wbr>packages/ovirtlago/testlib.py"<wbr>, line 68, in wrapper
return func(prefix.virt_env.engine_<wbr>vm().get_api(), *args, **kwargs)
File "/home/jenkins/workspace/<wbr>ovirt-master_change-queue-<wbr>tester/ovirt-system-tests/<wbr>basic-suite-master/test-<wbr>scenarios/004_basic_sanity.py"<wbr>, line 500, in verify_add_vm_template
lambda: api.vms.get(VM1_NAME).status.<wbr>state == 'down',
File "/usr/lib/python2.7/site-<wbr>packages/ovirtlago/testlib.py"<wbr>, line 271, in assert_true_within_long
assert_equals_within_long(<wbr>func, True, allowed_exceptions)
File "/usr/lib/python2.7/site-<wbr>packages/ovirtlago/testlib.py"<wbr>, line 258, in assert_equals_within_long
func, value, LONG_TIMEOUT, allowed_exceptions=allowed_<wbr>exceptions
File "/usr/lib/python2.7/site-<wbr>packages/ovirtlago/testlib.py"<wbr>, line 219, in assert_equals_within
res = func()
File "/home/jenkins/workspace/<wbr>ovirt-master_change-queue-<wbr>tester/ovirt-system-tests/<wbr>basic-suite-master/test-<wbr>scenarios/004_basic_sanity.py"<wbr>, line 500, in <lambda>
lambda: api.vms.get(VM1_NAME).status.<wbr>state == 'down',
'\'NoneType\' object has no attribute \'status\'\n------------------<wbr>-- >> begin captured logging << --------------------\<wbr>novirtlago.testlib: ERROR: * Unhandled exception in <function <lambda> at 0x4bafb90>\nTraceback (most recent call last):\n File "/usr/lib/python2.7/site-<wbr>packages/ovirtlago/testlib.py"<wbr>, line 219, in assert_equals_within\n res = func()\n File "/home/jenkins/workspace/<wbr>ovirt-master_change-queue-<wbr>tester/ovirt-system-tests/<wbr>basic-suite-master/test-<wbr>scenarios/004_basic_sanity.py"<wbr>, line 500, in <lambda>\n lambda: api.vms.get(VM1_NAME).status.<wbr>state == \'down\',\nAttributeError: \'NoneType\' object has no attribute \'status\'\n------------------<wbr>--- >> end captured logging << ---------------------'</pre>
</div>
</blockquote>
<div><br>
</div>
</div>
</div>
<div>This is a test error - code like this is always
wrong:</div>
<div><br>
</div>
<div> api.vms.get(VM1_NAME).status.<wbr>state ==
something</div>
<div><br>
</div>
<div>In this case, api.vms.get() returned None. The
test code</div>
<div>should handle None and fail with meaningfull
error, or maybe</div>
<div>retry the call.<br>
</div>
</div>
</div>
</blockquote>
<div><br>
</div>
<div>It doesn't matter - if api.vms.get(VM1_NAME) return
None, we'll fail the test. So we can add an assert here,
but still fail in exactly the same manner. </div>
<div>Gracefully with 'VM1_NAME was not found' ? Perhaps.</div>
<div> </div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px
0.8ex;border-left:1px solid
rgb(204,204,204);padding-left:1ex">
<div dir="ltr">
<div class="gmail_quote">
<div> <br>
</div>
<div>
<div class="gmail-h5">
<blockquote class="gmail_quote" style="margin:0px
0px 0px 0.8ex;border-left:1px solid
rgb(204,204,204);padding-left:1ex">
<div bgcolor="#FFFFFF">
<p><span style="font-weight:normal">engine
log: </span><b style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25"><b><br>
</b></b></p>
<pre style="color:rgb(0,0,0);font-style:normal;font-variant-ligatures:normal;font-variant-caps:normal;font-weight:normal;letter-spacing:normal;text-align:start;text-indent:0px;text-transform:none;word-spacing:0px;text-decoration-style:initial;text-decoration-color:initial">{"jsonrpc": "2.0", "id": "32bfeb29-e70f-48b2-84c7-<wbr>91cf22ea408c", "result": {"status": "OK", "domain": "2d776fb7-eba8-4ee2-97b6-<wbr>4350c28ddb39", "voltype": "LEAF", "description": "", "parent": "a1192fcc-4660-41a7-a1a5-<wbr>a221808f603b", "format": "COW", "generation": 0, "image": "dc033235-ab4b-4ef0-be79-<wbr>6e8a22bfb0bc", "ctime": "1511365200", "disktype": "DATA", "legality": "LEGAL", "mtime": "0", "apparentsize": "1073741824", "children": [], "pool": "", "capacity": "41126400", "uuid": "6a354b93-86af-41fb-a68b-<wbr>10897ae3562f", "truesize": "1073741824", "type": "SPARSE", "lease": {"owners": [], "version": null}}}�
2017-11-22 10:40:39,454-05 DEBUG [org.ovirt.vdsm.jsonrpc.<wbr>client.internal.<wbr>ResponseWorker] (ResponseWorker) [] Message received: {"jsonrpc": "2.0", "id": "32bfeb29-e70f-48b2-84c7-<wbr>91cf22ea408c", "result": {"status": "OK", "domain": "2d776fb7-eba8-4ee2-97b6-<wbr>4350c28ddb39", "voltype": "LEAF", "description": "", "parent": "a1192fcc-4660-41a7-a1a5-<wbr>a221808f603b", "format": "COW", "generation": 0, "image": "dc033235-ab4b-4ef0-be79-<wbr>6e8a22bfb0bc", "ctime": "1511365200", "disktype": "DATA", "legality": "LEGAL", "mtime": "0", "apparentsize": "1073741824", "children": [], "pool": "", "capacity": "41126400", "uuid": "6a354b93-86af-41fb-a68b-<wbr>10897ae3562f", "truesize": "1073741824", "type": "SPARSE", "lease": {"owners": [], "version": null}}}
2017-11-22 10:40:39,454-05 INFO [org.ovirt.engine.core.<wbr>vdsbroker.vdsbroker.<wbr>GetVolumeInfoVDSCommand] (EE-ManagedThreadFactory-<wbr>engineScheduled-Thread-34) [c90b2f35-7a80-476f-9b23-<wbr>78beecef7c37] FINISH, GetVolumeInfoVDSCommand, return: org.ovirt.engine.core.common.<wbr>businessentities.storage.<wbr>DiskImage@6903fdd6, log id: 85b379d
2017-11-22 10:40:39,455-05 INFO [org.ovirt.engine.core.<wbr>vdsbroker.irsbroker.<wbr>GetImageInfoVDSCommand] (EE-ManagedThreadFactory-<wbr>engineScheduled-Thread-34) [c90b2f35-7a80-476f-9b23-<wbr>78beecef7c37] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.<wbr>businessentities.storage.<wbr>DiskImage@6903fdd6, log id: 75d29166
2017-11-22 10:40:39,455-05 DEBUG [org.ovirt.engine.core.common.<wbr>di.interceptor.<wbr>DebugLoggingInterceptor] (EE-ManagedThreadFactory-<wbr>engineScheduled-Thread-34) [c90b2f35-7a80-476f-9b23-<wbr>78beecef7c37] method: runVdsCommand, params: [GetImageInfo, GetImageInfoVDSCommandParamete<wbr>rs:{storagePoolId='0762073b-<wbr>b0ab-4ee2-8af9-dafa930a5fd4', ignoreFailoverLimit='false', storageDomainId='2d776fb7-<wbr>eba8-4ee2-97b6-4350c28ddb39', imageGroupId='dc033235-ab4b-<wbr>4ef0-be79-6e8a22bfb0bc', imageId='6a354b93-86af-41fb-<wbr>a68b-10897ae3562f'}], timeElapsed: 165ms
2017-11-22 10:40:39,528-05 DEBUG [org.ovirt.engine.core.common.<wbr>di.interceptor.<wbr>DebugLoggingInterceptor] (EE-ManagedThreadFactory-<wbr>engineScheduled-Thread-34) [c90b2f35-7a80-476f-9b23-<wbr>78beecef7c37] method: getVmsWithPlugInfo, params: [dc033235-ab4b-4ef0-be79-<wbr>6e8a22bfb0bc], timeElapsed: 68ms
2017-11-22 10:40:39,543-05 INFO [org.ovirt.engine.core.utils.<wbr>transaction.<wbr>TransactionSupport] (EE-ManagedThreadFactory-<wbr>engineScheduled-Thread-34) [] transaction rolled back
2017-11-22 10:40:39,543-05 WARN [org.ovirt.engine.core.bll.<wbr>lock.InMemoryLockManager] (EE-ManagedThreadFactory-<wbr>engineScheduled-Thread-34) [] Trying to release a shared lock for key: '93d271d5-e0af-4795-b800-<wbr>55465c7b8826TEMPLATE' , but lock does not exist
2017-11-22 10:40:39,543-05 WARN [org.ovirt.engine.core.bll.<wbr>lock.InMemoryLockManager] (EE-ManagedThreadFactory-<wbr>engineScheduled-Thread-34) [] Trying to release a shared lock for key: 'fb76119e-9283-4c8b-9185-<wbr>5d79e2481bc7DISK' , but lock does not exist
2017-11-22 10:40:39,543-05 WARN [org.ovirt.engine.core.bll.<wbr>lock.InMemoryLockManager] (EE-ManagedThreadFactory-<wbr>engineScheduled-Thread-34) [] Trying to release exclusive lock which does not exist, lock key: 'vm1VM_NAME'
2017-11-22 10:40:39,543-05 INFO [org.ovirt.engine.core.bll.<wbr>AddVmCommand] (EE-ManagedThreadFactory-<wbr>engineScheduled-Thread-34) [] Lock freed to object 'EngineLock:{exclusiveLocks='[<wbr>vm1=VM_NAME]', sharedLocks='[93d271d5-e0af-<wbr>4795-b800-55465c7b8826=<wbr>TEMPLATE, fb76119e-9283-4c8b-9185-<wbr>5d79e2481bc7=DISK]'}'
2017-11-22 10:40:39,556-05 ERROR [org.ovirt.engine.core.dal.<wbr>dbbroker.auditloghandling.<wbr>AuditLogDirector] (EE-ManagedThreadFactory-<wbr>engineScheduled-Thread-34) [] EVENT_ID: USER_ADD_VM_FINISHED_FAILURE(<wbr>60), Failed to complete VM vm1 creation.
2017-11-22 10:40:39,556-05 ERROR [org.ovirt.engine.core.bll.<wbr>tasks.CommandCallbacksPoller] (EE-ManagedThreadFactory-<wbr>engineScheduled-Thread-34) [] Failed invoking callback end method 'onSucceeded' for command '2760a62f-e4ee-4dd2-b13a-<wbr>1bb548e3e62d' with exception 'null', the callback is marked for end method retries
2017-11-22 10:40:39,935-05 DEBUG [org.ovirt.engine.core.common.<wbr>di.interceptor.<wbr>DebugLoggingInterceptor] (EE-ManagedThreadFactory-<wbr>engineScheduled-Thread-35) [] method: get, params: [d25423f6-34bc-4cde-82fa-<wbr>c0eedfc85386], timeElapsed: 3ms
2017-11-22 10:40:39,949-05 DEBUG [org.ovirt.engine.core.common.<wbr>di.interceptor.<wbr>DebugLoggingInterceptor] (EE-ManagedThreadFactory-<wbr>engineScheduled-Thread-71) [] method: get, params: [7c9ec3eb-2838-4b06-9408-<wbr>326b67869bdc], timeElapsed: 2ms
2017-11-22 10:40:40,606-05 DEBUG [org.ovirt.engine.core.aaa.<wbr>filters.SsoRestApiAuthFilter] (default task-22) [] Entered SsoRestApiAuthFilter
vdsm log:
2017-11-22 10:36:11,973-0500 ERROR (jsonrpc/7) [storage.TaskManager.Task] (Task='5b6ab546-b560-41fc-<wbr>9b56-de465aa55eee') Unexpected error (task:875)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-<wbr>packages/vdsm/storage/task.py"<wbr>, line 882, in _run
return fn(*args, **kargs)
File "<string>", line 2, in getAllTasksInfo
File "/usr/lib/python2.7/site-<wbr>packages/vdsm/common/api.py", line 48, in method
ret = func(*args, **kwargs)
File "/usr/lib/python2.7/site-<wbr>packages/vdsm/storage/hsm.py", line 2216, in getAllTasksInfo
allTasksInfo = self._pool.getAllTasksInfo()
File "/usr/lib/python2.7/site-<wbr>packages/vdsm/storage/<wbr>securable.py", line 77, in wrapper
raise SecureError("Secured object is not in safe state")
SecureError: Secured object is not in safe state
2017-11-22 10:36:11,975-0500 INFO (jsonrpc/7) [storage.TaskManager.Task] (Task='5b6ab546-b560-41fc-<wbr>9b56-de465aa55eee') aborting: Task is aborted: u'Secured object is not in safe state' - code 100 (task:1181)
2017-11-22 10:36:11,976-0500 ERROR (jsonrpc/7) [storage.Dispatcher] FINISH getAllTasksInfo error=Secured object is not in safe state (dispatcher:86)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-<wbr>packages/vdsm/storage/<wbr>dispatcher.py", line 73, in wrapper
result = ctask.prepare(func, *args, **kwargs)
File "/usr/lib/python2.7/site-<wbr>packages/vdsm/storage/task.py"<wbr>, line 108, in wrapper
return m(self, *a, **kw)
File "/usr/lib/python2.7/site-<wbr>packages/vdsm/storage/task.py"<wbr>, line 1189, in prepare
raise self.error
SecureError: Secured object is not in safe state
2017-11-22 10:36:11,976-0500 INFO (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call Host.getAllTasksInfo failed (error 654) in 0.01 seconds (__init__:573)
2017-11-22 10:36:11,979-0500 INFO (jsonrpc/2) [vdsm.api] START getAllTasksStatuses(spUUID=<wbr>None, options=None) from=::1,52728, task_id=172b5528-cc76-426a-<wbr>81d3-43143b49a878 (api:46)
2017-11-22 10:36:11,979-0500 INFO (jsonrpc/2) [vdsm.api] FINISH getAllTasksStatuses error=Secured object is not in safe state from=::1,52728, task_id=172b5528-cc76-426a-<wbr>81d3-43143b49a878 (api:50)</pre>
</div>
</blockquote>
<div><br>
</div>
</div>
</div>
<div>This is <a
href="https://bugzilla.redhat.com/1426429"
target="_blank" moz-do-not-send="true">https://bugzilla.redhat.<wbr>com/1426429</a><br>
</div>
<div><br>
</div>
<div>Not related to the real error.</div>
<span class="gmail-">
<blockquote class="gmail_quote" style="margin:0px
0px 0px 0.8ex;border-left:1px solid
rgb(204,204,204);padding-left:1ex">
<div bgcolor="#FFFFFF">
<pre style="color:rgb(0,0,0);font-style:normal;font-variant-ligatures:normal;font-variant-caps:normal;font-weight:normal;letter-spacing:normal;text-align:start;text-indent:0px;text-transform:none;word-spacing:0px;text-decoration-style:initial;text-decoration-color:initial">2017-11-22 10:36:11,980-0500 ERROR (jsonrpc/2) [storage.TaskManager.Task] (Task='172b5528-cc76-426a-<wbr>81d3-43143b49a878') Unexpected error (task:875)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-<wbr>packages/vdsm/storage/task.py"<wbr>, line 882, in _run
return fn(*args, **kargs)
File "<string>", line 2, in getAllTasksStatuses
File "/usr/lib/python2.7/site-<wbr>packages/vdsm/common/api.py", line 48, in method
ret = func(*args, **kwargs)
File "/usr/lib/python2.7/site-<wbr>packages/vdsm/storage/hsm.py", line 2176, in getAllTasksStatuses
allTasksStatus = self._pool.<wbr>getAllTasksStatuses()
File "/usr/lib/python2.7/site-<wbr>packages/vdsm/storage/<wbr>securable.py", line 77, in wrapper
raise SecureError("Secured object is not in safe state")
SecureError: Secured object is not in safe state
2017-11-22 10:36:11,980-0500 INFO (jsonrpc/2) [storage.TaskManager.Task] (Task='172b5528-cc76-426a-<wbr>81d3-43143b49a878') aborting: Task is aborted: u'Secured object is not in safe state' - code 100 (task:1181)
2017-11-22 10:36:11,981-0500 ERROR (jsonrpc/2) [storage.Dispatcher] FINISH getAllTasksStatuses error=Secured object is not in safe state (dispatcher:86)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-<wbr>packages/vdsm/storage/<wbr>dispatcher.py", line 73, in wrapper
result = ctask.prepare(func, *args, **kwargs)
File "/usr/lib/python2.7/site-<wbr>packages/vdsm/storage/task.py"<wbr>, line 108, in wrapper
return m(self, *a, **kw)
File "/usr/lib/python2.7/site-<wbr>packages/vdsm/storage/task.py"<wbr>, line 1189, in prepare
raise self.error
SecureError: Secured object is not in safe state</pre>
</div>
</blockquote>
<div><br>
</div>
</span>
<div>The way to find the relevant errors is to find
the entry point of this flow</div>
<div>in engine.log, and then follow this in vdsm.log
using flow_id=xxx.</div>
<div><br>
</div>
<div>Ideally we would send a uuid to engine for every
operation, and be</div>
<div>able to query the operation status using the
uuid. This is the way</div>
<div>storage jobs are managed in vdsm side since 4.1.</div>
<div><br>
</div>
<div>If we had this every test would generate a uuids
and debugging</div>
<div>failing test would be much faster.</div>
<div><br>
</div>
<div>Nir</div>
<blockquote class="gmail_quote" style="margin:0px 0px
0px 0.8ex;border-left:1px solid
rgb(204,204,204);padding-left:1ex">
<div bgcolor="#FFFFFF">
<p><b style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25"><br>
<br>
</b></p>
<p dir="ltr"
style="line-height:1.38;margin-top:0pt;margin-bottom:0pt"><b
style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25"><span style="font-size:11pt;font-family:Arial;color:rgb(0,0,0);background-color:transparent;font-weight:400;font-style:normal;font-variant:normal;text-decoration:none;vertical-align:baseline;white-space:pre-wrap"></error></span></b></p>
<b style="font-weight:normal"
id="gmail-m_5033699571211795255m_-8160106625429842286docs-internal-guid-5859b7a1-e4a5-ffe9-fc92-59c9c5a7be25">
</b><br
class="gmail-m_5033699571211795255m_-8160106625429842286Apple-interchange-newline">
<p><br>
</p>
</div>
______________________________<wbr>_________________<br>
Devel mailing list<br>
<a href="mailto:Devel@ovirt.org" target="_blank"
moz-do-not-send="true">Devel@ovirt.org</a><br>
<a
href="http://lists.ovirt.org/mailman/listinfo/devel"
rel="noreferrer" target="_blank"
moz-do-not-send="true">http://lists.ovirt.org/<wbr>mailman/listinfo/devel</a></blockquote>
</div>
</div>
<br>
______________________________<wbr>_________________<br>
Devel mailing list<br>
<a href="mailto:Devel@ovirt.org" moz-do-not-send="true">Devel@ovirt.org</a><br>
<a href="http://lists.ovirt.org/mailman/listinfo/devel"
rel="noreferrer" target="_blank" moz-do-not-send="true">http://lists.ovirt.org/<wbr>mailman/listinfo/devel</a><br>
</blockquote>
</div>
<br>
</div>
</div>
</blockquote>
<p><br>
</p>
</body>
</html>