Bugzilla will be upgraded to version 5.0. The upgrade date is tentatively scheduled for 2 December 2018, pending final testing and feedback.
Bug 1434105 - Live storage migration failed
Live storage migration failed
Status: CLOSED WONTFIX
Product: ovirt-engine
Classification: oVirt
Component: BLL.Storage (Show other bugs)
4.1.1.4
x86_64 Linux
unspecified Severity high (vote)
: ovirt-4.3.0
: ---
Assigned To: Benny Zlotnik
SATHEESARAN
: Reopened
: 1440198 (view as bug list)
Depends On: 1312909
Blocks: Gluster-HC-2 1433896
  Show dependency treegraph
 
Reported: 2017-03-20 13:49 EDT by SATHEESARAN
Modified: 2018-07-02 04:51 EDT (History)
7 users (show)

See Also:
Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2018-07-02 04:51:29 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: Storage
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---
amureini: ovirt‑4.3?
sasundar: planning_ack?
sasundar: devel_ack?
sasundar: testing_ack?


Attachments (Terms of Use)
compressed archived vdsm.log (586.60 KB, application/x-gzip)
2017-03-20 14:10 EDT, SATHEESARAN
no flags Details
compressed archived engine.log (341.94 KB, application/x-gzip)
2017-03-20 14:11 EDT, SATHEESARAN
no flags Details
vdsm.log from host6 which ran the VM (644.23 KB, application/x-xz)
2017-03-21 06:32 EDT, SATHEESARAN
no flags Details

  None (edit)
Description SATHEESARAN 2017-03-20 13:49:48 EDT
Description of problem:
------------------------
I have 2 glusterfs data domain backed with sharded replica 3 gluster volumes ( Domain_1 and domain_3 ). I had a VM with its disk on Domain_1. When tried to move the disk ( with the VM active ), from one domain ( Domain_1 ) to another domain ( Domain_3), I observed an error while performing live storage migration

Version-Release number of selected component (if applicable):
--------------------------------------------------------------
RHV-4.1.1-5

How reproducible:
-----------------
Always

Steps to Reproduce:
--------------------
1. Create 2 storage glusterfs data domain backed with sharded replica 3 gluster volumes
2. Create a VM with its root disk from domain_1
3. Install the VM with OS and perform some I/O inside the VM
4. Migrate the disk from one domain to another

Actual results:
---------------
live storage migration failed
The events says this - "User admin@internal-authz have failed to move disk set2_appvm51_Disk1 to domain Domain_3."

Expected results:
------------------
Disk should get migrated to another domain successfully
Comment 1 SATHEESARAN 2017-03-20 14:10 EDT
Created attachment 1264818 [details]
compressed archived vdsm.log
Comment 2 SATHEESARAN 2017-03-20 14:11 EDT
Created attachment 1264819 [details]
compressed archived engine.log
Comment 3 SATHEESARAN 2017-03-21 06:31:45 EDT
I could see that the VM was running on host6 and I see the following errors with vdsm.log on host6

# xzgrep ERROR /var/log/vdsm/vdsm.log.1.xz 
2017-03-20 08:54:51,213+0530 ERROR (monitor/1025388) [storage.Monitor] Error checking domain 10253882-040a-4f28-a6b6-3c2015fb7594 (monitor:426)
2017-03-20 08:54:51,250+0530 ERROR (check/loop) [storage.Monitor] Error checking path /rhev/data-center/mnt/glusterSD/10.70.36.73:_engine/10253882-040a-4f28-a6b6-3c2015fb7594/dom_md/metadata (monitor:485)
2017-03-20 08:54:55,631+0530 ERROR (check/loop) [storage.Monitor] Error checking path /rhev/data-center/mnt/glusterSD/10.70.36.73:_engine/10253882-040a-4f28-a6b6-3c2015fb7594/dom_md/metadata (monitor:485)
2017-03-20 08:55:01,224+0530 ERROR (monitor/1025388) [storage.Monitor] Error checking domain 10253882-040a-4f28-a6b6-3c2015fb7594 (monitor:426)
2017-03-20 18:58:52,706+0530 ERROR (jsonrpc/3) [virt.vm] (vmId='226433a3-4a34-46d6-91b6-2a679c394ec9') Replication job unfinished (drive: 'sda', srcDisk: {u'device': u'disk', u'poolID': u'00000001-0001-0001-0001-000000000311', u'volumeID': u'80c9f20c-3dd7-466b-808d-62337f6cc153', u'domainID': u'4828a460-1825-4ba9-b456-64afad078198', u'imageID': u'da3c126e-d848-4b2e-b1fe-eb9c4cf6b04d'}, job: {'end': 5059117056L, 'bandwidth': 0L, 'type': 2, 'cur': 5040308224L}) (vm:3753)
2017-03-20 18:58:53,990+0530 ERROR (jsonrpc/1) [virt.vm] (vmId='226433a3-4a34-46d6-91b6-2a679c394ec9') Replication job unfinished (drive: 'sda', srcDisk: {u'device': u'disk', u'poolID': u'00000001-0001-0001-0001-000000000311', u'volumeID': u'80c9f20c-3dd7-466b-808d-62337f6cc153', u'domainID': u'4828a460-1825-4ba9-b456-64afad078198', u'imageID': u'da3c126e-d848-4b2e-b1fe-eb9c4cf6b04d'}, job: {'end': 5062262784L, 'bandwidth': 0L, 'type': 2, 'cur': 5061869568L}) (vm:3753)
2017-03-20 18:59:00,186+0530 ERROR (jsonrpc/0) [virt.vm] (vmId='226433a3-4a34-46d6-91b6-2a679c394ec9') Live merge failed (job: 140f8b05-293f-4347-a0d1-fcde17df1e38) (vm:4798)
Comment 4 SATHEESARAN 2017-03-21 06:32 EDT
Created attachment 1265006 [details]
vdsm.log from host6 which ran the VM
Comment 5 Adam Litke 2017-03-21 10:23:07 EDT
Seeing the following exception in the log.  This seems to indicate a problem on the gluster side.  Can you check to make sure your gluster storage wasn't reporting errors?  I am not really sure where to look for that but something has caused the gluster mount to become disconnected.

