[ovirt-users] usb redirection in native mode does not work in linked clones

Cristian Mammoli c.mammoli at apra.it
Mon Jul 27 15:35:45 UTC 2015


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 at 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 at 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 at 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 at 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 at 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 at 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 at 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





More information about the Users mailing list