Re: [ovirt-devel] [ OST Failure Report ] [ oVirt Master ] [ 14-12-2017 ] [ 004_basic_sanity.disk_operations ]

14 Dec 2017


      ...
On 14 Dec 2017, at 13:00, Dafna Ron <dron@redhat.com> wrote:
=20
Hi,=20
We have a failure on basic suite on test: =
004_basic_sanity.disk_operations
I think that we query a snapshot that was already deleted successfully =
and report the snapshot as gone. and that is because of a different =
error in update vm query which happens before.=20
=20
Link and headline of suspected patches:=20
https://gerrit.ovirt.org/#/c/85168/ =
<https://gerrit.ovirt.org/#/c/85168/> - core: Prevent retry lease =
hotplag in case of failure.
=20
Link to Job:
http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4393 =
<http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4393>
=20
Link to all logs:
=
http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4393/artifac=
t/ =
<http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4393/artifa=
ct/>
=20
(Relevant) error snippet from the log:=20
<error>
=20
Engine:=20
=20
=20
=20
2017-12-14 02:38:01,470-05 ERROR =
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand] =
(EE-ManagedThreadFactory-engineScheduled-Thread-5) [] Command =
'GetAllVmStatsVDSCommand(HostName =3D lago-basic-suite-master-host-1, =
VdsIdVD
=
SCommandParametersBase:{hostId=3D'f1c2314f-5617-4c9e-84e0-e822160fbde9'})'=
 execution failed: VDSGenericException: VDSErrorException: Failed to =
GetAllVmStatsVDS, error =3D Internal JSON-RPC error: {'reason': "VM =
'7cab7e5a-cb12-4977-ac4f-652185
32df7e' was not defined yet or was undefined"}, code =3D -32603
2017-12-14 02:38:01,470-05 DEBUG =
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand] =
(EE-ManagedThreadFactory-engineScheduled-Thread-5) [] Exception: =
org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericE
xception: VDSErrorException: Failed to GetAllVmStatsVDS, error =3D =
Internal JSON-RPC error: {'reason': "VM =
'7cab7e5a-cb12-4977-ac4f-65218532df7e' was not defined yet or was =
undefined"}, code =3D -32603
        at =
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createDefaultCo=
ncreteException(VdsBrokerCommand.java:81) [vdsbroker.jar:]
        at =
org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.createExceptio=
n(BrokerCommandBase.java:224) [vdsbroker.jar:]
        at =
org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.proceedProxyRe=
turnValue(BrokerCommandBase.java:194) [vdsbroker.jar:]
        at =
org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand.executeV=
dsBrokerCommand(GetAllVmStatsVDSCommand.java:23) [vdsbroker.jar:]
        at =
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSComma=
nd(VdsBrokerCommand.java:112) [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:387) [vdsbroker.jar:]
        at =
org.ovirt.engine.core.vdsbroker.ResourceManager$Proxy$_$$_WeldSubclass.run=
VdsCommand$$super(Unknown Source) [vdsbroker.jar:]
        at sun.reflect.GeneratedMethodAccessor247.invoke(Unknown =
Source) [:1.8.0_151]
        at =
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorIm=
--Apple-Mail=_4507365F-4541-4953-A54F-924C8DA4DC7F
Content-Transfer-Encoding: quoted-printable
Content-Type: text/plain;
	charset=utf-8


pl.java:43) [rt.jar:1.8.0_151]
...
at java.lang.reflect.Method.invoke(Method.java:498) =
[rt.jar:1.8.0_151]
...
at =
org.jboss.weld.interceptor.proxy.TerminalAroundInvokeInvocationContext.pro=
ceedInternal(TerminalAroundInvokeInvocationContext.java:49) =
[weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
...
at =
org.jboss.weld.interceptor.proxy.AroundInvokeInvocationContext.proceed(Aro=
undInvokeInvocationContext.java:77) =
[weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
...
at =
org.ovirt.engine.core.common.di.interceptor.LoggingInterceptor.apply(Loggi=
ngInterceptor.java:12) [common.jar:]
...
at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown =
Source) [:1.8.0_151]
...
at =
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorIm=
pl.java:43) [rt.jar:1.8.0_151]
...
at java.lang.reflect.Method.invoke(Method.java:498) =
[rt.jar:1.8.0_151]
...
at =
org.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethod=
Invocation.invoke(SimpleInterceptorInvocation.java:73) =
[weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
...
at =
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeAroundInv=
oke(InterceptorMethodHandler.java:84) =
[weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
...
at =
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeIntercept=
ion(InterceptorMethodHandler.java:72) =
[weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
...
at =
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(Intercept=
orMethodHandler.java:56) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
...
at =
org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandle=
r.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79) =
[weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
...
at =
org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandle=
r.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:68) =
[weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
...
at =
org.ovirt.engine.core.vdsbroker.ResourceManager$Proxy$_$$_WeldSubclass.run=
VdsCommand(Unknown Source) [vdsbroker.jar:]
...
at =
org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher.poll(VmsSt=
atisticsFetcher.java:29) [vdsbroker.jar:]
...
at =
org.ovirt.engine.core.vdsbroker.monitoring.VmsListFetcher.fetch(VmsListFet=
cher.java:57) [vdsbroker.jar:]
...
at =
org.ovirt.engine.core.vdsbroker.monitoring.PollVmStatsRefresher.poll(PollV=
mStatsRefresher.java:42) [vdsbroker.jar:]
...
at =
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) =
[rt.jar:1.8.0_151]
...
at =
java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) =
[rt.jar:1.8.0_151]
...
at =
org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExe=
cutor$ManagedScheduledFutureTask.access$201(ManagedScheduledThreadPoolExec=
utor.java:383) [javax.enterprise.concurrent-1.0.jar:]
...
at =
org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExe=
cutor$ManagedScheduledFutureTask.run(ManagedScheduledThreadPoolExecutor.ja=
va:534) [javax.enterprise.concurrent-1.0.jar:]
...
at =
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:=
1149) [rt.jar:1.8.0_151]
...
at =
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java=
:624) [rt.jar:1.8.0_151]
...
at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_151]
        at =
