Bug 981950 - [vdsm] LV closes when disk hotunplug fails
Summary: [vdsm] LV closes when disk hotunplug fails
Keywords:
Status: CLOSED DUPLICATE of bug 981962
Alias: None
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: ovirt-engine
Version: 3.3.0
Hardware: x86_64
OS: Unspecified
unspecified
high
Target Milestone: ---
: 3.3.0
Assignee: Nobody's working on this, feel free to take it
QA Contact: Haim
URL:
Whiteboard: storage
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-07-07 09:13 UTC by Elad
Modified: 2016-02-10 18:38 UTC (History)
12 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2013-07-24 09:24:30 UTC
oVirt Team: Storage
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
logs (1.37 MB, application/x-gzip)
2013-07-07 09:13 UTC, Elad
no flags Details

Description Elad 2013-07-07 09:13:17 UTC
Created attachment 769897 [details]
logs

Description of problem:
After failure in disk hotunplug, LV closes
correlates to https://bugzilla.redhat.com/show_bug.cgi?id=980914

Version-Release number of selected component (if applicable):
vdsm-4.11.0-69.gitd70e3d5.el6.x86_64

How reproducible:
100%

Steps to Reproduce:
1. on a block pool (one host): run a VM with OS and several disks
2. hotunplug to one of the VM's disks and diring that, block connectivity to storage server
3. wait until vdsm comes up from fence
4. resume connectivity to storage server
5. disk hotunplug will fail 

Actual results:
engine reports that the disk is active when in fact, LV had been closed:
 lvs:
/dev/283c1cc8-1d44-47f6-970d-5df9f4b4dedf/531d1107-acb1-46aa-b95e-3389756e2d72 -wi-a----

User cannot deactivate/remove the disk

Expected results:
vdsm should perform some kind of a roll-back, and change LV state to active-open like it was before the failure

Additional info:
logs

Comment 1 Ayal Baron 2013-07-08 22:04:18 UTC
GIGO.
If engine is asking to unplug a disk that is not plugged then obviously that will fail.
Engine should handle this error properly (state that disk is not plugged).
Please note that the logs do not correspond with the reproduction steps as there is just 0.6 seconds from start to finish of hotunplug (the only one in the log that failed), so I'm not even convinced there really is a bug here.
Can you reproduce?

To be clear, hotunplug was called with [1]:
pool:   8510a3ba-2457-4df6-9140-8257f127bca5
domain: 283c1cc8-1d44-47f6-970d-5df9f4b4dedf
image:  3c6c5a7a-afd7-4d4c-a714-6a7f4ade82d9
volume: 9154698a-9b0b-4ff5-8425-39fab29f3b49

Then this image was prepared *successfully* [2]:
prepared volume path: /rhev/data-center/8510a3ba-2457-4df6-9140-8257f127bca5/283c1cc8-1d44-47f6-970d-5df9f4b4dedf/images/3c6c5a7a-afd7-4d4c-a714-6a7f4ade82d9/9154698a-9b0b-4ff5-8425-39fab29f3b49

And the hotunplug failed because it did not find the disk in the VM [3]: Hotunplug disk failed - Disk not found

i.e. there is nothing to unplug.

[1] Thread-26005::DEBUG::2013-07-07 11:39:27,953::BindingXMLRPC::929::vds::(wrapper) client [10.35.161.52]::call vmHotunplugDisk with ({'vmId': 'f9787114-5b0c-4548-a694-0616e8c4429f', 'drive': {'iface': 'virtio', 'format': 'raw', 'optional': 'false', 'volumeID': '9154698a-9b0b-4ff5-8425-39fab29f3b49', 'imageID': '3c6c5a7a-afd7-4d4c-a714-6a7f4ade82d9', 'readonly': 'false', 'domainID': '283c1cc8-1d44-47f6-970d-5df9f4b4dedf', 'deviceId': '3c6c5a7a-afd7-4d4c-a714-6a7f4ade82d9', 'poolID': '8510a3ba-2457-4df6-9140-8257f127bca5', 'device': 'disk', 'shared': 'false', 'propagateErrors': 'off', 'type': 'disk'}},) {} flowID [46ad12e8]


