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
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}}
(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'}]}
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