org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread=
.run(ManagedThreadFactoryImpl.java:250) =
[javax.enterprise.concurrent-1.0.jar:]
...
at =
...
=20
=20
=20
2017-12-14 02:42:15,525-05 INFO  =
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand] =
(EE-ManagedThreadFactory-engineScheduled-Thread-26) =
[c5f1846d-d042-4271-86f1-2b1787684554] Ending command =
'org.ovirt.engine.core.bll.snapshots.Re
moveSnapshotCommand' successfully.
2017-12-14 02:42:15,528-05 DEBUG =
[org.ovirt.engine.core.aaa.filters.SsoRestApiAuthFilter] (default =
task-16) [] Entered SsoRestApiAuthFilter
2017-12-14 02:42:15,528-05 DEBUG =
[org.ovirt.engine.core.aaa.filters.SsoRestApiAuthFilter] (default =
task-16) [] SsoRestApiAuthFilter authenticating with sso
2017-12-14 02:42:15,528-05 DEBUG =
[org.ovirt.engine.core.aaa.filters.SsoRestApiAuthFilter] (default =
task-16) [] SsoRestApiAuthFilter authenticating using BEARER header
2017-12-14 02:42:15,531-05 DEBUG =
[org.ovirt.engine.core.aaa.filters.SsoRestApiAuthFilter] (default =
task-16) [] SsoRestApiAuthFilter successfully authenticated using BEARER =
org.jboss.as.ee.concurrent.service.ElytronManagedThreadFactory$ElytronMana=
gedThread.run(ElytronManagedThreadFactory.java:78)
header
...
2017-12-14 02:42:15,531-05 DEBUG =
[org.ovirt.engine.core.aaa.filters.SsoRestApiNegotiationFilter] (default =
task-16) [] Entered SsoRestApiNegotiationFilter
2017-12-14 02:42:15,533-05 DEBUG =
[org.ovirt.engine.core.aaa.filters.SsoRestApiNegotiationFilter] (default =
task-16) [] SsoRestApiNegotiationFilter Not performing Negotiate Auth
2017-12-14 02:42:15,540-05 DEBUG =
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor] =
(EE-ManagedThreadFactory-engineScheduled-Thread-26) =
[c5f1846d-d042-4271-86f1-2b1787684554] method: get, params: =
[cc9ae472-ef79-456f-9e4
7-01fd1617e189], timeElapsed: 3ms
2017-12-14 02:42:15,543-05 DEBUG =
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor] =
(default task-16) [2c5d880a-5c36-41e7-8020-bb2007cf9be2] method: =
runQuery, params: [GetAllVmSnapshotsByVmId, IdQueryParameters:{refresh
=3D'false', filtered=3D'false'}], timeElapsed: 6ms
2017-12-14 02:42:15,548-05 WARN  =
[org.ovirt.engine.core.bll.GetVmConfigurationBySnapshotQuery] (default =
task-16) [2c5d880a-5c36-41e7-8020-bb2007cf9be2] Snapshot =
'20b155eb-c15d-42cb-a03f-c45813a045b8' does not exist
2017-12-14 02:42:15,548-05 DEBUG =
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor] =
(default task-16) [2c5d880a-5c36-41e7-8020-bb2007cf9be2] method: =
runQuery, params: [GetVmConfigurationBySnapshot, IdQueryParameters:{re
fresh=3D'false', filtered=3D'false'}], timeElapsed: 5ms
2017-12-14 02:42:15,548-05 ERROR =
[org.ovirt.engine.api.restapi.resource.AbstractBackendResource] (default =
task-16) [] Operation Failed: Entity not found: null
2017-12-14 02:42:15,554-05 INFO  =
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] =
(EE-ManagedThreadFactory-engineScheduled-Thread-26) =
[c5f1846d-d042-4271-86f1-2b1787684554] EVENT_ID: =
USER_REMOVE_SNAPSHOT_FINISHED_SUC
CESS(356), Snapshot 'dead_snap1' deletion for VM 'vm1' has been =
completed.
2017-12-14 02:42:16,660-05 DEBUG =
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand] =
(EE-ManagedThreadFactory-engineScheduled-Thread-50) [] START, =
GetAllVmStatsVDSCommand(HostName =3D lago-basic-suite-master-host-0, =
VdsIdVDS
=
CommandParametersBase:{hostId=3D'3c60017b-0bb3-4a3e-bc24-f1779100fe21'}), =
log id: f9a1165
2017-12-14 02:42:16,660-05 DEBUG =
[org.ovirt.vdsm.jsonrpc.client.reactors.stomp.impl.Message] =
(EE-ManagedThreadFactory-engineScheduled-Thread-50) [] SEND
destination:jms.topic.vdsm_requests
reply-to:jms.topic.vdsm_responses
content-length:103
=20
vdsm:=20
=20
2017-12-14 02:34:45,222-0500 ERROR (jsonrpc/7) [jsonrpc.JsonRpcServer] =
Internal server error (__init__:611)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py", line =
606, in _handle_request
    res =3D method(**params)
  File "/usr/lib/python2.7/site-packages/vdsm/rpc/Bridge.py", line =
