Bug 1467702 - MergeVDS method failed with 'Virtual machine does not exist'
MergeVDS method failed with 'Virtual machine does not exist'
Status: NEW
Product: ovirt-engine
Classification: oVirt
Component: BLL.Storage (Show other bugs)
4.2.0
Unspecified Unspecified
unspecified Severity medium (vote)
: ovirt-4.2.0
: ---
Assigned To: Ala Hino
Raz Tamir
: Automation
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2017-07-04 12:41 EDT by Raz Tamir
Modified: 2017-07-04 13:38 EDT (History)
1 user (show)

See Also:
Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed:
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: Storage
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---
rule-engine: ovirt‑4.2+


Attachments (Terms of Use)
engine and vdsm logs (5.86 MB, application/x-gzip)
2017-07-04 12:41 EDT, Raz Tamir
no flags Details

  None (edit)
Description Raz Tamir 2017-07-04 12:41:32 EDT
Created attachment 1294294 [details]
engine and vdsm logs

Description of problem:
After a successful LSM, the live merge operation fails with Engine exception thrown while sending merge command: org.ovirt.engine.core.common.errors.EngineException: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Virtual machine does not exist: {'vmId': 'f10e059b-0641-4bb1-975f-2c4d131dbc49'}, code = 1 (Failed with error noVM and code 1)

Happened once, so far, as far as I know.

I don't know if this is related but from the vdsm.log, the Live snapshot before the LSM operation should start with freezing the guest and after thaw it - it failed in both operation but the live snapshot succeded:

2017-06-29 15:39:51,700+0300 INFO  (jsonrpc/1) [virt.vm] (vmId='f10e059b-0641-4bb1-975f-2c4d131dbc49') Freezing guest filesystems (vm:3657)
2017-06-29 15:39:51,701+0300 WARN  (jsonrpc/1) [virt.vm] (vmId='f10e059b-0641-4bb1-975f-2c4d131dbc49') Unable to freeze guest filesystems: Guest agent is not responding: QEMU guest agent is not connected (vm:3662)
2017-06-29 15:39:51,701+0300 INFO  (jsonrpc/1) [vdsm.api] FINISH freeze return={'status': {'message': 'Guest agent is not responding: QEMU guest agent is not connected', 'code': 19}} from=::ffff:10.35.69.94,49954, flow_id=disks_syncAction_c23240ca-de09-4c8e (api:52)
2017-06-29 15:39:51,702+0300 INFO  (jsonrpc/1) [virt.vm] (vmId='f10e059b-0641-4bb1-975f-2c4d131dbc49') Taking a live snapshot (drives=vda, memory=True) (vm:3877)
2017-06-29 15:39:51,825+0300 INFO  (jsonrpc/1) [virt.vm] (vmId='f10e059b-0641-4bb1-975f-2c4d131dbc49') Completed live snapshot (vm:3879)
2017-06-29 15:39:51,825+0300 INFO  (jsonrpc/1) [vdsm.api] START thaw() from=::ffff:10.35.69.94,49954, flow_id=disks_syncAction_c23240ca-de09-4c8e (api:46)
2017-06-29 15:39:51,825+0300 INFO  (jsonrpc/1) [virt.vm] (vmId='f10e059b-0641-4bb1-975f-2c4d131dbc49') Thawing guest filesystems (vm:3681)
2017-06-29 15:39:51,826+0300 WARN  (jsonrpc/1) [virt.vm] (vmId='f10e059b-0641-4bb1-975f-2c4d131dbc49') Unable to thaw guest filesystems: Guest agent is not responding: QEMU guest agent is not connected (vm:3686)
2017-06-29 15:39:51,827+0300 INFO  (jsonrpc/1) [vdsm.api] FINISH thaw return={'status': {'message': 'Guest agent is not responding: QEMU guest agent is not connected', 'code': 19}} from=::ffff:10.35.69.94,49954, flow_id=disks_syncAction_c23240ca-de09-4c8e (api:52)



From engine.log:

