Bug 1283287 - Failed to hot unplug disk in VDSM which runs Python <= 2.7
Failed to hot unplug disk in VDSM which runs Python <= 2.7
Status: CLOSED CURRENTRELEASE
Product: vdsm
Classification: oVirt
Component: General (Show other bugs)
4.16.29
Unspecified Unspecified
urgent Severity urgent (vote)
: ovirt-3.5.6
: 4.16.30
Assigned To: Amit Aviram
Raz Tamir
storage
: Automation, Regression
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2015-11-18 10:36 EST by Raz Tamir
Modified: 2016-02-10 11:41 EST (History)
10 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2015-12-22 08:26:05 EST
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‑3.5.z+
rule-engine: blocker+
ylavi: planning_ack+
tnisan: devel_ack+
acanan: testing_ack+


Attachments (Terms of Use)
engine log (3.97 MB, text/plain)
2015-11-18 10:37 EST, Raz Tamir
no flags Details
vdsm rhevh 6.7 (10.00 MB, text/plain)
2015-11-18 10:41 EST, Raz Tamir
no flags Details
vdsm log rhel 6.7 (7.42 MB, text/plain)
2015-11-18 10:44 EST, Raz Tamir
no flags Details
rpm -qa (18.73 KB, text/plain)
2015-11-19 09:17 EST, Raz Tamir
no flags Details


External Trackers
Tracker ID Priority Status Summary Last Updated
oVirt gerrit 48908 master ABANDONED hotunplug: support python < 2.7 Never
oVirt gerrit 48916 ovirt-3.5 MERGED hotunplug: support python 2.6 Never
oVirt gerrit 49007 ovirt-3.5.6 MERGED hotunplug: support python 2.6 Never

  None (edit)
Description Raz Tamir 2015-11-18 10:36:48 EST
Description of problem:
When trying to hotunplug disk from vm with OS installed, I get the error :Failed to unplug disk X"
Occurs only on 3.5 environment

From vdsm log RHEL6.7:

Thread-128617::DEBUG::2015-11-18 17:29:24,099::libvirtconnection::151::root::(wrapper) Unknown libvirterror: ecode: 8 edom: 10 level: 2 message: invalid argument: invalid path: vdb
Thread-128617::ERROR::2015-11-18 17:29:24,099::sampling::488::vm.Vm::(collect) vmId=`091cb939-cb03-441d-b8d1-f241a10df67f`::Stats function failed: <AdvancedStatsFunction _sampleDisk at 0x1ef96f8>
Traceback (most recent call last):
  File "/usr/share/vdsm/virt/sampling.py", line 484, in collect
    statsFunction()
  File "/usr/share/vdsm/virt/sampling.py", line 359, in __call__
    retValue = self._function(*args, **kwargs)
  File "/usr/share/vdsm/virt/vm.py", line 326, in _sampleDisk
    diskSamples[vmDrive.name] = self._vm._dom.blockStats(vmDrive.name)
  File "/usr/share/vdsm/virt/vm.py", line 703, in f
    ret = attr(*args, **kwargs)
  File "/usr/lib/python2.6/site-packages/vdsm/libvirtconnection.py", line 119, in wrapper
    ret = f(*args, **kwargs)
  File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1881, in blockStats
    if ret is None: raise libvirtError ('virDomainBlockStats() failed', dom=self)
libvirtError: invalid argument: invalid path: vdb
Thread-128617::DEBUG::2015-11-18 17:29:24,125::libvirtconnection::151::root::(wrapper) Unknown libvirterror: ecode: 8 edom: 10 level: 2 message: invalid argument: invalid path: vdb
Thread-128617::ERROR::2015-11-18 17:29:24,125::sampling::488::vm.Vm::(collect) vmId=`091cb939-cb03-441d-b8d1-f241a10df67f`::Stats function failed: <AdvancedStatsFunction _sampleDiskLatency at 0x1efc5b0>
Traceback (most recent call last):
  File "/usr/share/vdsm/virt/sampling.py", line 484, in collect
    statsFunction()
  File "/usr/share/vdsm/virt/sampling.py", line 359, in __call__
    retValue = self._function(*args, **kwargs)
  File "/usr/share/vdsm/virt/vm.py", line 341, in _sampleDiskLatency
    vmDrive.name, flags=libvirt.VIR_TYPED_PARAM_STRING_OKAY)
  File "/usr/share/vdsm/virt/vm.py", line 703, in f
    ret = attr(*args, **kwargs)
  File "/usr/lib/python2.6/site-packages/vdsm/libvirtconnection.py", line 119, in wrapper
    ret = f(*args, **kwargs)
  File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1887, in blockStatsFlags
    if ret is None: raise libvirtError ('virDomainBlockStatsFlags() failed', dom=self)
libvirtError: invalid argument: invalid path: vdb
Thread-128617::DEBUG::2015-11-18 17:29:24,134::libvirtconnection::151::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present