201, in _dynamicMethod
    result =3D fn(*methodArgs)
  File "<string>", line 2, in getAllVmStats
  File "/usr/lib/python2.7/site-packages/vdsm/common/api.py", line 48, =
in method
    ret =3D func(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/API.py", line 1342, in =
getAllVmStats
    statsList =3D self._cif.getAllVmStats()
  File "/usr/lib/python2.7/site-packages/vdsm/clientIF.py", line 518, =
in getAllVmStats
    return [v.getStats() for v in self.vmContainer.values()]
  File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 1699, =
in getStats
    oga_stats =3D self._getGuestStats()
  File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 1895, =
in _getGuestStats
    self._update_guest_disk_mapping()
  File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 1909, =
in _update_guest_disk_mapping
    self._sync_metadata()
  File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 4995, =
in _sync_metadata
    self._md_desc.dump(self._dom)
  File "/usr/lib/python2.7/site-packages/vdsm/virt/metadata.py", line =
477, in dump
    dom.setMetadata(libvirt.VIR_DOMAIN_METADATA_ELEMENT,
  File "/usr/lib/python2.7/site-packages/vdsm/virt/virdomain.py", line =
47, in __getattr__
    % self.vmid)
NotConnectedError: VM '7cab7e5a-cb12-4977-ac4f-65218532df7e' was not =
defined yet or was undefined
it doesn=E2=80=99t seem to be relevant to this failure, but it deserves =
a fix nevertheless
Francesco?
...
=20
=20
=20
</error>
=20
_______________________________________________
Devel mailing list
Devel@ovirt.org
http://lists.ovirt.org/mailman/listinfo/devel
--Apple-Mail=_4507365F-4541-4953-A54F-924C8DA4DC7F
Content-Transfer-Encoding: quoted-printable
Content-Type: text/html;
	charset=utf-8

<html><head><meta http-equiv=3D"Content-Type" content=3D"text/html =
charset=3Dutf-8"></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 14 Dec 2017, at 13:00, Dafna Ron <<a =
href=3D"mailto:dron@redhat.com" class=3D"">dron@redhat.com</a>> =
wrote:</div><br class=3D"Apple-interchange-newline"><div class=3D"">
 =20

    <meta http-equiv=3D"content-type" content=3D"text/html; =
charset=3Dutf-8" class=3D"">
 =20
  <div text=3D"#000000" bgcolor=3D"#FFFFFF" class=3D""><p class=3D"">Hi, =
<br class=3D"">
    </p><p class=3D"">We have a failure on basic suite on test:
      004_basic_sanity.disk_operations<br class=3D"">
    </p>
    I think that we query a snapshot that was already deleted
    successfully and report the snapshot as gone. and that is because of
    a different error in update vm query which happens before. <br =
class=3D"">
    <br class=3D"">
    <b style=3D"font-weight:normal;" =
id=3D"docs-internal-guid-5859b7a1-54dd-82fe-8fc8-8fab5e981868" =
class=3D""><div style=3D"line-height: 1.38; margin-top: 0pt; =
margin-bottom: 0pt;" class=3D""><span style=3D"font-size: 11pt; =
font-family: Arial; background-color: transparent; font-weight: 400; =
font-style: normal; font-variant-ligatures: normal; font-variant-caps: =
normal; font-variant-east-asian: normal; font-variant-position: normal; =
text-decoration: none; vertical-align: baseline; white-space: pre-wrap;" =
class=3D"">Link and headline of suspected patches: </span></div>
      <a class=3D"moz-txt-link-freetext" =
href=3D"https://gerrit.ovirt.org/#/c/85168/">https://gerrit.ovirt.org/#/c/=
85168/</a> - core: Prevent retry lease
      hotplag in case of failure.<br class=3D"">
      <br class=3D""><div style=3D"line-height: 1.38; margin-top: 0pt; =
margin-bottom: 0pt;" class=3D""><span style=3D"font-size: 11pt; =
font-family: Arial; background-color: transparent; font-weight: 400; =
font-style: normal; font-variant-ligatures: normal; font-variant-caps: =
normal; font-variant-east-asian: normal; font-variant-position: normal; =
text-decoration: none; vertical-align: baseline; white-space: pre-wrap;" =
class=3D"">Link to Job:</span></div>
      <a class=3D"moz-txt-link-freetext" =
href=3D"http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4393=
">http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4393</a><b=
r class=3D"">
      <br class=3D""><div style=3D"line-height: 1.38; margin-top: 0pt; =
margin-bottom: 0pt;" class=3D""><span style=3D"font-size: 11pt; =
font-family: Arial; background-color: transparent; font-weight: 400; =
font-style: normal; font-variant-ligatures: normal; font-variant-caps: =
normal; font-variant-east-asian: normal; font-variant-position: normal; =
text-decoration: none; vertical-align: baseline; white-space: pre-wrap;" =
class=3D"">Link to all logs:</span></div>
<a class=3D"moz-txt-link-freetext" =
href=3D"http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4393=
/artifact/">http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/=
4393/artifact/</a><br class=3D"">
      <br class=3D""><div style=3D"line-height: 1.38; margin-top: 0pt; =
margin-bottom: 0pt;" class=3D""><span style=3D"font-size: 11pt; =
font-family: Arial; background-color: transparent; font-weight: 400; =
font-style: normal; font-variant-ligatures: normal; font-variant-caps: =
normal; font-variant-east-asian: normal; font-variant-position: normal; =
text-decoration: none; vertical-align: baseline; white-space: pre-wrap;" =
class=3D"">(Relevant) error snippet from the log: </span></div><div =
style=3D"line-height: 1.38; margin-top: 0pt; margin-bottom: 0pt;" =
class=3D""><span style=3D"font-size: 11pt; font-family: Arial; =
background-color: transparent; font-weight: 400; font-style: normal; =
font-variant-ligatures: normal; font-variant-caps: normal; =
font-variant-east-asian: normal; font-variant-position: normal; =
text-decoration: none; vertical-align: baseline; white-space: pre-wrap;" =
class=3D""><error></span></div>
      <br class=3D"">
      Engine: <br class=3D"">
      <br class=3D"">
      <br class=3D"">
      <br class=3D"">
      <b class=3D"">2017-12-14 02:38:01,470-05 ERROR
        =
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand]
        (EE-ManagedThreadFactory-engineScheduled-Thread-5) [] Command
        'GetAllVmStatsVDSCommand(HostName =3D
        lago-basic-suite-master-host-1, VdsIdVD<br class=3D"">