2017-06-29 15:43:42,466+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-5-thread-6) [disks_syncAction_c23240ca-de09-4c8e] START, MergeVDSCommand(HostName = host_mixed_1, MergeVDSCommandParameters:{hostId='13b43759-2cb8-44eb-8682-ad2fe5631900', vmId='f10e059b-0641-4bb1-975f-2c4d131dbc49', storagePoolId='bd907a90-1c67-42b5-8d85-7d36608c74c1', storageDomainId='b1789112-86d0-47e2-bb1c-8f4aa69fd112', imageGroupId='acdd7fb8-9dbd-4dd0-bc81-1f28dbc520a2', imageId='01229980-8a03-410e-8056-5dd8e69b813d', baseImageId='72b21d13-d3d3-448b-b476-f8897f298d4b', topImageId='01229980-8a03-410e-8056-5dd8e69b813d', bandwidth='0'}), log id: 64a1f1b5
2017-06-29 15:43:42,470+03 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-5-thread-6) [disks_syncAction_c23240ca-de09-4c8e] Failed in 'MergeVDS' method
2017-06-29 15:43:42,481+03 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (pool-5-thread-6) [disks_syncAction_c23240ca-de09-4c8e] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM host_mixed_1 command MergeVDS failed: Virtual machine does not exist: {'vmId': 'f10e059b-0641-4bb1-975f-2c4d131dbc49'}
2017-06-29 15:43:42,481+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-5-thread-6) [disks_syncAction_c23240ca-de09-4c8e] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand' return value 'StatusOnlyReturn [status=Status [code=1, message=Virtual machine does not exist: {'vmId': 'f10e059b-0641-4bb1-975f-2c4d131dbc49'}]]'
2017-06-29 15:43:42,481+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-5-thread-6) [disks_syncAction_c23240ca-de09-4c8e] HostName = host_mixed_1
2017-06-29 15:43:42,481+03 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-5-thread-6) [disks_syncAction_c23240ca-de09-4c8e] Command 'MergeVDSCommand(HostName = host_mixed_1, MergeVDSCommandParameters:{hostId='13b43759-2cb8-44eb-8682-ad2fe5631900', vmId='f10e059b-0641-4bb1-975f-2c4d131dbc49', storagePoolId='bd907a90-1c67-42b5-8d85-7d36608c74c1', storageDomainId='b1789112-86d0-47e2-bb1c-8f4aa69fd112', imageGroupId='acdd7fb8-9dbd-4dd0-bc81-1f28dbc520a2', imageId='01229980-8a03-410e-8056-5dd8e69b813d', baseImageId='72b21d13-d3d3-448b-b476-f8897f298d4b', topImageId='01229980-8a03-410e-8056-5dd8e69b813d', bandwidth='0'})' execution failed: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Virtual machine does not exist: {'vmId': 'f10e059b-0641-4bb1-975f-2c4d131dbc49'}, code = 1
2017-06-29 15:43:42,481+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-5-thread-6) [disks_syncAction_c23240ca-de09-4c8e] FINISH, MergeVDSCommand, log id: 64a1f1b5
2017-06-29 15:43:42,481+03 ERROR [org.ovirt.engine.core.bll.MergeCommand] (pool-5-thread-6) [disks_syncAction_c23240ca-de09-4c8e] Engine exception thrown while sending merge command: org.ovirt.engine.core.common.errors.EngineException: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to MergeVDS, error = Virtual machine does not exist: {'vmId': 'f10e059b-0641-4bb1-975f-2c4d131dbc49'}, code = 1 (Failed with error noVM and code 1)

from vdsm.log:

2017-06-29 15:43:38,703+0300 ERROR (jsonrpc/1) [api] FINISH destroy error=Virtual machine does not exist: {'vmId': 'f10e059b-0641-4bb1-975f-2c4d131dbc49'} (api:119)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/common/api.py", line 117, in method
    ret = func(*args, **kwargs)
  File "/usr/share/vdsm/API.py", line 306, in destroy
    res = self.vm.destroy(gracefulAttempts)
  File "/usr/share/vdsm/API.py", line 134, in vm
    raise exception.NoSuchVM(vmId=self._UUID)
NoSuchVM: Virtual machine does not exist: {'vmId': 'f10e059b-0641-4bb1-975f-2c4d131dbc49'}
2017-06-29 15:43:38,704+0300 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC call VM.destroy failed (error 1) in 0.00 seconds (__init__:583)
2017-06-29 15:43:42,468+0300 ERROR (jsonrpc/3) [api] FINISH merge error=Virtual machine does not exist: {'vmId': 'f10e059b-0641-4bb1-975f-2c4d131dbc49'} (api:119)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/common/api.py", line 117, in method
    ret = func(*args, **kwargs)
  File "/usr/share/vdsm/API.py", line 670, in merge
    return self.vm.merge(
  File "/usr/share/vdsm/API.py", line 134, in vm
    raise exception.NoSuchVM(vmId=self._UUID)
NoSuchVM: Virtual machine does not exist: {'vmId': 'f10e059b-0641-4bb1-975f-2c4d131dbc49'}
2017-06-29 15:43:42,469+0300 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC call VM.merge failed (error 1) in 0.01 seconds (__init__:583)

Version-Release number of selected component (if applicable):
vdsm-4.20.1-89.git2912779.el7.centos.x86_64
ovirt-engine-4.2.0-0.0.master.20170627181935.git9424f9b.el7.centos.noarch
Red Hat Enterprise Linux Server 7.4 Beta

How reproducible:
Don't know - saw it once so far

Steps to Reproduce:
1. Perform LSM
2.
3.

Actual results:


Expected results:


Additional info:

Note You need to log in before you can comment on or make changes to this bug.