From vdsm log RHEVH-6.7:

Thread-6504::DEBUG::2015-11-18 15:22:53,514::task::993::Storage.TaskManager.Task::(_decref) Task=`bd9717b9-0cce-4e4a-911e-1d6cb26f7ac5`::ref 0 aborting False
Thread-6504::DEBUG::2015-11-18 15:22:53,532::libvirtconnection::151::root::(wrapper) Unknown libvirterror: ecode: 8 edom: 10 level: 2 message: invalid argument: invalid path: vdb
Thread-6504::ERROR::2015-11-18 15:22:53,532::sampling::488::vm.Vm::(collect) vmId=`091cb939-cb03-441d-b8d1-f241a10df67f`::Stats function failed: <AdvancedStatsFunction _sampleDisk at 0x2bf33e8>
Traceback (most recent call last):
  File "/usr/share/vdsm/virt/sampling.py", line 484, in collect
  File "/usr/share/vdsm/virt/sampling.py", line 359, in __call__
  File "/usr/share/vdsm/virt/vm.py", line 326, in _sampleDisk
  File "/usr/share/vdsm/virt/vm.py", line 703, in f
  File "/usr/lib/python2.6/site-packages/vdsm/libvirtconnection.py", line 119, in wrapper
  File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1881, in blockStats
libvirtError: invalid argument: invalid path: vdb
Thread-6504::DEBUG::2015-11-18 15:22:53,555::libvirtconnection::151::root::(wrapper) Unknown libvirterror: ecode: 8 edom: 10 level: 2 message: invalid argument: invalid path: vdb
Thread-6504::ERROR::2015-11-18 15:22:53,555::sampling::488::vm.Vm::(collect) vmId=`091cb939-cb03-441d-b8d1-f241a10df67f`::Stats function failed: <AdvancedStatsFunction _sampleDiskLatency at 0x2bf22f0>
Traceback (most recent call last):
  File "/usr/share/vdsm/virt/sampling.py", line 484, in collect
  File "/usr/share/vdsm/virt/sampling.py", line 359, in __call__
  File "/usr/share/vdsm/virt/vm.py", line 341, in _sampleDiskLatency
  File "/usr/share/vdsm/virt/vm.py", line 703, in f
  File "/usr/lib/python2.6/site-packages/vdsm/libvirtconnection.py", line 119, in wrapper
  File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1887, in blockStatsFlags
libvirtError: invalid argument: invalid path: vdb
Thread-6504::DEBUG::2015-11-18 15:22:53,566::libvirtconnection::151::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present

From engine.log:

Thread-6504::DEBUG::2015-11-18 15:22:53,514::task::993::Storage.TaskManager.Task::(_decref) Task=`bd9717b9-0cce-4e4a-911e-1d6cb26f7ac5`::ref 0 aborting False
Thread-6504::DEBUG::2015-11-18 15:22:53,532::libvirtconnection::151::root::(wrapper) Unknown libvirterror: ecode: 8 edom: 10 level: 2 message: invalid argument: invalid path: vdb
Thread-6504::ERROR::2015-11-18 15:22:53,532::sampling::488::vm.Vm::(collect) vmId=`091cb939-cb03-441d-b8d1-f241a10df67f`::Stats function failed: <AdvancedStatsFunction _sampleDisk at 0x2bf33e8>
Traceback (most recent call last):
  File "/usr/share/vdsm/virt/sampling.py", line 484, in collect
  File "/usr/share/vdsm/virt/sampling.py", line 359, in __call__
  File "/usr/share/vdsm/virt/vm.py", line 326, in _sampleDisk
  File "/usr/share/vdsm/virt/vm.py", line 703, in f
  File "/usr/lib/python2.6/site-packages/vdsm/libvirtconnection.py", line 119, in wrapper
  File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1881, in blockStats
libvirtError: invalid argument: invalid path: vdb
Thread-6504::DEBUG::2015-11-18 15:22:53,555::libvirtconnection::151::root::(wrapper) Unknown libvirterror: ecode: 8 edom: 10 level: 2 message: invalid argument: invalid path: vdb
Thread-6504::ERROR::2015-11-18 15:22:53,555::sampling::488::vm.Vm::(collect) vmId=`091cb939-cb03-441d-b8d1-f241a10df67f`::Stats function failed: <AdvancedStatsFunction _sampleDiskLatency at 0x2bf22f0>
Traceback (most recent call last):
  File "/usr/share/vdsm/virt/sampling.py", line 484, in collect
  File "/usr/share/vdsm/virt/sampling.py", line 359, in __call__
  File "/usr/share/vdsm/virt/vm.py", line 341, in _sampleDiskLatency
  File "/usr/share/vdsm/virt/vm.py", line 703, in f
  File "/usr/lib/python2.6/site-packages/vdsm/libvirtconnection.py", line 119, in wrapper
  File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1887, in blockStatsFlags