SCommandParametersBase:{hostId=3D'f1c2314f-5617-4c9e-84e0-e822160fbde9'})'=

        execution failed: VDSGenericException: VDSErrorException: Failed
        to GetAllVmStatsVDS, error =3D Internal JSON-RPC error: =
{'reason':
        "VM '7cab7e5a-cb12-4977-ac4f-652185<br class=3D"">
        32df7e' was not defined yet or was undefined"}, code =3D =
-32603<br class=3D"">
        2017-12-14 02:38:01,470-05 DEBUG
        =
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand]
        (EE-ManagedThreadFactory-engineScheduled-Thread-5) [] Exception:
        org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException:
        VDSGenericE<br class=3D"">
        xception: VDSErrorException: Failed to GetAllVmStatsVDS, error =3D=

        Internal JSON-RPC error: {'reason': "VM
        '7cab7e5a-cb12-4977-ac4f-65218532df7e' was not defined yet or
        was undefined"}, code =3D -32603<br class=3D"">
                at
=
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createDefaultCo=
ncreteException(VdsBrokerCommand.java:81)
        [vdsbroker.jar:]<br class=3D"">
                at
=
org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.createExceptio=
n(BrokerCommandBase.java:224)
        [vdsbroker.jar:]<br class=3D"">
                at
=
org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.proceedProxyRe=
turnValue(BrokerCommandBase.java:194)
        [vdsbroker.jar:]<br class=3D"">
                at
=
org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand.executeV=
dsBrokerCommand(GetAllVmStatsVDSCommand.java:23)
        [vdsbroker.jar:]<br class=3D"">
                at
=
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSComma=
nd(VdsBrokerCommand.java:112)
        [vdsbroker.jar:]<br class=3D"">
                at
=
org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBa=
se.java:73)
        [vdsbroker.jar:]<br class=3D"">
                at
        =