[2] Thread-26006::INFO::2013-07-07 11:39:28,538::clientIF::335::vds::(prepareVolumePath) prepared volume path: /rhev/data-center/8510a3ba-2457-4df6-9140-8257f127bca5/283c1cc8-1d44-47f6-970d-5df9f4b4dedf/images/3c6c5a7a-afd7-4d4c-a714-6a7f4ade82d9/9154698a-9b0b-4ff5-8425-39fab29f3b49

[3] Thread-26006::ERROR::2013-07-07 11:39:28,538::vm::3181::vm.Vm::(hotunplugDisk) vmId=`f9787114-5b0c-4548-a694-0616e8c4429f`::Hotunplug disk failed - Disk not found: {'iface': 'virtio', 'volumeInfo': {'path': '/rhev/data-center/8510a3ba-2457-4df6-9140-8257f127bca5/283c1cc8-1d44-47f6-970d-5df9f4b4dedf/images/3c6c5a7a-afd7-4d4c-a714-6a7f4ade82d9/9154698a-9b0b-4ff5-8425-39fab29f3b49', 'volType': 'path'}, 'format': 'raw', 'optional': 'false', 'volumeID': '9154698a-9b0b-4ff5-8425-39fab29f3b49', 'imageID': '3c6c5a7a-afd7-4d4c-a714-6a7f4ade82d9', 'readonly': 'false', 'domainID': '283c1cc8-1d44-47f6-970d-5df9f4b4dedf', 'deviceId': '3c6c5a7a-afd7-4d4c-a714-6a7f4ade82d9', 'poolID': '8510a3ba-2457-4df6-9140-8257f127bca5', 'device': 'disk', 'shared': 'false', 'path': '/rhev/data-center/8510a3ba-2457-4df6-9140-8257f127bca5/283c1cc8-1d44-47f6-970d-5df9f4b4dedf/images/3c6c5a7a-afd7-4d4c-a714-6a7f4ade82d9/9154698a-9b0b-4ff5-8425-39fab29f3b49', 'propagateErrors': 'off', 'type': 'disk', 'volumeChain': [{'path': '/rhev/data-center/8510a3ba-2457-4df6-9140-8257f127bca5/283c1cc8-1d44-47f6-970d-5df9f4b4dedf/images/3c6c5a7a-afd7-4d4c-a714-6a7f4ade82d9/9154698a-9b0b-4ff5-8425-39fab29f3b49', 'domainID': '283c1cc8-1d44-47f6-970d-5df9f4b4dedf', 'vmVolInfo': {'path': '/rhev/data-center/8510a3ba-2457-4df6-9140-8257f127bca5/283c1cc8-1d44-47f6-970d-5df9f4b4dedf/images/3c6c5a7a-afd7-4d4c-a714-6a7f4ade82d9/9154698a-9b0b-4ff5-8425-39fab29f3b49', 'volType': 'path'}, 'volumeID': '9154698a-9b0b-4ff5-8425-39fab29f3b49', 'imageID': '3c6c5a7a-afd7-4d4c-a714-6a7f4ade82d9'}]}
Thread-26006::DEBUG::2013-07-07 11:39:28,538::BindingXMLRPC::936::vds::(wrapper) return vmHotunplugDisk with {'status': {'message': 'Disk not found', 'code': 46}}

Comment 2 Elad 2013-07-09 08:39:55 UTC
(In reply to Ayal Baron from comment #1)
> GIGO.
> If engine is asking to unplug a disk that is not plugged then obviously that
> will fail.

This is not the case. The disk is plugged to the VM, and the lv is active


> Engine should handle this error properly (state that disk is not plugged).
> Please note that the logs do not correspond with the reproduction steps as
> there is just 0.6 seconds from start to finish of hotunplug (the only one in
> the log that failed), so I'm not even convinced there really is a bug here.
> Can you reproduce?

Yes,

Steps: 
1) plugged a disk to VM
2) unplugged the disk and during that, restart vdsm service.