2017-03-20 08:54:55,631+0530 ERROR (check/loop) [storage.Monitor] Error checking path /rhev/data-center/mnt/glusterSD/10.70.36.73:_engine/10253882-040a-4f28-a6b6-3c2015fb7594/dom_md/metadata (monitor:485)
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/monitor.py", line 483, in _pathChecked
    delay = result.delay()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/check.py", line 368, in delay
    raise exception.MiscFileReadException(self.path, self.rc, self.err)
MiscFileReadException: Internal file read failure: (u'/rhev/data-center/mnt/glusterSD/10.70.36.73:_engine/10253882-040a-4f28-a6b6-3c2015fb7594/dom_md/metadata', 1, bytearray(b"/usr/bin/dd: failed to open \'/rhev/data-center/mnt/glusterSD/10.70.36.73:_engine/10253882-040a-4f28-a6b6-3c2015fb7594/dom_md/metadata\': Transport endpoint is not connected\n"))
Comment 6 Sahina Bose 2017-03-22 01:15:13 EDT
(In reply to Adam Litke from comment #5)
> Seeing the following exception in the log.  This seems to indicate a problem
> on the gluster side.  Can you check to make sure your gluster storage wasn't
> reporting errors?  I am not really sure where to look for that but something
> has caused the gluster mount to become disconnected.
> 
> 2017-03-20 08:54:55,631+0530 ERROR (check/loop) [storage.Monitor] Error
> checking path
> /rhev/data-center/mnt/glusterSD/10.70.36.73:_engine/10253882-040a-4f28-a6b6-
> 3c2015fb7594/dom_md/metadata (monitor:485)
> Traceback (most recent call last):
>   File "/usr/share/vdsm/storage/monitor.py", line 483, in _pathChecked
>     delay = result.delay()
>   File "/usr/lib/python2.7/site-packages/vdsm/storage/check.py", line 368,
> in delay
>     raise exception.MiscFileReadException(self.path, self.rc, self.err)
> MiscFileReadException: Internal file read failure:
> (u'/rhev/data-center/mnt/glusterSD/10.70.36.73:_engine/10253882-040a-4f28-
> a6b6-3c2015fb7594/dom_md/metadata', 1, bytearray(b"/usr/bin/dd: failed to
> open
> \'/rhev/data-center/mnt/glusterSD/10.70.36.73:_engine/10253882-040a-4f28-
> a6b6-3c2015fb7594/dom_md/metadata\': Transport endpoint is not connected\n"))

This error is from the HE gluster volume (HE storage domain). Does that affect the live migration on the other storage domains?
Comment 7 Adam Litke 2017-03-28 14:47:53 EDT
Sahina you are correct.  Those monitoring errors are unrelated.
Comment 8 Adam Litke 2017-03-28 15:12:02 EDT
After further analyzing the engine logs I am concerned that there could be a problem with the engine flow for LiveMigrateDiskCommand.  This command performs the following actions in sequence:

1. CreateImagePlaceholder - Clone the disk structure from the source domain to the destination domain.

2. VmReplicateDiskStart - Instruct qemu to replicate the active volume of the source disk to the active layer of the destination disk and mirror all writes to both the source and destination disks.  This operation is a two phase process.  First, data is copied from the source to the destination.  Once this converges, subsequent writes are sent to both the source and destination simultaneously. 

3. SyncImageGroupData - Sync the contents of source disk's internal volumes to the corresponding destination disk volumes.

--- wait for SyncImageGroupData to complete ---

4. VmReplicateDiskFinish - Instruct qemu to pivot to the destination disk and suspend write mirroring on the source disk.  This only works if step 2 has converged to the mirroring phase and step 3 is also complete.


What appears to be happening in the attached logs is that due to high I/O, step 2  is unable to converge before step 4 is executed.  This is usually not a problem since step 3 can take a relatively long time and with low I/O step 2 will converge quickly.

The following log entry confirms that step 2 did not converge (cur != end):

2017-03-20 18:58:52,706+0530 ERROR (jsonrpc/3) [virt.vm] (vmId='226433a3-4a34-46d6-91b6-2a679c394ec9') Replication job unfinished (drive: 'sda', srcDisk: {u'device': u'disk', u'poolID': u'00000001-0001-0001-0001-000000000311', u'volumeID': u'80c9f20c-3dd7-466b-808d-62337f6cc153', u'domainID': u'4828a460-1825-4ba9-b456-64afad078198', u'imageID': u'da3c126e-d848-4b2e-b1fe-eb9c4cf6b04d'}, job: {'end': 5059117056L, 'bandwidth': 0L, 'type': 2, 'cur': 5040308224L}) (vm:3753)


I believe the engine needs to add an additional step before VmReplicateDiskFinish which checks that the replication has converged.  Alternatively, we could wait and retry VmReplicateDiskFinish a number of times before failing the entire operation.
Comment 9 Adam Litke 2017-03-28 15:36:00 EDT
I just talked to Liron and this is a known issue and already has an assigned bug.

*** This bug has been marked as a duplicate of bug 1312909 ***
Comment 12 Sahina Bose 2017-04-17 03:11:57 EDT
*** Bug 1440198 has been marked as a duplicate of this bug. ***
Comment 14 Tal Nisan 2018-07-02 04:51:29 EDT
The whole LSM flow was changed, please reopen if the issue still exists.

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