org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33)
        [dal.jar:]<br class=3D"">
                at
=
org.ovirt.engine.core.vdsbroker.vdsbroker.DefaultVdsCommandExecutor.execut=
e(DefaultVdsCommandExecutor.java:14)
        [vdsbroker.jar:]<br class=3D"">
                at
=
org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceMana=
ger.java:387)
        [vdsbroker.jar:]<br class=3D"">
                at
=
org.ovirt.engine.core.vdsbroker.ResourceManager$Proxy$_$$_WeldSubclass.run=
VdsCommand$$super(Unknown
        Source) [vdsbroker.jar:]<br class=3D"">
                at =
sun.reflect.GeneratedMethodAccessor247.invoke(Unknown
        Source) [:1.8.0_151]<br class=3D"">
                at
=
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorIm=
pl.java:43)
        [rt.jar:1.8.0_151]<br class=3D"">
                at =
java.lang.reflect.Method.invoke(Method.java:498)
        [rt.jar:1.8.0_151]<br class=3D"">
                at
=
org.jboss.weld.interceptor.proxy.TerminalAroundInvokeInvocationContext.pro=
ceedInternal(TerminalAroundInvokeInvocationContext.java:49)
        [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]<br class=3D"">
                at
=
org.jboss.weld.interceptor.proxy.AroundInvokeInvocationContext.proceed(Aro=
undInvokeInvocationContext.java:77)
        [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]<br class=3D"">
                at
=
org.ovirt.engine.core.common.di.interceptor.LoggingInterceptor.apply(Loggi=
ngInterceptor.java:12)
        [common.jar:]<br class=3D"">
                at =
