hi,
I have a problem with ovirt 3.6.
When I click on the button "run" to start vm, it not start and terminate
immediatly.
This is the error in the admin portale:
VM ubuexp is down with error. Exit message: internal error: process
exited while connecting to monitor: 2016-04-18T08:18:22.499782Z
qemu-kvm: -drive
file=/rhev/data-center/00000001-0001-0001-0001-00000000037d/88dfff37-4ad5-446c-a957-1cf67829c9a6/images/da93350c-8926-42bf-99fa-8a7aca043fcd/22e7803d-e266-4e3e-ae34-0181f8acef8b,if=none,id=drive-virtio-disk0,format=qcow2,serial=da93350c-8926-42bf-99fa-8a7aca043fcd,cache=none,werror=stop,rerror=stop,aio=native:
Could not open
'/rhev/data-center/00000001-0001-0001-0001-00000000037d/88dfff37-4ad5-446c-a957-1cf67829c9a6/images/da93350c-8926-42bf-99fa-8a7aca043fcd/22e7803d-e266-4e3e-ae34-0181f8acef8b':
Permission denied
.
My ovirt installation is composed of thefollowing:
- 1 manager (virtualized)
- 1 host
- storage iscsi
Everything seems to work well from the web administration portal, but
all vm do not start.
I attach a log file.
Please help me!
Nick
2016-04-18 08:26:51,102 INFO [org.ovirt.engine.docs.utils.servlet.ContextSensitiveHelpMappingServlet] (default task-17) [] Context-sensitive help is not installed. Manual directory doesn't exist: /usr/share/ovirt-engine/manual
2016-04-18 08:27:38,035 INFO [org.ovirt.engine.extension.aaa.jdbc.core.Tasks] (default task-20) [] (house keeping) deleting failed logins prior to 2016-04-11 06:27:38Z.
2016-04-18 08:27:38,082 INFO [org.ovirt.engine.extension.aaa.jdbc.core.Tasks] (default task-20) [] (house keeping) deleting failed logins prior to 2016-04-11 06:27:38Z.
2016-04-18 08:27:38,174 INFO [org.ovirt.engine.core.bll.aaa.LoginAdminUserCommand] (default task-20) [] Running command: LoginAdminUserCommand internal: false.
2016-04-18 08:27:38,189 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-20) [] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin@internal logged in.
2016-04-18 08:27:53,935 INFO [org.ovirt.engine.core.bll.RunVmCommand] (default task-46) [7960fc9] Lock Acquired to object 'EngineLock:{exclusiveLocks='[f6f199d5-f808-447a-bff2-6109eb2c9439=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sha
redLocks='null'}'
2016-04-18 08:27:54,006 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (default task-46) [7960fc9] START, IsVmDuringInitiatingVDSCommand( IsVmDuringInitiatingVDSCommandParameters:{runAsync='true', vmId='f6f199d5
-f808-447a-bff2-6109eb2c9439'}), log id: 71df70c1
2016-04-18 08:27:54,006 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (default task-46) [7960fc9] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 71df70c1
2016-04-18 08:27:54,055 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-42) [7960fc9] Running command: RunVmCommand internal: false. Entities affected : ID: f6f199d5-f808-447a-bff2-6109eb2c9439 Type: VMA
ction group RUN_VM with role type USER
2016-04-18 08:27:54,083 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-42) [7960fc9] START, UpdateVmDynamicDataVDSCommand( UpdateVmDynamicDataVDSCommandParameters:{runAsync='true',
hostId='null', vmId='00000000-0000-0000-0000-000000000000', vmDynamic='org.ovirt.engine.core.common.businessentities.VmDynamic@e46bf4ae'}), log id: 7ef6f688
2016-04-18 08:27:54,090 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-42) [7960fc9] FINISH, UpdateVmDynamicDataVDSCommand, log id: 7ef6f688
2016-04-18 08:27:54,092 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-42) [7960fc9] START, CreateVmVDSCommand( CreateVmVDSCommandParameters:{runAsync='true', hostId='7b383276-2183-4fdd-94ec-
2ff27c03c79b', vmId='f6f199d5-f808-447a-bff2-6109eb2c9439', vm='VM [ubuexp]'}), log id: 32cadda7
2016-04-18 08:27:54,095 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-42) [7960fc9] START, CreateVDSCommand(HostName = h1o.polito.it, CreateVmVDSCommandParameters:{runAsync='true', h
ostId='7b383276-2183-4fdd-94ec-2ff27c03c79b', vmId='f6f199d5-f808-447a-bff2-6109eb2c9439', vm='VM [ubuexp]'}), log id: 12f140c0
2016-04-18 08:27:54,100 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmInfoBuilderBase] (org.ovirt.thread.pool-8-thread-42) [7960fc9] Bootable disk 'da93350c-8926-42bf-99fa-8a7aca043fcd' set to index '0'
2016-04-18 08:27:54,115 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-42) [7960fc9] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand pitReinjection=false,memGuaranteedSize=
1014,smpThreadsPerCore=1,cpuType=Westmere,vmId=f6f199d5-f808-447a-bff2-6109eb2c9439,acpiEnable=true,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,vmType=kvm,keyboardLayout=en-us,smp=2,smpCore
sPerSocket=2,emulatedMachine=pc-i440fx-rhel7.2.0,smartcardEnable=false,fileTransferEnable=true,guestNumaNodes=[{memory=2028, cpus=0,1, nodeIndex=0}],transparentHugePages=true,vmName=ubuexp,maxVCpus=32,kvmEnable=true,devices=[{address={
bus=0x00, domain=0x0000, function=0x7, slot=0x05, type=pci}, index=0, model=ich9-ehci1, type=controller, specParams={}, device=usb, deviceId=1e675706-bc9c-46c0-9b07-e378f8b48259}, {address={bus=0x00, domain=0x0000, function=0x0, slot=0
x02, type=pci}, type=video, specParams={vgamem=16384, heads=1, ram=65536, vram=8192}, device=qxl, deviceId=353ffb3c-60a8-4972-b353-09c8f3cb271a}, {type=graphics, specParams={fileTransferEnable=true, copyPasteEnable=true}, device=spice,
deviceId=4672e3ff-bd8c-4bb1-a732-87ce7fb7345e}, {iface=ide, shared=false, path=, address={bus=1, controller=0, unit=0, type=drive, target=0}, readonly=true, index=2, type=disk, specParams={path=}, device=cdrom, deviceId=d7fd72f7-906a-
45cf-bb9e-e3b9c360e6b9}, {shared=false, address={bus=0x00, domain=0x0000, function=0x0, slot=0x07, type=pci}, imageID=da93350c-8926-42bf-99fa-8a7aca043fcd, format=cow, index=0, optional=false, type=disk, deviceId=da93350c-8926-42bf-99f
a-8a7aca043fcd, domainID=88dfff37-4ad5-446c-a957-1cf67829c9a6, propagateErrors=off, iface=virtio, readonly=false, bootOrder=1, poolID=00000001-0001-0001-0001-00000000037d, volumeID=22e7803d-e266-4e3e-ae34-0181f8acef8b, specParams={}, d
evice=disk}, {filter=vdsm-no-mac-spoofing, nicModel=pv, address={bus=0x00, domain=0x0000, function=0x0, slot=0x03, type=pci}, type=interface, specParams={inbound={}, outbound={}}, device=bridge, linkActive=true, deviceId=41373990-2b13-
49d3-8d10-044b7a72bffa, macAddr=00:1a:4a:16:01:54, network=ovirtmgmt}, {address={bus=0x00, domain=0x0000, function=0x1, slot=0x05, type=pci}, index=0, model=ich9-uhci2, type=controller, specParams={}, device=usb, deviceId=2ed4923e-9b1b
-4a13-bfea-4dfb97b08c0a}, {address={bus=0x00, domain=0x0000, function=0x2, slot=0x05, type=pci}, index=0, model=ich9-uhci3, type=controller, specParams={}, device=usb, deviceId=5b6cd3df-a8f9-4c5c-80ee-5b5d3e30624e}, {address={bus=0x00,
function=0x0, domain=0x0000, slot=0x05, type=pci, multifunction=on}, index=0, model=ich9-uhci1, type=controller, specParams={}, device=usb, deviceId=79096162-f47e-49b2-b6d7-64b15e20b1f9}, {bus=usb, type=redir, specParams={}, device=sp
icevmc, deviceId=866350fc-648e-4aba-a6b2-e9fe1541cea6}, {bus=usb, type=redir, specParams={}, device=spicevmc, deviceId=4ef81515-5a3a-4227-9b1f-16ea0811d173}, {bus=usb, type=redir, specParams={}, device=spicevmc, deviceId=5e45da86-2b1d-
4afe-b77b-604f57033034}, {bus=usb, type=redir, specParams={}, device=spicevmc, deviceId=02079c4b-e598-49b7-ad18-14a80dafed5e}, {address={bus=0x00, function=0x0, domain=0x0000, slot=0x08, type=pci}, type=balloon, specParams={model=virti
o}, device=memballoon, deviceId=179422ed-4069-4101-a81f-824f5551d48c}, {address={bus=0x00, domain=0x0000, function=0x0, slot=0x04, type=pci}, index=0, model=virtio-scsi, type=controller, specParams={}, device=scsi, deviceId=0741a4db-09
79-4650-a01f-0032bfc571c7}, {address={bus=0x00, domain=0x0000, function=0x0, slot=0x06, type=pci}, type=controller, specParams={}, device=virtio-serial, deviceId=a65a4aa6-55b1-4603-b970-ce3839af34ef}],custom={device_b065d6bc-5396-4609-
a9aa-f11cc905af8bdevice_88d6bc1a-0595-4dc7-a7d6-fd70c3294227=VmDevice:{id='VmDeviceId:{deviceId='88d6bc1a-0595-4dc7-a7d6-fd70c3294227', vmId='f6f199d5-f808-447a-bff2-6109eb2c9439'}', device='unix', type='CHANNEL', bootOrder='0', specPa
rams='[]', address='{bus=0, controller=0, type=virtio-serial, port=1}', managed='false', plugged='true', readOnly='false', deviceAlias='channel0', customProperties='[]', snapshotId='null', logicalName='null', usingScsiReservation='fals
e'}, device_b065d6bc-5396-4609-a9aa-f11cc905af8bdevice_88d6bc1a-0595-4dc7-a7d6-fd70c3294227device_23ec0612-0a0a-48f2-8303-9f38b6a4d128device_a1a14019-637b-4584-93e5-b505e0dfab25=VmDevice:{id='VmDeviceId:{deviceId='a1a14019-637b-4584-93
e5-b505e0dfab25', vmId='f6f199d5-f808-447a-bff2-6109eb2c9439'}', device='spicevmc', type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0, controller=0, type=virtio-serial, port=3}', managed='false', plugged='true', readOnly=
'false', deviceAlias='channel2', customProperties='[]', snapshotId='null', logicalName='null', usingScsiReservation='false'}, device_b065d6bc-5396-4609-a9aa-f11cc905af8b=VmDevice:{id='VmDeviceId:{deviceId='b065d6bc-5396-4609-a9aa-f11cc
905af8b', vmId='f6f199d5-f808-447a-bff2-6109eb2c9439'}', device='ide', type='CONTROLLER', bootOrder='0', specParams='[]', address='{slot=0x01, bus=0x00, domain=0x0000, type=pci, function=0x1}', managed='false', plugged='true', readOnly
='false', deviceAlias='ide', customProperties='[]', snapshotId='null', logicalName='null', usingScsiReservation='false'}, device_b065d6bc-5396-4609-a9aa-f11cc905af8bdevice_88d6bc1a-0595-4dc7-a7d6-fd70c3294227device_23ec0612-0a0a-48f2-8
303-9f38b6a4d128=VmDevice:{id='VmDeviceId:{deviceId='23ec0612-0a0a-48f2-8303-9f38b6a4d128', vmId='f6f199d5-f808-447a-bff2-6109eb2c9439'}', device='unix', type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0, controller=0, ty
pe=virtio-serial, port=2}', managed='false', plugged='true', readOnly='false', deviceAlias='channel1', customProperties='[]', snapshotId='null', logicalName='null', usingScsiReservation='false'}},display=qxl,timeOffset=0,spiceSslCipher
Suite=DEFAULT,nice=0,copyPasteEnable=true,maxMemSize=4194304,maxMemSlots=16,bootMenuEnable=true,memSize=2028
2016-04-18 08:27:55,138 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-42) [7960fc9] FINISH, CreateVDSCommand, log id: 12f140c0
2016-04-18 08:27:55,171 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-42) [7960fc9] FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 32cadda7
2016-04-18 08:27:55,171 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-42) [7960fc9] Lock freed to object 'EngineLock:{exclusiveLocks='[f6f199d5-f808-447a-bff2-6109eb2c9439=<VM, ACTION_TYPE_FAILED_OBJECT
_LOCKED>]', sharedLocks='null'}'
2016-04-18 08:27:55,183 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-42) [7960fc9] Correlation ID: 7960fc9, Job ID: bf7d99cb-af93-4e7f-8b1e-5984e44d0f6f, Call Stack: null,
Custom Event ID: -1, Message: VM ubuexp was started by admin@internal (Host: h1o.polito.it).
2016-04-18 08:27:56,265 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-1) [] START, DestroyVDSCommand(HostName = h1o.polito.it, DestroyVmVDSCommandParameters:{runAsync='true', hostId='7b38327
6-2183-4fdd-94ec-2ff27c03c79b', vmId='f6f199d5-f808-447a-bff2-6109eb2c9439', force='false', secondsToWait='0', gracefully='false', reason='', ignoreNoVm='true'}), log id: 2dceb6bf
2016-04-18 08:27:57,553 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-1) [] FINISH, DestroyVDSCommand, log id: 2dceb6bf
2016-04-18 08:27:57,620 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ForkJoinPool-1-worker-1) [] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM ubuexp is down with error. Exit
message: internal error: process exited while connecting to monitor: 2016-04-18T06:27:51.137788Z qemu-kvm: -drive file=/rhev/data-center/00000001-0001-0001-0001-00000000037d/88dfff37-4ad5-446c-a957-1cf67829c9a6/images/da93350c-8926-42b
f-99fa-8a7aca043fcd/22e7803d-e266-4e3e-ae34-0181f8acef8b,if=none,id=drive-virtio-disk0,format=qcow2,serial=da93350c-8926-42bf-99fa-8a7aca043fcd,cache=none,werror=stop,rerror=stop,aio=native: Could not open '/rhev/data-center/00000001-0
001-0001-0001-00000000037d/88dfff37-4ad5-446c-a957-1cf67829c9a6/images/da93350c-8926-42bf-99fa-8a7aca043fcd/22e7803d-e266-4e3e-ae34-0181f8acef8b': Permission denied
.
2016-04-18 08:27:57,620 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (ForkJoinPool-1-worker-1) [] Running on vds during rerun failed vm: '7b383276-2183-4fdd-94ec-2ff27c03c79b'
2016-04-18 08:27:57,622 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (ForkJoinPool-1-worker-1) [] VM 'f6f199d5-f808-447a-bff2-6109eb2c9439(ubuexp) is running in db and not running in VDS 'h1o.polito.it'
2016-04-18 08:27:57,632 ERROR [org.ovirt.engine.core.vdsbroker.VmsMonitoring] (ForkJoinPool-1-worker-1) [] Rerun VM 'f6f199d5-f808-447a-bff2-6109eb2c9439'. Called from VDS 'h1o.polito.it'
2016-04-18 08:27:57,652 WARN [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-44) [] Correlation ID: 7960fc9, Job ID: bf7d99cb-af93-4e7f-8b1e-5984e44d0f6f, Call Stack: null, Custom
Event ID: -1, Message: Failed to run VM ubuexp on Host h1o.polito.it.
2016-04-18 08:27:57,664 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-44) [] Lock Acquired to object 'EngineLock:{exclusiveLocks='[f6f199d5-f808-447a-bff2-6109eb2c9439=<VM, ACTION_TYPE_FAILED_OBJECT_LOC
KED>]', sharedLocks='null'}'
2016-04-18 08:27:57,690 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-8-thread-44) [] START, IsVmDuringInitiatingVDSCommand( IsVmDuringInitiatingVDSCommandParameters:{runAsync='true', vmI
d='f6f199d5-f808-447a-bff2-6109eb2c9439'}), log id: 15aecd74
2016-04-18 08:27:57,692 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-8-thread-44) [] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 15aecd74
2016-04-18 08:27:57,703 WARN [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-44) [] CanDoAction of action 'RunVm' failed for user admin@internal. Reasons: VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__T
YPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,SCHEDULING_NO_HOSTS
2016-04-18 08:27:57,703 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-44) [] Lock freed to object 'EngineLock:{exclusiveLocks='[f6f199d5-f808-447a-bff2-6109eb2c9439=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED
>]', sharedLocks='null'}'
2016-04-18 08:27:57,713 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-44) [] Correlation ID: 7960fc9, Job ID: bf7d99cb-af93-4e7f-8b1e-5984e44d0f6f, Call Stack: null, Custom
Event ID: -1, Message: Failed to run VM ubuexp (User: admin@internal).
2016-04-18 08:27:57,727 INFO [org.ovirt.engine.core.bll.ProcessDownVmCommand] (org.ovirt.thread.pool-8-thread-43) [15e223c] Running command: ProcessDownVmCommand internal: true.
2016-04-18 08:28:33,863 INFO [org.ovirt.engine.core.bll.AddPermissionCommand] (org.ovirt.thread.pool-8-thread-49) [2d8d0c92] Running command: AddPermissionCommand internal: false. Entities affected : ID: f6f199d5-f808-447a-bff2-6109e
b2c9439 Type: VMAction group MANIPULATE_PERMISSIONS with role type USER, ID: f6f199d5-f808-447a-bff2-6109eb2c9439 Type: VMAction group ADD_USERS_AND_GROUPS_FROM_DIRECTORY with role type USER
2016-04-18 08:28:34,022 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-49) [2d8d0c92] Correlation ID: 2d8d0c92, Call Stack: null, Custom Event ID: -1, Message: User/Group ad
min, Namespace *, Authorization provider: internal-authz was granted permission for Role UserRole on VM ubuexp, by admin@internal.
2016-04-18 08:28:39,311 INFO [org.ovirt.engine.core.bll.RunVmCommand] (default task-47) [6a7fa686] Lock Acquired to object 'EngineLock:{exclusiveLocks='[f6f199d5-f808-447a-bff2-6109eb2c9439=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sh
aredLocks='null'}'
2016-04-18 08:28:39,348 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (default task-47) [6a7fa686] START, IsVmDuringInitiatingVDSCommand( IsVmDuringInitiatingVDSCommandParameters:{runAsync='true', vmId='f6f199d
5-f808-447a-bff2-6109eb2c9439'}), log id: 64e7c58f
2016-04-18 08:28:39,348 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (default task-47) [6a7fa686] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 64e7c58f
2016-04-18 08:28:39,397 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-50) [6a7fa686] Running command: RunVmCommand internal: false. Entities affected : ID: f6f199d5-f808-447a-bff2-6109eb2c9439 Type: VM
Action group RUN_VM with role type USER
2016-04-18 08:28:39,432 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-50) [6a7fa686] START, UpdateVmDynamicDataVDSCommand( UpdateVmDynamicDataVDSCommandParameters:{runAsync='true'
, hostId='null', vmId='00000000-0000-0000-0000-000000000000', vmDynamic='org.ovirt.engine.core.common.businessentities.VmDynamic@78836aae'}), log id: 3a30171b
2016-04-18 08:28:39,434 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-50) [6a7fa686] FINISH, UpdateVmDynamicDataVDSCommand, log id: 3a30171b
2016-04-18 08:28:39,439 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-50) [6a7fa686] START, CreateVmVDSCommand( CreateVmVDSCommandParameters:{runAsync='true', hostId='7b383276-2183-4fdd-94ec
-2ff27c03c79b', vmId='f6f199d5-f808-447a-bff2-6109eb2c9439', vm='VM [ubuexp]'}), log id: 2253c9f5
2016-04-18 08:28:39,442 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-50) [6a7fa686] START, CreateVDSCommand(HostName = h1o.polito.it, CreateVmVDSCommandParameters:{runAsync='true',
hostId='7b383276-2183-4fdd-94ec-2ff27c03c79b', vmId='f6f199d5-f808-447a-bff2-6109eb2c9439', vm='VM [ubuexp]'}), log id: 8bfa6b4
2016-04-18 08:28:39,451 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmInfoBuilderBase] (org.ovirt.thread.pool-8-thread-50) [6a7fa686] Bootable disk 'da93350c-8926-42bf-99fa-8a7aca043fcd' set to index '0'
2016-04-18 08:28:39,474 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-50) [6a7fa686] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand pitReinjection=false,memGuaranteedSize
=1014,smpThreadsPerCore=1,cpuType=Westmere,vmId=f6f199d5-f808-447a-bff2-6109eb2c9439,acpiEnable=true,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,vmType=kvm,keyboardLayout=en-us,smp=2,smpCor
esPerSocket=2,emulatedMachine=pc-i440fx-rhel7.2.0,smartcardEnable=false,fileTransferEnable=true,guestNumaNodes=[{memory=2028, cpus=0,1, nodeIndex=0}],transparentHugePages=true,vmName=ubuexp,maxVCpus=32,kvmEnable=true,devices=[{address=
{bus=0x00, domain=0x0000, function=0x7, slot=0x05, type=pci}, index=0, model=ich9-ehci1, type=controller, specParams={}, device=usb, deviceId=1e675706-bc9c-46c0-9b07-e378f8b48259}, {address={bus=0x00, domain=0x0000, function=0x0, slot=
0x02, type=pci}, type=video, specParams={vgamem=16384, heads=1, ram=65536, vram=8192}, device=qxl, deviceId=353ffb3c-60a8-4972-b353-09c8f3cb271a}, {type=graphics, specParams={fileTransferEnable=true, copyPasteEnable=true}, device=spice
, deviceId=4672e3ff-bd8c-4bb1-a732-87ce7fb7345e}, {iface=ide, shared=false, path=, address={bus=1, controller=0, unit=0, type=drive, target=0}, readonly=true, index=2, type=disk, specParams={path=}, device=cdrom, deviceId=d7fd72f7-906a
-45cf-bb9e-e3b9c360e6b9}, {shared=false, address={bus=0x00, domain=0x0000, function=0x0, slot=0x07, type=pci}, imageID=da93350c-8926-42bf-99fa-8a7aca043fcd, format=cow, index=0, optional=false, type=disk, deviceId=da93350c-8926-42bf-99
fa-8a7aca043fcd, domainID=88dfff37-4ad5-446c-a957-1cf67829c9a6, propagateErrors=off, iface=virtio, readonly=false, bootOrder=1, poolID=00000001-0001-0001-0001-00000000037d, volumeID=22e7803d-e266-4e3e-ae34-0181f8acef8b, specParams={},
device=disk}, {filter=vdsm-no-mac-spoofing, nicModel=pv, address={bus=0x00, domain=0x0000, function=0x0, slot=0x03, type=pci}, type=interface, specParams={inbound={}, outbound={}}, device=bridge, linkActive=true, deviceId=41373990-2b13
-49d3-8d10-044b7a72bffa, macAddr=00:1a:4a:16:01:54, network=ovirtmgmt}, {address={bus=0x00, domain=0x0000, function=0x1, slot=0x05, type=pci}, index=0, model=ich9-uhci2, type=controller, specParams={}, device=usb, deviceId=2ed4923e-9b1
b-4a13-bfea-4dfb97b08c0a}, {address={bus=0x00, domain=0x0000, function=0x2, slot=0x05, type=pci}, index=0, model=ich9-uhci3, type=controller, specParams={}, device=usb, deviceId=5b6cd3df-a8f9-4c5c-80ee-5b5d3e30624e}, {address={bus=0x00
, function=0x0, domain=0x0000, slot=0x05, type=pci, multifunction=on}, index=0, model=ich9-uhci1, type=controller, specParams={}, device=usb, deviceId=79096162-f47e-49b2-b6d7-64b15e20b1f9}, {bus=usb, type=redir, specParams={}, device=s
picevmc, deviceId=866350fc-648e-4aba-a6b2-e9fe1541cea6}, {bus=usb, type=redir, specParams={}, device=spicevmc, deviceId=4ef81515-5a3a-4227-9b1f-16ea0811d173}, {bus=usb, type=redir, specParams={}, device=spicevmc, deviceId=5e45da86-2b1d
-4afe-b77b-604f57033034}, {bus=usb, type=redir, specParams={}, device=spicevmc, deviceId=02079c4b-e598-49b7-ad18-14a80dafed5e}, {address={bus=0x00, function=0x0, domain=0x0000, slot=0x08, type=pci}, type=balloon, specParams={model=virt
io}, device=memballoon, deviceId=179422ed-4069-4101-a81f-824f5551d48c}, {address={bus=0x00, domain=0x0000, function=0x0, slot=0x04, type=pci}, index=0, model=virtio-scsi, type=controller, specParams={}, device=scsi, deviceId=0741a4db-0
979-4650-a01f-0032bfc571c7}, {address={bus=0x00, domain=0x0000, function=0x0, slot=0x06, type=pci}, type=controller, specParams={}, device=virtio-serial, deviceId=a65a4aa6-55b1-4603-b970-ce3839af34ef}],custom={device_b065d6bc-5396-4609
-a9aa-f11cc905af8bdevice_88d6bc1a-0595-4dc7-a7d6-fd70c3294227=VmDevice:{id='VmDeviceId:{deviceId='88d6bc1a-0595-4dc7-a7d6-fd70c3294227', vmId='f6f199d5-f808-447a-bff2-6109eb2c9439'}', device='unix', type='CHANNEL', bootOrder='0', specP
arams='[]', address='{bus=0, controller=0, type=virtio-serial, port=1}', managed='false', plugged='true', readOnly='false', deviceAlias='channel0', customProperties='[]', snapshotId='null', logicalName='null', usingScsiReservation='fal
se'}, device_b065d6bc-5396-4609-a9aa-f11cc905af8bdevice_88d6bc1a-0595-4dc7-a7d6-fd70c3294227device_23ec0612-0a0a-48f2-8303-9f38b6a4d128device_a1a14019-637b-4584-93e5-b505e0dfab25=VmDevice:{id='VmDeviceId:{deviceId='a1a14019-637b-4584-9
3e5-b505e0dfab25', vmId='f6f199d5-f808-447a-bff2-6109eb2c9439'}', device='spicevmc', type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0, controller=0, type=virtio-serial, port=3}', managed='false', plugged='true', readOnly
='false', deviceAlias='channel2', customProperties='[]', snapshotId='null', logicalName='null', usingScsiReservation='false'}, device_b065d6bc-5396-4609-a9aa-f11cc905af8b=VmDevice:{id='VmDeviceId:{deviceId='b065d6bc-5396-4609-a9aa-f11c
c905af8b', vmId='f6f199d5-f808-447a-bff2-6109eb2c9439'}', device='ide', type='CONTROLLER', bootOrder='0', specParams='[]', address='{slot=0x01, bus=0x00, domain=0x0000, type=pci, function=0x1}', managed='false', plugged='true', readOnl
y='false', deviceAlias='ide', customProperties='[]', snapshotId='null', logicalName='null', usingScsiReservation='false'}, device_b065d6bc-5396-4609-a9aa-f11cc905af8bdevice_88d6bc1a-0595-4dc7-a7d6-fd70c3294227device_23ec0612-0a0a-48f2-
8303-9f38b6a4d128=VmDevice:{id='VmDeviceId:{deviceId='23ec0612-0a0a-48f2-8303-9f38b6a4d128', vmId='f6f199d5-f808-447a-bff2-6109eb2c9439'}', device='unix', type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0, controller=0, t
ype=virtio-serial, port=2}', managed='false', plugged='true', readOnly='false', deviceAlias='channel1', customProperties='[]', snapshotId='null', logicalName='null', usingScsiReservation='false'}},display=qxl,timeOffset=0,spiceSslCiphe
rSuite=DEFAULT,nice=0,copyPasteEnable=true,maxMemSize=4194304,maxMemSlots=16,bootMenuEnable=true,memSize=2028
2016-04-18 08:28:39,488 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-50) [6a7fa686] FINISH, CreateVDSCommand, log id: 8bfa6b4
2016-04-18 08:28:39,498 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-50) [6a7fa686] FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 2253c9f5
2016-04-18 08:28:39,499 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-50) [6a7fa686] Lock freed to object 'EngineLock:{exclusiveLocks='[f6f199d5-f808-447a-bff2-6109eb2c9439=<VM, ACTION_TYPE_FAILED_OBJEC
T_LOCKED>]', sharedLocks='null'}'
2016-04-18 08:28:39,509 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-50) [6a7fa686] Correlation ID: 6a7fa686, Job ID: 5f264e97-998c-4abd-8041-c797d14fecb8, Call Stack: nul
l, Custom Event ID: -1, Message: VM ubuexp was started by admin@internal (Host: h1o.polito.it).
2016-04-18 08:28:40,925 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-3) [] START, DestroyVDSCommand(HostName = h1o.polito.it, DestroyVmVDSCommandParameters:{runAsync='true', hostId='7b38327
6-2183-4fdd-94ec-2ff27c03c79b', vmId='f6f199d5-f808-447a-bff2-6109eb2c9439', force='false', secondsToWait='0', gracefully='false', reason='', ignoreNoVm='true'}), log id: 7db9b3c5
2016-04-18 08:28:42,206 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-3) [] FINISH, DestroyVDSCommand, log id: 7db9b3c5
2016-04-18 08:28:42,257 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ForkJoinPool-1-worker-3) [] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM ubuexp is down with error. Exit
message: internal error: process exited while connecting to monitor: 2016-04-18T06:28:36.800050Z qemu-kvm: -drive file=/rhev/data-center/00000001-0001-0001-0001-00000000037d/88dfff37-4ad5-446c-a957-1cf67829c9a6/images/da93350c-8926-42b
f-99fa-8a7aca043fcd/22e7803d-e266-4e3e-ae34-0181f8acef8b,if=none,id=drive-virtio-disk0,format=qcow2,serial=da93350c-8926-42bf-99fa-8a7aca043fcd,cache=none,werror=stop,rerror=stop,aio=native: Could not open '/rhev/data-center/00000001-0
001-0001-0001-00000000037d/88dfff37-4ad5-446c-a957-1cf67829c9a6/images/da93350c-8926-42bf-99fa-8a7aca043fcd/22e7803d-e266-4e3e-ae34-0181f8acef8b': Permission denied
.
2016-04-18 08:28:42,257 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (ForkJoinPool-1-worker-3) [] Running on vds during rerun failed vm: '7b383276-2183-4fdd-94ec-2ff27c03c79b'
2016-04-18 08:28:42,258 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (ForkJoinPool-1-worker-3) [] VM 'f6f199d5-f808-447a-bff2-6109eb2c9439(ubuexp) is running in db and not running in VDS 'h1o.polito.it'
2016-04-18 08:28:42,263 ERROR [org.ovirt.engine.core.vdsbroker.VmsMonitoring] (ForkJoinPool-1-worker-3) [] Rerun VM 'f6f199d5-f808-447a-bff2-6109eb2c9439'. Called from VDS 'h1o.polito.it'
2016-04-18 08:28:42,280 WARN [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-3) [] Correlation ID: 6a7fa686, Job ID: 5f264e97-998c-4abd-8041-c797d14fecb8, Call Stack: null, Custom
Event ID: -1, Message: Failed to run VM ubuexp on Host h1o.polito.it.
2016-04-18 08:28:42,300 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-3) [] Lock Acquired to object 'EngineLock:{exclusiveLocks='[f6f199d5-f808-447a-bff2-6109eb2c9439=<VM, ACTION_TYPE_FAILED_OBJECT_LOCK
ED>]', sharedLocks='null'}'
2016-04-18 08:28:42,327 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-8-thread-3) [] START, IsVmDuringInitiatingVDSCommand( IsVmDuringInitiatingVDSCommandParameters:{runAsync='true', vmId
='f6f199d5-f808-447a-bff2-6109eb2c9439'}), log id: 3056a9ec
2016-04-18 08:28:42,328 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-8-thread-3) [] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 3056a9ec
2016-04-18 08:28:42,335 WARN [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-3) [] CanDoAction of action 'RunVm' failed for user admin@internal. Reasons: VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TY
PE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,SCHEDULING_NO_HOSTS
2016-04-18 08:28:42,336 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-3) [] Lock freed to object 'EngineLock:{exclusiveLocks='[f6f199d5-f808-447a-bff2-6109eb2c9439=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>
]', sharedLocks='null'}'
2016-04-18 08:28:42,356 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-3) [] Correlation ID: 6a7fa686, Job ID: 5f264e97-998c-4abd-8041-c797d14fecb8, Call Stack: null, Custom
Event ID: -1, Message: Failed to run VM ubuexp (User: admin@internal).
2016-04-18 08:28:42,364 INFO [org.ovirt.engine.core.bll.ProcessDownVmCommand] (org.ovirt.thread.pool-8-thread-4) [8644965] Running command: ProcessDownVmCommand internal: true.
2016-04-18 08:29:31,900 INFO [org.ovirt.engine.core.bll.RemovePermissionCommand] (org.ovirt.thread.pool-8-thread-15) [41590401] Running command: RemovePermissionCommand internal: false. Entities affected : ID: f6f199d5-f808-447a-bff2
-6109eb2c9439 Type: VMAction group MANIPULATE_PERMISSIONS with role type USER
2016-04-18 08:29:31,989 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-15) [41590401] Correlation ID: 41590401, Call Stack: null, Custom Event ID: -1, Message: User/Group ad
min Role UserRole permission was removed from VM ubuexp by admin@internal
2016-04-18 08:32:42,420 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetFileStatsVDSCommand] (default task-56) [] START, GetFileStatsVDSCommand( GetFileStatsParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-000000
00037d', ignoreFailoverLimit='false'}), log id: 5b5ae667
2016-04-18 08:32:43,439 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetFileStatsVDSCommand] (default task-56) [] FINISH, GetFileStatsVDSCommand, return: {.keep={status=0, ctime=1456394993.0, size=0}, debian-8.3.0-amd64-netinst.iso
={status=0, ctime=1458572308.0, size=258998272}, CentOS-7-x86_64-DVD-1511.iso={status=0, ctime=1458572789.0, size=4329570304}, ubuntu-14.04.4-desktop-amd64+mac.iso={status=0, ctime=1458574793.0, size=1067450368}}, log id: 5b5ae667
2016-04-18 08:32:43,470 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-56) [] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Refresh image list succeeded for domain(s):
ISO_DOMAIN (All file type)
2016-04-18 08:34:58,206 INFO [org.ovirt.engine.core.bll.AddVmCommand] (default task-22) [17590a05] Lock Acquired to object 'EngineLock:{exclusiveLocks='[test=<VM_NAME, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='[00000000-0000-0
000-0000-000000000000=<TEMPLATE, ACTION_TYPE_FAILED_TEMPLATE_IS_USED_FOR_CREATE_VM$VmName test>]'}'
2016-04-18 08:34:58,306 INFO [org.ovirt.engine.core.bll.AddVmCommand] (default task-22) [] Running command: AddVmCommand internal: false. Entities affected : ID: 00000002-0002-0002-0002-0000000002c5 Type: VdsGroupsAction group CREATE
_VM with role type USER, ID: 00000000-0000-0000-0000-000000000000 Type: VmTemplateAction group CREATE_VM with role type USER
2016-04-18 08:34:58,553 INFO [org.ovirt.engine.core.bll.AddGraphicsDeviceCommand] (default task-22) [65fccdff] Running command: AddGraphicsDeviceCommand internal: true. Entities affected : ID: 7c6bda56-5adf-45b1-9613-dd0529e6454f Typ
e: VMAction group EDIT_VM_PROPERTIES with role type USER
2016-04-18 08:34:58,576 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-22) [65fccdff] Correlation ID: 17590a05, Job ID: d3a926c3-907b-4a27-aaa3-4642a58a20bf, Call Stack: null, Custom Event ID
: -1, Message: VM test was created by admin@internal.
2016-04-18 08:34:58,580 INFO [org.ovirt.engine.core.bll.AddVmCommand] (default task-22) [65fccdff] Lock freed to object 'EngineLock:{exclusiveLocks='[test=<VM_NAME, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='[00000000-0000-0000
-0000-000000000000=<TEMPLATE, ACTION_TYPE_FAILED_TEMPLATE_IS_USED_FOR_CREATE_VM$VmName test>]'}'
2016-04-18 08:34:59,376 INFO [org.ovirt.engine.core.bll.network.vm.AddVmInterfaceCommand] (default task-20) [67984a1c] Running command: AddVmInterfaceCommand internal: false. Entities affected : ID: 7c6bda56-5adf-45b1-9613-dd0529e645
4f Type: VMAction group CONFIGURE_VM_NETWORK with role type USER, ID: 0000000a-000a-000a-000a-000000000398 Type: VnicProfileAction group CONFIGURE_VM_NETWORK with role type USER
2016-04-18 08:34:59,451 INFO [org.ovirt.engine.core.bll.network.vm.ActivateDeactivateVmNicCommand] (default task-20) [52c6a649] Running command: ActivateDeactivateVmNicCommand internal: true. Entities affected : ID: 7c6bda56-5adf-45b
1-9613-dd0529e6454f Type: VM
2016-04-18 08:34:59,489 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-20) [52c6a649] Correlation ID: 52c6a649, Call Stack: null, Custom Event ID: -1, Message: Network Interface nic1 (VirtIO)
was plugged to VM test. (User: admin@internal)
2016-04-18 08:34:59,512 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-20) [52c6a649] Correlation ID: 67984a1c, Call Stack: null, Custom Event ID: -1, Message: Interface nic1 (VirtIO) was add
ed to VM test. (User: admin@internal)
2016-04-18 08:35:00,058 INFO [org.ovirt.engine.core.bll.network.vm.ReorderVmNicsCommand] (default task-25) [a809b06] Running command: ReorderVmNicsCommand internal: false. Entities affected : ID: 7c6bda56-5adf-45b1-9613-dd0529e6454f
Type: VMAction group CREATE_VM with role type USER
2016-04-18 08:35:12,199 INFO [org.ovirt.engine.core.bll.RunVmCommand] (default task-45) [7e7bf671] Lock Acquired to object 'EngineLock:{exclusiveLocks='[7c6bda56-5adf-45b1-9613-dd0529e6454f=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sh
aredLocks='null'}'
2016-04-18 08:35:12,220 WARN [org.ovirt.engine.core.bll.RunVmCommand] (default task-45) [7e7bf671] CanDoAction of action 'RunVm' failed for user admin@internal. Reasons: VAR__ACTION__RUN,VAR__TYPE__VM,VM_CANNOT_RUN_FROM_DISK_WITHOUT_D
ISK
2016-04-18 08:35:12,220 INFO [org.ovirt.engine.core.bll.RunVmCommand] (default task-45) [7e7bf671] Lock freed to object 'EngineLock:{exclusiveLocks='[7c6bda56-5adf-45b1-9613-dd0529e6454f=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', share
dLocks='null'}'
2016-04-18 08:37:14,091 INFO [org.ovirt.engine.core.bll.AddDiskCommand] (default task-36) [11334fb] Lock Acquired to object 'EngineLock:{exclusiveLocks='[7c6bda56-5adf-45b1-9613-dd0529e6454f=<VM_DISK_BOOT, ACTION_TYPE_FAILED_OBJECT_LO
CKED>]', sharedLocks='[7c6bda56-5adf-45b1-9613-dd0529e6454f=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>]'}'
2016-04-18 08:37:14,116 INFO [org.ovirt.engine.core.bll.AddDiskCommand] (default task-36) [11334fb] Running command: AddDiskCommand internal: false. Entities affected : ID: 7c6bda56-5adf-45b1-9613-dd0529e6454f Type: VMAction group CO
NFIGURE_VM_STORAGE with role type USER, ID: 88dfff37-4ad5-446c-a957-1cf67829c9a6 Type: StorageAction group CREATE_DISK with role type USER
2016-04-18 08:37:14,144 INFO [org.ovirt.engine.core.bll.AddImageFromScratchCommand] (default task-36) [296d51dc] Running command: AddImageFromScratchCommand internal: true. Entities affected : ID: 88dfff37-4ad5-446c-a957-1cf67829c9a6
Type: Storage
2016-04-18 08:37:14,219 INFO [org.ovirt.engine.core.bll.AddImageFromScratchCommand] (default task-36) [296d51dc] Lock freed to object 'EngineLock:{exclusiveLocks='[7c6bda56-5adf-45b1-9613-dd0529e6454f=<VM_DISK_BOOT, ACTION_TYPE_FAILED
_OBJECT_LOCKED>]', sharedLocks='[7c6bda56-5adf-45b1-9613-dd0529e6454f=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>]'}'
2016-04-18 08:37:14,349 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (default task-36) [296d51dc] START, CreateImageVDSCommand( CreateImageVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0
001-0001-00000000037d', ignoreFailoverLimit='false', storageDomainId='88dfff37-4ad5-446c-a957-1cf67829c9a6', imageGroupId='1b97d5c8-c061-4666-9e64-d168a2c317ff', imageSizeInBytes='21474836480', volumeFormat='RAW', newImageId='97c1edf3-
51cc-4516-9e2d-eac016476f97', newImageDescription='{"DiskAlias":"test_Disk1","DiskDescription":""}', imageInitialSizeInBytes='0'}), log id: 30f00a88
2016-04-18 08:37:14,354 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (default task-36) [296d51dc] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
2016-04-18 08:37:15,442 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (default task-36) [296d51dc] FINISH, CreateImageVDSCommand, return: 97c1edf3-51cc-4516-9e2d-eac016476f97, log id: 30f00a88
2016-04-18 08:37:15,454 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (default task-36) [296d51dc] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command '7fc0a863-eb74-4755-a9a2-0289583b3f6e'
2016-04-18 08:37:15,456 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (default task-36) [296d51dc] CommandMultiAsyncTasks::AttachTask: Attaching task '0b0d9eac-1423-41f8-82cf-82159a2127b5' to command '7fc0a863-eb74-4755-a9a2
-0289583b3f6e'.
2016-04-18 08:37:15,490 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (default task-36) [296d51dc] Adding task '0b0d9eac-1423-41f8-82cf-82159a2127b5' (Parent Command 'AddDisk', Parameters Type 'org.ovirt.engine.core.common.a
synctasks.AsyncTaskParameters'), polling hasn't started yet..
2016-04-18 08:37:15,596 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-36) [296d51dc] Correlation ID: 11334fb, Job ID: e10dbae6-cc5a-4180-8f8a-4a0887d2e445, Call Stack: null, Custom Event ID:
-1, Message: Add-Disk operation of test_Disk1 was initiated on VM test by admin@internal.
2016-04-18 08:37:15,597 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (default task-36) [296d51dc] BaseAsyncTask::startPollingTask: Starting to poll task '0b0d9eac-1423-41f8-82cf-82159a2127b5'.
2016-04-18 08:37:16,981 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-40) [] Polling and updating Async Tasks: 1 tasks, 1 tasks to poll now
2016-04-18 08:37:18,638 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-40) [] SPMAsyncTask::PollTask: Polling task '0b0d9eac-1423-41f8-82cf-82159a2127b5' (Parent Command 'AddDisk', Parameters Type '
org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'.
2016-04-18 08:37:18,656 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-40) [] BaseAsyncTask::onTaskEndSuccess: Task '0b0d9eac-1423-41f8-82cf-82159a2127b5' (Parent Command 'AddDisk', Parameters Type
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully.
2016-04-18 08:37:18,723 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-40) [] CommandAsyncTask::endActionIfNecessary: All tasks of command '7fc0a863-eb74-4755-a9a2-0289583b3f6e' has ended -> exe
cuting 'endAction'
2016-04-18 08:37:18,723 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-40) [] CommandAsyncTask::endAction: Ending action for '1' tasks (command ID: '7fc0a863-eb74-4755-a9a2-0289583b3f6e'): calli
ng endAction '.
2016-04-18 08:37:18,725 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-23) [] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'AddDisk', executionIndex: '0'
2016-04-18 08:37:18,749 INFO [org.ovirt.engine.core.bll.AddDiskCommand] (org.ovirt.thread.pool-8-thread-23) [11334fb] Ending command 'org.ovirt.engine.core.bll.AddDiskCommand' successfully.
2016-04-18 08:37:18,826 INFO [org.ovirt.engine.core.bll.AddImageFromScratchCommand] (org.ovirt.thread.pool-8-thread-23) [296d51dc] Ending command 'org.ovirt.engine.core.bll.AddImageFromScratchCommand' successfully.
2016-04-18 08:37:18,843 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-23) [296d51dc] START, GetImageInfoVDSCommand( GetImageInfoVDSCommandParameters:{runAsync='true', storagePo
olId='00000001-0001-0001-0001-00000000037d', ignoreFailoverLimit='false', storageDomainId='88dfff37-4ad5-446c-a957-1cf67829c9a6', imageGroupId='1b97d5c8-c061-4666-9e64-d168a2c317ff', imageId='97c1edf3-51cc-4516-9e2d-eac016476f97'}), lo
g id: 2c03d5d1
2016-04-18 08:37:19,870 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-23) [296d51dc] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.stora
ge.DiskImage@c35bb35f, log id: 2c03d5d1
2016-04-18 08:37:19,914 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-23) [] Correlation ID: 11334fb, Job ID: e10dbae6-cc5a-4180-8f8a-4a0887d2e445, Call Stack: null, Custom
Event ID: -1, Message: The disk test_Disk1 was successfully added to VM test.
2016-04-18 08:37:19,915 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-23) [] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'AddDisk' completed, handling th
e result.
2016-04-18 08:37:19,915 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-23) [] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'AddDisk' succeeded, clearing ta
sks.
2016-04-18 08:37:19,919 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-23) [] SPMAsyncTask::ClearAsyncTask: Attempting to clear task '0b0d9eac-1423-41f8-82cf-82159a2127b5'
2016-04-18 08:37:19,922 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-23) [] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{runAsync='true', storagePoolId=
'00000001-0001-0001-0001-00000000037d', ignoreFailoverLimit='false', taskId='0b0d9eac-1423-41f8-82cf-82159a2127b5'}), log id: 661dc6fc
2016-04-18 08:37:19,923 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-23) [] START, HSMClearTaskVDSCommand(HostName = h1o.polito.it, HSMTaskGuidBaseVDSCommandParameters:{runAsy
nc='true', hostId='7b383276-2183-4fdd-94ec-2ff27c03c79b', taskId='0b0d9eac-1423-41f8-82cf-82159a2127b5'}), log id: 4ce1a57f
2016-04-18 08:37:20,944 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-23) [] FINISH, HSMClearTaskVDSCommand, log id: 4ce1a57f
2016-04-18 08:37:20,944 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-23) [] FINISH, SPMClearTaskVDSCommand, log id: 661dc6fc
2016-04-18 08:37:20,968 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-23) [] BaseAsyncTask::removeTaskFromDB: Removed task '0b0d9eac-1423-41f8-82cf-82159a2127b5' from DataBase
2016-04-18 08:37:20,968 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-23) [] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity '7fc0a86
3-eb74-4755-a9a2-0289583b3f6e'
2016-04-18 08:37:23,028 INFO [org.ovirt.engine.core.bll.RunVmCommand] (default task-58) [63499dc6] Lock Acquired to object 'EngineLock:{exclusiveLocks='[7c6bda56-5adf-45b1-9613-dd0529e6454f=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sh
aredLocks='null'}'
2016-04-18 08:37:23,091 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (default task-58) [63499dc6] START, IsVmDuringInitiatingVDSCommand( IsVmDuringInitiatingVDSCommandParameters:{runAsync='true', vmId='7c6bda5
6-5adf-45b1-9613-dd0529e6454f'}), log id: 67b2c320
2016-04-18 08:37:23,091 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (default task-58) [63499dc6] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 67b2c320
2016-04-18 08:37:23,132 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-25) [63499dc6] Running command: RunVmCommand internal: false. Entities affected : ID: 7c6bda56-5adf-45b1-9613-dd0529e6454f Type: VM
Action group RUN_VM with role type USER
2016-04-18 08:37:23,170 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-25) [63499dc6] Running VM with attached cd 'CentOS-7-x86_64-DVD-1511.iso'
2016-04-18 08:37:23,171 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-25) [63499dc6] START, UpdateVmDynamicDataVDSCommand( UpdateVmDynamicDataVDSCommandParameters:{runAsync='true'
, hostId='null', vmId='00000000-0000-0000-0000-000000000000', vmDynamic='org.ovirt.engine.core.common.businessentities.VmDynamic@fa71aff7'}), log id: b09a61f
2016-04-18 08:37:23,172 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-25) [63499dc6] FINISH, UpdateVmDynamicDataVDSCommand, log id: b09a61f
2016-04-18 08:37:23,175 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (org.ovirt.thread.pool-8-thread-25) [63499dc6] START, IsoPrefixVDSCommand(HostName = h1o.polito.it, VdsAndPoolIDVDSParametersBase:{runAsync='
true', hostId='7b383276-2183-4fdd-94ec-2ff27c03c79b', storagePoolId='00000001-0001-0001-0001-00000000037d'}), log id: a24ef85
2016-04-18 08:37:24,185 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (org.ovirt.thread.pool-8-thread-25) [63499dc6] FINISH, IsoPrefixVDSCommand, return: /rhev/data-center/mnt/linuxlaib.polito.it:_var_lib_export
s_iso/fcd5beb2-2884-4a24-b3f0-fb955d3297ba/images/11111111-1111-1111-1111-111111111111, log id: a24ef85
2016-04-18 08:37:24,191 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-25) [63499dc6] START, CreateVmVDSCommand( CreateVmVDSCommandParameters:{runAsync='true', hostId='7b383276-2183-4fdd-94ec
-2ff27c03c79b', vmId='7c6bda56-5adf-45b1-9613-dd0529e6454f', vm='VM [test]'}), log id: 1fdcaca8
2016-04-18 08:37:24,195 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-25) [63499dc6] START, CreateVDSCommand(HostName = h1o.polito.it, CreateVmVDSCommandParameters:{runAsync='true',
hostId='7b383276-2183-4fdd-94ec-2ff27c03c79b', vmId='7c6bda56-5adf-45b1-9613-dd0529e6454f', vm='VM [test]'}), log id: 73db9c60
2016-04-18 08:37:24,203 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmInfoBuilderBase] (org.ovirt.thread.pool-8-thread-25) [63499dc6] Bootable disk '1b97d5c8-c061-4666-9e64-d168a2c317ff' set to index '0'
2016-04-18 08:37:24,226 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-25) [63499dc6] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand pitReinjection=false,memGuaranteedSize
=1024,smpThreadsPerCore=1,cpuType=Westmere,vmId=7c6bda56-5adf-45b1-9613-dd0529e6454f,acpiEnable=true,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,vmType=kvm,keyboardLayout=en-us,smp=1,smpCor
esPerSocket=1,emulatedMachine=pc-i440fx-rhel7.2.0,smartcardEnable=false,fileTransferEnable=true,guestNumaNodes=[{memory=1024, cpus=0, nodeIndex=0}],transparentHugePages=true,vmName=test,maxVCpus=16,kvmEnable=true,devices=[{index=0, mod
el=ich9-ehci1, type=controller, specParams={}, device=usb, deviceId=685a1d6e-ae48-4c91-bc92-6c9fac5216fa}, {type=video, specParams={vgamem=16384, heads=1, ram=65536, vram=8192}, device=qxl, deviceId=a6ef942a-1288-4265-b26b-96726f5e8460
}, {type=graphics, specParams={fileTransferEnable=true, copyPasteEnable=true}, device=spice, deviceId=2b8b3073-0e55-4250-b144-ccdbaf322aaf}, {iface=ide, shared=false, path=/rhev/data-center/mnt/linuxlaib.polito.it:_var_lib_exports_iso/
fcd5beb2-2884-4a24-b3f0-fb955d3297ba/images/11111111-1111-1111-1111-111111111111/CentOS-7-x86_64-DVD-1511.iso, readonly=true, index=2, type=disk, specParams={path=CentOS-7-x86_64-DVD-1511.iso}, device=cdrom, deviceId=0a075ade-5903-4cd1
-8eec-a93bae9e134c}, {shared=false, imageID=1b97d5c8-c061-4666-9e64-d168a2c317ff, format=raw, index=0, optional=false, type=disk, deviceId=1b97d5c8-c061-4666-9e64-d168a2c317ff, domainID=88dfff37-4ad5-446c-a957-1cf67829c9a6, propagateEr
rors=off, iface=virtio, readonly=false, bootOrder=1, poolID=00000001-0001-0001-0001-00000000037d, volumeID=97c1edf3-51cc-4516-9e2d-eac016476f97, specParams={}, device=disk}, {filter=vdsm-no-mac-spoofing, nicModel=pv, type=interface, sp
ecParams={inbound={}, outbound={}}, device=bridge, linkActive=true, deviceId=f41706c9-6e73-4f1b-8198-9f965e84432b, macAddr=00:1a:4a:16:01:55, network=ovirtmgmt}, {index=0, model=ich9-uhci1, type=controller, specParams={}, device=usb, d
eviceId=3ee397a0-3dba-4bbc-bf2e-97835c73b00d}, {index=0, model=ich9-uhci2, type=controller, specParams={}, device=usb, deviceId=35a8ae6a-09df-40fb-911f-7c3b22472c8c}, {index=0, model=ich9-uhci3, type=controller, specParams={}, device=u
sb, deviceId=52b15750-90cc-4087-a0fc-d1e1b54f38d6}, {bus=usb, type=redir, specParams={}, device=spicevmc, deviceId=bfa5c929-1c6a-4d35-9ce1-51fa00c2e317}, {bus=usb, type=redir, specParams={}, device=spicevmc, deviceId=49365046-0cc5-4332
-ad47-0747183ddcf9}, {bus=usb, type=redir, specParams={}, device=spicevmc, deviceId=4c6bd65a-3f04-416a-b75a-2c7bfbb7a0ec}, {bus=usb, type=redir, specParams={}, device=spicevmc, deviceId=1c22bb52-1c68-48b5-9f23-517e3bf12392}, {type=ball
oon, specParams={model=virtio}, device=memballoon, deviceId=83cd8cc7-d6c8-4dc2-b122-b85ddfb5d7fc}, {index=0, model=virtio-scsi, type=controller, specParams={}, device=scsi, deviceId=63b729ae-8601-4eb7-8e60-39fff4b61f6a}, {type=controll
er, specParams={}, device=virtio-serial, deviceId=12e69d92-1382-4317-9c3e-0b785df8e1a9}],custom={},display=qxl,timeOffset=0,spiceSslCipherSuite=DEFAULT,nice=0,copyPasteEnable=true,maxMemSize=4194304,maxMemSlots=16,bootMenuEnable=false,
memSize=1024
2016-04-18 08:37:25,163 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-25) [63499dc6] FINISH, CreateVDSCommand, log id: 73db9c60
2016-04-18 08:37:25,194 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-25) [63499dc6] FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 1fdcaca8
2016-04-18 08:37:25,194 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-25) [63499dc6] Lock freed to object 'EngineLock:{exclusiveLocks='[7c6bda56-5adf-45b1-9613-dd0529e6454f=<VM, ACTION_TYPE_FAILED_OBJEC
T_LOCKED>]', sharedLocks='null'}'
2016-04-18 08:37:25,204 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-25) [63499dc6] Correlation ID: 63499dc6, Job ID: 2eed3ec3-6258-4bfc-9eed-1253b157bd8e, Call Stack: nul
l, Custom Event ID: -1, Message: VM test was started by admin@internal (Host: h1o.polito.it).
2016-04-18 08:37:25,497 WARN [org.ovirt.engine.core.vdsbroker.VmsMonitoring] (DefaultQuartzScheduler_Worker-46) [] skipping VM '7c6bda56-5adf-45b1-9613-dd0529e6454f' from this monitoring cycle - the VM data has changed since fetching
the data
2016-04-18 08:37:25,497 WARN [org.ovirt.engine.core.vdsbroker.VmsMonitoring] (DefaultQuartzScheduler_Worker-46) [] VM '7c6bda56-5adf-45b1-9613-dd0529e6454f' not in changed list, skipping devices update.
2016-04-18 08:37:26,588 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-5) [] START, DestroyVDSCommand(HostName = h1o.polito.it, DestroyVmVDSCommandParameters:{runAsync='true', hostId='7b38327
6-2183-4fdd-94ec-2ff27c03c79b', vmId='7c6bda56-5adf-45b1-9613-dd0529e6454f', force='false', secondsToWait='0', gracefully='false', reason='', ignoreNoVm='true'}), log id: 397d475e
2016-04-18 08:37:27,634 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-5) [] FINISH, DestroyVDSCommand, log id: 397d475e
2016-04-18 08:37:27,652 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ForkJoinPool-1-worker-5) [] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM test is down with error. Exit me
ssage: internal error: process exited while connecting to monitor: 2016-04-18T06:37:21.390833Z qemu-kvm: -drive file=/rhev/data-center/00000001-0001-0001-0001-00000000037d/88dfff37-4ad5-446c-a957-1cf67829c9a6/images/1b97d5c8-c061-4666-
9e64-d168a2c317ff/97c1edf3-51cc-4516-9e2d-eac016476f97,if=none,id=drive-virtio-disk0,format=raw,serial=1b97d5c8-c061-4666-9e64-d168a2c317ff,cache=none,werror=stop,rerror=stop,aio=native: Could not open '/rhev/data-center/00000001-0001-
0001-0001-00000000037d/88dfff37-4ad5-446c-a957-1cf67829c9a6/images/1b97d5c8-c061-4666-9e64-d168a2c317ff/97c1edf3-51cc-4516-9e2d-eac016476f97': Permission denied
.
2016-04-18 08:37:27,652 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (ForkJoinPool-1-worker-5) [] Running on vds during rerun failed vm: '7b383276-2183-4fdd-94ec-2ff27c03c79b'
2016-04-18 08:37:27,654 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (ForkJoinPool-1-worker-5) [] VM '7c6bda56-5adf-45b1-9613-dd0529e6454f(test) is running in db and not running in VDS 'h1o.polito.it'
2016-04-18 08:37:27,661 ERROR [org.ovirt.engine.core.vdsbroker.VmsMonitoring] (ForkJoinPool-1-worker-5) [] Rerun VM '7c6bda56-5adf-45b1-9613-dd0529e6454f'. Called from VDS 'h1o.polito.it'
2016-04-18 08:37:27,710 WARN [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-22) [] Correlation ID: 63499dc6, Job ID: 2eed3ec3-6258-4bfc-9eed-1253b157bd8e, Call Stack: null, Custo
m Event ID: -1, Message: Failed to run VM test on Host h1o.polito.it.
2016-04-18 08:37:27,717 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-22) [] Lock Acquired to object 'EngineLock:{exclusiveLocks='[7c6bda56-5adf-45b1-9613-dd0529e6454f=<VM, ACTION_TYPE_FAILED_OBJECT_LOC
KED>]', sharedLocks='null'}'
2016-04-18 08:37:27,737 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-8-thread-22) [] START, IsVmDuringInitiatingVDSCommand( IsVmDuringInitiatingVDSCommandParameters:{runAsync='true', vmI
d='7c6bda56-5adf-45b1-9613-dd0529e6454f'}), log id: 571f0200
2016-04-18 08:37:27,737 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-8-thread-22) [] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 571f0200
2016-04-18 08:37:27,742 WARN [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-22) [] CanDoAction of action 'RunVm' failed for user admin@internal. Reasons: VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__T
YPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,SCHEDULING_NO_HOSTS
2016-04-18 08:37:27,742 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-22) [] Lock freed to object 'EngineLock:{exclusiveLocks='[7c6bda56-5adf-45b1-9613-dd0529e6454f=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED
>]', sharedLocks='null'}'
2016-04-18 08:37:27,759 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-22) [] Correlation ID: 63499dc6, Job ID: 2eed3ec3-6258-4bfc-9eed-1253b157bd8e, Call Stack: null, Custo
m Event ID: -1, Message: Failed to run VM test (User: admin@internal).
2016-04-18 08:37:27,767 INFO [org.ovirt.engine.core.bll.ProcessDownVmCommand] (org.ovirt.thread.pool-8-thread-28) [2a263cc4] Running command: ProcessDownVmCommand internal: true.
2016-04-18 08:37:58,921 INFO [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-95) [73ad26f1] Attempting to update VMs/Templates Ovf.
2016-04-18 08:37:58,924 INFO [org.ovirt.engine.core.bll.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler_Worker-95) [7e09f10b] Running command: ProcessOvfUpdateForStoragePoolCommand internal: true. Entities affected : I
D: 00000001-0001-0001-0001-00000000037d Type: StoragePool
2016-04-18 08:37:58,926 INFO [org.ovirt.engine.core.bll.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler_Worker-95) [7e09f10b] Attempting to update VM OVFs in Data Center 'Default'
2016-04-18 08:37:59,013 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UpdateVMVDSCommand] (DefaultQuartzScheduler_Worker-95) [7e09f10b] START, UpdateVMVDSCommand( UpdateVMVDSCommandParameters:{runAsync='true', storagePoolId='0000000
1-0001-0001-0001-00000000037d', ignoreFailoverLimit='false', storageDomainId='00000000-0000-0000-0000-000000000000', infoDictionary.size='1'}), log id: 5016b3d7
2016-04-18 08:38:00,071 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UpdateVMVDSCommand] (DefaultQuartzScheduler_Worker-95) [7e09f10b] FINISH, UpdateVMVDSCommand, log id: 5016b3d7
2016-04-18 08:38:00,103 INFO [org.ovirt.engine.core.bll.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler_Worker-95) [7e09f10b] Successfully updated VM OVFs in Data Center 'Default'
2016-04-18 08:38:00,103 INFO [org.ovirt.engine.core.bll.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler_Worker-95) [7e09f10b] Attempting to update template OVFs in Data Center 'Default'
2016-04-18 08:38:00,104 INFO [org.ovirt.engine.core.bll.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler_Worker-95) [7e09f10b] Successfully updated templates OVFs in Data Center 'Default'
2016-04-18 08:38:00,104 INFO [org.ovirt.engine.core.bll.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler_Worker-95) [7e09f10b] Attempting to remove unneeded template/vm OVFs in Data Center 'Default'
2016-04-18 08:38:00,176 INFO [org.ovirt.engine.core.bll.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler_Worker-95) [7e09f10b] Successfully removed unneeded template/vm OVFs in Data Center 'Default'
2016-04-18 08:38:00,177 INFO [org.ovirt.engine.core.bll.ProcessOvfUpdateForStoragePoolCommand] (DefaultQuartzScheduler_Worker-95) [7e09f10b] Lock freed to object 'EngineLock:{exclusiveLocks='[00000001-0001-0001-0001-00000000037d=<OVF_
UPDATE, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2016-04-18 08:38:40,417 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-4) [1d912c1b] Setting new tasks map. The map contains now 0 tasks
2016-04-18 08:38:40,417 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-4) [1d912c1b] Cleared all tasks of pool '00000001-0001-0001-0001-00000000037d'.
_______________________________________________
Users mailing list
Users@ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
