[ OST Failure Report ] [ oVirt Master ] [ 14-12-2017 ] [ 004_basic_sanity.disk_operations ]

14 Dec 2017

      This is a multi-part message in MIME format.
--------------8561B2DB99010E59BD5F2E03
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: 7bit

Hi,

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.

*

Link and headline of suspected patches:

https://gerrit.ovirt.org/#/c/85168/ - core: Prevent retry lease hotplag
in case of failure.

Link to Job:

http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4393

Link to all logs:

http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4393/artifact/

(Relevant) error snippet from the log:

<error>

Engine:

*2017-12-14 02:38:01,470-05 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-5) [] Command
'GetAllVmStatsVDSCommand(HostName = lago-basic-suite-master-host-1, VdsIdVD
SCommandParametersBase:{hostId='f1c2314f-5617-4c9e-84e0-e822160fbde9'})'
execution failed: VDSGenericException: VDSErrorException: Failed to
GetAllVmStatsVDS, error = Internal JSON-RPC error: {'reason': "VM
'7cab7e5a-cb12-4977-ac4f-652185
32df7e' was not defined yet or was undefined"}, code = -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 =
Internal JSON-RPC error: {'reason': "VM
'7cab7e5a-cb12-4977-ac4f-65218532df7e' was not defined yet or was
undefined"}, code = -32603
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createDefaultConcreteException(VdsBrokerCommand.java:81)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.createException(BrokerCommandBase.java:224)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.proceedProxyReturnValue(BrokerCommandBase.java:194)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand.executeVdsBrokerCommand(GetAllVmStatsVDSCommand.java:23)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:112)
[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:387)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.ResourceManager$Proxy$_$$_WeldSubclass.runVdsCommand$$super(Unknown
Source) [vdsbroker.jar:]
        at sun.reflect.GeneratedMethodAccessor247.invoke(Unknown Source)
[:1.8.0_151]
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.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.proceedInternal(TerminalAroundInvokeInvocationContext.java:49)
[weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
        at
org.jboss.weld.interceptor.proxy.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:77)
[weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
        at
org.ovirt.engine.core.common.di.interceptor.LoggingInterceptor.apply(LoggingInterceptor.java:12)
[common.jar:]
        at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown Source)
[:1.8.0_151]
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.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$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:73)
[weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
        at
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeAroundInvoke(InterceptorMethodHandler.java:84)
[weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
        at
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeInterception(InterceptorMethodHandler.java:72)
[weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
        at
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(InterceptorMethodHandler.java:56)
[weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
        at
org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79)
[weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
        at
org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.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.runVdsCommand(Unknown
Source) [vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher.poll(VmsStatisticsFetcher.java:29)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.monitoring.VmsListFetcher.fetch(VmsListFetcher.java:57)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.monitoring.PollVmStatsRefresher.poll(PollVmStatsRefresher.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.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.access$201(ManagedScheduledThreadPoolExecutor.java:383)
[javax.enterprise.concurrent-1.0.jar:]
        at
org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.run(ManagedScheduledThreadPoolExecutor.java: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
org.jboss.as.ee.concurrent.service.ElytronManagedThreadFactory$ElytronManagedThread.run(ElytronManagedThreadFactory.java:78)

*

*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
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
='false', filtered='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='false', filtered='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 = lago-basic-suite-master-host-0, VdsIdVDS
CommandParametersBase:{hostId='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

vdsm:

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 = method(**params)
  File "/usr/lib/python2.7/site-packages/vdsm/rpc/Bridge.py", line 201,
in _dynamicMethod
    result = fn(*methodArgs)
  File "<string>", line 2, in getAllVmStats
  File "/usr/lib/python2.7/site-packages/vdsm/common/api.py", line 48,
in method
    ret = func(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/API.py", line 1342, in
getAllVmStats
    statsList = 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 = 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

*

</error>

*

--------------8561B2DB99010E59BD5F2E03
Content-Type: text/html; charset=utf-8
Content-Transfer-Encoding: 8bit

<html>
  <head>

    <meta http-equiv="content-type" content="text/html; charset=utf-8">
  </head>
  <body text="#000000" bgcolor="#FFFFFF">
    <p>Hi, <br>
    </p>
    <p>We have a failure on basic suite on test:
      004_basic_sanity.disk_operations<br>
    </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>
    <br>
    <b style="font-weight:normal;"
      id="docs-internal-guid-5859b7a1-54dd-82fe-8fc8-8fab5e981868">
      <p dir="ltr"
        style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span style="font-size:11pt;font-family:Arial;color:#000000;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 of suspected patches: </span></p>
      <a class="moz-txt-link-freetext" href="https://gerrit.ovirt.org/#/c/85168/">https://gerrit.ovirt.org/#/c/85168/</a> - core: Prevent retry lease
      hotplag in case of failure.<br>
      <br>
      <p dir="ltr"
        style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span style="font-size:11pt;font-family:Arial;color:#000000;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></p>
      <a class="moz-txt-link-freetext" href="http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4393">http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4393</a><br>
      <br>
      <p dir="ltr"
        style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span style="font-size:11pt;font-family:Arial;color:#000000;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></p>
<a class="moz-txt-link-freetext" href="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>
      <br>
      <p dir="ltr"
        style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span style="font-size:11pt;font-family:Arial;color:#000000;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></p>
      <p dir="ltr"
        style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span style="font-size:11pt;font-family:Arial;color:#000000;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>
      <br>
      Engine: <br>
      <br>
      <br>
      <br>
      <b>2017-12-14 02:38:01,470-05 ERROR
        [org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand]
        (EE-ManagedThreadFactory-engineScheduled-Thread-5) [] Command
        'GetAllVmStatsVDSCommand(HostName =
        lago-basic-suite-master-host-1, VdsIdVD<br>
SCommandParametersBase:{hostId='f1c2314f-5617-4c9e-84e0-e822160fbde9'})'
        execution failed: VDSGenericException: VDSErrorException: Failed
        to GetAllVmStatsVDS, error = Internal JSON-RPC error: {'reason':
        "VM '7cab7e5a-cb12-4977-ac4f-652185<br>
        32df7e' was not defined yet or was undefined"}, code = -32603<br>
        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>
        xception: VDSErrorException: Failed to GetAllVmStatsVDS, error =
        Internal JSON-RPC error: {'reason': "VM
        '7cab7e5a-cb12-4977-ac4f-65218532df7e' was not defined yet or
        was undefined"}, code = -32603<br>
                at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createDefaultConcreteException(VdsBrokerCommand.java:81)
        [vdsbroker.jar:]<br>
                at
org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.createException(BrokerCommandBase.java:224)
        [vdsbroker.jar:]<br>
                at
org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.proceedProxyReturnValue(BrokerCommandBase.java:194)
        [vdsbroker.jar:]<br>
                at
org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand.executeVdsBrokerCommand(GetAllVmStatsVDSCommand.java:23)
        [vdsbroker.jar:]<br>
                at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:112)
        [vdsbroker.jar:]<br>
                at
org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:73)
        [vdsbroker.jar:]<br>
                at
        org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33)
        [dal.jar:]<br>
                at
org.ovirt.engine.core.vdsbroker.vdsbroker.DefaultVdsCommandExecutor.execute(DefaultVdsCommandExecutor.java:14)
        [vdsbroker.jar:]<br>
                at
org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:387)
        [vdsbroker.jar:]<br>
                at
org.ovirt.engine.core.vdsbroker.ResourceManager$Proxy$_$$_WeldSubclass.runVdsCommand$$super(Unknown
        Source) [vdsbroker.jar:]<br>
                at sun.reflect.GeneratedMethodAccessor247.invoke(Unknown
        Source) [:1.8.0_151]<br>
                at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        [rt.jar:1.8.0_151]<br>
                at java.lang.reflect.Method.invoke(Method.java:498)
        [rt.jar:1.8.0_151]<br>
                at
org.jboss.weld.interceptor.proxy.TerminalAroundInvokeInvocationContext.proceedInternal(TerminalAroundInvokeInvocationContext.java:49)
        [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]<br>
                at
org.jboss.weld.interceptor.proxy.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:77)
        [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]<br>
                at
org.ovirt.engine.core.common.di.interceptor.LoggingInterceptor.apply(LoggingInterceptor.java:12)
        [common.jar:]<br>
                at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown
        Source) [:1.8.0_151]<br>
                at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        [rt.jar:1.8.0_151]<br>
                at java.lang.reflect.Method.invoke(Method.java:498)
        [rt.jar:1.8.0_151]<br>
                at
org.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:73)
        [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]<br>
                at
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeAroundInvoke(InterceptorMethodHandler.java:84)
        [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]<br>
                at
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeInterception(InterceptorMethodHandler.java:72)
        [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]<br>
                at
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(InterceptorMethodHandler.java:56)
        [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]<br>
                at
org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79)
        [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]<br>
                at
org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:68)
        [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]<br>
                at
org.ovirt.engine.core.vdsbroker.ResourceManager$Proxy$_$$_WeldSubclass.runVdsCommand(Unknown
        Source) [vdsbroker.jar:]<br>
                at
org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher.poll(VmsStatisticsFetcher.java:29)
        [vdsbroker.jar:]<br>
                at
org.ovirt.engine.core.vdsbroker.monitoring.VmsListFetcher.fetch(VmsListFetcher.java:57)
        [vdsbroker.jar:]<br>
                at
org.ovirt.engine.core.vdsbroker.monitoring.PollVmStatsRefresher.poll(PollVmStatsRefresher.java:42)
        [vdsbroker.jar:]<br>
                at
        java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        [rt.jar:1.8.0_151]<br>
                at
        java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
        [rt.jar:1.8.0_151]<br>
                at
org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.access$201(ManagedScheduledThreadPoolExecutor.java:383)
        [javax.enterprise.concurrent-1.0.jar:]<br>
                at
org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.run(ManagedScheduledThreadPoolExecutor.java:534)
        [javax.enterprise.concurrent-1.0.jar:]<br>
                at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        [rt.jar:1.8.0_151]<br>
                at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        [rt.jar:1.8.0_151]<br>
                at java.lang.Thread.run(Thread.java:748)
        [rt.jar:1.8.0_151]<br>
                at
org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread.run(ManagedThreadFactoryImpl.java:250)
        [javax.enterprise.concurrent-1.0.jar:]<br>
                at
org.jboss.as.ee.concurrent.service.ElytronManagedThreadFactory$ElytronManagedThread.run(ElytronManagedThreadFactory.java:78)<br>
        <br>
      </b><br>
      <br>
      <b>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>
        moveSnapshotCommand' successfully.<br>
        2017-12-14 02:42:15,528-05 DEBUG
        [org.ovirt.engine.core.aaa.filters.SsoRestApiAuthFilter]
        (default task-16) [] Entered SsoRestApiAuthFilter<br>
        2017-12-14 02:42:15,528-05 DEBUG
        [org.ovirt.engine.core.aaa.filters.SsoRestApiAuthFilter]
        (default task-16) [] SsoRestApiAuthFilter authenticating with
        sso<br>
        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>
        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>
        2017-12-14 02:42:15,531-05 DEBUG
        [org.ovirt.engine.core.aaa.filters.SsoRestApiNegotiationFilter]
        (default task-16) [] Entered SsoRestApiNegotiationFilter<br>
        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>
        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>
        7-01fd1617e189], timeElapsed: 3ms<br>
        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>
        ='false', filtered='false'}], timeElapsed: 6ms<br>
        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>
        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>
        fresh='false', filtered='false'}], timeElapsed: 5ms<br>
        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>
        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>
        CESS(356), Snapshot 'dead_snap1' deletion for VM 'vm1' has been
        completed.<br>
        2017-12-14 02:42:16,660-05 DEBUG
        [org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand]
        (EE-ManagedThreadFactory-engineScheduled-Thread-50) [] START,
        GetAllVmStatsVDSCommand(HostName =
        lago-basic-suite-master-host-0, VdsIdVDS<br>
CommandParametersBase:{hostId='3c60017b-0bb3-4a3e-bc24-f1779100fe21'}),
        log id: f9a1165<br>
        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>
        destination:jms.topic.vdsm_requests<br>
        reply-to:jms.topic.vdsm_responses<br>
        content-length:103<br>
        <br>
        vdsm: <br>
        <br>
        2017-12-14 02:34:45,222-0500 ERROR (jsonrpc/7)
        [jsonrpc.JsonRpcServer] Internal server error (__init__:611)<br>
        Traceback (most recent call last):<br>
          File "/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py",
        line 606, in _handle_request<br>
            res = method(**params)<br>
          File "/usr/lib/python2.7/site-packages/vdsm/rpc/Bridge.py",
        line 201, in _dynamicMethod<br>
            result = fn(*methodArgs)<br>
          File "<string>", line 2, in getAllVmStats<br>
          File "/usr/lib/python2.7/site-packages/vdsm/common/api.py",
        line 48, in method<br>
            ret = func(*args, **kwargs)<br>
          File "/usr/lib/python2.7/site-packages/vdsm/API.py", line
        1342, in getAllVmStats<br>
            statsList = self._cif.getAllVmStats()<br>
          File "/usr/lib/python2.7/site-packages/vdsm/clientIF.py", line
        518, in getAllVmStats<br>
            return [v.getStats() for v in self.vmContainer.values()]<br>
          File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line
        1699, in getStats<br>
            oga_stats = self._getGuestStats()<br>
          File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line
        1895, in _getGuestStats<br>
            self._update_guest_disk_mapping()<br>
          File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line
        1909, in _update_guest_disk_mapping<br>
            self._sync_metadata()<br>
          File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line
        4995, in _sync_metadata<br>
            self._md_desc.dump(self._dom)<br>
          File "/usr/lib/python2.7/site-packages/vdsm/virt/metadata.py",
        line 477, in dump<br>
            dom.setMetadata(libvirt.VIR_DOMAIN_METADATA_ELEMENT,<br>
          File
        "/usr/lib/python2.7/site-packages/vdsm/virt/virdomain.py", line
        47, in __getattr__<br>
            % self.vmid)<br>
        NotConnectedError: VM '7cab7e5a-cb12-4977-ac4f-65218532df7e' was
        not defined yet or was undefined<br>
        <br>
        <br>
        <br>
      </b><br>
      <br>
      <p dir="ltr"
        style="line-height:1.38;margin-top:0pt;margin-bottom:0pt;"><span style="font-size:11pt;font-family:Arial;color:#000000;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>
    </b><br class="Apple-interchange-newline">
  </body>
</html>

--------------8561B2DB99010E59BD5F2E03--

Dafna Ron

Michal Skrivanek

Francesco Romani

Michal Skrivanek

tags

participants (3)