sun.reflect.GeneratedMethodAccessor69.invoke(Unknown
        Source) [:1.8.0_151]<br class=3D"">
                at
=
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorIm=
pl.java:43)
        [rt.jar:1.8.0_151]<br class=3D"">
                at =
java.lang.reflect.Method.invoke(Method.java:498)
        [rt.jar:1.8.0_151]<br class=3D"">
                at
=
org.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethod=
Invocation.invoke(SimpleInterceptorInvocation.java:73)
        [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]<br class=3D"">
                at
=
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeAroundInv=
oke(InterceptorMethodHandler.java:84)
        [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]<br class=3D"">
                at
=
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeIntercept=
ion(InterceptorMethodHandler.java:72)
        [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]<br class=3D"">
                at
=
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(Intercept=
orMethodHandler.java:56)
        [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]<br class=3D"">
                at
=
org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandle=
r.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79)
        [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]<br class=3D"">
                at
=
org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandle=
r.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:68)
        [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]<br class=3D"">
                at
=
org.ovirt.engine.core.vdsbroker.ResourceManager$Proxy$_$$_WeldSubclass.run=
VdsCommand(Unknown
        Source) [vdsbroker.jar:]<br class=3D"">
                at
=
org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher.poll(VmsSt=
atisticsFetcher.java:29)
        [vdsbroker.jar:]<br class=3D"">
                at
=
org.ovirt.engine.core.vdsbroker.monitoring.VmsListFetcher.fetch(VmsListFet=
cher.java:57)
        [vdsbroker.jar:]<br class=3D"">
                at
=
org.ovirt.engine.core.vdsbroker.monitoring.PollVmStatsRefresher.poll(PollV=
mStatsRefresher.java:42)
        [vdsbroker.jar:]<br class=3D"">
                at
        =
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        [rt.jar:1.8.0_151]<br class=3D"">
                at
        java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
        [rt.jar:1.8.0_151]<br class=3D"">
                at
=
org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExe=
cutor$ManagedScheduledFutureTask.access$201(ManagedScheduledThreadPoolExec=
utor.java:383)
        [javax.enterprise.concurrent-1.0.jar:]<br class=3D"">
                at
=
org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExe=
cutor$ManagedScheduledFutureTask.run(ManagedScheduledThreadPoolExecutor.ja=
va:534)
        [javax.enterprise.concurrent-1.0.jar:]<br class=3D"">
                at
=
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:=
1149)
        [rt.jar:1.8.0_151]<br class=3D"">
                at
=
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java=
:624)
        [rt.jar:1.8.0_151]<br class=3D"">
                at =
java.lang.Thread.run(Thread.java:748)
        [rt.jar:1.8.0_151]<br class=3D"">
                at
=
org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread=
.run(ManagedThreadFactoryImpl.java:250)
        [javax.enterprise.concurrent-1.0.jar:]<br class=3D"">
                at
=
org.jboss.as.ee.concurrent.service.ElytronManagedThreadFactory$ElytronMana=
gedThread.run(ElytronManagedThreadFactory.java:78)<br class=3D"">
        <br class=3D"">
      </b><br class=3D"">
      <br class=3D"">
      <b class=3D"">2017-12-14 02:42:15,525-05 INFO 
        [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand]
        (EE-ManagedThreadFactory-engineScheduled-Thread-26)
        [c5f1846d-d042-4271-86f1-2b1787684554] Ending command
        'org.ovirt.engine.core.bll.snapshots.Re<br class=3D"">
        moveSnapshotCommand' successfully.<br class=3D"">
        2017-12-14 02:42:15,528-05 DEBUG
        [org.ovirt.engine.core.aaa.filters.SsoRestApiAuthFilter]
        (default task-16) [] Entered SsoRestApiAuthFilter<br class=3D"">
        2017-12-14 02:42:15,528-05 DEBUG
        [org.ovirt.engine.core.aaa.filters.SsoRestApiAuthFilter]
        (default task-16) [] SsoRestApiAuthFilter authenticating with
        sso<br class=3D"">
        2017-12-14 02:42:15,528-05 DEBUG
        [org.ovirt.engine.core.aaa.filters.SsoRestApiAuthFilter]
        (default task-16) [] SsoRestApiAuthFilter authenticating using
        BEARER header<br class=3D"">
        2017-12-14 02:42:15,531-05 DEBUG
        [org.ovirt.engine.core.aaa.filters.SsoRestApiAuthFilter]
        (default task-16) [] SsoRestApiAuthFilter successfully
        authenticated using BEARER header<br class=3D"">
        2017-12-14 02:42:15,531-05 DEBUG
        [org.ovirt.engine.core.aaa.filters.SsoRestApiNegotiationFilter]
        (default task-16) [] Entered SsoRestApiNegotiationFilter<br =