libvirtError: invalid argument: invalid path: vdb
Thread-6504::DEBUG::2015-11-18 15:22:53,566::libvirtconnection::151::root::(wrapper) Unknown libvirterror: ecode: 80 edom: 20 level: 2 message: metadata not found: Requested metadata element is not present



Version-Release number of selected component (if applicable):
vdsm-4.16.29-1.el6ev.x86_64
libvirt-0.10.2-54.el6_7.2.x86_64
rhevm-3.5.6.2-0.1.el6ev.noarch


How reproducible:
90%

Steps to Reproduce:
1. vm + 1 bootable disk
2. Add new sparse disk (2GB)
3. Start the vm and hot unplug the second disk

Actual results:
Described above

Expected results:
Hot unplug should work when there is guest on the vm

Additional info:
Comment 1 Raz Tamir 2015-11-18 10:37 EST
Created attachment 1096130 [details]
engine log
Comment 2 Raz Tamir 2015-11-18 10:41 EST
Created attachment 1096131 [details]
vdsm rhevh 6.7
Comment 3 Raz Tamir 2015-11-18 10:44 EST
Created attachment 1096132 [details]
vdsm log rhel 6.7
Comment 6 Dan Kenigsberg 2015-11-19 08:29:46 EST
I think that a more relevant vdsm.log excerpt is

Thread-6596::DEBUG::2015-11-18 15:17:33,107::vm::4083::vm.Vm::(hotunplugDisk) vmId=`091cb939-cb03-441d-b8d1-f241a10df67f`::Hotunplug disk xml: <disk device="disk" snapshot="no" type="file">
	<address bus="0x00" domain="0x0000" function="0x0" slot="0x09" type="pci"/>
	<source file="/rhev/data-center/3c2f6b8c-8459-48f9-b578-ddab8133d2fb/8d4a21f6-f441-4b67-bda7-c2a31040a026/images/d284d796-ef9d-441e-add6-7b680d1ed55f/07720411-e1bf-4cf1-a34e-395304cd0477"/>
	<target bus="virtio" dev="vdb"/>
	<serial>d284d796-ef9d-441e-add6-7b680d1ed55f</serial>
	<driver cache="none" error_policy="stop" io="threads" name="qemu" type="raw"/>
</disk>

Thread-6596::DEBUG::2015-11-18 15:17:33,154::vm::4141::vm.Vm::(_waitForDriveRemoval) vmId=`091cb939-cb03-441d-b8d1-f241a10df67f`::Waiting for hotunplug to finish
Thread-6596::ERROR::2015-11-18 15:17:33,161::__init__::506::jsonrpc.JsonRpcServer::(_serveRequest) Internal server error
Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/yajsonrpc/__init__.py", line 501, in _serveRequest
  File "/usr/share/vdsm/rpc/Bridge.py", line 271, in _dynamicMethod
  File "/usr/share/vdsm/API.py", line 467, in hotunplugDisk
  File "/usr/share/vdsm/virt/vm.py", line 4089, in hotunplugDisk
  File "/usr/share/vdsm/virt/vm.py", line 4145, in _waitForDriveRemoval
  File "/usr/share/vdsm/virt/vm.py", line 4155, in _isDriveAttached
  File "/usr/lib64/python2.6/xml/etree/ElementTree.py", line 355, in findall
  File "/usr/lib64/python2.6/xml/etree/ElementPath.py", line 198, in findall
  File "/usr/lib64/python2.6/xml/etree/ElementPath.py", line 176, in _compile
  File "/usr/lib64/python2.6/xml/etree/ElementPath.py", line 93, in __init__
SyntaxError: expected path separator ([)
Comment 7 Amit Aviram 2015-11-19 09:09:06 EST
ratamir, can you please provide the "rpm -qa" output in your host?
(Dan, thanks)
Comment 8 Raz Tamir 2015-11-19 09:17 EST
Created attachment 1096693 [details]
rpm -qa

Attached 'rpm -qa' output
Comment 9 Amit Aviram 2015-11-19 10:00:25 EST
Thank you ratamir.
The problem here is that the code in "_isDriveAttached" in VDSM relies on python version >= 2.7, and the python version your host has is python-2.6.6-64.el6.x86_64..

Allon, We can demand a >= 2.7 version of python in vdsm spec- or implement this part differently. what do you think?
Comment 10 Amit Aviram 2015-11-22 03:16:16 EST
We will fix the patch to be supported by python with a version lesser than 2.7
Comment 12 Raz Tamir 2015-11-25 02:24:44 EST
Verified on vt18.3
Comment 13 Raz Tamir 2015-11-25 04:14:58 EST
vdsm version - vdsm-4.16.30-1.el6ev.x86_64
Comment 14 Sandro Bonazzola 2015-12-22 08:26:05 EST
oVirt 3.5.6 has been released and the bz verified, moving to closed current release.

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