Hi, linked clones with usb redirection in native mode does not start: engine error: VM TestPoolAuto-1 is down with error. Exit message: internal error: process exited while connecting to monitor: qemu-kvm: -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2: Duplicate ID 'usb' for device . engine.log: 2015-07-27 17:31:38,849 INFO [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-6) [8d12350] Lock Acquired to object EngineLock [exclusiveLocks= key: 6d6dddff-9b9f-4675-a5df-b932fa7f5181 value: VM , sharedLocks= ] 2015-07-27 17:31:38,885 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-6) [8d12350] START, IsVmDuringInitiatingVDSCommand( vmId = 6d6dddff-9b9f-4675-a5df-b932fa7f5181), log id: 2482c678 2015-07-27 17:31:38,888 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-6) [8d12350] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 2482c678 2015-07-27 17:31:38,967 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-26) [8d12350] Running command: RunVmCommand internal: false. Entities affected : ID: 6d6dddff-9b9f-4675-a5df-b932fa7f5181 Type: VMAction group VM_BASIC_OPERATIONS with role type USER 2015-07-27 17:31:38,994 INFO [org.ovirt.engine.core.bll.scheduling.policyunits.HaReservationWeightPolicyUnit] (org.ovirt.thread.pool-8-thread-26) [8d12350] Started HA reservation scoring method 2015-07-27 17:31:39,039 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-26) [8d12350] Running VM with attached cd it_windows_7_professional_with_sp1_vl_build_x64_dvd_u_677841.iso 2015-07-27 17:31:39,042 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-26) [8d12350] START, UpdateVmDynamicDataVDSCommand(HostName = kvm01, HostId = d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe, vmDynamic=org.ovirt.engine.core.common.businessentities.VmDynamic@57941d64), log id: 7f82ab20 2015-07-27 17:31:39,051 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-26) [8d12350] FINISH, UpdateVmDynamicDataVDSCommand, log id: 7f82ab20 2015-07-27 17:31:39,057 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (org.ovirt.thread.pool-8-thread-26) [8d12350] START, IsoPrefixVDSCommand(HostName = kvm01, HostId = d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe, storagePoolId=00000002-0002-0002-0002-00000000005e), log id: 2ecbcc6c 2015-07-27 17:31:39,066 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (org.ovirt.thread.pool-8-thread-26) [8d12350] FINISH, IsoPrefixVDSCommand, return: /rhev/data-center/mnt/192.168.18.101:_mnt_zpool01_zfs__nfs__01/66fe6211-6f52-492e-9b59-efbf09b2cb52/images/11111111-1111-1111-1111-111111111111, log id: 2ecbcc6c 2015-07-27 17:31:39,079 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-26) [8d12350] START, CreateVmVDSCommand(HostName = kvm01, HostId = d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe, vmId=6d6dddff-9b9f-4675-a5df-b932fa7f5181, vm=VM [TestPoolAuto-1]), log id: df22f34 2015-07-27 17:31:39,090 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-26) [8d12350] START, CreateVDSCommand(HostName = kvm01, HostId = d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe, vmId=6d6dddff-9b9f-4675-a5df-b932fa7f5181, vm=VM [TestPoolAuto-1]), log id: 70ee094a 2015-07-27 17:31:39,120 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-26) [8d12350] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand kvmEnable=true,keyboardLayout=en-us,nice=0,displayNetwork=ovirtmgmt,copyPasteEnable=true,timeOffset=7200,transparentHugePages=true,vmId=6d6dddff-9b9f-4675-a5df-b932fa7f5181,acpiEnable=true,custom={device_d7ef36ee-f7ad-4e8d-b53f-18bc4ee66ba0=VmDevice {vmId=6d6dddff-9b9f-4675-a5df-b932fa7f5181, deviceId=d7ef36ee-f7ad-4e8d-b53f-18bc4ee66ba0, device=usb, type=CONTROLLER, bootOrder=0, specParams={}, address={slot=0x01, bus=0x00, domain=0x0000, type=pci, function=0x2}, managed=false, plugged=true, readOnly=false, deviceAlias=, customProperties={}, snapshotId=null, logicalName=null}},spiceSslCipherSuite=DEFAULT,memSize=4096,smp=2,emulatedMachine=rhel6.5.0,vmType=kvm,memGuaranteedSize=1024,display=qxl,smartcardEnable=false,bootMenuEnable=false,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,smpCoresPerSocket=1,maxVCpus=16,hypervEnable=true,devices=[{index=0, model=ich9-ehci1, specParams={}, device=usb, type=controller, deviceId=8c556fea-3d3c-4dfe-9d1a-c2db1f8b0757}, {specParams={vram=32768, heads=1}, device=qxl, type=video, deviceId=dbd5530c-542b-4907-9369-e59aab5cc8dc}, {shared=false, bootOrder=2, iface=ide, index=2, address={unit=0, bus=1, target=0, controller=0, type=drive}, specParams={path=it_windows_7_professional_with_sp1_vl_build_x64_dvd_u_677841.iso}, path=/rhev/data-center/mnt/192.168.18.101:_mnt_zpool01_zfs__nfs__01/66fe6211-6f52-492e-9b59-efbf09b2cb52/images/11111111-1111-1111-1111-111111111111/it_windows_7_professional_with_sp1_vl_build_x64_dvd_u_677841.iso, device=cdrom, type=disk, readonly=true, deviceId=b5c5e147-22dc-48b6-9bc8-c4c61e17b252}, {shared=false, index=0, volumeID=49dbcbec-3d1f-4d83-b76d-66ec23198641, propagateErrors=off, format=cow, type=disk, iface=virtio, bootOrder=1, address={bus=0x00, domain=0x0000, type=pci, slot=0x07, function=0x0}, domainID=5f20ecf7-7d8d-4dab-857a-6eb1aa9b9842, imageID=4d35b208-dc27-4850-a0b9-72297628d82a, specParams={}, optional=false, device=disk, poolID=00000002-0002-0002-0002-00000000005e, readonly=false, deviceId=4d35b208-dc27-4850-a0b9-72297628d82a}, {nicModel=pv, address={bus=0x00, domain=0x0000, type=pci, slot=0x03, function=0x0}, specParams={outbound={}, inbound={}}, macAddr=00:01:a4:a3:96:0a, device=bridge, linkActive=true, type=interface, filter=vdsm-no-mac-spoofing, network=ovirtmgmt, deviceId=de7ea263-e827-4e7d-b568-9963ce773777}, {address={bus=0x00, domain=0x0000, type=pci, slot=0x04, function=0x0}, specParams={}, device=ich6, type=sound, deviceId=8e75a71c-ff1c-49da-b79e-dbda01c01900}, {index=0, model=ich9-uhci3, specParams={}, device=usb, type=controller, deviceId=bce30bbc-a868-4138-ac8a-0baabb037d84}, {index=0, model=ich9-uhci2, specParams={}, device=usb, type=controller, deviceId=cb61c6a3-5b83-4a8d-b580-eb5d66aa0517}, {address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x2}, specParams={}, device=usb, type=controller, deviceId=d7ef36ee-f7ad-4e8d-b53f-18bc4ee66ba0}, {index=0, model=ich9-uhci1, specParams={}, device=usb, type=controller, deviceId=49903b9e-35a4-4044-a9e1-3bd1cf3bcf30}, {bus=usb, specParams={}, device=spicevmc, type=redir, deviceId=87c24afa-e85c-48dd-a611-8b5c3147c433}, {bus=usb, specParams={}, device=spicevmc, type=redir, deviceId=f385013f-a124-490e-97cb-6aa03d468773}, {bus=usb, specParams={}, device=spicevmc, type=redir, deviceId=2136c7f2-6c3e-47e4-9fcb-fa0a6f9939aa}, {bus=usb, specParams={}, device=spicevmc, type=redir, deviceId=4ba33476-2fd9-4685-9b8b-cb4d325b7155}, {index=0, model=virtio-scsi, address={bus=0x00, domain=0x0000, type=pci, slot=0x05, function=0x0}, specParams={}, device=scsi, type=controller, deviceId=d34e9c5f-549e-49b1-8569-7010b40beb0c}, {address={bus=0x00, domain=0x0000, type=pci, slot=0x06, function=0x0}, specParams={}, device=virtio-serial, type=controller, deviceId=3e360c6f-26b3-46f9-99e3-6d3726f8fdbc}],vmName=TestPoolAuto-1,cpuType=Conroe,fileTransferEnable=true 2015-07-27 17:31:39,245 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-26) [8d12350] FINISH, CreateVDSCommand, log id: 70ee094a 2015-07-27 17:31:39,261 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-26) [8d12350] FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: df22f34 2015-07-27 17:31:39,267 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-26) [8d12350] Lock freed to object EngineLock [exclusiveLocks= key: 6d6dddff-9b9f-4675-a5df-b932fa7f5181 value: VM , sharedLocks= ] 2015-07-27 17:31:39,286 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-26) [8d12350] Correlation ID: 8d12350, Job ID: 10031639-2593-49f3-9c9f-5b3db8c998ac, Call Stack: null, Custom Event ID: -1, Message: VM TestPoolAuto-1 was started by admin@internal (Host: kvm01). 2015-07-27 17:31:44,233 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (DefaultQuartzScheduler_Worker-20) [30539cc] START, DestroyVDSCommand(HostName = kvm01, HostId = d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe, vmId=6d6dddff-9b9f-4675-a5df-b932fa7f5181, force=false, secondsToWait=0, gracefully=false, reason=), log id: 19140c59 2015-07-27 17:31:44,703 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (DefaultQuartzScheduler_Worker-20) [30539cc] FINISH, DestroyVDSCommand, log id: 19140c59 2015-07-27 17:31:44,716 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-20) [30539cc] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM TestPoolAuto-1 is down with error. Exit message: internal error: process exited while connecting to monitor: qemu-kvm: -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2: Duplicate ID 'usb' for device . 2015-07-27 17:31:44,719 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-20) [30539cc] Running on vds during rerun failed vm: null 2015-07-27 17:31:44,726 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-20) [30539cc] VM TestPoolAuto-1 (6d6dddff-9b9f-4675-a5df-b932fa7f5181) is running in db and not running in VDS kvm01 2015-07-27 17:31:44,766 ERROR [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-20) [30539cc] Rerun vm 6d6dddff-9b9f-4675-a5df-b932fa7f5181. Called from vds kvm01 2015-07-27 17:31:44,779 WARN [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-15) [30539cc] Correlation ID: 8d12350, Job ID: 10031639-2593-49f3-9c9f-5b3db8c998ac, Call Stack: null, Custom Event ID: -1, Message: Failed to run VM TestPoolAuto-1 on Host kvm01. 2015-07-27 17:31:44,789 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-15) [30539cc] Lock Acquired to object EngineLock [exclusiveLocks= key: 6d6dddff-9b9f-4675-a5df-b932fa7f5181 value: VM , sharedLocks= ] 2015-07-27 17:31:44,860 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-8-thread-15) [30539cc] START, IsVmDuringInitiatingVDSCommand( vmId = 6d6dddff-9b9f-4675-a5df-b932fa7f5181), log id: 1878f455 2015-07-27 17:31:44,867 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-8-thread-15) [30539cc] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 1878f455 2015-07-27 17:31:44,912 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-15) [30539cc] Running command: RunVmCommand internal: false. Entities affected : ID: 6d6dddff-9b9f-4675-a5df-b932fa7f5181 Type: VMAction group VM_BASIC_OPERATIONS with role type USER 2015-07-27 17:31:44,955 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-15) [30539cc] Running VM with attached cd it_windows_7_professional_with_sp1_vl_build_x64_dvd_u_677841.iso 2015-07-27 17:31:44,958 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-15) [30539cc] START, UpdateVmDynamicDataVDSCommand(HostName = kvm02, HostId = 4aeb8095-1198-4afe-aab2-d9c6408c88c2, vmDynamic=org.ovirt.engine.core.common.businessentities.VmDynamic@5ee9414d), log id: 75db7c56 2015-07-27 17:31:44,964 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-15) [30539cc] FINISH, UpdateVmDynamicDataVDSCommand, log id: 75db7c56 2015-07-27 17:31:44,972 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (org.ovirt.thread.pool-8-thread-15) [30539cc] START, IsoPrefixVDSCommand(HostName = kvm02, HostId = 4aeb8095-1198-4afe-aab2-d9c6408c88c2, storagePoolId=00000002-0002-0002-0002-00000000005e), log id: 2762047d 2015-07-27 17:31:44,981 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (org.ovirt.thread.pool-8-thread-15) [30539cc] FINISH, IsoPrefixVDSCommand, return: /rhev/data-center/mnt/192.168.18.101:_mnt_zpool01_zfs__nfs__01/66fe6211-6f52-492e-9b59-efbf09b2cb52/images/11111111-1111-1111-1111-111111111111, log id: 2762047d 2015-07-27 17:31:44,995 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-15) [30539cc] START, CreateVmVDSCommand(HostName = kvm02, HostId = 4aeb8095-1198-4afe-aab2-d9c6408c88c2, vmId=6d6dddff-9b9f-4675-a5df-b932fa7f5181, vm=VM [TestPoolAuto-1]), log id: 787773d8 2015-07-27 17:31:45,007 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-15) [30539cc] START, CreateVDSCommand(HostName = kvm02, HostId = 4aeb8095-1198-4afe-aab2-d9c6408c88c2, vmId=6d6dddff-9b9f-4675-a5df-b932fa7f5181, vm=VM [TestPoolAuto-1]), log id: 28b6a2c4 2015-07-27 17:31:45,035 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-15) [30539cc] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand kvmEnable=true,keyboardLayout=en-us,nice=0,displayNetwork=ovirtmgmt,copyPasteEnable=true,timeOffset=7200,transparentHugePages=true,vmId=6d6dddff-9b9f-4675-a5df-b932fa7f5181,acpiEnable=true,custom={device_d7ef36ee-f7ad-4e8d-b53f-18bc4ee66ba0=VmDevice {vmId=6d6dddff-9b9f-4675-a5df-b932fa7f5181, deviceId=d7ef36ee-f7ad-4e8d-b53f-18bc4ee66ba0, device=usb, type=CONTROLLER, bootOrder=0, specParams={}, address={slot=0x01, bus=0x00, domain=0x0000, type=pci, function=0x2}, managed=false, plugged=true, readOnly=false, deviceAlias=, customProperties={}, snapshotId=null, logicalName=null}},spiceSslCipherSuite=DEFAULT,memSize=4096,smp=2,emulatedMachine=rhel6.5.0,vmType=kvm,memGuaranteedSize=1024,display=qxl,smartcardEnable=false,bootMenuEnable=false,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,smpCoresPerSocket=1,maxVCpus=16,hypervEnable=true,devices=[{index=0, model=ich9-ehci1, specParams={}, device=usb, type=controller, deviceId=8c556fea-3d3c-4dfe-9d1a-c2db1f8b0757}, {specParams={vram=32768, heads=1}, device=qxl, type=video, deviceId=dbd5530c-542b-4907-9369-e59aab5cc8dc}, {shared=false, bootOrder=2, iface=ide, index=2, address={unit=0, bus=1, target=0, controller=0, type=drive}, specParams={path=it_windows_7_professional_with_sp1_vl_build_x64_dvd_u_677841.iso}, path=/rhev/data-center/mnt/192.168.18.101:_mnt_zpool01_zfs__nfs__01/66fe6211-6f52-492e-9b59-efbf09b2cb52/images/11111111-1111-1111-1111-111111111111/it_windows_7_professional_with_sp1_vl_build_x64_dvd_u_677841.iso, device=cdrom, type=disk, readonly=true, deviceId=b5c5e147-22dc-48b6-9bc8-c4c61e17b252}, {shared=false, index=0, volumeID=49dbcbec-3d1f-4d83-b76d-66ec23198641, propagateErrors=off, format=cow, type=disk, iface=virtio, bootOrder=1, address={bus=0x00, domain=0x0000, type=pci, slot=0x07, function=0x0}, domainID=5f20ecf7-7d8d-4dab-857a-6eb1aa9b9842, imageID=4d35b208-dc27-4850-a0b9-72297628d82a, specParams={}, optional=false, device=disk, poolID=00000002-0002-0002-0002-00000000005e, readonly=false, deviceId=4d35b208-dc27-4850-a0b9-72297628d82a}, {nicModel=pv, address={bus=0x00, domain=0x0000, type=pci, slot=0x03, function=0x0}, specParams={outbound={}, inbound={}}, macAddr=00:01:a4:a3:96:0a, device=bridge, linkActive=true, type=interface, filter=vdsm-no-mac-spoofing, network=ovirtmgmt, deviceId=de7ea263-e827-4e7d-b568-9963ce773777}, {address={bus=0x00, domain=0x0000, type=pci, slot=0x04, function=0x0}, specParams={}, device=ich6, type=sound, deviceId=8e75a71c-ff1c-49da-b79e-dbda01c01900}, {index=0, model=ich9-uhci3, specParams={}, device=usb, type=controller, deviceId=bce30bbc-a868-4138-ac8a-0baabb037d84}, {index=0, model=ich9-uhci2, specParams={}, device=usb, type=controller, deviceId=cb61c6a3-5b83-4a8d-b580-eb5d66aa0517}, {address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x2}, specParams={}, device=usb, type=controller, deviceId=d7ef36ee-f7ad-4e8d-b53f-18bc4ee66ba0}, {index=0, model=ich9-uhci1, specParams={}, device=usb, type=controller, deviceId=49903b9e-35a4-4044-a9e1-3bd1cf3bcf30}, {bus=usb, specParams={}, device=spicevmc, type=redir, deviceId=87c24afa-e85c-48dd-a611-8b5c3147c433}, {bus=usb, specParams={}, device=spicevmc, type=redir, deviceId=f385013f-a124-490e-97cb-6aa03d468773}, {bus=usb, specParams={}, device=spicevmc, type=redir, deviceId=2136c7f2-6c3e-47e4-9fcb-fa0a6f9939aa}, {bus=usb, specParams={}, device=spicevmc, type=redir, deviceId=4ba33476-2fd9-4685-9b8b-cb4d325b7155}, {index=0, model=virtio-scsi, address={bus=0x00, domain=0x0000, type=pci, slot=0x05, function=0x0}, specParams={}, device=scsi, type=controller, deviceId=d34e9c5f-549e-49b1-8569-7010b40beb0c}, {address={bus=0x00, domain=0x0000, type=pci, slot=0x06, function=0x0}, specParams={}, device=virtio-serial, type=controller, deviceId=3e360c6f-26b3-46f9-99e3-6d3726f8fdbc}],vmName=TestPoolAuto-1,cpuType=Conroe,fileTransferEnable=true 2015-07-27 17:31:45,224 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-15) [30539cc] FINISH, CreateVDSCommand, log id: 28b6a2c4 2015-07-27 17:31:45,235 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-15) [30539cc] FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 787773d8 2015-07-27 17:31:45,236 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-15) [30539cc] Lock freed to object EngineLock [exclusiveLocks= key: 6d6dddff-9b9f-4675-a5df-b932fa7f5181 value: VM , sharedLocks= ] 2015-07-27 17:31:45,263 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-15) [30539cc] Correlation ID: 8d12350, Job ID: 10031639-2593-49f3-9c9f-5b3db8c998ac, Call Stack: null, Custom Event ID: -1, Message: VM TestPoolAuto-1 was started by admin@internal (Host: kvm02). 2015-07-27 17:31:52,968 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (DefaultQuartzScheduler_Worker-2) START, DestroyVDSCommand(HostName = kvm02, HostId = 4aeb8095-1198-4afe-aab2-d9c6408c88c2, vmId=6d6dddff-9b9f-4675-a5df-b932fa7f5181, force=false, secondsToWait=0, gracefully=false, reason=), log id: 4f97fd6f 2015-07-27 17:31:53,315 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (DefaultQuartzScheduler_Worker-2) FINISH, DestroyVDSCommand, log id: 4f97fd6f 2015-07-27 17:31:53,330 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-2) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM TestPoolAuto-1 is down with error. Exit message: internal error: process exited while connecting to monitor: qemu-kvm: -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2: Duplicate ID 'usb' for device . 2015-07-27 17:31:53,332 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-2) Running on vds during rerun failed vm: null 2015-07-27 17:31:53,335 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-2) VM TestPoolAuto-1 (6d6dddff-9b9f-4675-a5df-b932fa7f5181) is running in db and not running in VDS kvm02 2015-07-27 17:31:53,346 ERROR [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-2) Rerun vm 6d6dddff-9b9f-4675-a5df-b932fa7f5181. Called from vds kvm02 2015-07-27 17:31:53,361 WARN [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-29) Correlation ID: 8d12350, Job ID: 10031639-2593-49f3-9c9f-5b3db8c998ac, Call Stack: null, Custom Event ID: -1, Message: Failed to run VM TestPoolAuto-1 on Host kvm02. 2015-07-27 17:31:53,375 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-29) Lock Acquired to object EngineLock [exclusiveLocks= key: 6d6dddff-9b9f-4675-a5df-b932fa7f5181 value: VM , sharedLocks= ] 2015-07-27 17:31:53,404 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-8-thread-29) START, IsVmDuringInitiatingVDSCommand( vmId = 6d6dddff-9b9f-4675-a5df-b932fa7f5181), log id: 38b9da17 2015-07-27 17:31:53,411 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-8-thread-29) FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 38b9da17 2015-07-27 17:31:53,428 WARN [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-29) CanDoAction of action RunVm failed for user admin@internal. Reasons: VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,SCHEDULING_NO_HOSTS 2015-07-27 17:31:53,438 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-29) Lock freed to object EngineLock [exclusiveLocks= key: 6d6dddff-9b9f-4675-a5df-b932fa7f5181 value: VM , sharedLocks= ] 2015-07-27 17:31:53,478 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-29) Correlation ID: 8d12350, Job ID: 10031639-2593-49f3-9c9f-5b3db8c998ac, Call Stack: null, Custom Event ID: -1, Message: Failed to run VM TestPoolAuto-1 (User: admin@internal). 2015-07-27 17:31:53,492 INFO [org.ovirt.engine.core.bll.ProcessDownVmCommand] (org.ovirt.thread.pool-8-thread-20) [18c68eb4] Running command: ProcessDownVmCommand internal: true. 2015-07-27 17:31:53,498 INFO [org.ovirt.engine.core.bll.RestoreStatelessVmCommand] (org.ovirt.thread.pool-8-thread-20) [76fde751] Running command: RestoreStatelessVmCommand internal: true. Entities affected : ID: 6d6dddff-9b9f-4675-a5df-b932fa7f5181 Type: VM 2015-07-27 17:31:53,511 INFO [org.ovirt.engine.core.bll.UpdateVmVersionCommand] (org.ovirt.thread.pool-8-thread-20) [3b023b93] Lock Acquired to object EngineLock [exclusiveLocks= key: 6d6dddff-9b9f-4675-a5df-b932fa7f5181 value: VM , sharedLocks= key: 2b474919-6a63-4387-8394-a76af360b9b2 value: TEMPLATE ] 2015-07-27 17:31:53,517 WARN [org.ovirt.engine.core.bll.UpdateVmVersionCommand] (org.ovirt.thread.pool-8-thread-20) [3b023b93] CanDoAction of action UpdateVmVersion failed for user admin@internal. Reasons: VAR__ACTION__UPDATE_VM_VERSION,VAR__TYPE__VM,ACTION_TYPE_FAILED_VM_ALREADY_IN_LATEST_VERSION 2015-07-27 17:31:53,519 INFO [org.ovirt.engine.core.bll.UpdateVmVersionCommand] (org.ovirt.thread.pool-8-thread-20) [3b023b93] Lock freed to object EngineLock [exclusiveLocks= key: 6d6dddff-9b9f-4675-a5df-b932fa7f5181 value: VM , sharedLocks= key: 2b474919-6a63-4387-8394-a76af360b9b2 value: TEMPLATE ] 2015-07-27 17:31:53,520 WARN [org.ovirt.engine.core.bll.RestoreStatelessVmCommand] (org.ovirt.thread.pool-8-thread-20) [3b023b93] Couldnt update VM TestPoolAuto-1 (6d6dddff-9b9f-4675-a5df-b932fa7f5181) version from its template, continue with restoring stateless snapshot. Host log: 2015-07-27 15:33:15.517+0000: starting up LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin QEMU_AUDIO_DRV=spice /usr/libexec/qemu-kvm -name TestPoolAuto-1 -S -machine rhel6.5.0,accel=kvm,usb=off -cpu Conroe,hv_relaxed -m 4096 -realtime mlock=off -smp 2,maxcpus=16,sockets=16,cores=1,threads=1 -uuid 6d6dddff-9b9f-4675-a5df-b932fa7f5181 -smbios type=1,manufacturer=oVirt,product=oVirt Node,version=3.5-0.999.201504280931.el7.centos,serial=C0B14ED1-183E-B601-C2DC-00145E1623F4,uuid=6d6dddff-9b9f-4675-a5df-b932fa7f5181 -no-user-config -nodefaults -chardev socket,id=charmonitor,path=/var/lib/libvirt/qemu/TestPoolAuto-1.monitor,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=2015-07-27T17:33:15,clock=vm,driftfix=slew -global kvm-pit.lost_tick_policy=discard -no-hpet -no-shutdown -boot strict=on -device ich9-usb-ehci1,id=usb,bus=pci.0,addr=0x8.0x7 -device ich9-usb-uhci3,masterbus=usb.0,firstport=4,bus=pci.0,addr=0x8.0x2 -device ich9-usb-uhci2,masterbus=usb.0,firstport=2,bus=pci.0,addr=0x8.0x1 -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -device ich9-usb-uhci1,masterbus=usb.0,firstport=0,bus=pci.0,multifunction=on,addr=0x8 -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x5 -device virtio-serial-pci,id=virtio-serial0,max_ports=16,bus=pci.0,addr=0x6 -drive file=/rhev/data-center/mnt/192.168.18.101:_mnt_zpool01_zfs__nfs__01/66fe6211-6f52-492e-9b59-efbf09b2cb52/images/11111111-1111-1111-1111-111111111111/it_windows_7_professional_with_sp1_vl_build_x64_dvd_u_677841.iso,if=none,id=drive-ide0-1-0,readonly=on,format=raw,serial= -device ide-cd,bus=ide.1,unit=0,drive=drive-ide0-1-0,id=ide0-1-0,bootindex=2 -drive file=/rhev/data-center/00000002-0002-0002-0002-00000000005e/5f20ecf7-7d8d-4dab-857a-6eb1aa9b9842/images/4d35b208-dc27-4850-a0b9-72297628d82a/49dbcbec-3d1f-4d83-b76d-66ec23198641,if=none,id=drive-virtio-disk0,format=qcow2,serial=4d35b208-dc27-4850-a0b9-72297628d82a,cache=none,werror=stop,rerror=stop,aio=native -device virtio-blk-pci,scsi=off,bus=pci.0,addr=0x7,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,fd=31,id=hostnet0,vhost=on,vhostfd=32 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=00:01:a4:a3:96:0a,bus=pci.0,addr=0x3 -chardev socket,id=charchannel0,path=/var/lib/libvirt/qemu/channels/6d6dddff-9b9f-4675-a5df-b932fa7f5181.com.redhat.rhevm.vdsm,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=com.redhat.rhevm.vdsm -chardev socket,id=charchannel1,path=/var/lib/libvirt/qemu/channels/6d6dddff-9b9f-4675-a5df-b932fa7f5181.org.qemu.guest_agent.0,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=2,chardev=charchannel1,id=channel1,name=org.qemu.guest_agent.0 -chardev spicevmc,id=charchannel2,name=vdagent -device virtserialport,bus=virtio-serial0.0,nr=3,chardev=charchannel2,id=channel2,name=com.redhat.spice.0 -spice tls-port=5902,addr=192.168.0.55,x509-dir=/etc/pki/vdsm/libvirt-spice,tls-channel=main,tls-channel=display,tls-channel=inputs,tls-channel=cursor,tls-channel=playback,tls-channel=record,tls-channel=smartcard,tls-channel=usbredir,seamless-migration=on -k en-us -vga qxl -global qxl-vga.ram_size=67108864 -global qxl-vga.vram_size=33554432 -global qxl-vga.vgamem_mb=16 -device intel-hda,id=sound0,bus=pci.0,addr=0x4 -device hda-duplex,id=sound0-codec0,bus=sound0.0,cad=0 -chardev spicevmc,id=charredir0,name=usbredir -device usb-redir,chardev=charredir0,id=redir0 -chardev spicevmc,id=charredir1,name=usbredir -device usb-redir,chardev=charredir1,id=redir1 -chardev spicevmc,id=charredir2,name=usbredir -device usb-redir,chardev=charredir2,id=redir2 -chardev spicevmc,id=charredir3,name=usbredir -device usb-redir,chardev=charredir3,id=redir3 -msg timestamp=on qemu-kvm: -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2: Duplicate ID 'usb' for device 2015-07-27 15:33:15.948+0000: shutting down