class=3D"">
        2017-12-14 02:42:15,533-05 DEBUG
        [org.ovirt.engine.core.aaa.filters.SsoRestApiNegotiationFilter]
        (default task-16) [] SsoRestApiNegotiationFilter Not performing
        Negotiate Auth<br class=3D"">
        2017-12-14 02:42:15,540-05 DEBUG
        =
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
        (EE-ManagedThreadFactory-engineScheduled-Thread-26)
        [c5f1846d-d042-4271-86f1-2b1787684554] method: get, params:
        [cc9ae472-ef79-456f-9e4<br class=3D"">
        7-01fd1617e189], timeElapsed: 3ms<br class=3D"">
        2017-12-14 02:42:15,543-05 DEBUG
        =
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
        (default task-16) [2c5d880a-5c36-41e7-8020-bb2007cf9be2] method:
        runQuery, params: [GetAllVmSnapshotsByVmId,
        IdQueryParameters:{refresh<br class=3D"">
        =3D'false', filtered=3D'false'}], timeElapsed: 6ms<br class=3D"">
        2017-12-14 02:42:15,548-05 WARN 
        [org.ovirt.engine.core.bll.GetVmConfigurationBySnapshotQuery]
        (default task-16) [2c5d880a-5c36-41e7-8020-bb2007cf9be2]
        Snapshot '20b155eb-c15d-42cb-a03f-c45813a045b8' does not =
exist<br class=3D"">
        2017-12-14 02:42:15,548-05 DEBUG
        =
[org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor]
        (default task-16) [2c5d880a-5c36-41e7-8020-bb2007cf9be2] method:
        runQuery, params: [GetVmConfigurationBySnapshot,
        IdQueryParameters:{re<br class=3D"">
        fresh=3D'false', filtered=3D'false'}], timeElapsed: 5ms<br =
class=3D"">
        2017-12-14 02:42:15,548-05 ERROR
        [org.ovirt.engine.api.restapi.resource.AbstractBackendResource]
        (default task-16) [] Operation Failed: Entity not found: null<br =
class=3D"">
        2017-12-14 02:42:15,554-05 INFO 
        =
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
        (EE-ManagedThreadFactory-engineScheduled-Thread-26)
        [c5f1846d-d042-4271-86f1-2b1787684554] EVENT_ID:
        USER_REMOVE_SNAPSHOT_FINISHED_SUC<br class=3D"">
        CESS(356), Snapshot 'dead_snap1' deletion for VM 'vm1' has been
        completed.<br class=3D"">
        2017-12-14 02:42:16,660-05 DEBUG
        =
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand]
        (EE-ManagedThreadFactory-engineScheduled-Thread-50) [] START,
        GetAllVmStatsVDSCommand(HostName =3D
        lago-basic-suite-master-host-0, VdsIdVDS<br class=3D"">
CommandParametersBase:{hostId=3D'3c60017b-0bb3-4a3e-bc24-f1779100fe21'}),
        log id: f9a1165<br class=3D"">
        2017-12-14 02:42:16,660-05 DEBUG
        [org.ovirt.vdsm.jsonrpc.client.reactors.stomp.impl.Message]
        (EE-ManagedThreadFactory-engineScheduled-Thread-50) [] SEND<br =
class=3D"">
        destination:jms.topic.vdsm_requests<br class=3D"">
        reply-to:jms.topic.vdsm_responses<br class=3D"">
        content-length:103<br class=3D"">
        <br class=3D"">
        vdsm: </b></b></div></div></blockquote><blockquote =
type=3D"cite" class=3D""><div class=3D""><div text=3D"#000000" =
bgcolor=3D"#FFFFFF" class=3D""><b style=3D"font-weight:normal;" =
id=3D"docs-internal-guid-5859b7a1-54dd-82fe-8fc8-8fab5e981868" =
class=3D""><b class=3D"">
        <br class=3D"">
        2017-12-14 02:34:45,222-0500 ERROR (jsonrpc/7)
        [jsonrpc.JsonRpcServer] Internal server error (__init__:611)<br =