Here are the results:

Disk is plugged:

LV is active:

/dev/283c1cc8-1d44-47f6-970d-5df9f4b4dedf/11b2d5f4-63fa-4948-ae92-294624ac012f -wi-ao---

unplug to disk with failure:

Thread-466::INFO::2013-07-09 11:34:12,958::logUtils::44::dispatcher::(wrapper) Run and protect: prepareImage(sdUUID='283c1cc8-1d44-47f6-970d-5df9f4b4dedf', spUUID='8510a3ba-2457-4df6-9140-8257f127bca5', imgUUID='9417e7d2-b13c-44c5-952a-e53d8006ddde', volUUID='11b2d5f4-63fa-4948-ae92-294624ac012f')


LV state:

/dev/283c1cc8-1d44-47f6-970d-5df9f4b4dedf/11b2d5f4-63fa-4948-ae92-294624ac012f -wi-a----

Engine reports the disk as active.
After that, tried to unplug again the same disk:

Thread-171::ERROR::2013-07-09 11:38:32,316::vm::3181::vm.Vm::(hotunplugDisk) vmId=`3cadeaf7-5406-473c-80e6-90c889269978`::Hotunplug disk failed - Disk not found: {'iface': 'virtio', 'volumeInfo': {'path': '/rhev/d
ata-center/8510a3ba-2457-4df6-9140-8257f127bca5/283c1cc8-1d44-47f6-970d-5df9f4b4dedf/images/9417e7d2-b13c-44c5-952a-e53d8006ddde/11b2d5f4-63fa-4948-ae92-294624ac012f', 'volType': 'path'}, 'format': 'raw', 'optiona
l': 'false', 'volumeID': '11b2d5f4-63fa-4948-ae92-294624ac012f', 'imageID': '9417e7d2-b13c-44c5-952a-e53d8006ddde', 'readonly': 'false', 'domainID': '283c1cc8-1d44-47f6-970d-5df9f4b4dedf', 'deviceId': '9417e7d2-b1
3c-44c5-952a-e53d8006ddde', 'poolID': '8510a3ba-2457-4df6-9140-8257f127bca5', 'device': 'disk', 'shared': 'false', 'path': '/rhev/data-center/8510a3ba-2457-4df6-9140-8257f127bca5/283c1cc8-1d44-47f6-970d-5df9f4b4de
df/images/9417e7d2-b13c-44c5-952a-e53d8006ddde/11b2d5f4-63fa-4948-ae92-294624ac012f', 'propagateErrors': 'off', 'type': 'disk', 'volumeChain': [{'path': '/rhev/data-center/8510a3ba-2457-4df6-9140-8257f127bca5/283c
1cc8-1d44-47f6-970d-5df9f4b4dedf/images/9417e7d2-b13c-44c5-952a-e53d8006ddde/11b2d5f4-63fa-4948-ae92-294624ac012f', 'domainID': '283c1cc8-1d44-47f6-970d-5df9f4b4dedf', 'vmVolInfo': {'path': '/rhev/data-center/8510
a3ba-2457-4df6-9140-8257f127bca5/283c1cc8-1d44-47f6-970d-5df9f4b4dedf/images/9417e7d2-b13c-44c5-952a-e53d8006ddde/11b2d5f4-63fa-4948-ae92-294624ac012f', 'volType': 'path'}, 'volumeID': '11b2d5f4-63fa-4948-ae92-294
624ac012f', 'imageID': '9417e7d2-b13c-44c5-952a-e53d8006ddde'}]}

Comment 3 Ayal Baron 2013-07-10 09:27:30 UTC
Active LV is not indication the the disk is plugged, it's just an indication that the LV was not deactivated.
I believe this is a dup of 981962


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