Bug 1519149 - LSM fails to vmReplicateDisk with Drive replication error', 'code': 55
Summary: LSM fails to vmReplicateDisk with Drive replication error', 'code': 55
Keywords:
Status: CLOSED DUPLICATE of bug 1518558
Alias: None
Product: vdsm
Classification: oVirt
Component: General
Version: 4.20.8
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: ---
: ---
Assignee: Dan Kenigsberg
QA Contact: Raz Tamir
URL:
Whiteboard:
Depends On: 1306562
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-11-30 09:40 UTC by Raz Tamir
Modified: 2018-10-20 17:41 UTC (History)
2 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-11-30 09:58:44 UTC
oVirt Team: Storage
Embargoed:


Attachments (Terms of Use)
engine and vdsm logs (1.95 MB, application/x-gzip)
2017-11-30 09:40 UTC, Raz Tamir
no flags Details

Description Raz Tamir 2017-11-30 09:40:57 UTC
Created attachment 1360774 [details]
engine and vdsm logs

Description of problem:
In our automation (tier 2) I see LSM fails to migrate all VM's disks (4) with 

* engine.log:

2017-11-30 03:50:40,825+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-89) [2ae21af8] START, VmReplicateDiskStartVDSCommand(HostName = host_mixed_2, VmReplicateDiskParameters:{hostId='93b9001c-7c1a-4db1-86bc-a676ceaebcdb', vmId='08aee2d4-8ed3-4523-9bc5-b27ae16a3264', storagePoolId='4eabbc3f-aae9-404f-bde3-262d505fa6d0', srcStorageDomainId='3aa5f55a-9d9b-4420-8fc0-3a2d6d2c143c', targetStorageDomainId='7805b2e7-8640-4558-a404-b60f6ecf5b0d', imageGroupId='ebccdc23-f542-4574-8c01-5b90c8826dfa', imageId='904da173-7589-4668-ad6a-0aa7254c1f8a'}), log id: 534cc790
2017-11-30 03:50:43,448+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-89) [2ae21af8] Failed in 'VmReplicateDiskStartVDS' method
2017-11-30 03:50:43,455+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-89) [2ae21af8] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM host_mixed_2 command VmReplicateDiskStartVDS failed: Drive replication error
2017-11-30 03:50:43,456+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-89) [2ae21af8] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand' return value 'StatusOnlyReturn [status=Status [code=55, message=Drive replication error]]'
2017-11-30 03:50:43,456+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-89) [2ae21af8] HostName = host_mixed_2
2017-11-30 03:50:43,456+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-89) [2ae21af8] Command 'VmReplicateDiskStartVDSCommand(HostName = host_mixed_2, VmReplicateDiskParameters:{hostId='93b9001c-7c1a-4db1-86bc-a676ceaebcdb', vmId='08aee2d4-8ed3-4523-9bc5-b27ae16a3264', storagePoolId='4eabbc3f-aae9-404f-bde3-262d505fa6d0', srcStorageDomainId='3aa5f55a-9d9b-4420-8fc0-3a2d6d2c143c', targetStorageDomainId='7805b2e7-8640-4558-a404-b60f6ecf5b0d', imageGroupId='ebccdc23-f542-4574-8c01-5b90c8826dfa', imageId='904da173-7589-4668-ad6a-0aa7254c1f8a'})' execution failed: VDSGenericException: VDSErrorException: Failed to VmReplicateDiskStartVDS, error = Drive replication error, code = 55
2017-11-30 03:50:43,456+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-89) [2ae21af8] FINISH, VmReplicateDiskStartVDSCommand, log id: 534cc790
2017-11-30 03:50:43,457+02 ERROR [org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-89) [2ae21af8] Failed VmReplicateDiskStart (Disk 'ebccdc23-f542-4574-8c01-5b90c8826dfa' , VM '08aee2d4-8ed3-4523-9bc5-b27ae16a3264')
2017-11-30 03:50:43,458+02 INFO  [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-89) [2ae21af8] Command 'LiveMigrateDisk' id: 'cdc8f8b3-2d0b-48f6-9376-ec96cc89cd6f' failed when attempting to perform the next operation, marking as FAILED '[b57c852c-e0f7-4bc4-86c4-e18dd99ee2cb, 1a897141-0430-4076-80c6-f80941ca2632]'
2017-11-30 03:50:43,458+02 INFO  [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-89) [2ae21af8] Command 'LiveMigrateDisk' id: 'cdc8f8b3-2d0b-48f6-9376-ec96cc89cd6f' child commands '[b57c852c-e0f7-4bc4-86c4-e18dd99ee2cb, 1a897141-0430-4076-80c6-f80941ca2632]' executions were completed, status 'FAILED'
2017-11-30 03:50:44,853+02 ERROR [org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [2ae21af8] Ending command 'org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand' with failure.
2017-11-30 03:50:44,854+02 ERROR [org.ovirt.engine.core.bll.storage.lsm.LiveMigrateDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-99) [2ae21af8] Failed during live storage migration of disk 'ebccdc23-f542-4574-8c01-5b90c8826dfa' of vm '08aee2d4-8ed3-4523-9bc5-b27ae16a3264', attempting to end replication before deleting the target disk


* vdsm.log:

2017-11-30 03:50:43,405+0200 ERROR (jsonrpc/0) [virt.vm] (vmId='08aee2d4-8ed3-4523-9bc5-b27ae16a3264') Unable to start replication for vda to {'domainID': '7805b2e7-8640-4558-a404-b60f6ecf5b0d', 'volumeInfo': {'pat
h': u'storage_local_ge3_volume_1/7805b2e7-8640-4558-a404-b60f6ecf5b0d/images/ebccdc23-f542-4574-8c01-5b90c8826dfa/904da173-7589-4668-ad6a-0aa7254c1f8a', 'protocol': 'gluster', 'hosts': [{'port': '0', 'transport': '
tcp', 'name': 'gluster01.scl.lab.tlv.redhat.com'}, {'port': '0', 'transport': 'tcp', 'name': 'gluster02.scl.lab.tlv.redhat.com'}, {'port': '0', 'transport': 'tcp', 'name': 'gluster03.scl.lab.tlv.redhat.com'}]}, 'fo
rmat': 'cow', 'poolID': '4eabbc3f-aae9-404f-bde3-262d505fa6d0', 'device': 'disk', 'protocol': 'gluster', 'propagateErrors': 'off', 'diskType': 'network', 'cache': 'none', 'volumeID': '904da173-7589-4668-ad6a-0aa725
4c1f8a', 'imageID': 'ebccdc23-f542-4574-8c01-5b90c8826dfa', 'hosts': [{'port': '0', 'transport': 'tcp', 'name': 'gluster01.scl.lab.tlv.redhat.com'}], 'path': u'storage_local_ge3_volume_1/7805b2e7-8640-4558-a404-b60
f6ecf5b0d/images/ebccdc23-f542-4574-8c01-5b90c8826dfa/904da173-7589-4668-ad6a-0aa7254c1f8a', 'volumeChain': [{'domainID': '7805b2e7-8640-4558-a404-b60f6ecf5b0d', 'leaseOffset': 0, 'path': u'storage_local_ge3_volume
_1/7805b2e7-8640-4558-a404-b60f6ecf5b0d/images/ebccdc23-f542-4574-8c01-5b90c8826dfa/904da173-7589-4668-ad6a-0aa7254c1f8a', 'volumeID': u'904da173-7589-4668-ad6a-0aa7254c1f8a', 'leasePath': u'/rhev/data-center/mnt/g
lusterSD/gluster01.scl.lab.tlv.redhat.com:_storage__local__ge3__volume__1/7805b2e7-8640-4558-a404-b60f6ecf5b0d/images/ebccdc23-f542-4574-8c01-5b90c8826dfa/904da173-7589-4668-ad6a-0aa7254c1f8a.lease', 'imageID': 'eb
ccdc23-f542-4574-8c01-5b90c8826dfa'}, {'domainID': '7805b2e7-8640-4558-a404-b60f6ecf5b0d', 'leaseOffset': 0, 'path': u'storage_local_ge3_volume_1/7805b2e7-8640-4558-a404-b60f6ecf5b0d/images/ebccdc23-f542-4574-8c01-
5b90c8826dfa/fffa32af-71e6-44e7-bfbd-bd36da693b06', 'volumeID': u'fffa32af-71e6-44e7-bfbd-bd36da693b06', 'leasePath': u'/rhev/data-center/mnt/glusterSD/gluster01.scl.lab.tlv.redhat.com:_storage__local__ge3__volume_
_1/7805b2e7-8640-4558-a404-b60f6ecf5b0d/images/ebccdc23-f542-4574-8c01-5b90c8826dfa/fffa32af-71e6-44e7-bfbd-bd36da693b06.lease', 'imageID': 'ebccdc23-f542-4574-8c01-5b90c8826dfa'}, {'domainID': '7805b2e7-8640-4558-
a404-b60f6ecf5b0d', 'leaseOffset': 0, 'path': u'storage_local_ge3_volume_1/7805b2e7-8640-4558-a404-b60f6ecf5b0d/images/ebccdc23-f542-4574-8c01-5b90c8826dfa/778de876-f54d-404c-87e2-dd181fcc07e5', 'volumeID': u'778de
876-f54d-404c-87e2-dd181fcc07e5', 'leasePath': u'/rhev/data-center/mnt/glusterSD/gluster01.scl.lab.tlv.redhat.com:_storage__local__ge3__volume__1/7805b2e7-8640-4558-a404-b60f6ecf5b0d/images/ebccdc23-f542-4574-8c01-
5b90c8826dfa/778de876-f54d-404c-87e2-dd181fcc07e5.lease', 'imageID': 'ebccdc23-f542-4574-8c01-5b90c8826dfa'}]} (vm:4365)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 4359, in diskReplicateStart
    self._startDriveReplication(drive)
  File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 4495, in _startDriveReplication
    self._dom.blockCopy(drive.name, destxml, flags=flags)
  File "/usr/lib/python2.7/site-packages/vdsm/virt/virdomain.py", line 98, in f
    ret = attr(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/libvirtconnection.py", line 125, in wrapper
    ret = f(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/utils.py", line 586, in wrapper
    return func(inst, *args, **kwargs)
  File "/usr/lib64/python2.7/site-packages/libvirt.py", line 688, in blockCopy
    if ret == -1: raise libvirtError ('virDomainBlockCopy() failed', dom=self)
libvirtError: argument unsupported: non-file destination not supported yet
2017-11-30 03:50:43,443+0200 INFO  (jsonrpc/0) [api.virt] FINISH diskReplicateStart return={'status': {'message': 'Drive replication error', 'code': 55}} from=::ffff:10.35.161.183,42380, flow_id=2ae21af8 (api:52)

(libvirt.log doesn't exist)



Version-Release number of selected component (if applicable):
vdsm-4.20.8-1.el7ev.x86_64
libvirt-3.2.0-14.el7_4.4.x86_64
rhvm-4.2.0-0.5.master.el7.noarch

How reproducible:
seen once in tier 2

Steps to Reproduce:
1. Create a VM with 4 disks
2. Run VM on SPM
3. Migrate VM's disks to different storage domain

Actual results:


Expected results:


Additional info:

Comment 1 Raz Tamir 2017-11-30 09:52:53 UTC
Probably same of https://bugzilla.redhat.com/show_bug.cgi?id=1481688

Comment 2 Allon Mureinik 2017-11-30 09:58:44 UTC

*** This bug has been marked as a duplicate of bug 1481688 ***

Comment 3 Raz Tamir 2017-11-30 10:04:44 UTC
Allon,

bug 1481688 was verified on 4.1.8.

The issue still exists in 4.2 D/S.
What am I missing?

Comment 4 Allon Mureinik 2017-11-30 12:42:36 UTC
Arg, wrong bug. Thanks Raz.

LSM doesn't work with libgfapi enabled. This was disabled by bug 1518558.

*** This bug has been marked as a duplicate of bug 1518558 ***


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