OOps, my bad!

here it is:

Thread-130::DEBUG::2014-03-31 14:31:00,570::BindingXMLRPC::1067::vds::(wrapper) client [10.125.1.171]::call vmCreate with ({'acpiEnable': 'true', 'emulatedMachine': 'pc-1.0', 'vmId': '2f50cbb4-f80f-4761-bb0d-1d351f497af7', 'memGuaranteedSize': 1024, 'spiceSslCipherSuite': 'DEFAULT', 'timeOffset': '0', 'cpuType': 'Conroe', 'smp': '1', 'custom': {'device_7a09b642-7018-43b8-9938-33432b99cdc1device_dce622cc-29fa-431d-b10f-677903ffebbadevice_156942ac-5c99-496b-8c6a-3ffab96c3164device_e2e8af70-760d-4d07-b27e-cbbcb638affb': 'VmDevice {vmId=2f50cbb4-f80f-4761-bb0d-1d351f497af7, deviceId=e2e8af70-760d-4d07-b27e-cbbcb638affb, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}', 'device_7a09b642-7018-43b8-9938-33432b99cdc1': 'VmDevice {vmId=2f50cbb4-f80f-4761-bb0d-1d351f497af7, deviceId=7a09b642-7018-43b8-9938-33432b99cdc1, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}', 'device_7a09b642-7018-43b8-9938-33432b99cdc1device_dce622cc-29fa-431d-b10f-677903ffebbadevice_156942ac-5c99-496b-8c6a-3ffab96c3164device_e2e8af70-760d-4d07-b27e-cbbcb638affbdevice_87060fa4-d4d9-4140-9915-73babd76fc12': 'VmDevice {vmId=2f50cbb4-f80f-4761-bb0d-1d351f497af7, deviceId=87060fa4-d4d9-4140-9915-73babd76fc12, device=virtio-serial, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x04, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=virtio-serial0, customProperties={}, snapshotId=null}', 'device_7a09b642-7018-43b8-9938-33432b99cdc1device_dce622cc-29fa-431d-b10f-677903ffebbadevice_156942ac-5c99-496b-8c6a-3ffab96c3164': 'VmDevice {vmId=2f50cbb4-f80f-4761-bb0d-1d351f497af7, deviceId=156942ac-5c99-496b-8c6a-3ffab96c3164, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}', 'device_7a09b642-7018-43b8-9938-33432b99cdc1device_dce622cc-29fa-431d-b10f-677903ffebba': 'VmDevice {vmId=2f50cbb4-f80f-4761-bb0d-1d351f497af7, deviceId=dce622cc-29fa-431d-b10f-677903ffebba, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}'}, 'vmType': 'kvm', 'memSize': 10240, 'smpCoresPerSocket': '1', 'vmName': 'satelit', 'nice': '0', 'smartcardEnable': 'false', 'keyboardLayout': 'en-us', 'kvmEnable': 'true', 'pitReinjection': 'false', 'transparentHugePages': 'true', 'devices': [{'device': 'qxl', 'specParams': {'vram': '32768', 'ram': '65536', 'heads': '1'}, 'type': 'video', 'deviceId': '21fbf3bc-a4e0-4706-a2f2-af14f3433a2d', 'address': {'slot': '0x02', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}}, {'index': '2', 'iface': 'ide', 'bootOrder': '2', 'specParams': {'path': ''}, 'readonly': 'true', 'deviceId': 'af3420c5-b179-4761-ac69-85831cee3b49', 'address': {'bus': '1', 'controller': '0', 'type': 'drive', 'target': '0', 'unit': '0'}, 'device': 'cdrom', 'shared': 'false', 'path': '', 'type': 'disk'}, {'index': 0, 'iface': 'virtio', 'format': 'raw', 'bootOrder': '1', 'poolID': '5849b030-626e-47cb-ad90-3ce782d831b3', 'volumeID': '82231f1f-2c7a-4aee-a596-af209fe5e081', 'imageID': 'faa6b382-eaa7-48d4-80fb-3e5999e1a167', 'specParams': {}, 'readonly': 'false', 'domainID': '041e8dbe-f405-4aca-bb78-3bf3cc7dc190', 'optional': 'false', 'deviceId': 'faa6b382-eaa7-48d4-80fb-3e5999e1a167', 'address': {'slot': '0x05', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device': 'disk', 'shared': 'false', 'propagateErrors': 'off', 'type': 'disk'}, {'nicModel': 'pv', 'macAddr': '00:1a:4a:69:90:dd', 'linkActive': 'true', 'network': 'VPO_IPPROXY', 'filter': 'vdsm-no-mac-spoofing', 'specParams': {'inbound': {'average': 25600, 'peak': 26880, 'burst': 256000}, 'outbound': {'average': 25600, 'peak': 26880, 'burst': 256000}}, 'deviceId': '10591bf3-0131-480a-8f89-5b8db7d49cd8', 'address': {'slot': '0x07', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device': 'bridge', 'type': 'interface'}, {'device': 'memballoon', 'specParams': {'model': 'virtio'}, 'type': 'balloon', 'deviceId': 'b9561cf2-37f0-4e64-bc7b-8c1921c06f9b'}, {'index': '0', 'specParams': {}, 'deviceId': 'd02fc85d-4862-4e0f-a7c5-eadce3509935', 'address': {'slot': '0x03', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device': 'scsi', 'model': 'virtio-scsi', 'type': 'controller'}], 'spiceSecureChannels': 'smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard', 'display': 'qxl'},) {}
Thread-130::INFO::2014-03-31 14:31:00,578::API::668::vds::(_getNetworkIp) network None: using 0
Thread-130::INFO::2014-03-31 14:31:00,578::clientIF::366::vds::(createVm) vmContainerLock acquired by vm 2f50cbb4-f80f-4761-bb0d-1d351f497af7
Thread-130::DEBUG::2014-03-31 14:31:00,582::clientIF::379::vds::(createVm) Total desktops after creation of 2f50cbb4-f80f-4761-bb0d-1d351f497af7 is 2
Thread-130::DEBUG::2014-03-31 14:31:00,582::BindingXMLRPC::1074::vds::(wrapper) return vmCreate with {'status': {'message': 'Done', 'code': 0}, 'vmList': {'status': 'WaitForLaunch', 'acpiEnable': 'true', 'emulatedMachine': 'pc-1.0', 'vmId': '2f50cbb4-f80f-4761-bb0d-1d351f497af7', 'pid': '0', 'memGuaranteedSize': 1024, 'timeOffset': '0', 'keyboardLayout': 'en-us', 'displayPort': '-1', 'displaySecurePort': '-1', 'spiceSslCipherSuite': 'DEFAULT', 'cpuType': 'Conroe', 'custom': {'device_7a09b642-7018-43b8-9938-33432b99cdc1device_dce622cc-29fa-431d-b10f-677903ffebbadevice_156942ac-5c99-496b-8c6a-3ffab96c3164device_e2e8af70-760d-4d07-b27e-cbbcb638affb': 'VmDevice {vmId=2f50cbb4-f80f-4761-bb0d-1d351f497af7, deviceId=e2e8af70-760d-4d07-b27e-cbbcb638affb, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}', 'device_7a09b642-7018-43b8-9938-33432b99cdc1': 'VmDevice {vmId=2f50cbb4-f80f-4761-bb0d-1d351f497af7, deviceId=7a09b642-7018-43b8-9938-33432b99cdc1, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}', 'device_7a09b642-7018-43b8-9938-33432b99cdc1device_dce622cc-29fa-431d-b10f-677903ffebbadevice_156942ac-5c99-496b-8c6a-3ffab96c3164device_e2e8af70-760d-4d07-b27e-cbbcb638affbdevice_87060fa4-d4d9-4140-9915-73babd76fc12': 'VmDevice {vmId=2f50cbb4-f80f-4761-bb0d-1d351f497af7, deviceId=87060fa4-d4d9-4140-9915-73babd76fc12, device=virtio-serial, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x04, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=virtio-serial0, customProperties={}, snapshotId=null}', 'device_7a09b642-7018-43b8-9938-33432b99cdc1device_dce622cc-29fa-431d-b10f-677903ffebbadevice_156942ac-5c99-496b-8c6a-3ffab96c3164': 'VmDevice {vmId=2f50cbb4-f80f-4761-bb0d-1d351f497af7, deviceId=156942ac-5c99-496b-8c6a-3ffab96c3164, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}', 'device_7a09b642-7018-43b8-9938-33432b99cdc1device_dce622cc-29fa-431d-b10f-677903ffebba': 'VmDevice {vmId=2f50cbb4-f80f-4761-bb0d-1d351f497af7, deviceId=dce622cc-29fa-431d-b10f-677903ffebba, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}'}, 'clientIp': '', 'nicModel': 'rtl8139,pv', 'smartcardEnable': 'false', 'kvmEnable': 'true', 'pitReinjection': 'false', 'transparentHugePages': 'true', 'devices': [{'device': 'qxl', 'specParams': {'vram': '32768', 'ram': '65536', 'heads': '1'}, 'type': 'video', 'deviceId': '21fbf3bc-a4e0-4706-a2f2-af14f3433a2d', 'address': {'slot': '0x02', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}}, {'index': '2', 'iface': 'ide', 'bootOrder': '2', 'specParams': {'path': ''}, 'readonly': 'true', 'deviceId': 'af3420c5-b179-4761-ac69-85831cee3b49', 'address': {'bus': '1', 'controller': '0', 'type': 'drive', 'target': '0', 'unit': '0'}, 'device': 'cdrom', 'shared': 'false', 'path': '', 'type': 'disk'}, {'index': 0, 'iface': 'virtio', 'format': 'raw', 'bootOrder': '1', 'poolID': '5849b030-626e-47cb-ad90-3ce782d831b3', 'volumeID': '82231f1f-2c7a-4aee-a596-af209fe5e081', 'imageID': 'faa6b382-eaa7-48d4-80fb-3e5999e1a167', 'specParams': {}, 'readonly': 'false', 'domainID': '041e8dbe-f405-4aca-bb78-3bf3cc7dc190', 'optional': 'false', 'deviceId': 'faa6b382-eaa7-48d4-80fb-3e5999e1a167', 'address': {'slot': '0x05', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device': 'disk', 'shared': 'false', 'propagateErrors': 'off', 'type': 'disk'}, {'nicModel': 'pv', 'macAddr': '00:1a:4a:69:90:dd', 'linkActive': 'true', 'network': 'VPO_IPPROXY', 'filter': 'vdsm-no-mac-spoofing', 'specParams': {'inbound': {'average': 25600, 'peak': 26880, 'burst': 256000}, 'outbound': {'average': 25600, 'peak': 26880, 'burst': 256000}}, 'deviceId': '10591bf3-0131-480a-8f89-5b8db7d49cd8', 'address': {'slot': '0x07', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device': 'bridge', 'type': 'interface'}, {'device': 'memballoon', 'specParams': {'model': 'virtio'}, 'type': 'balloon', 'deviceId': 'b9561cf2-37f0-4e64-bc7b-8c1921c06f9b'}, {'index': '0', 'specParams': {}, 'deviceId': 'd02fc85d-4862-4e0f-a7c5-eadce3509935', 'address': {'slot': '0x03', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 'device': 'scsi', 'model': 'virtio-scsi', 'type': 'controller'}], 'smp': '1', 'vmType': 'kvm', 'memSize': 10240, 'displayIp': '0', 'spiceSecureChannels': 'smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard', 'smpCoresPerSocket': '1', 'vmName': 'satelit', 'display': 'qxl', 'nice': '0'}}
Thread-469::DEBUG::2014-03-31 14:31:00,584::vm::2242::vm.Vm::(_startUnderlyingVm) vmId=`2f50cbb4-f80f-4761-bb0d-1d351f497af7`::Start
Thread-469::DEBUG::2014-03-31 14:31:00,584::vm::2246::vm.Vm::(_startUnderlyingVm) vmId=`2f50cbb4-f80f-4761-bb0d-1d351f497af7`::_ongoingCreations acquired
Thread-469::INFO::2014-03-31 14:31:00,585::vm::3097::vm.Vm::(_run) vmId=`2f50cbb4-f80f-4761-bb0d-1d351f497af7`::VM wrapper has started
Thread-469::DEBUG::2014-03-31 14:31:00,585::task::595::TaskManager.Task::(_updateState) Task=`afd2f80d-4245-4368-aa74-ce9326e49816`::moving from state init -> state preparing
Thread-469::INFO::2014-03-31 14:31:00,585::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='041e8dbe-f405-4aca-bb78-3bf3cc7dc190', spUUID='5849b030-626e-47cb-ad90-3ce782d831b3', imgUUID='faa6b382-eaa7-48d4-80fb-3e5999e1a167', volUUID='82231f1f-2c7a-4aee-a596-af209fe5e081', options=None)
Thread-469::INFO::2014-03-31 14:31:00,590::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '128230096896', 'apparentsize': '161061273600'}
Thread-469::DEBUG::2014-03-31 14:31:00,590::task::1185::TaskManager.Task::(prepare) Task=`afd2f80d-4245-4368-aa74-ce9326e49816`::finished: {'truesize': '128230096896', 'apparentsize': '161061273600'}
Thread-469::DEBUG::2014-03-31 14:31:00,590::task::595::TaskManager.Task::(_updateState) Task=`afd2f80d-4245-4368-aa74-ce9326e49816`::moving from state preparing -> state finished
Thread-469::DEBUG::2014-03-31 14:31:00,590::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-469::DEBUG::2014-03-31 14:31:00,590::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-469::DEBUG::2014-03-31 14:31:00,591::task::990::TaskManager.Task::(_decref) Task=`afd2f80d-4245-4368-aa74-ce9326e49816`::ref 0 aborting False
Thread-469::INFO::2014-03-31 14:31:00,591::clientIF::324::vds::(prepareVolumePath) prepared volume path:
Thread-469::DEBUG::2014-03-31 14:31:00,591::task::595::TaskManager.Task::(_updateState) Task=`ebc21d48-03ca-4764-a5eb-6544c680fb6c`::moving from state init -> state preparing
Thread-469::INFO::2014-03-31 14:31:00,591::logUtils::44::dispatcher::(wrapper) Run and protect: prepareImage(sdUUID='041e8dbe-f405-4aca-bb78-3bf3cc7dc190', spUUID='5849b030-626e-47cb-ad90-3ce782d831b3', imgUUID='faa6b382-eaa7-48d4-80fb-3e5999e1a167', leafUUID='82231f1f-2c7a-4aee-a596-af209fe5e081')
Thread-469::DEBUG::2014-03-31 14:31:00,592::resourceManager::198::ResourceManager.Request::(__init__) ResName=`Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190`ReqID=`6bd72828-e18d-4461-822d-4b5c80152dce`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '3237' at 'prepareImage'
Thread-469::DEBUG::2014-03-31 14:31:00,592::resourceManager::542::ResourceManager::(registerResource) Trying to register resource 'Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190' for lock type 'shared'
Thread-469::DEBUG::2014-03-31 14:31:00,592::resourceManager::601::ResourceManager::(registerResource) Resource 'Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190' is free. Now locking as 'shared' (1 active user)
Thread-469::DEBUG::2014-03-31 14:31:00,592::resourceManager::238::ResourceManager.Request::(grant) ResName=`Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190`ReqID=`6bd72828-e18d-4461-822d-4b5c80152dce`::Granted request
Thread-469::DEBUG::2014-03-31 14:31:00,593::task::827::TaskManager.Task::(resourceAcquired) Task=`ebc21d48-03ca-4764-a5eb-6544c680fb6c`::_resourcesAcquired: Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190 (shared)
Thread-469::DEBUG::2014-03-31 14:31:00,593::task::990::TaskManager.Task::(_decref) Task=`ebc21d48-03ca-4764-a5eb-6544c680fb6c`::ref 1 aborting False
Thread-469::WARNING::2014-03-31 14:31:00,600::fileUtils::167::Storage.fileUtils::(createdir) Dir /var/run/vdsm/storage/041e8dbe-f405-4aca-bb78-3bf3cc7dc190 already exists
Thread-469::DEBUG::2014-03-31 14:31:00,600::fileSD::446::Storage.StorageDomain::(createImageLinks) img run dir already exists: /var/run/vdsm/storage/041e8dbe-f405-4aca-bb78-3bf3cc7dc190/faa6b382-eaa7-48d4-80fb-3e5999e1a167
Thread-469::DEBUG::2014-03-31 14:31:00,601::fileVolume::529::Storage.Volume::(validateVolumePath) validate path for 82231f1f-2c7a-4aee-a596-af209fe5e081
Thread-469::INFO::2014-03-31 14:31:00,602::logUtils::47::dispatcher::(wrapper) Run and protect: prepareImage, Return response: {'info': {'domainID': '041e8dbe-f405-4aca-bb78-3bf3cc7dc190', 'volType': 'path', 'leaseOffset': 0, 'path': '/rhev/data-center/mnt/glusterSD/10.125.1.194:gluster__data2/041e8dbe-f405-4aca-bb78-3bf3cc7dc190/images/faa6b382-eaa7-48d4-80fb-3e5999e1a167/82231f1f-2c7a-4aee-a596-af209fe5e081', 'volumeID': '82231f1f-2c7a-4aee-a596-af209fe5e081', 'leasePath': '/rhev/data-center/mnt/glusterSD/10.125.1.194:gluster__data2/041e8dbe-f405-4aca-bb78-3bf3cc7dc190/images/faa6b382-eaa7-48d4-80fb-3e5999e1a167/82231f1f-2c7a-4aee-a596-af209fe5e081.lease', 'imageID': 'faa6b382-eaa7-48d4-80fb-3e5999e1a167'}, 'path': '/rhev/data-center/mnt/glusterSD/10.125.1.194:gluster__data2/041e8dbe-f405-4aca-bb78-3bf3cc7dc190/images/faa6b382-eaa7-48d4-80fb-3e5999e1a167/82231f1f-2c7a-4aee-a596-af209fe5e081', 'imgVolumesInfo': [{'domainID': '041e8dbe-f405-4aca-bb78-3bf3cc7dc190', 'volType': 'path', 'leaseOffset': 0, 'path': '/rhev/data-center/mnt/glusterSD/10.125.1.194:gluster__data2/041e8dbe-f405-4aca-bb78-3bf3cc7dc190/images/faa6b382-eaa7-48d4-80fb-3e5999e1a167/82231f1f-2c7a-4aee-a596-af209fe5e081', 'volumeID': '82231f1f-2c7a-4aee-a596-af209fe5e081', 'leasePath': '/rhev/data-center/mnt/glusterSD/10.125.1.194:gluster__data2/041e8dbe-f405-4aca-bb78-3bf3cc7dc190/images/faa6b382-eaa7-48d4-80fb-3e5999e1a167/82231f1f-2c7a-4aee-a596-af209fe5e081.lease', 'imageID': 'faa6b382-eaa7-48d4-80fb-3e5999e1a167'}]}
Thread-469::DEBUG::2014-03-31 14:31:00,603::task::1185::TaskManager.Task::(prepare) Task=`ebc21d48-03ca-4764-a5eb-6544c680fb6c`::finished: {'info': {'domainID': '041e8dbe-f405-4aca-bb78-3bf3cc7dc190', 'volType': 'path', 'leaseOffset': 0, 'path': '/rhev/data-center/mnt/glusterSD/10.125.1.194:gluster__data2/041e8dbe-f405-4aca-bb78-3bf3cc7dc190/images/faa6b382-eaa7-48d4-80fb-3e5999e1a167/82231f1f-2c7a-4aee-a596-af209fe5e081', 'volumeID': '82231f1f-2c7a-4aee-a596-af209fe5e081', 'leasePath': '/rhev/data-center/mnt/glusterSD/10.125.1.194:gluster__data2/041e8dbe-f405-4aca-bb78-3bf3cc7dc190/images/faa6b382-eaa7-48d4-80fb-3e5999e1a167/82231f1f-2c7a-4aee-a596-af209fe5e081.lease', 'imageID': 'faa6b382-eaa7-48d4-80fb-3e5999e1a167'}, 'path': '/rhev/data-center/mnt/glusterSD/10.125.1.194:gluster__data2/041e8dbe-f405-4aca-bb78-3bf3cc7dc190/images/faa6b382-eaa7-48d4-80fb-3e5999e1a167/82231f1f-2c7a-4aee-a596-af209fe5e081', 'imgVolumesInfo': [{'domainID': '041e8dbe-f405-4aca-bb78-3bf3cc7dc190', 'volType': 'path', 'leaseOffset': 0, 'path': '/rhev/data-center/mnt/glusterSD/10.125.1.194:gluster__data2/041e8dbe-f405-4aca-bb78-3bf3cc7dc190/images/faa6b382-eaa7-48d4-80fb-3e5999e1a167/82231f1f-2c7a-4aee-a596-af209fe5e081', 'volumeID': '82231f1f-2c7a-4aee-a596-af209fe5e081', 'leasePath': '/rhev/data-center/mnt/glusterSD/10.125.1.194:gluster__data2/041e8dbe-f405-4aca-bb78-3bf3cc7dc190/images/faa6b382-eaa7-48d4-80fb-3e5999e1a167/82231f1f-2c7a-4aee-a596-af209fe5e081.lease', 'imageID': 'faa6b382-eaa7-48d4-80fb-3e5999e1a167'}]}
Thread-469::DEBUG::2014-03-31 14:31:00,603::task::595::TaskManager.Task::(_updateState) Task=`ebc21d48-03ca-4764-a5eb-6544c680fb6c`::moving from state preparing -> state finished
Thread-469::DEBUG::2014-03-31 14:31:00,603::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190': < ResourceRef 'Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190', isValid: 'True' obj: 'None'>}
Thread-469::DEBUG::2014-03-31 14:31:00,603::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-469::DEBUG::2014-03-31 14:31:00,603::resourceManager::616::ResourceManager::(releaseResource) Trying to release resource 'Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190'
Thread-469::DEBUG::2014-03-31 14:31:00,604::resourceManager::635::ResourceManager::(releaseResource) Released resource 'Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190' (0 active users)
Thread-469::DEBUG::2014-03-31 14:31:00,604::resourceManager::641::ResourceManager::(releaseResource) Resource 'Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190' is free, finding out if anyone is waiting for it.
Thread-469::DEBUG::2014-03-31 14:31:00,604::resourceManager::649::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190', Clearing records.
Thread-469::DEBUG::2014-03-31 14:31:00,604::task::990::TaskManager.Task::(_decref) Task=`ebc21d48-03ca-4764-a5eb-6544c680fb6c`::ref 0 aborting False
Thread-469::INFO::2014-03-31 14:31:00,604::clientIF::324::vds::(prepareVolumePath) prepared volume path: /rhev/data-center/mnt/glusterSD/10.125.1.194:gluster__data2/041e8dbe-f405-4aca-bb78-3bf3cc7dc190/images/faa6b382-eaa7-48d4-80fb-3e5999e1a167/82231f1f-2c7a-4aee-a596-af209fe5e081
Thread-469::DEBUG::2014-03-31 14:31:00,613::vm::2263::vm.Vm::(_startUnderlyingVm) vmId=`2f50cbb4-f80f-4761-bb0d-1d351f497af7`::_ongoingCreations released
Thread-469::ERROR::2014-03-31 14:31:00,614::vm::2289::vm.Vm::(_startUnderlyingVm) vmId=`2f50cbb4-f80f-4761-bb0d-1d351f497af7`::The vm start process failed
Traceback (most recent call last):
  File "/usr/share/vdsm/vm.py", line 2249, in _startUnderlyingVm
    self._run()
  File "/usr/share/vdsm/vm.py", line 3135, in _run
    domxml = hooks.before_vm_start(self._buildCmdLine(), self.conf)
  File "/usr/share/vdsm/vm.py", line 2965, in _buildCmdLine
    self._appendDevices(domxml)
  File "/usr/share/vdsm/vm.py", line 2922, in _appendDevices
    deviceXML = dev.getXML().toxml(encoding='utf-8')
  File "/usr/lib64/python2.7/xml/dom/minidom.py", line 46, in toxml
    return self.toprettyxml("", "", encoding)
  File "/usr/lib64/python2.7/xml/dom/minidom.py", line 60, in toprettyxml
    self.writexml(writer, "", indent, newl)
  File "/usr/share/vdsm/vm.py", line 5268, in __hacked_writexml
    node.writexml(writer, indent + addindent, addindent, newl)
  File "/usr/share/vdsm/vm.py", line 5268, in __hacked_writexml
    node.writexml(writer, indent + addindent, addindent, newl)
  File "/usr/share/vdsm/vm.py", line 5256, in __hacked_writexml
    xml.dom.minidom._write_data(writer, attrs[a_name].value)
  File "/usr/lib64/python2.7/xml/dom/minidom.py", line 296, in _write_data
    data = data.replace("&", "&amp;").replace("<", "&lt;"). \
AttributeError: 'int' object has no attribute 'replace'
Thread-469::DEBUG::2014-03-31 14:31:00,618::vm::2731::vm.Vm::(setDownStatus) vmId=`2f50cbb4-f80f-4761-bb0d-1d351f497af7`::Changed state to Down: 'int' object has no attribute 'replace'
Thread-130::DEBUG::2014-03-31 14:31:02,693::BindingXMLRPC::1067::vds::(wrapper) client [10.125.1.171]::call vmGetStats with ('2f50cbb4-f80f-4761-bb0d-1d351f497af7',) {}
Thread-130::DEBUG::2014-03-31 14:31:02,694::BindingXMLRPC::1074::vds::(wrapper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 'statsList': [{'status': 'Down', 'hash': '0', 'exitMessage': "'int' object has no attribute 'replace'", 'vmId': '2f50cbb4-f80f-4761-bb0d-1d351f497af7', 'timeOffset': '0', 'exitCode': 1}]}
Thread-130::DEBUG::2014-03-31 14:31:02,707::BindingXMLRPC::1067::vds::(wrapper) client [10.125.1.171]::call vmDestroy with ('2f50cbb4-f80f-4761-bb0d-1d351f497af7',) {}
Thread-130::INFO::2014-03-31 14:31:02,708::API::327::vds::(destroy) vmContainerLock acquired by vm 2f50cbb4-f80f-4761-bb0d-1d351f497af7
Thread-130::DEBUG::2014-03-31 14:31:02,708::vm::4629::vm.Vm::(destroy) vmId=`2f50cbb4-f80f-4761-bb0d-1d351f497af7`::destroy Called
Thread-130::INFO::2014-03-31 14:31:02,708::vm::4575::vm.Vm::(releaseVm) vmId=`2f50cbb4-f80f-4761-bb0d-1d351f497af7`::Release VM resources
Thread-130::WARNING::2014-03-31 14:31:02,708::vm::1967::vm.Vm::(_set_lastStatus) vmId=`2f50cbb4-f80f-4761-bb0d-1d351f497af7`::trying to set state to Powering down when already Down
Thread-130::DEBUG::2014-03-31 14:31:02,709::task::595::TaskManager.Task::(_updateState) Task=`e42042ca-c4fe-467b-8810-99099482dfdb`::moving from state init -> state preparing
Thread-130::INFO::2014-03-31 14:31:02,709::logUtils::44::dispatcher::(wrapper) Run and protect: teardownImage(sdUUID='041e8dbe-f405-4aca-bb78-3bf3cc7dc190', spUUID='5849b030-626e-47cb-ad90-3ce782d831b3', imgUUID='faa6b382-eaa7-48d4-80fb-3e5999e1a167', volUUID=None)
Thread-130::DEBUG::2014-03-31 14:31:02,710::resourceManager::198::ResourceManager.Request::(__init__) ResName=`Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190`ReqID=`94ad1f7a-b152-49ae-ba64-83ffeeb82ee1`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '3285' at 'teardownImage'
Thread-130::DEBUG::2014-03-31 14:31:02,710::resourceManager::542::ResourceManager::(registerResource) Trying to register resource 'Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190' for lock type 'shared'
Thread-130::DEBUG::2014-03-31 14:31:02,710::resourceManager::601::ResourceManager::(registerResource) Resource 'Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190' is free. Now locking as 'shared' (1 active user)
Thread-130::DEBUG::2014-03-31 14:31:02,711::resourceManager::238::ResourceManager.Request::(grant) ResName=`Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190`ReqID=`94ad1f7a-b152-49ae-ba64-83ffeeb82ee1`::Granted request
Thread-130::DEBUG::2014-03-31 14:31:02,711::task::827::TaskManager.Task::(resourceAcquired) Task=`e42042ca-c4fe-467b-8810-99099482dfdb`::_resourcesAcquired: Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190 (shared)
Thread-130::DEBUG::2014-03-31 14:31:02,711::task::990::TaskManager.Task::(_decref) Task=`e42042ca-c4fe-467b-8810-99099482dfdb`::ref 1 aborting False
Thread-130::INFO::2014-03-31 14:31:02,712::logUtils::47::dispatcher::(wrapper) Run and protect: teardownImage, Return response: None
Thread-130::DEBUG::2014-03-31 14:31:02,712::task::1185::TaskManager.Task::(prepare) Task=`e42042ca-c4fe-467b-8810-99099482dfdb`::finished: None
Thread-130::DEBUG::2014-03-31 14:31:02,713::task::595::TaskManager.Task::(_updateState) Task=`e42042ca-c4fe-467b-8810-99099482dfdb`::moving from state preparing -> state finished
Thread-130::DEBUG::2014-03-31 14:31:02,713::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190': < ResourceRef 'Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190', isValid: 'True' obj: 'None'>}
Thread-130::DEBUG::2014-03-31 14:31:02,713::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-130::DEBUG::2014-03-31 14:31:02,713::resourceManager::616::ResourceManager::(releaseResource) Trying to release resource 'Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190'
Thread-130::DEBUG::2014-03-31 14:31:02,714::resourceManager::635::ResourceManager::(releaseResource) Released resource 'Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190' (0 active users)
Thread-130::DEBUG::2014-03-31 14:31:02,714::resourceManager::641::ResourceManager::(releaseResource) Resource 'Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190' is free, finding out if anyone is waiting for it.
Thread-130::DEBUG::2014-03-31 14:31:02,714::resourceManager::649::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.041e8dbe-f405-4aca-bb78-3bf3cc7dc190', Clearing records.
Thread-130::DEBUG::2014-03-31 14:31:02,714::task::990::TaskManager.Task::(_decref) Task=`e42042ca-c4fe-467b-8810-99099482dfdb`::ref 0 aborting False
Thread-130::WARNING::2014-03-31 14:31:02,715::utils::129::root::(rmFile) File: /var/lib/libvirt/qemu/channels/2f50cbb4-f80f-4761-bb0d-1d351f497af7.com.redhat.rhevm.vdsm already removed
Thread-130::WARNING::2014-03-31 14:31:02,716::utils::129::root::(rmFile) File: /var/lib/libvirt/qemu/channels/2f50cbb4-f80f-4761-bb0d-1d351f497af7.org.qemu.guest_agent.0 already removed
Thread-130::DEBUG::2014-03-31 14:31:02,717::task::595::TaskManager.Task::(_updateState) Task=`2a6b057d-fe6e-4768-b32b-986295e416f5`::moving from state init -> state preparing
Thread-130::INFO::2014-03-31 14:31:02,717::logUtils::44::dispatcher::(wrapper) Run and protect: inappropriateDevices(thiefId='2f50cbb4-f80f-4761-bb0d-1d351f497af7')
Thread-130::INFO::2014-03-31 14:31:02,718::logUtils::47::dispatcher::(wrapper) Run and protect: inappropriateDevices, Return response: None
Thread-130::DEBUG::2014-03-31 14:31:02,718::task::1185::TaskManager.Task::(prepare) Task=`2a6b057d-fe6e-4768-b32b-986295e416f5`::finished: None
Thread-130::DEBUG::2014-03-31 14:31:02,718::task::595::TaskManager.Task::(_updateState) Task=`2a6b057d-fe6e-4768-b32b-986295e416f5`::moving from state preparing -> state finished
Thread-130::DEBUG::2014-03-31 14:31:02,718::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-130::DEBUG::2014-03-31 14:31:02,718::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-130::DEBUG::2014-03-31 14:31:02,719::task::990::TaskManager.Task::(_decref) Task=`2a6b057d-fe6e-4768-b32b-986295e416f5`::ref 0 aborting False
Thread-130::DEBUG::2014-03-31 14:31:02,719::vm::4623::vm.Vm::(deleteVm) vmId=`2f50cbb4-f80f-4761-bb0d-1d351f497af7`::Total desktops after destroy of 2f50cbb4-f80f-4761-bb0d-1d351f497af7 is 1
Thread-130::DEBUG::2014-03-31 14:31:02,720::BindingXMLRPC::1074::vds::(wrapper) return vmDestroy with {'status': {'message': 'Machine destroyed', 'code': 0}}
Thread-23::DEBUG::2014-03-31 14:31:02,742::fileSD::225::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.125.1.193:_mnt_storage__filer1_export__nfs1_export/62f795ed-486c-443d-93e9-2c16595fe546/dom_md/metadata bs=4096 count=1' (cwd None)
Thread-23::DEBUG::2014-03-31 14:31:02,837::fileSD::225::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n491 bytes (491 B) copied, 0.000564355 s, 870 kB/s\n'; <rc> = 0
Thread-21::DEBUG::2014-03-31 14:31:02,870::fileSD::225::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/10.125.1.193:_mnt_storage__filer1_export__nfs2_iso/b157f887-ae9a-4337-8c55-7c8a9df017bb/dom_md/metadata bs=4096 count=1' (cwd None)
Thread-21::DEBUG::2014-03-31 14:31:02,905::fileSD::225::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n369 bytes (369 B) copied, 0.000450599 s, 819 kB/s\n'; <rc> = 0
Thread-20::DEBUG::2014-03-31 14:31:05,798::fileSD::225::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/glusterSD/10.125.1.194:gluster__data2/041e8dbe-f405-4aca-bb78-3bf3cc7dc190/dom_md/metadata bs=4096 count=1' (cwd None)
Thread-20::DEBUG::2014-03-31 14:31:05,825::fileSD::225::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n608 bytes (608 B) copied, 0.000467098 s, 1.3 MB/s\n'; <rc> = 0
Thread-130::DEBUG::2014-03-31 14:31:05,835::task::595::TaskManager.Task::(_updateState) Task=`4ccb0515-1051-4084-87a8-5f672be6755b`::moving from state init -> state preparing
Thread-130::INFO::2014-03-31 14:31:05,835::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-130::INFO::2014-03-31 14:31:05,835::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'041e8dbe-f405-4aca-bb78-3bf3cc7dc190': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000467098', 'lastCheck': '0.0', 'valid': True}, 'b157f887-ae9a-4337-8c55-7c8a9df017bb': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000450599', 'lastCheck': '2.9', 'valid': True}, '5fe658b1-43ff-4bfd-97d6-28217cf415df': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000212863', 'lastCheck': '8.5', 'valid': True}, '62f795ed-486c-443d-93e9-2c16595fe546': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000564355', 'lastCheck': '3.0', 'valid': True}}
Thread-130::DEBUG::2014-03-31 14:31:05,836::task::1185::TaskManager.Task::(prepare) Task=`4ccb0515-1051-4084-87a8-5f672be6755b`::finished: {'041e8dbe-f405-4aca-bb78-3bf3cc7dc190': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000467098', 'lastCheck': '0.0', 'valid': True}, 'b157f887-ae9a-4337-8c55-7c8a9df017bb': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000450599', 'lastCheck': '2.9', 'valid': True}, '5fe658b1-43ff-4bfd-97d6-28217cf415df': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000212863', 'lastCheck': '8.5', 'valid': True}, '62f795ed-486c-443d-93e9-2c16595fe546': {'code': 0, 'version': 0, 'acquired': True, 'delay': '0.000564355', 'lastCheck': '3.0', 'valid': True}}
Thread-130::DEBUG::2014-03-31 14:31:05,836::task::595::TaskManager.Task::(_updateState) Task=`4ccb0515-1051-4084-87a8-5f672be6755b`::moving from state preparing -> state finished
Thread-130::DEBUG::2014-03-31 14:31:05,836::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-130::DEBUG::2014-03-31 14:31:05,836::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-130::DEBUG::2014-03-31 14:31:05,836::task::990::TaskManager.Task::(_decref) Task=`4ccb0515-1051-4084-87a8-5f672be6755b`::ref 0 aborting False
Thread-22::DEBUG::2014-03-31 14:31:07,355::fileSD::225::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/glusterSD/10.125.1.194:gluster__data3/5fe658b1-43ff-4bfd-97d6-28217cf415df/dom_md/metadata bs=4096 count=1' (cwd None)
Thread-22::DEBUG::2014-03-31 14:31:07,437::fileSD::225::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n653 bytes (653 B) copied, 0.00062957 s, 1.0 MB/s\n'; <rc> = 0



On Mon, Mar 31, 2014 at 2:21 PM, Omer Frenkel <ofrenkel@redhat.com> wrote:


----- Original Message -----
> From: "Gabi C" <gabicr@gmail.com>
> To: "Dan Kenigsberg" <danken@redhat.com>
> Cc: users@ovirt.org
> Sent: Monday, March 31, 2014 1:58:26 PM
> Subject: Re: [Users] VM satelit is down. Exit message: 'int' object has no attribute 'replace'.
>
> Thanks!
>
> Here it is:
>

thanks, but this is engine.log
we would find more information on /var/log/vdsm/vdsm.log the host that tried to run the vm (virtual6)

>
> 2014-03-31 13:53:54,737 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (ajp--127.0.0.1-8702-20) [787f133c] Lock Acquired to object EngineLock
> [exclusiveLocks= key: 92fbccc5-1c99-4020-822b-74d43ad214c3 value: VM
> , sharedLocks= ]
> 2014-03-31 13:53:54,763 INFO
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand]
> (ajp--127.0.0.1-8702-20) [787f133c] START, IsVmDuringInitiatingVDSCommand(
> vmId = 92fbccc5-1c99-4020-822b-74d43ad214c3), log id: 685abcbf
> 2014-03-31 13:53:54,767 INFO
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand]
> (ajp--127.0.0.1-8702-20) [787f133c] FINISH, IsVmDuringInitiatingVDSCommand,
> return: false, log id: 685abcbf
> 2014-03-31 13:53:54,811 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (org.ovirt.thread.pool-6-thread-4) [787f133c] Running command: RunVmCommand
> internal: false. Entities affected : ID:
> 92fbccc5-1c99-4020-822b-74d43ad214c3 Type: VM
> 2014-03-31 13:53:54,839 INFO
> [org.ovirt.engine.core.bll.scheduling.policyunits.HaReservationWeightPolicyUnit]
> (org.ovirt.thread.pool-6-thread-4) [787f133c] Started HA reservation scoring
> method
> 2014-03-31 13:53:54,855 INFO
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
> (org.ovirt.thread.pool-6-thread-4) [787f133c] START,
> CreateVmVDSCommand(HostName = virtual6, HostId =
> e11c37b0-d79d-417b-bd6f-6dc172f7921c,
> vmId=92fbccc5-1c99-4020-822b-74d43ad214c3, vm=VM [PRTG]), log id: 497b9920
> 2014-03-31 13:53:54,863 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> (org.ovirt.thread.pool-6-thread-4) [787f133c] START,
> CreateVDSCommand(HostName = virtual6, HostId =
> e11c37b0-d79d-417b-bd6f-6dc172f7921c,
> vmId=92fbccc5-1c99-4020-822b-74d43ad214c3, vm=VM [PRTG]), log id: 7b64d5f2
> 2014-03-31 13:53:54,923 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> (org.ovirt.thread.pool-6-thread-4) [787f133c]
> org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand
> spiceSslCipherSuite=DEFAULT,memSize=2048,kvmEnable=true,smp=1,vmType=kvm,emulatedMachine=pc-1.0,keyboardLayout=en-us,memGuaranteedSize=1365,nice=0,display=qxl,smartcardEnable=false,smpCoresPerSocket=1,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,timeOffset=3600,transparentHugePages=true,vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,devices=[{address={bus=0x00,
> domain=0x0000, slot=0x02, type=pci, function=0x0}, specParams={vram=32768,
> heads=1}, device=qxl, type=video,
> deviceId=e46018f8-fbfc-484d-891a-e7ade9f88c51}, {shared=false, bootOrder=2,
> iface=ide, index=2, address={unit=0, bus=1, target=0, controller=0,
> type=drive}, specParams={path=}, path=, device=cdrom, type=disk,
> readonly=true, deviceId=8eac07a3-d353-43db-b2e3-5f8fe414bdfe},
> {shared=false, index=0, volumeID=438299fb-0a72-4005-b0c8-5544eece6dba,
> propagateErrors=off, format=raw, type=disk, iface=virtio, bootOrder=1,
> address={bus=0x00, domain=0x0000, slot=0x06, type=pci, function=0x0},
> domainID=041e8dbe-f405-4aca-bb78-3bf3cc7dc190,
> imageID=68051a25-d3de-46b4-9e4b-686d824146bf, specParams={}, optional=false,
> device=disk, poolID=5849b030-626e-47cb-ad90-3ce782d831b3, readonly=false,
> deviceId=68051a25-d3de-46b4-9e4b-686d824146bf}, {nicModel=pv,
> address={bus=0x00, domain=0x0000, slot=0x03, type=pci, function=0x0},
> specParams={outbound={peak=26880, burst=256000, average=25600},
> inbound={peak=26880, burst=256000, average=25600}},
> macAddr=00:1a:4a:69:90:de, device=bridge, linkActive=true, type=interface,
> filter=vdsm-no-mac-spoofing, network=VPO_IPPROXY,
> deviceId=553de5f6-e108-4c45-84d2-7a292304211f}, {specParams={model=virtio},
> device=memballoon, type=balloon,
> deviceId=68c759aa-6266-432c-9b8b-7a4b215eee57}, {index=0, model=virtio-scsi,
> address={bus=0x00, domain=0x0000, slot=0x04, type=pci, function=0x0},
> specParams={}, device=scsi, type=controller,
> deviceId=fc27e446-7932-40e4-98bd-2d13237ed6f5}],acpiEnable=true,cpuShares=1024,vmName=PRTG,cpuType=Conroe,custom={device_ac3c9c1c-9d8d-4ced-ba59-977f54ccb9eedevice_804006d1-ed61-4c0e-9818-0d0f4f0e8e3cdevice_b6ac752a-13e2-4107-aa8e-ddc054551f15=VmDevice
> {vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,
> deviceId=b6ac752a-13e2-4107-aa8e-ddc054551f15, device=unix, type=CHANNEL,
> bootOrder=0, specParams={}, address={port=1, bus=0, controller=0,
> type=virtio-serial}, managed=false, plugged=true, readOnly=false,
> deviceAlias=channel0, customProperties={}, snapshotId=null},
> device_ac3c9c1c-9d8d-4ced-ba59-977f54ccb9eedevice_804006d1-ed61-4c0e-9818-0d0f4f0e8e3cdevice_b6ac752a-13e2-4107-aa8e-ddc054551f15device_83ffb451-8ba0-4b56-8082-b243b793d83e=VmDevice
> {vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,
> deviceId=83ffb451-8ba0-4b56-8082-b243b793d83e, device=unix, type=CHANNEL,
> bootOrder=0, specParams={}, address={port=2, bus=0, controller=0,
> type=virtio-serial}, managed=false, plugged=true, readOnly=false,
> deviceAlias=channel1, customProperties={}, snapshotId=null},
> device_ac3c9c1c-9d8d-4ced-ba59-977f54ccb9eedevice_804006d1-ed61-4c0e-9818-0d0f4f0e8e3cdevice_b6ac752a-13e2-4107-aa8e-ddc054551f15device_83ffb451-8ba0-4b56-8082-b243b793d83edevice_f8e59a5e-20a3-4a45-91bf-804ad60f9efb=VmDevice
> {vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,
> deviceId=f8e59a5e-20a3-4a45-91bf-804ad60f9efb, device=spicevmc,
> type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0,
> controller=0, type=virtio-serial}, managed=false, plugged=true,
> readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null},
> device_ac3c9c1c-9d8d-4ced-ba59-977f54ccb9ee=VmDevice
> {vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,
> deviceId=ac3c9c1c-9d8d-4ced-ba59-977f54ccb9ee, device=ide, type=CONTROLLER,
> bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci,
> slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false,
> deviceAlias=ide0, customProperties={}, snapshotId=null},
> device_ac3c9c1c-9d8d-4ced-ba59-977f54ccb9eedevice_804006d1-ed61-4c0e-9818-0d0f4f0e8e3c=VmDevice
> {vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,
> deviceId=804006d1-ed61-4c0e-9818-0d0f4f0e8e3c, device=virtio-serial,
> type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00,
> domain=0x0000, type=pci, slot=0x05, function=0x0}, managed=false,
> plugged=true, readOnly=false, deviceAlias=virtio-serial0,
> customProperties={}, snapshotId=null}}
> 2014-03-31 13:53:54,971 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> (org.ovirt.thread.pool-6-thread-4) [787f133c] FINISH, CreateVDSCommand, log
> id: 7b64d5f2
> 2014-03-31 13:53:54,982 INFO
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
> (org.ovirt.thread.pool-6-thread-4) [787f133c] FINISH, CreateVmVDSCommand,
> return: WaitForLaunch, log id: 497b9920
> 2014-03-31 13:53:54,986 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (org.ovirt.thread.pool-6-thread-4) [787f133c] Lock freed to object
> EngineLock [exclusiveLocks= key: 92fbccc5-1c99-4020-822b-74d43ad214c3 value:
> VM
> , sharedLocks= ]
> 2014-03-31 13:53:54,995 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (org.ovirt.thread.pool-6-thread-4) [787f133c] Correlation ID: 787f133c, Job
> ID: e9bc3c5d-a16f-4cfc-ae35-340d153893b9, Call Stack: null, Custom Event ID:
> -1, Message: VM PRTG was started by admin (Host: virtual6).
> 2014-03-31 13:53:55,232 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand]
> (DefaultQuartzScheduler_Worker-15) START, DestroyVDSCommand(HostName =
> virtual6, HostId = e11c37b0-d79d-417b-bd6f-6dc172f7921c,
> vmId=92fbccc5-1c99-4020-822b-74d43ad214c3, force=false, secondsToWait=0,
> gracefully=false), log id: 780a285e
> 2014-03-31 13:53:55,252 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand]
> (DefaultQuartzScheduler_Worker-15) FINISH, DestroyVDSCommand, log id:
> 780a285e
> 2014-03-31 13:53:55,315 INFO
> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
> (org.ovirt.thread.pool-6-thread-22) Domain
> b157f887-ae9a-4337-8c55-7c8a9df017bb:imagini recovered from problem. vds:
> virtual5
> 2014-03-31 13:53:55,319 INFO
> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
> (org.ovirt.thread.pool-6-thread-22) Domain
> 62f795ed-486c-443d-93e9-2c16595fe546:masini recovered from problem. vds:
> virtual5
> 2014-03-31 13:53:55,342 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (DefaultQuartzScheduler_Worker-15) Correlation ID: null, Call Stack: null,
> Custom Event ID: -1, Message: VM PRTG is down. Exit message: 'int' object
> has no attribute 'replace'.
> 2014-03-31 13:53:55,346 INFO
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (DefaultQuartzScheduler_Worker-15) Running on vds during rerun failed vm:
> null
> 2014-03-31 13:53:55,351 INFO
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (DefaultQuartzScheduler_Worker-15) VM PRTG
> (92fbccc5-1c99-4020-822b-74d43ad214c3) is running in db and not running in
> VDS virtual6
> 2014-03-31 13:53:55,355 INFO
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (DefaultQuartzScheduler_Worker-15) add VM PRTG to HA rerun treatment
> 2014-03-31 13:53:55,366 ERROR
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (DefaultQuartzScheduler_Worker-15) Rerun vm
> 92fbccc5-1c99-4020-822b-74d43ad214c3. Called from vds virtual6
> 2014-03-31 13:53:55,375 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (org.ovirt.thread.pool-6-thread-25) Correlation ID: 787f133c, Job ID:
> e9bc3c5d-a16f-4cfc-ae35-340d153893b9, Call Stack: null, Custom Event ID: -1,
> Message: Failed to run VM PRTG on Host virtual6.
> 2014-03-31 13:53:55,399 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (org.ovirt.thread.pool-6-thread-25) Lock Acquired to object EngineLock
> [exclusiveLocks= key: 92fbccc5-1c99-4020-822b-74d43ad214c3 value: VM
> , sharedLocks= ]
> 2014-03-31 13:53:55,424 INFO
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand]
> (org.ovirt.thread.pool-6-thread-25) START, IsVmDuringInitiatingVDSCommand(
> vmId = 92fbccc5-1c99-4020-822b-74d43ad214c3), log id: 80df73c
> 2014-03-31 13:53:55,429 INFO
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand]
> (org.ovirt.thread.pool-6-thread-25) FINISH, IsVmDuringInitiatingVDSCommand,
> return: false, log id: 80df73c
> 2014-03-31 13:53:55,458 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (org.ovirt.thread.pool-6-thread-25) Running command: RunVmCommand internal:
> false. Entities affected : ID: 92fbccc5-1c99-4020-822b-74d43ad214c3 Type: VM
> 2014-03-31 13:53:55,464 INFO
> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
> (org.ovirt.thread.pool-6-thread-21) Domain
> b157f887-ae9a-4337-8c55-7c8a9df017bb:imagini recovered from problem. vds:
> virtual4
> 2014-03-31 13:53:55,482 INFO
> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
> (org.ovirt.thread.pool-6-thread-21) Domain
> 62f795ed-486c-443d-93e9-2c16595fe546:masini recovered from problem. vds:
> virtual4
> 2014-03-31 13:53:55,534 INFO
> [org.ovirt.engine.core.bll.scheduling.policyunits.HaReservationWeightPolicyUnit]
> (org.ovirt.thread.pool-6-thread-25) Started HA reservation scoring method
> 2014-03-31 13:53:55,551 INFO
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
> (org.ovirt.thread.pool-6-thread-25) START, CreateVmVDSCommand(HostName =
> virtual5, HostId = ee8c0f32-5129-48ec-b024-8ae83d5835eb,
> vmId=92fbccc5-1c99-4020-822b-74d43ad214c3, vm=VM [PRTG]), log id: 5db07e26
> 2014-03-31 13:53:55,561 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> (org.ovirt.thread.pool-6-thread-25) START, CreateVDSCommand(HostName =
> virtual5, HostId = ee8c0f32-5129-48ec-b024-8ae83d5835eb,
> vmId=92fbccc5-1c99-4020-822b-74d43ad214c3, vm=VM [PRTG]), log id: 41f8abfd
> 2014-03-31 13:53:55,624 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> (org.ovirt.thread.pool-6-thread-25)
> org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand
> spiceSslCipherSuite=DEFAULT,memSize=2048,kvmEnable=true,smp=1,vmType=kvm,emulatedMachine=pc-1.0,keyboardLayout=en-us,memGuaranteedSize=1365,nice=0,display=qxl,smartcardEnable=false,smpCoresPerSocket=1,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,timeOffset=3600,transparentHugePages=true,vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,devices=[{address={bus=0x00,
> domain=0x0000, slot=0x02, type=pci, function=0x0}, specParams={vram=32768,
> heads=1}, device=qxl, type=video,
> deviceId=e46018f8-fbfc-484d-891a-e7ade9f88c51}, {shared=false, bootOrder=2,
> iface=ide, index=2, address={unit=0, bus=1, target=0, controller=0,
> type=drive}, specParams={path=}, path=, device=cdrom, type=disk,
> readonly=true, deviceId=8eac07a3-d353-43db-b2e3-5f8fe414bdfe},
> {shared=false, index=0, volumeID=438299fb-0a72-4005-b0c8-5544eece6dba,
> propagateErrors=off, format=raw, type=disk, iface=virtio, bootOrder=1,
> address={bus=0x00, domain=0x0000, slot=0x06, type=pci, function=0x0},
> domainID=041e8dbe-f405-4aca-bb78-3bf3cc7dc190,
> imageID=68051a25-d3de-46b4-9e4b-686d824146bf, specParams={}, optional=false,
> device=disk, poolID=5849b030-626e-47cb-ad90-3ce782d831b3, readonly=false,
> deviceId=68051a25-d3de-46b4-9e4b-686d824146bf}, {nicModel=pv,
> address={bus=0x00, domain=0x0000, slot=0x03, type=pci, function=0x0},
> specParams={outbound={peak=26880, burst=256000, average=25600},
> inbound={peak=26880, burst=256000, average=25600}},
> macAddr=00:1a:4a:69:90:de, device=bridge, linkActive=true, type=interface,
> filter=vdsm-no-mac-spoofing, network=VPO_IPPROXY,
> deviceId=553de5f6-e108-4c45-84d2-7a292304211f}, {specParams={model=virtio},
> device=memballoon, type=balloon,
> deviceId=68c759aa-6266-432c-9b8b-7a4b215eee57}, {index=0, model=virtio-scsi,
> address={bus=0x00, domain=0x0000, slot=0x04, type=pci, function=0x0},
> specParams={}, device=scsi, type=controller,
> deviceId=fc27e446-7932-40e4-98bd-2d13237ed6f5}],acpiEnable=true,cpuShares=1024,vmName=PRTG,cpuType=Conroe,custom={device_ac3c9c1c-9d8d-4ced-ba59-977f54ccb9eedevice_804006d1-ed61-4c0e-9818-0d0f4f0e8e3cdevice_b6ac752a-13e2-4107-aa8e-ddc054551f15=VmDevice
> {vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,
> deviceId=b6ac752a-13e2-4107-aa8e-ddc054551f15, device=unix, type=CHANNEL,
> bootOrder=0, specParams={}, address={port=1, bus=0, controller=0,
> type=virtio-serial}, managed=false, plugged=true, readOnly=false,
> deviceAlias=channel0, customProperties={}, snapshotId=null},
> device_ac3c9c1c-9d8d-4ced-ba59-977f54ccb9eedevice_804006d1-ed61-4c0e-9818-0d0f4f0e8e3cdevice_b6ac752a-13e2-4107-aa8e-ddc054551f15device_83ffb451-8ba0-4b56-8082-b243b793d83e=VmDevice
> {vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,
> deviceId=83ffb451-8ba0-4b56-8082-b243b793d83e, device=unix, type=CHANNEL,
> bootOrder=0, specParams={}, address={port=2, bus=0, controller=0,
> type=virtio-serial}, managed=false, plugged=true, readOnly=false,
> deviceAlias=channel1, customProperties={}, snapshotId=null},
> device_ac3c9c1c-9d8d-4ced-ba59-977f54ccb9eedevice_804006d1-ed61-4c0e-9818-0d0f4f0e8e3cdevice_b6ac752a-13e2-4107-aa8e-ddc054551f15device_83ffb451-8ba0-4b56-8082-b243b793d83edevice_f8e59a5e-20a3-4a45-91bf-804ad60f9efb=VmDevice
> {vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,
> deviceId=f8e59a5e-20a3-4a45-91bf-804ad60f9efb, device=spicevmc,
> type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0,
> controller=0, type=virtio-serial}, managed=false, plugged=true,
> readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null},
> device_ac3c9c1c-9d8d-4ced-ba59-977f54ccb9ee=VmDevice
> {vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,
> deviceId=ac3c9c1c-9d8d-4ced-ba59-977f54ccb9ee, device=ide, type=CONTROLLER,
> bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci,
> slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false,
> deviceAlias=ide0, customProperties={}, snapshotId=null},
> device_ac3c9c1c-9d8d-4ced-ba59-977f54ccb9eedevice_804006d1-ed61-4c0e-9818-0d0f4f0e8e3c=VmDevice
> {vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,
> deviceId=804006d1-ed61-4c0e-9818-0d0f4f0e8e3c, device=virtio-serial,
> type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00,
> domain=0x0000, type=pci, slot=0x05, function=0x0}, managed=false,
> plugged=true, readOnly=false, deviceAlias=virtio-serial0,
> customProperties={}, snapshotId=null}}
> 2014-03-31 13:53:55,675 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> (org.ovirt.thread.pool-6-thread-25) FINISH, CreateVDSCommand, log id:
> 41f8abfd
> 2014-03-31 13:53:55,683 INFO
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
> (org.ovirt.thread.pool-6-thread-25) FINISH, CreateVmVDSCommand, return:
> WaitForLaunch, log id: 5db07e26
> 2014-03-31 13:53:55,685 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (org.ovirt.thread.pool-6-thread-25) Lock freed to object EngineLock
> [exclusiveLocks= key: 92fbccc5-1c99-4020-822b-74d43ad214c3 value: VM
> , sharedLocks= ]
> 2014-03-31 13:53:55,692 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (org.ovirt.thread.pool-6-thread-25) Correlation ID: 787f133c, Job ID:
> e9bc3c5d-a16f-4cfc-ae35-340d153893b9, Call Stack: null, Custom Event ID: -1,
> Message: VM PRTG was started by admin (Host: virtual5).
> 2014-03-31 13:53:58,350 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand]
> (DefaultQuartzScheduler_Worker-25) START, DestroyVDSCommand(HostName =
> virtual5, HostId = ee8c0f32-5129-48ec-b024-8ae83d5835eb,
> vmId=92fbccc5-1c99-4020-822b-74d43ad214c3, force=false, secondsToWait=0,
> gracefully=false), log id: 49a8c278
> 2014-03-31 13:53:58,370 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand]
> (DefaultQuartzScheduler_Worker-25) FINISH, DestroyVDSCommand, log id:
> 49a8c278
> 2014-03-31 13:53:58,433 INFO
> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
> (org.ovirt.thread.pool-6-thread-36) Domain
> b157f887-ae9a-4337-8c55-7c8a9df017bb:imagini recovered from problem. vds:
> virtual6
> 2014-03-31 13:53:58,436 INFO
> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
> (org.ovirt.thread.pool-6-thread-36) Domain
> b157f887-ae9a-4337-8c55-7c8a9df017bb:imagini has recovered from problem. No
> active host in the DC is reporting it as problematic, so clearing the domain
> recovery timer.
> 2014-03-31 13:53:58,445 INFO
> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
> (org.ovirt.thread.pool-6-thread-36) Domain
> 62f795ed-486c-443d-93e9-2c16595fe546:masini recovered from problem. vds:
> virtual6
> 2014-03-31 13:53:58,450 INFO
> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
> (org.ovirt.thread.pool-6-thread-36) Domain
> 62f795ed-486c-443d-93e9-2c16595fe546:masini has recovered from problem. No
> active host in the DC is reporting it as problematic, so clearing the domain
> recovery timer.
> 2014-03-31 13:53:58,454 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (DefaultQuartzScheduler_Worker-25) Correlation ID: null, Call Stack: null,
> Custom Event ID: -1, Message: VM PRTG is down. Exit message: 'int' object
> has no attribute 'replace'.
> 2014-03-31 13:53:58,460 INFO
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (DefaultQuartzScheduler_Worker-25) Running on vds during rerun failed vm:
> null
> 2014-03-31 13:53:58,463 INFO
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (DefaultQuartzScheduler_Worker-25) VM PRTG
> (92fbccc5-1c99-4020-822b-74d43ad214c3) is running in db and not running in
> VDS virtual5
> 2014-03-31 13:53:58,466 INFO
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (DefaultQuartzScheduler_Worker-25) add VM PRTG to HA rerun treatment
> 2014-03-31 13:53:58,475 ERROR
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (DefaultQuartzScheduler_Worker-25) Rerun vm
> 92fbccc5-1c99-4020-822b-74d43ad214c3. Called from vds virtual5
> 2014-03-31 13:53:58,482 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (org.ovirt.thread.pool-6-thread-19) Correlation ID: 787f133c, Job ID:
> e9bc3c5d-a16f-4cfc-ae35-340d153893b9, Call Stack: null, Custom Event ID: -1,
> Message: Failed to run VM PRTG on Host virtual5.
> 2014-03-31 13:53:58,501 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (org.ovirt.thread.pool-6-thread-19) Lock Acquired to object EngineLock
> [exclusiveLocks= key: 92fbccc5-1c99-4020-822b-74d43ad214c3 value: VM
> , sharedLocks= ]
> 2014-03-31 13:53:58,526 INFO
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand]
> (org.ovirt.thread.pool-6-thread-19) START, IsVmDuringInitiatingVDSCommand(
> vmId = 92fbccc5-1c99-4020-822b-74d43ad214c3), log id: 2b5bee5b
> 2014-03-31 13:53:58,532 INFO
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand]
> (org.ovirt.thread.pool-6-thread-19) FINISH, IsVmDuringInitiatingVDSCommand,
> return: false, log id: 2b5bee5b
> 2014-03-31 13:53:58,556 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (org.ovirt.thread.pool-6-thread-19) Running command: RunVmCommand internal:
> false. Entities affected : ID: 92fbccc5-1c99-4020-822b-74d43ad214c3 Type: VM
> 2014-03-31 13:53:58,589 INFO
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
> (org.ovirt.thread.pool-6-thread-19) START, CreateVmVDSCommand(HostName =
> virtual4, HostId = f4fc34ed-4261-46f1-ac5e-c849eb7e9b7a,
> vmId=92fbccc5-1c99-4020-822b-74d43ad214c3, vm=VM [PRTG]), log id: 5bfb709
> 2014-03-31 13:53:58,596 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> (org.ovirt.thread.pool-6-thread-19) START, CreateVDSCommand(HostName =
> virtual4, HostId = f4fc34ed-4261-46f1-ac5e-c849eb7e9b7a,
> vmId=92fbccc5-1c99-4020-822b-74d43ad214c3, vm=VM [PRTG]), log id: 2fa9cbb3
> 2014-03-31 13:53:58,887 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> (org.ovirt.thread.pool-6-thread-19)
> org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand
> spiceSslCipherSuite=DEFAULT,memSize=2048,kvmEnable=true,smp=1,vmType=kvm,emulatedMachine=pc-1.0,keyboardLayout=en-us,memGuaranteedSize=1365,nice=0,display=qxl,smartcardEnable=false,smpCoresPerSocket=1,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,timeOffset=3600,transparentHugePages=true,vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,devices=[{address={bus=0x00,
> domain=0x0000, slot=0x02, type=pci, function=0x0}, specParams={vram=32768,
> heads=1}, device=qxl, type=video,
> deviceId=e46018f8-fbfc-484d-891a-e7ade9f88c51}, {shared=false, bootOrder=2,
> iface=ide, index=2, address={unit=0, bus=1, target=0, controller=0,
> type=drive}, specParams={path=}, path=, device=cdrom, type=disk,
> readonly=true, deviceId=8eac07a3-d353-43db-b2e3-5f8fe414bdfe},
> {shared=false, index=0, volumeID=438299fb-0a72-4005-b0c8-5544eece6dba,
> propagateErrors=off, format=raw, type=disk, iface=virtio, bootOrder=1,
> address={bus=0x00, domain=0x0000, slot=0x06, type=pci, function=0x0},
> domainID=041e8dbe-f405-4aca-bb78-3bf3cc7dc190,
> imageID=68051a25-d3de-46b4-9e4b-686d824146bf, specParams={}, optional=false,
> device=disk, poolID=5849b030-626e-47cb-ad90-3ce782d831b3, readonly=false,
> deviceId=68051a25-d3de-46b4-9e4b-686d824146bf}, {nicModel=pv,
> address={bus=0x00, domain=0x0000, slot=0x03, type=pci, function=0x0},
> specParams={outbound={peak=26880, burst=256000, average=25600},
> inbound={peak=26880, burst=256000, average=25600}},
> macAddr=00:1a:4a:69:90:de, device=bridge, linkActive=true, type=interface,
> filter=vdsm-no-mac-spoofing, network=VPO_IPPROXY,
> deviceId=553de5f6-e108-4c45-84d2-7a292304211f}, {specParams={model=virtio},
> device=memballoon, type=balloon,
> deviceId=68c759aa-6266-432c-9b8b-7a4b215eee57}, {index=0, model=virtio-scsi,
> address={bus=0x00, domain=0x0000, slot=0x04, type=pci, function=0x0},
> specParams={}, device=scsi, type=controller,
> deviceId=fc27e446-7932-40e4-98bd-2d13237ed6f5}],acpiEnable=true,cpuShares=1024,vmName=PRTG,cpuType=Conroe,custom={device_ac3c9c1c-9d8d-4ced-ba59-977f54ccb9eedevice_804006d1-ed61-4c0e-9818-0d0f4f0e8e3cdevice_b6ac752a-13e2-4107-aa8e-ddc054551f15=VmDevice
> {vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,
> deviceId=b6ac752a-13e2-4107-aa8e-ddc054551f15, device=unix, type=CHANNEL,
> bootOrder=0, specParams={}, address={port=1, bus=0, controller=0,
> type=virtio-serial}, managed=false, plugged=true, readOnly=false,
> deviceAlias=channel0, customProperties={}, snapshotId=null},
> device_ac3c9c1c-9d8d-4ced-ba59-977f54ccb9eedevice_804006d1-ed61-4c0e-9818-0d0f4f0e8e3cdevice_b6ac752a-13e2-4107-aa8e-ddc054551f15device_83ffb451-8ba0-4b56-8082-b243b793d83e=VmDevice
> {vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,
> deviceId=83ffb451-8ba0-4b56-8082-b243b793d83e, device=unix, type=CHANNEL,
> bootOrder=0, specParams={}, address={port=2, bus=0, controller=0,
> type=virtio-serial}, managed=false, plugged=true, readOnly=false,
> deviceAlias=channel1, customProperties={}, snapshotId=null},
> device_ac3c9c1c-9d8d-4ced-ba59-977f54ccb9eedevice_804006d1-ed61-4c0e-9818-0d0f4f0e8e3cdevice_b6ac752a-13e2-4107-aa8e-ddc054551f15device_83ffb451-8ba0-4b56-8082-b243b793d83edevice_f8e59a5e-20a3-4a45-91bf-804ad60f9efb=VmDevice
> {vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,
> deviceId=f8e59a5e-20a3-4a45-91bf-804ad60f9efb, device=spicevmc,
> type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0,
> controller=0, type=virtio-serial}, managed=false, plugged=true,
> readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null},
> device_ac3c9c1c-9d8d-4ced-ba59-977f54ccb9ee=VmDevice
> {vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,
> deviceId=ac3c9c1c-9d8d-4ced-ba59-977f54ccb9ee, device=ide, type=CONTROLLER,
> bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci,
> slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false,
> deviceAlias=ide0, customProperties={}, snapshotId=null},
> device_ac3c9c1c-9d8d-4ced-ba59-977f54ccb9eedevice_804006d1-ed61-4c0e-9818-0d0f4f0e8e3c=VmDevice
> {vmId=92fbccc5-1c99-4020-822b-74d43ad214c3,
> deviceId=804006d1-ed61-4c0e-9818-0d0f4f0e8e3c, device=virtio-serial,
> type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00,
> domain=0x0000, type=pci, slot=0x05, function=0x0}, managed=false,
> plugged=true, readOnly=false, deviceAlias=virtio-serial0,
> customProperties={}, snapshotId=null}}
> 2014-03-31 13:53:58,936 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> (org.ovirt.thread.pool-6-thread-19) FINISH, CreateVDSCommand, log id:
> 2fa9cbb3
> 2014-03-31 13:53:58,943 INFO
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
> (org.ovirt.thread.pool-6-thread-19) FINISH, CreateVmVDSCommand, return:
> WaitForLaunch, log id: 5bfb709
> 2014-03-31 13:53:58,946 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (org.ovirt.thread.pool-6-thread-19) Lock freed to object EngineLock
> [exclusiveLocks= key: 92fbccc5-1c99-4020-822b-74d43ad214c3 value: VM
> , sharedLocks= ]
> 2014-03-31 13:53:58,952 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (org.ovirt.thread.pool-6-thread-19) Correlation ID: 787f133c, Job ID:
> e9bc3c5d-a16f-4cfc-ae35-340d153893b9, Call Stack: null, Custom Event ID: -1,
> Message: VM PRTG was started by admin (Host: virtual4).
> 2014-03-31 13:53:59,142 INFO
> [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand]
> (DefaultQuartzScheduler_Worker-26) START,
> GlusterVolumesListVDSCommand(HostName = virtual6, HostId =
> e11c37b0-d79d-417b-bd6f-6dc172f7921c), log id: 45331b03
> 2014-03-31 13:53:59,186 INFO
> [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand]
> (DefaultQuartzScheduler_Worker-26) FINISH, GlusterVolumesListVDSCommand,
> return:
> {3eb2a0de-c6f7-4ef8-a9fd-777d9e529adc=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@7ab347f8,
> a297bf18-e147-4792-b590-1f485732f8ee=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@237e1375},
> log id: 45331b03
> 2014-03-31 13:54:01,519 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand]
> (DefaultQuartzScheduler_Worker-32) START, DestroyVDSCommand(HostName =
> virtual4, HostId = f4fc34ed-4261-46f1-ac5e-c849eb7e9b7a,
> vmId=92fbccc5-1c99-4020-822b-74d43ad214c3, force=false, secondsToWait=0,
> gracefully=false), log id: 27d3bc97
> 2014-03-31 13:54:01,540 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand]
> (DefaultQuartzScheduler_Worker-32) FINISH, DestroyVDSCommand, log id:
> 27d3bc97
> 2014-03-31 13:54:01,561 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (DefaultQuartzScheduler_Worker-32) Correlation ID: null, Call Stack: null,
> Custom Event ID: -1, Message: VM PRTG is down. Exit message: 'int' object
> has no attribute 'replace'.
> 2014-03-31 13:54:01,565 INFO
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (DefaultQuartzScheduler_Worker-32) Running on vds during rerun failed vm:
> null
> 2014-03-31 13:54:01,568 INFO
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (DefaultQuartzScheduler_Worker-32) VM PRTG
> (92fbccc5-1c99-4020-822b-74d43ad214c3) is running in db and not running in
> VDS virtual4
> 2014-03-31 13:54:01,571 INFO
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (DefaultQuartzScheduler_Worker-32) add VM PRTG to HA rerun treatment
> 2014-03-31 13:54:01,579 ERROR
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (DefaultQuartzScheduler_Worker-32) Rerun vm
> 92fbccc5-1c99-4020-822b-74d43ad214c3. Called from vds virtual4
> 2014-03-31 13:54:01,587 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (org.ovirt.thread.pool-6-thread-14) Correlation ID: 787f133c, Job ID:
> e9bc3c5d-a16f-4cfc-ae35-340d153893b9, Call Stack: null, Custom Event ID: -1,
> Message: Failed to run VM PRTG on Host virtual4.
> 2014-03-31 13:54:01,605 INFO
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (org.ovirt.thread.pool-6-thread-14) Correlation ID: 787f133c, Job ID:
> e9bc3c5d-a16f-4cfc-ae35-340d153893b9, Call Stack: null, Custom Event ID: -1,
> Message: Failed to run VM PRTG (User: admin).
>
>
>
> On Mon, Mar 31, 2014 at 1:47 PM, Dan Kenigsberg < danken@redhat.com > wrote:
>
>
>
> On Mon, Mar 31, 2014 at 01:38:29PM +0300, Gabi C wrote:
> > Hello!
> >
> > 3.3.3 migrated to latest stable 3.4.0
> >
> > 3 nodes F19
> >
> > KVM Version:1.4.2 - 15.fc19
> > LIBVIRT Version:libvirt-1.0.5.9-1.fc19
> > VDSM Version:libvirt-1.0.5.9-1.fc19
> >
> > oVirt Engine Version: 3.4.0-1.fc19
> >
> >
> > Upgraded took place with 3 Vm up and 2 down: first upgraded engine,then
> > after freeing one node at a time node of and updating it.
> >
> >
> > After upgrade when I try to run any of the 2 powered down machines, I get
> > "VM ......... is down. Exit message: 'int' object has no attribute
> > 'replace'."
>
> Would you share an excerpt of your /var/log/vdsm/vdsm.log? Most
> interesting is the backtrace ending up with this error message.
>
>
> _______________________________________________
> Users mailing list
> Users@ovirt.org
> http://lists.ovirt.org/mailman/listinfo/users
>