class=3D"">
        Traceback (most recent call last):<br class=3D"">
          File =
"/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py",
        line 606, in _handle_request<br class=3D"">
            res =3D method(**params)<br class=3D"">
          File =
"/usr/lib/python2.7/site-packages/vdsm/rpc/Bridge.py",
        line 201, in _dynamicMethod<br class=3D"">
            result =3D fn(*methodArgs)<br class=3D"">
          File "<string>", line 2, in getAllVmStats<br =
class=3D"">
          File =
"/usr/lib/python2.7/site-packages/vdsm/common/api.py",
        line 48, in method<br class=3D"">
            ret =3D func(*args, **kwargs)<br class=3D"">
          File "/usr/lib/python2.7/site-packages/vdsm/API.py", line
        1342, in getAllVmStats<br class=3D"">
            statsList =3D self._cif.getAllVmStats()<br =
class=3D"">
          File "/usr/lib/python2.7/site-packages/vdsm/clientIF.py", =
line
        518, in getAllVmStats<br class=3D"">
            return [v.getStats() for v in =
self.vmContainer.values()]<br class=3D"">
          File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", =
line
        1699, in getStats<br class=3D"">
            oga_stats =3D self._getGuestStats()<br =
class=3D"">
          File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", =
line
        1895, in _getGuestStats<br class=3D"">
            self._update_guest_disk_mapping()<br =
class=3D"">
          File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", =
line
        1909, in _update_guest_disk_mapping<br class=3D"">
            self._sync_metadata()<br class=3D"">
          File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", =
line
        4995, in _sync_metadata<br class=3D"">
            self._md_desc.dump(self._dom)<br class=3D"">
          File =
"/usr/lib/python2.7/site-packages/vdsm/virt/metadata.py",
        line 477, in dump<br class=3D"">
            =
dom.setMetadata(libvirt.VIR_DOMAIN_METADATA_ELEMENT,<br class=3D"">
          File
        "/usr/lib/python2.7/site-packages/vdsm/virt/virdomain.py", line
        47, in __getattr__<br class=3D"">
            % self.vmid)<br class=3D"">
        NotConnectedError: VM '7cab7e5a-cb12-4977-ac4f-65218532df7e' was
        not defined yet or was undefined<br =
class=3D""></b></b></div></div></blockquote><div><br class=3D""></div>it =
doesn=E2=80=99t seem to be relevant to this failure, but it deserves a =
fix nevertheless</div><div>Francesco?</div><div><br class=3D""><blockquote=
 type=3D"cite" class=3D""><div class=3D""><div text=3D"#000000" =
bgcolor=3D"#FFFFFF" class=3D""><b style=3D"font-weight:normal;" =
id=3D"docs-internal-guid-5859b7a1-54dd-82fe-8fc8-8fab5e981868" =
class=3D""><b class=3D"">
        <br class=3D"">
      </b><br class=3D"">
      <br class=3D""><div style=3D"line-height: 1.38; margin-top: 0pt; =
margin-bottom: 0pt;" class=3D""><span style=3D"font-size: 11pt; =
font-family: Arial; background-color: transparent; font-weight: 400; =
font-style: normal; font-variant-ligatures: normal; font-variant-caps: =
normal; font-variant-east-asian: normal; font-variant-position: normal; =
text-decoration: none; vertical-align: baseline; white-space: pre-wrap;" =
class=3D""></error></span></div>
    </b><br class=3D"Apple-interchange-newline">
  </div>

_______________________________________________<br class=3D"">Devel =
mailing list<br class=3D""><a href=3D"mailto:Devel@ovirt.org" =
class=3D"">Devel@ovirt.org</a><br =
class=3D"">http://lists.ovirt.org/mailman/listinfo/devel</div></blockquote=
...
</div><br class=3D""></body></html>=
--Apple-Mail=_4507365F-4541-4953-A54F-924C8DA4DC7F--

Re: [ovirt-devel] [ OST Failure Report ] [ oVirt Master ] [ 14-12-2017 ] [ 004_basic_sanity.disk_operations ]

Michal Skrivanek