Created attachment 638063 [details] Fixed clientIF.py file Description of problem: clientIF.py throws an error about volPath being referenced before assignment when I create a vm through foreman. Version-Release number of selected component (if applicable): Latest stable ovirt code was used. 3.1 How reproducible: Every time I kicked off a vm build I received the same error message and the vm would fail to build. Foreman would then roll back the creation. Steps to Reproduce: 1. Install the latest foreman packages on a server 2. Connect foreman to your ovirt cluster 3. Initiate a vm build. Actual results: VM would fail to power on and throw an error message saying. volPath in clientIF.py referenced before assignment. Expected results: Vm would power on successfully. Additional info: My fix was to add volPath = None to line #220 in clientIF.py I have attached the fixed file. I will work on submitting a patch tomorrow when I get in to work.
Would you attach an excerpt of your vdsm.log, from vmCreate to the relevant backtrace? I'm not sure that assigning a default None value is the best approach, so I'd like to understand which drive specification was passed to prepareVolumePath(). P.S. does forman interact with vdsm directly, or via oVirt-Engine?
AFAIK this happens because of wrong vm status retuns from ovirt via API. e.g. when creating a new vm, the vm status is ready, while the disks are still being created.
Sure no problem. Here's my log file I saw on the ovirt node when I tried to kick off a vm build in foreman: Thread-157549::DEBUG::2012-11-02 13:59:21,666::resourceManager::558::ResourceManager::(releaseResour ce) Resource 'Storage.7d3aeead-4140-4a87-a648-1b4ab1009b3e' is free, finding out if anyone is waitin g for it. Thread-157549::DEBUG::2012-11-02 13:59:21,666::resourceManager::565::ResourceManager::(releaseResour ce) No one is waiting for resource 'Storage.7d3aeead-4140-4a87-a648-1b4ab1009b3e', Clearing records. Thread-157549::DEBUG::2012-11-02 13:59:21,666::task::978::TaskManager.Task::(_decref) Task=`0908296e -8beb-415c-9b0d-e214eb83f5b5`::ref 0 aborting False Thread-157549::DEBUG::2012-11-02 13:59:21,666::vm::580::vm.Vm::(_startUnderlyingVm) vmId=`e5dfe2ac-8 6e5-4f64-ac50-4977a624a9d5`::_ongoingCreations released Thread-157549::ERROR::2012-11-02 13:59:21,666::vm::604::vm.Vm::(_startUnderlyingVm) vmId=`e5dfe2ac-8 6e5-4f64-ac50-4977a624a9d5`::The vm start process failed Traceback (most recent call last): File "/usr/share/vdsm/vm.py", line 570, in _startUnderlyingVm self._run() File "/usr/share/vdsm/libvirtvm.py", line 1290, in _run self.preparePaths(devices[vm.DISK_DEVICES]) File "/usr/share/vdsm/vm.py", line 616, in preparePaths drive['path'] = self.cif.prepareVolumePath(drive, self.id) File "/usr/share/vdsm/clientIF.py", line 274, in prepareVolumePath self.log.info("prepared volume path: %s", volPath) UnboundLocalError: local variable 'volPath' referenced before assignment Thread-157549::DEBUG::2012-11-02 13:59:21,670::vm::920::vm.Vm::(setDownStatus) vmId=`e5dfe2ac-86e5-4f64-ac50-4977a624a9d5`::Changed state to Down: local variable 'volPath' referenced before assignment Thread-157551::DEBUG::2012-11-02 13:59:22,551::task::588::TaskManager.Task::(_updateState) Task=`83bc84dd-c719-4eff-b9b8-d468ad739968`::moving from state init -> state preparing
I'm still missing the most important part of the log, which is the line with the VM parameters passed from Engine to vdsm (it should be a bit higher up, marked with vmCreate).
Found it. Thread-157548::DEBUG::2012-11-02 13:59:21,656::BindingXMLRPC::865::vds::(wrapper) return vmCreate wi th {'status': {'message': 'Done', 'code': 0}, 'vmList': {'status': 'WaitForLaunch', 'acpiEnable': 't rue', 'emulatedMachine': 'pc-0.14', 'tabletEnable': 'true', 'pid': '0', 'timeOffset': '0', 'displayP ort': '-1', 'displaySecurePort': '-1', 'spiceSslCipherSuite': 'DEFAULT', 'cpuType': 'Conroe', 'custo m': {}, 'clientIp': '', 'nicModel': 'rtl8139,pv', 'keyboardLayout': 'en-us', 'kvmEnable': 'true', 'p itReinjection': 'false', 'vmId': 'e5dfe2ac-86e5-4f64-ac50-4977a624a9d5', 'transparentHugePages': 'tr ue', 'devices': [{'device': 'qxl', 'specParams': {'vram': '65536'}, 'type': 'video', 'deviceId': 'f9 fc0fcb-06e7-430b-bddb-9568e6a845bf'}, {'index': '2', 'iface': 'ide', 'specParams': {'path': ''}, 're adonly': 'true', 'deviceId': '29d0065a-69de-41a1-8904-eca5d4d25a2e', 'device': 'cdrom', 'type': 'dis k'}, {'index': 0, 'iface': 'virtio', 'format': 'cow', 'bootOrder': '2', 'volumeID': '04dc394b-bd64-4 15d-a763-4b4dd749d131', 'imageID': 'f6d6984f-b3b9-4653-ba2e-727b15ca3d35', 'specParams': {}, 'readon ly': 'false', 'domainID': '7d3aeead-4140-4a87-a648-1b4ab1009b3e', 'optional': 'false', 'deviceId': ' f6d6984f-b3b9-4653-ba2e-727b15ca3d35', 'poolID': '4c350671-7fac-4170-b901-9794b876ec73', 'device': ' disk', 'shared': 'false', 'propagateErrors': 'off', 'type': 'disk'}, {'nicModel': 'pv', 'macAddr': ' 00:1a:4a:c0:03:19', 'network': '54', 'bootOrder': '1', 'specParams': {}, 'deviceId': '7f75664d-7c7e- 4c61-88ee-5b76e058ab88', 'device': 'bridge', 'type': 'interface'}, {'device': 'memballoon', 'specPar ams': {'model': 'virtio'}, 'type': 'balloon', 'deviceId': '259ebf8f-5cf4-4345-96da-bc97133f0151'}], 'smp': '2', 'vmType': 'kvm', 'memSize': 1024, 'displayIp': '0', 'spiceSecureChannels': 'smain,sinput s,scursor,splayback,srecord,sdisplay', 'smpCoresPerSocket': '2', 'vmName': 'foreman-test1-ovirt-csc- local', 'display': 'vnc', 'nice': '0'}} Thread-157549::INFO::2012-11-02 13:59:21,657::libvirtvm::1285::vm.Vm::(_run) vmId=`e5dfe2ac-86e5-4f6 4-ac50-4977a624a9d5`::VM wrapper has started Thread-157549::DEBUG::2012-11-02 13:59:21,658::task::588::TaskManager.Task::(_updateState) Task=`090 8296e-8beb-415c-9b0d-e214eb83f5b5`::moving from state init -> state preparing
Would you please attach the whole log, from vmCreate to the exception? I find it hard to understand how did we manage not to set volPath (and how presetting it to None helps anybody. Does you patch enables the VM to boot?)
Yes setting it to None allows the vm's to boot. When it is not set, I get that error message and ovirt will refuse to power on the virtual machine. I will have the log attached shortly.
Created attachment 640072 [details] vdsm log file
This bug is about VM payload and has nothing to do with storage.
Related to https://bugzilla.redhat.com/show_bug.cgi?id=843387 Invalid inputs: 'specParams': {} 'specParams': {'path': ''} Anyway we should not railse outbound variable. (This bug was foresighted a long time ago): http://gerrit.ovirt.org/#/c/6803/3
Same problem here using python sdk api, with 3.1 under fedora-17 x64. Simply doing (with a being an API object): a.templates.add(params.Template(name='test', vm=params.VM(id=a.vms.get(name='no-so').get_id()), cluster=params.Cluster(id=a.clusters.get(name='Iscsi_Cluster').get_id()), description='borrar')) # Wait until template is ready a.vms.add( params.VM(name='test_vm', cluster = params.Cluster(id=a.clusters.get(name='Iscsi_Cluster').get_id()), template = params.Template(id=a.templates.get(name='test').get_id()), description='test mas tes', memory=256*1024*1024) ) # Wait until machine is finished To this point, all goes fine. Now, when i try to start the machine, i get the same error. (In my case, setting volPath to '' at begining of the method 'prepareVolumePath'. I also has tested using directly cluster and template (instead of params.Cluster), adding and removing params, but always same result. If you need something, i can remove the 'volPath = ""' that i have added and repeat tests.
http://gerrit.ovirt.org/#/c/6803/4
http://gerrit.ovirt.org/#/c/6803/7
this one missed the branch date for 3.2, but it's merged to master as 0499051e4816274bcbc3564953782ecab9d8f8c5
(In reply to comment #14) > this one missed the branch date for 3.2, but it's merged to master as > 0499051e4816274bcbc3564953782ecab9d8f8c5 If there's a real need to backport this to ovirt-3.2, go ahead.
as RC is built, moving to ON_QA (hopefully did not catch incorrect bugs when doing this)
closing as this should be in 3.3 (doing so in bulk, so may be incorrect)