the new template has the sysprep fields filled correctly? Well, for the first template I used the "initial run" section in the pool options, not in the template ones. Anyway I tried to fill the new template options with the correct settings but it did not sysprep. I can use "run once" as admin to make the rebased vm sysprep but that would mean to run them one by one... do you see any error in the log? can you attach the engine.log for the time user takes vm from pool?
Here it is 2015-07-27 12:15:16,807 INFO [org.ovirt.engine.core.bll.AttachUserToVmFromPoolAndRunCommand] (ajp--127.0.0.1-8702-10) [4ae1c9cd] Lock Acquired to object EngineLock [exclusiveLocks= key: d69d8d20-68b7-4fed-9c08-5c2ecb257583 value: USER_VM_POOL , sharedLocks= ] 2015-07-27 12:15:16,893 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-10) [4ae1c9cd] START, IsVmDuringInitiatingVDSCommand( vmId = bc628809-6018-48d9-a0d0-793d8e2ae60b), log id: 3c0ac499 2015-07-27 12:15:16,895 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-10) [4ae1c9cd] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 3c0ac499 2015-07-27 12:15:16,948 INFO [org.ovirt.engine.core.bll.AttachUserToVmFromPoolAndRunCommand] (ajp--127.0.0.1-8702-10) [4ae1c9cd] Running command: AttachUserToVmFromPoolAndRunCommand internal: false. Entities affected : ID: e4c8cd94-a75d-4838-80ff-f311e611aad5 Type: VmPoolAction group VM_POOL_BASIC_OPERATIONS with role type USER 2015-07-27 12:15:16,989 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-10) [4ae1c9cd] START, IsVmDuringInitiatingVDSCommand( vmId = bc628809-6018-48d9-a0d0-793d8e2ae60b), log id: 62940db1 2015-07-27 12:15:16,990 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-10) [4ae1c9cd] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 62940db1 2015-07-27 12:15:17,020 INFO [org.ovirt.engine.core.bll.AddPermissionCommand] (ajp--127.0.0.1-8702-10) [37aaec5a] Running command: AddPermissionCommand internal: true. Entities affected : ID: bc628809-6018-48d9-a0d0-793d8e2ae60b Type: VMAction group MANIPULATE_PERMISSIONS with role type USER 2015-07-27 12:15:17,032 INFO [org.ovirt.engine.core.bll.AttachUserToVmFromPoolAndRunCommand] (ajp--127.0.0.1-8702-10) [37aaec5a] Succceeded giving user d69d8d20-68b7-4fed-9c08-5c2ecb257583 permission to Vm bc628809-6018-48d9-a0d0-793d8e2ae60b 2015-07-27 12:15:17,052 INFO [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-10) [65308fd0] Lock Acquired to object EngineLock [exclusiveLocks= key: bc628809-6018-48d9-a0d0-793d8e2ae60b value: VM , sharedLocks= ] 2015-07-27 12:15:17,124 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-10) [65308fd0] START, IsVmDuringInitiatingVDSCommand( vmId = bc628809-6018-48d9-a0d0-793d8e2ae60b), log id: 6d6561c 2015-07-27 12:15:17,126 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-10) [65308fd0] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 6d6561c 2015-07-27 12:15:17,177 INFO [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-10) [65308fd0] Running command: RunVmCommand internal: true. Entities affected : ID: bc628809-6018-48d9-a0d0-793d8e2ae60b Type: VMAction group VM_BASIC_OPERATIONS with role type USER 2015-07-27 12:15:17,185 INFO [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-10) [65308fd0] Creating stateless snapshot for VM TestPoolAuto-1 (bc628809-6018-48d9-a0d0-793d8e2ae60b) 2015-07-27 12:15:17,245 INFO [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (ajp--127.0.0.1-8702-10) Command 01824f40-86e8-4116-a8c3-f67f20e2e351 persisting async task placeholder for child command 1359dec2-5257-466d-a612-fb78b424d1b5 2015-07-27 12:15:17,280 INFO [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (ajp--127.0.0.1-8702-10) Running command: CreateAllSnapshotsFromVmCommand internal: true. Entities affected : ID: bc628809-6018-48d9-a0d0-793d8e2ae60b Type: VMAction group MANIPULATE_VM_SNAPSHOTS with role type USER 2015-07-27 12:15:17,316 INFO [org.ovirt.engine.core.bll.CreateSnapshotCommand] (ajp--127.0.0.1-8702-10) [44c90b11] Running command: CreateSnapshotCommand internal: true. Entities affected : ID: 00000000-0000-0000-0000-000000000000 Type: Storage 2015-07-27 12:15:17,320 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (ajp--127.0.0.1-8702-10) [44c90b11] START, CreateSnapshotVDSCommand( storagePoolId = 00000002-0002-0002-0002-00000000005e, ignoreFailoverLimit = false, storageDomainId = 5f20ecf7-7d8d-4dab-857a-6eb1aa9b9842, imageGroupId = 76760a81-ee92-4791-bce2-766d3798ee85, imageSizeInBytes = 42949672960, volumeFormat = COW, newImageId = 4b802949-5ae2-4a25-bab3-d28db0773d7a, newImageDescription = , imageId = e694497f-aa78-4481-82f3-148561c18c58, sourceImageGroupId = 76760a81-ee92-4791-bce2-766d3798ee85), log id: 12d3a44d 2015-07-27 12:15:17,340 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (ajp--127.0.0.1-8702-10) [44c90b11] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID 2015-07-27 12:15:18,248 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (ajp--127.0.0.1-8702-10) [44c90b11] FINISH, CreateSnapshotVDSCommand, return: 4b802949-5ae2-4a25-bab3-d28db0773d7a, log id: 12d3a44d 2015-07-27 12:15:18,263 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (ajp--127.0.0.1-8702-10) [44c90b11] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command d8318acc-d96c-4958-a8c5-1f93cad54765 2015-07-27 12:15:18,270 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (ajp--127.0.0.1-8702-10) [44c90b11] CommandMultiAsyncTasks::AttachTask: Attaching task 4ddc7a8b-f741-4478-bd40-05e857d5efb9 to command d8318acc-d96c-4958-a8c5-1f93cad54765. 2015-07-27 12:15:18,294 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (ajp--127.0.0.1-8702-10) [44c90b11] Adding task 4ddc7a8b-f741-4478-bd40-05e857d5efb9 (Parent Command RunVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet.. 2015-07-27 12:15:18,347 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-10) Correlation ID: 65308fd0, Job ID: 679f1cd8-2ffe-4e16-bc51-857ffab80eab, Call Stack: null, Custom Event ID: -1, Message: VM TestPoolAuto-1 was restarted on Host <UNKNOWN> 2015-07-27 12:15:18,356 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (ajp--127.0.0.1-8702-10) BaseAsyncTask::startPollingTask: Starting to poll task 4ddc7a8b-f741-4478-bd40-05e857d5efb9. 2015-07-27 12:15:18,397 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-10) Correlation ID: 4ae1c9cd, Job ID: 679f1cd8-2ffe-4e16-bc51-857ffab80eab, Call Stack: null, Custom Event ID: -1, Message: Attaching User c.mammoli to VM TestPoolAuto-1 in VM Pool TestPoolAuto was initiated by c.mammoli@apra.it. 2015-07-27 12:15:18,409 INFO [org.ovirt.engine.core.bll.AttachUserToVmFromPoolAndRunCommand] (ajp--127.0.0.1-8702-10) Lock freed to object EngineLock [exclusiveLocks= key: d69d8d20-68b7-4fed-9c08-5c2ecb257583 value: USER_VM_POOL , sharedLocks= ] 2015-07-27 12:15:27,422 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-38) [48348cff] Polling and updating Async Tasks: 1 tasks, 1 tasks to poll now 2015-07-27 12:15:27,434 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-38) [48348cff] SPMAsyncTask::PollTask: Polling task 4ddc7a8b-f741-4478-bd40-05e857d5efb9 (Parent Command RunVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'. 2015-07-27 12:15:27,444 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-38) [48348cff] BaseAsyncTask::onTaskEndSuccess: Task 4ddc7a8b-f741-4478-bd40-05e857d5efb9 (Parent Command RunVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully. 2015-07-27 12:15:27,454 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-38) [48348cff] CommandAsyncTask::endActionIfNecessary: All tasks of command d8318acc-d96c-4958-a8c5-1f93cad54765 has ended -> executing endAction 2015-07-27 12:15:27,462 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-38) [48348cff] CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: d8318acc-d96c-4958-a8c5-1f93cad54765): calling endAction . 2015-07-27 12:15:27,469 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-36) [48348cff] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction RunVm, executionIndex: 0 2015-07-27 12:15:27,492 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] Ending command successfully: org.ovirt.engine.core.bll.RunVmCommand 2015-07-27 12:15:27,498 INFO [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (org.ovirt.thread.pool-8-thread-36) Ending command successfully: org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand 2015-07-27 12:15:27,509 INFO [org.ovirt.engine.core.bll.CreateSnapshotCommand] (org.ovirt.thread.pool-8-thread-36) [44c90b11] Ending command successfully: org.ovirt.engine.core.bll.CreateSnapshotCommand 2015-07-27 12:15:27,516 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-36) [44c90b11] START, GetImageInfoVDSCommand( storagePoolId = 00000002-0002-0002-0002-00000000005e, ignoreFailoverLimit = false, storageDomainId = 5f20ecf7-7d8d-4dab-857a-6eb1aa9b9842, imageGroupId = 76760a81-ee92-4791-bce2-766d3798ee85, imageId = 4b802949-5ae2-4a25-bab3-d28db0773d7a), log id: 37defe64 2015-07-27 12:15:28,543 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-36) [44c90b11] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@95824dd7, log id: 37defe64 2015-07-27 12:15:28,563 INFO [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (org.ovirt.thread.pool-8-thread-36) Lock freed to object EngineLock [exclusiveLocks= key: bc628809-6018-48d9-a0d0-793d8e2ae60b value: VM , sharedLocks= ] 2015-07-27 12:15:28,593 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] Lock Acquired to object EngineLock [exclusiveLocks= key: bc628809-6018-48d9-a0d0-793d8e2ae60b value: VM , sharedLocks= ] 2015-07-27 12:15:28,637 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] START, IsVmDuringInitiatingVDSCommand( vmId = bc628809-6018-48d9-a0d0-793d8e2ae60b), log id: 57b435ef 2015-07-27 12:15:28,645 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 57b435ef 2015-07-27 12:15:28,679 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] Running command: RunVmCommand internal: true. Entities affected : ID: bc628809-6018-48d9-a0d0-793d8e2ae60b Type: VMAction group VM_BASIC_OPERATIONS with role type USER 2015-07-27 12:15:28,707 INFO [org.ovirt.engine.core.bll.scheduling.policyunits.HaReservationWeightPolicyUnit] (org.ovirt.thread.pool-8-thread-36) [65308fd0] Started HA reservation scoring method 2015-07-27 12:15:28,715 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] Running VM with attached cd it_windows_7_professional_with_sp1_vl_build_x64_dvd_u_677841.iso 2015-07-27 12:15:28,718 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] START, UpdateVmDynamicDataVDSCommand(HostName = kvm01, HostId = d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe, vmDynamic=org.ovirt.engine.core.common.businessentities.VmDynamic@2f8b9428), log id: 215bb51c 2015-07-27 12:15:28,723 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] FINISH, UpdateVmDynamicDataVDSCommand, log id: 215bb51c 2015-07-27 12:15:28,730 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] START, IsoPrefixVDSCommand(HostName = kvm01, HostId = d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe, storagePoolId=00000002-0002-0002-0002-00000000005e), log id: 36f416ec 2015-07-27 12:15:28,739 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] 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: 36f416ec 2015-07-27 12:15:28,759 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] START, CreateVmVDSCommand(HostName = kvm01, HostId = d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe, vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, vm=VM [TestPoolAuto-1]), log id: 707f395a 2015-07-27 12:15:28,770 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.SysprepHandler] (org.ovirt.thread.pool-8-thread-36) [65308fd0] Could not find value for key user. Going to use default value of: 2015-07-27 12:15:28,780 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVmFromSysPrepVDSCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] START, CreateVmFromSysPrepVDSCommand(HostName = kvm01, HostId = d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe, vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, vm=VM [TestPoolAuto-1]), log id: 28780d5f 2015-07-27 12:15:28,830 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVmFromSysPrepVDSCommand kvmEnable=true,keyboardLayout=en-us,nice=0,displayNetwork=ovirtmgmt,copyPasteEnable=true,timeOffset=7200,transparentHugePages=true,vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b,acpiEnable=true,custom={device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1ac=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=0d2383cf-4790-4d3a-b62d-c78d1ec8e1ac, 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=ide0, customProperties={}, snapshotId=null, logicalName=null}, device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1acdevice_5726451e-8bd2-4869-90e4-58dd83e0f707device_38f7dd0b-94be-4eba-9792-8978fadce286=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=38f7dd0b-94be-4eba-9792-8978fadce286, 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}, device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1acdevice_5726451e-8bd2-4869-90e4-58dd83e0f707device_38f7dd0b-94be-4eba-9792-8978fadce286device_7fa37687-1772-4aee-9018-5f121e12e717=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=7fa37687-1772-4aee-9018-5f121e12e717, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=1}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null, logicalName=null}, device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1acdevice_5726451e-8bd2-4869-90e4-58dd83e0f707=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=5726451e-8bd2-4869-90e4-58dd83e0f707, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=2}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, 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, address={bus=0x00, domain=0x0000, type=pci, slot=0x08, function=0x7}, specParams={}, device=usb, type=controller, deviceId=46b1c50e-76bf-47a4-b10a-1d98ad138fa5}, {shared=false, iface=fdc, index=0, specParams={vmPayload={file={Unattend.xml=PD94bWwgdmVyc2lvbj0iMS4wIiBlbmNvZGluZz0iVVRGLTgiPz4NCjx1bmF0dGVuZCB4bWxucz0idXJuOnNjaGVtYXMtbWljcm9zb2Z0LWNvbTp1bmF0dGVuZCI+DQogICAgPHNldHRpbmdzIHBhc3M9IndpbmRvd3NQRSI+DQogICAgICAgIDxjb21wb25lbnQgbmFtZT0iTWljcm9zb2Z0LVdpbmRvd3MtU2V0dXAiIHByb2Nlc3NvckFyY2hpdGVjdHVyZT0ieDg2IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPFVzZXJEYXRhPg0KICAgICAgICAgICAgICAgIDxQcm9kdWN0S2V5Pg0KICAgICAgICAgICAgICAgICAgICA8S2V5PjwhW0NEQVRBW3ZyN2Q5LWs2eXZ2LXFydzI0LWNxNnc4LWJoZmdyXV0+PC9LZXk+DQogICAgICAgICAgICAgICAgPC9Qcm9kdWN0S2V5Pg0KICAgICAgICAgICAgICAgIDxBY2NlcHRFdWxhPnRydWU8L0FjY2VwdEV1bGE+DQogICAgICAgICAgICAgICAgPEZ1bGxOYW1lPiJ1c2VyIjwvRnVsbE5hbWU+DQogICAgICAgICAgICAgICAgPE9yZ2FuaXphdGlvbj48IVtDREFUQVthcHJhLml0XV0+PC9Pcmdhbml6YXRpb24+DQogICAgICAgICAgICA8L1VzZXJEYXRhPg0KICAgICAgICAgICAgPEltYWdlSW5zdGFsbD4NCiAgICAgICAgICAgICAgICA8T1NJbWFnZT4NCiAgICAgICAgICAgICAgICAgICAgPEluc3RhbGxUb0F2YWlsYWJsZVBhcnRpdGlvbj50cnVlPC9JbnN0YWxsVG9BdmFpbGFibGVQYXJ0aXRpb24+DQogICAgICAgICAgICAgICAgPC9PU0ltYWdlPg0KICAgICAgICAgICAgPC9JbWFnZUluc3RhbGw+DQogICAgICAgIDwvY29tcG9uZW50Pg0KICAgICAgICA8Y29tcG9uZW50IG5hbWU9Ik1pY3Jvc29mdC1XaW5kb3dzLUludGVybmF0aW9uYWwtQ29yZS1XaW5QRSIgcHJvY2Vzc29yQXJjaGl0ZWN0dXJlPSJ4ODYiIHB1YmxpY0tleVRva2VuPSIzMWJmMzg1NmFkMzY0ZTM1IiBsYW5ndWFnZT0ibmV1dHJhbCIgdmVyc2lvblNjb3BlPSJub25TeFMiIHhtbG5zOndjbT0iaHR0cDovL3NjaGVtYXMubWljcm9zb2Z0LmNvbS9XTUlDb25maWcvMjAwMi9TdGF0ZSIgeG1sbnM6eHNpPSJodHRwOi8vd3d3LnczLm9yZy8yMDAxL1hNTFNjaGVtYS1pbnN0YW5jZSI+DQogICAgICAgICAgICA8U2V0dXBVSUxhbmd1YWdlPg0KICAgICAgICAgICAgICAgIDxVSUxhbmd1YWdlPjwhW0NEQVRBW2VuX1VTXV0+PC9VSUxhbmd1YWdlPg0KICAgICAgICAgICAgPC9TZXR1cFVJTGFuZ3VhZ2U+DQogICAgICAgICAgICA8SW5wdXRMb2NhbGU+PCFbQ0RBVEFbZW5fVVNdXT48L0lucHV0TG9jYWxlPg0KICAgICAgICAgICAgPFVJTGFuZ3VhZ2U+PCFbQ0RBVEFbZW5fVVNdXT48L1VJTGFuZ3VhZ2U+DQogICAgICAgICAgICA8U3lzdGVtTG9jYWxlPjwhW0NEQVRBW2VuX1VTXV0+PC9TeXN0ZW1Mb2NhbGU+DQogICAgICAgICAgICA8VXNlckxvY2FsZT48IVtDREFUQVtlbl9VU11dPjwvVXNlckxvY2FsZT4NCiAgICAgICAgPC9jb21wb25lbnQ+DQogICAgPC9zZXR0aW5ncz4NCiAgICA8c2V0dGluZ3MgcGFzcz0ic3BlY2lhbGl6ZSI+DQogICAgICAgIDxjb21wb25lbnQgbmFtZT0iTWljcm9zb2Z0LVdpbmRvd3MtU2hlbGwtU2V0dXAiIHByb2Nlc3NvckFyY2hpdGVjdHVyZT0ieDg2IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPERpc3BsYXk+DQogICAgICAgICAgICAgICAgPENvbG9yRGVwdGg+MzI8L0NvbG9yRGVwdGg+DQogICAgICAgICAgICAgICAgPERQST45NjwvRFBJPg0KICAgICAgICAgICAgICAgIDxIb3Jpem9udGFsUmVzb2x1dGlvbj4xMDI0PC9Ib3Jpem9udGFsUmVzb2x1dGlvbj4NCiAgICAgICAgICAgICAgICA8UmVmcmVzaFJhdGU+NzU8L1JlZnJlc2hSYXRlPg0KICAgICAgICAgICAgICAgIDxWZXJ0aWNhbFJlc29sdXRpb24+NzY4PC9WZXJ0aWNhbFJlc29sdXRpb24+DQogICAgICAgICAgICA8L0Rpc3BsYXk+DQogICAgICAgICAgICA8Q29tcHV0ZXJOYW1lPjwhW0NEQVRBW1Rlc3RQb29sQXV0by0xXV0+PC9Db21wdXRlck5hbWU+DQogICAgICAgICAgICA8VGltZVpvbmU+PCFbQ0RBVEFbR01UIFN0YW5kYXJkIFRpbWVdXT48L1RpbWVab25lPg0KICAgICAgICA8L2NvbXBvbmVudD4NCiAgICAgICAgPGNvbXBvbmVudCBuYW1lPSJNaWNyb3NvZnQtV2luZG93cy1JbnRlcm5hdGlvbmFsLUNvcmUiIHByb2Nlc3NvckFyY2hpdGVjdHVyZT0ieDg2IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPElucHV0TG9jYWxlPjwhW0NEQVRBW2VuX1VTXV0+PC9JbnB1dExvY2FsZT4NCiAgICAgICAgICAgIDxVc2VyTG9jYWxlPjwhW0NEQVRBW2VuX1VTXV0+PC9Vc2VyTG9jYWxlPg0KICAgICAgICAgICAgPFN5c3RlbUxvY2FsZT48IVtDREFUQVtlbl9VU11dPjwvU3lzdGVtTG9jYWxlPg0KICAgICAgICAgICAgPFVJTGFuZ3VhZ2U+PCFbQ0RBVEFbZW5fVVNdXT48L1VJTGFuZ3VhZ2U+DQogICAgICAgIDwvY29tcG9uZW50Pg0KICAgICAgICA8Y29tcG9uZW50IG5hbWU9Ik1pY3Jvc29mdC1XaW5kb3dzLVVuYXR0ZW5kZWRKb2luIiBwcm9jZXNzb3JBcmNoaXRlY3R1cmU9ImFtZDY0IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPElkZW50aWZpY2F0aW9uPg0KICAgICAgICAgICAgICAgIDxDcmVkZW50aWFscz4NCiAgICAgICAgICAgICAgICAgICAgPERvbWFpbj48IVtDREFUQVtdXT48L0RvbWFpbj4NCiAgICAgICAgICAgICAgICAgICAgPFBhc3N3b3JkPjwhW0NEQVRBW11dPjwvUGFzc3dvcmQ+DQogICAgICAgICAgICAgICAgICAgIDxVc2VybmFtZT48IVtDREFUQVtdXT48L1VzZXJuYW1lPg0KICAgICAgICAgICAgICAgIDwvQ3JlZGVudGlhbHM+DQogICAgICAgICAgICAgICAgPEpvaW5Eb21haW4+PCFbQ0RBVEFbXV0+PC9Kb2luRG9tYWluPg0KICAgICAgICAgICAgICAgIDxNYWNoaW5lT2JqZWN0T1U+PCFbQ0RBVEFbXV0+PC9NYWNoaW5lT2JqZWN0T1U+DQogICAgICAgICAgICA8L0lkZW50aWZpY2F0aW9uPg0KICAgICAgICA8L2NvbXBvbmVudD4NCiAgICA8L3NldHRpbmdzPg0KICAgIDxzZXR0aW5ncyBwYXNzPSJvb2JlU3lzdGVtIj4NCiAgICAgICAgPGNvbXBvbmVudCBuYW1lPSJNaWNyb3NvZnQtV2luZG93cy1JbnRlcm5hdGlvbmFsLUNvcmUiIHByb2Nlc3NvckFyY2hpdGVjdHVyZT0ieDg2IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPElucHV0TG9jYWxlPjwhW0NEQVRBW2VuX1VTXV0+PC9JbnB1dExvY2FsZT4NCiAgICAgICAgICAgIDxVc2VyTG9jYWxlPjwhW0NEQVRBW2VuX1VTXV0+PC9Vc2VyTG9jYWxlPg0KICAgICAgICAgICAgPFN5c3RlbUxvY2FsZT48IVtDREFUQVtlbl9VU11dPjwvU3lzdGVtTG9jYWxlPg0KICAgICAgICAgICAgPFVJTGFuZ3VhZ2U+PCFbQ0RBVEFbZW5fVVNdXT48L1VJTGFuZ3VhZ2U+DQogICAgICAgIDwvY29tcG9uZW50Pg0KICAgICAgICA8Y29tcG9uZW50IG5hbWU9Ik1pY3Jvc29mdC1XaW5kb3dzLVNoZWxsLVNldHVwIiBwcm9jZXNzb3JBcmNoaXRlY3R1cmU9ImFtZDY0IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPE9PQkU+DQogICAgICAgICAgICAgICAgPFByb3RlY3RZb3VyUEM+MjwvUHJvdGVjdFlvdXJQQz4NCiAgICAgICAgICAgICAgICA8TmV0d29ya0xvY2F0aW9uPldvcms8L05ldHdvcmtMb2NhdGlvbj4NCiAgICAgICAgICAgICAgICA8SGlkZUVVTEFQYWdlPnRydWU8L0hpZGVFVUxBUGFnZT4NCiAgICAgICAgICAgIDwvT09CRT4NCiAgICAgICAgICAgIDxVc2VyQWNjb3VudHM+DQogICAgICAgICAgICAgICAgPEFkbWluaXN0cmF0b3JQYXNzd29yZD4NCiAgICAgICAgICAgICAgICAgICAgPFZhbHVlPjwhW0NEQVRBW1Jmb2Nlc3ExMjNdXT48L1ZhbHVlPg0KICAgICAgICAgICAgICAgICAgICA8UGxhaW5UZXh0PnRydWU8L1BsYWluVGV4dD4NCiAgICAgICAgICAgICAgICA8L0FkbWluaXN0cmF0b3JQYXNzd29yZD4NCiAgICAgICAgICAgICAgICA8TG9jYWxBY2NvdW50cz4NCiAgICAgICAgICAgICAgICAgICAgPExvY2FsQWNjb3VudCB3Y206YWN0aW9uPSJhZGQiPg0KICAgICAgICAgICAgICAgICAgICAgICAgPFBhc3N3b3JkPg0KICAgICAgICAgICAgICAgICAgICAgICAgICAgIDxWYWx1ZT48IVtDREFUQVtSZm9jZXNxMTIzXV0+PC9WYWx1ZT4NCiAgICAgICAgICAgICAgICAgICAgICAgICAgICA8UGxhaW5UZXh0PnRydWU8L1BsYWluVGV4dD4NCiAgICAgICAgICAgICAgICAgICAgICAgIDwvUGFzc3dvcmQ+DQogICAgICAgICAgICAgICAgICAgICAgICA8R3JvdXA+YWRtaW5pc3RyYXRvcnM8L0dyb3VwPg0KICAgICAgICAgICAgICAgICAgICAgICAgPE5hbWU+dXNlcjwvTmFtZT4NCiAgICAgICAgICAgICAgICAgICAgICAgIDxEaXNwbGF5TmFtZT51c2VyPC9EaXNwbGF5TmFtZT4NCiAgICAgICAgICAgICAgICAgICAgPC9Mb2NhbEFjY291bnQ+DQogICAgICAgICAgICAgICAgPC9Mb2NhbEFjY291bnRzPg0KICAgICAgICAgICAgPC9Vc2VyQWNjb3VudHM+DQogICAgICAgIDwvY29tcG9uZW50Pg0KICAgIDwvc2V0dGluZ3M+DQogICAgPGNwaTpvZmZsaW5lSW1hZ2UgY3BpOnNvdXJjZT0id2ltOmQ6L3NvdXJjZXMvaW5zdGFsbC53aW0jV2luZG93cyA3IEVOVEVSUFJJU0UiIHhtbG5zOmNwaT0idXJuOnNjaGVtYXMtbWljcm9zb2Z0LWNvbTpjcGkiLz4NCjwvdW5hdHRlbmQ+DQo=}}}, path=, device=floppy, type=disk, readonly=true, deviceId=fb539842-44d0-4e62-bce6-a298099f3271}, {specParams={vram=32768, heads=1}, device=qxl, type=video, deviceId=663b34a7-736f-407b-a095-f255416e2e1e}, {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=77ac75cd-3033-4b32-82d9-1d5b16402f87}, {shared=false, index=0, volumeID=4b802949-5ae2-4a25-bab3-d28db0773d7a, 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=76760a81-ee92-4791-bce2-766d3798ee85, specParams={}, optional=false, device=disk, poolID=00000002-0002-0002-0002-00000000005e, readonly=false, deviceId=76760a81-ee92-4791-bce2-766d3798ee85}, {nicModel=pv, address={bus=0x00, domain=0x0000, type=pci, slot=0x03, function=0x0}, specParams={outbound={}, inbound={}}, macAddr=00:01:a4:a3:96:08, device=bridge, linkActive=true, type=interface, filter=vdsm-no-mac-spoofing, network=ovirtmgmt, deviceId=9be5f331-21d1-473f-9acf-7b75af1a2a71}, {index=0, model=ich9-uhci2, address={bus=0x00, domain=0x0000, type=pci, slot=0x08, function=0x1}, specParams={}, device=usb, type=controller, deviceId=0c634be5-68b0-4aca-84e5-39be52c1aad7}, {index=0, model=ich9-uhci3, address={bus=0x00, domain=0x0000, type=pci, slot=0x08, function=0x2}, specParams={}, device=usb, type=controller, deviceId=a3efe93f-f96a-44b3-a61a-dbb58e13cad1}, {index=0, model=ich9-uhci1, address={bus=0x00, domain=0x0000, type=pci, multifunction=on, slot=0x08, function=0x0}, specParams={}, device=usb, type=controller, deviceId=b9de904c-e90f-4f0a-aa3a-e336e76e1161}, {bus=usb, specParams={}, device=spicevmc, type=redir, deviceId=9526bf90-1421-4d66-a55b-4999725347d1}, {bus=usb, specParams={}, device=spicevmc, type=redir, deviceId=00a043f7-7d19-40b8-a674-c1d0addf3b23}, {bus=usb, specParams={}, device=spicevmc, type=redir, deviceId=330d6439-46b5-4924-88a5-752aaafc42a0}, {bus=usb, specParams={}, device=spicevmc, type=redir, deviceId=4678aa61-99ea-47ec-a34e-47923f8a857d}, {address={bus=0x00, domain=0x0000, type=pci, slot=0x06, function=0x0}, specParams={}, device=virtio-serial, type=controller, deviceId=e61366be-a79d-428e-8020-4b95e017a687}],vmName=TestPoolAuto-1,cpuType=Conroe,fileTransferEnable=true 2015-07-27 12:15:29,123 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVmFromSysPrepVDSCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] FINISH, CreateVmFromSysPrepVDSCommand, log id: 28780d5f 2015-07-27 12:15:29,139 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 707f395a 2015-07-27 12:15:29,145 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] Lock freed to object EngineLock [exclusiveLocks= key: bc628809-6018-48d9-a0d0-793d8e2ae60b value: VM , sharedLocks= ] 2015-07-27 12:15:29,164 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-36) [65308fd0] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type RunVm completed, handling the result. 2015-07-27 12:15:29,171 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-36) [65308fd0] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type RunVm succeeded, clearing tasks. 2015-07-27 12:15:29,190 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-36) [65308fd0] SPMAsyncTask::ClearAsyncTask: Attempting to clear task 4ddc7a8b-f741-4478-bd40-05e857d5efb9 2015-07-27 12:15:29,197 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] START, SPMClearTaskVDSCommand( storagePoolId = 00000002-0002-0002-0002-00000000005e, ignoreFailoverLimit = false, taskId = 4ddc7a8b-f741-4478-bd40-05e857d5efb9), log id: 20a0441a 2015-07-27 12:15:29,207 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] START, HSMClearTaskVDSCommand(HostName = kvm02, HostId = 4aeb8095-1198-4afe-aab2-d9c6408c88c2, taskId=4ddc7a8b-f741-4478-bd40-05e857d5efb9), log id: 79d717b1 2015-07-27 12:15:29,236 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] FINISH, HSMClearTaskVDSCommand, log id: 79d717b1 2015-07-27 12:15:29,242 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-36) [65308fd0] FINISH, SPMClearTaskVDSCommand, log id: 20a0441a 2015-07-27 12:15:29,252 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-36) [65308fd0] BaseAsyncTask::removeTaskFromDB: Removed task 4ddc7a8b-f741-4478-bd40-05e857d5efb9 from DataBase 2015-07-27 12:15:29,259 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-36) [65308fd0] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity d8318acc-d96c-4958-a8c5-1f93cad54765 2015-07-27 12:15:30,950 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-74) [62ecfb7d] START, FullListVdsCommand(HostName = kvm01, HostId = d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe, vds=Host[kvm01,d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe], vmIds=[bc628809-6018-48d9-a0d0-793d8e2ae60b]), log id: ee7263c 2015-07-27 12:15:30,961 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-74) [62ecfb7d] FINISH, FullListVdsCommand, return: [{acpiEnable=true, emulatedMachine=rhel6.5.0, vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, memGuaranteedSize=1024, transparentHugePages=true, displaySecurePort=-1, spiceSslCipherSuite=DEFAULT, cpuType=Conroe, smp=2, smartcardEnable=false, hypervEnable=true, custom={device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1ac=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=0d2383cf-4790-4d3a-b62d-c78d1ec8e1ac, 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=ide0, customProperties={}, snapshotId=null, logicalName=null}, device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1acdevice_5726451e-8bd2-4869-90e4-58dd83e0f707device_38f7dd0b-94be-4eba-9792-8978fadce286device_7fa37687-1772-4aee-9018-5f121e12e717=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=7fa37687-1772-4aee-9018-5f121e12e717, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=1}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null, logicalName=null}, device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1acdevice_5726451e-8bd2-4869-90e4-58dd83e0f707device_38f7dd0b-94be-4eba-9792-8978fadce286=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=38f7dd0b-94be-4eba-9792-8978fadce286, 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}, device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1acdevice_5726451e-8bd2-4869-90e4-58dd83e0f707=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=5726451e-8bd2-4869-90e4-58dd83e0f707, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=2}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null, logicalName=null}}, vmType=kvm, memSize=4096, smpCoresPerSocket=1, vmName=TestPoolAuto-1, nice=0, status=WaitForLaunch, bootMenuEnable=false, pid=0, copyPasteEnable=true, displayIp=192.168.0.55, displayPort=-1, guestDiskMapping={}, clientIp=, fileTransferEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, kvmEnable=true, displayNetwork=ovirtmgmt, devices=[Ljava.lang.Object;@697f34c8, timeOffset=7200, maxVCpus=16, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, display=qxl}], log id: ee7263c 2015-07-27 12:15:31,022 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-74) [62ecfb7d] Received a floppy Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device 2015-07-27 12:15:31,030 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-74) [62ecfb7d] Received a qxl Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {device=qxl, specParams={vram=32768, heads=1}, deviceType=video, type=video, deviceId=663b34a7-736f-407b-a095-f255416e2e1e} 2015-07-27 12:15:31,041 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-74) [62ecfb7d] Received a spicevmc Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {bus=usb, specParams={}, deviceType=redir, deviceId=9526bf90-1421-4d66-a55b-4999725347d1, device=spicevmc, type=redir} 2015-07-27 12:15:31,051 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-74) [62ecfb7d] Received a spicevmc Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {bus=usb, specParams={}, deviceType=redir, deviceId=00a043f7-7d19-40b8-a674-c1d0addf3b23, device=spicevmc, type=redir} 2015-07-27 12:15:31,056 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-74) [62ecfb7d] Received a spicevmc Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {bus=usb, specParams={}, deviceType=redir, deviceId=330d6439-46b5-4924-88a5-752aaafc42a0, device=spicevmc, type=redir} 2015-07-27 12:15:31,057 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-74) [62ecfb7d] Received a spicevmc Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {bus=usb, specParams={}, deviceType=redir, deviceId=4678aa61-99ea-47ec-a34e-47923f8a857d, device=spicevmc, type=redir} 2015-07-27 12:15:34,128 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-98) VM TestPoolAuto-1 bc628809-6018-48d9-a0d0-793d8e2ae60b moved from WaitForLaunch --> PoweringUp 2015-07-27 12:15:34,129 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-98) START, FullListVdsCommand(HostName = kvm01, HostId = d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe, vds=Host[kvm01,d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe], vmIds=[bc628809-6018-48d9-a0d0-793d8e2ae60b]), log id: 2353a676 2015-07-27 12:15:34,141 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-98) FINISH, FullListVdsCommand, return: [{acpiEnable=true, emulatedMachine=rhel6.5.0, vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, memGuaranteedSize=1024, transparentHugePages=true, displaySecurePort=5900, spiceSslCipherSuite=DEFAULT, cpuType=Conroe, smp=2, pauseCode=NOERR, smartcardEnable=false, hypervEnable=true, custom={device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1ac=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=0d2383cf-4790-4d3a-b62d-c78d1ec8e1ac, 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=ide0, customProperties={}, snapshotId=null, logicalName=null}, device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1acdevice_5726451e-8bd2-4869-90e4-58dd83e0f707device_38f7dd0b-94be-4eba-9792-8978fadce286device_7fa37687-1772-4aee-9018-5f121e12e717=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=7fa37687-1772-4aee-9018-5f121e12e717, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=1}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null, logicalName=null}, device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1acdevice_5726451e-8bd2-4869-90e4-58dd83e0f707device_38f7dd0b-94be-4eba-9792-8978fadce286=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=38f7dd0b-94be-4eba-9792-8978fadce286, 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}, device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1acdevice_5726451e-8bd2-4869-90e4-58dd83e0f707=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=5726451e-8bd2-4869-90e4-58dd83e0f707, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=2}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null, logicalName=null}}, vmType=kvm, memSize=4096, smpCoresPerSocket=1, vmName=TestPoolAuto-1, nice=0, status=Up, bootMenuEnable=false, pid=18291, copyPasteEnable=true, displayIp=192.168.0.55, displayPort=-1, guestDiskMapping={}, clientIp=, fileTransferEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, kvmEnable=true, displayNetwork=ovirtmgmt, devices=[Ljava.lang.Object;@48d59f18, timeOffset=7200, maxVCpus=16, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, display=qxl}], log id: 2353a676 2015-07-27 12:15:34,204 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-98) Received a memballoon Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {device=memballoon, specParams={model=none}, deviceType=balloon, type=balloon, alias=balloon0} 2015-07-27 12:15:34,213 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-98) Received a spicevmc Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {bus=usb, specParams={}, deviceType=redir, deviceId=9526bf90-1421-4d66-a55b-4999725347d1, device=spicevmc, type=redir} 2015-07-27 12:15:34,224 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-98) Received a spicevmc Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {bus=usb, specParams={}, deviceType=redir, deviceId=00a043f7-7d19-40b8-a674-c1d0addf3b23, device=spicevmc, type=redir} 2015-07-27 12:15:34,234 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-98) Received a spicevmc Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {bus=usb, specParams={}, deviceType=redir, deviceId=330d6439-46b5-4924-88a5-752aaafc42a0, device=spicevmc, type=redir} 2015-07-27 12:15:34,248 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-98) Received a spicevmc Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {bus=usb, specParams={}, deviceType=redir, deviceId=4678aa61-99ea-47ec-a34e-47923f8a857d, device=spicevmc, type=redir} 2015-07-27 12:15:34,259 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-98) Received a spice Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {device=spice, specParams={displayNetwork=ovirtmgmt, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, keyMap=en-us, displayIp=192.168.0.55, copyPasteEnable=true}, deviceType=graphics, type=graphics, tlsPort=5900} 2015-07-27 12:16:29,505 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-13) [4ec0a66d] VM TestPoolAuto-1 bc628809-6018-48d9-a0d0-793d8e2ae60b moved from PoweringUp --> Up 2015-07-27 12:16:29,531 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-13) [4ec0a66d] Correlation ID: 65308fd0, Job ID: 679f1cd8-2ffe-4e16-bc51-857ffab80eab, Call Stack: null, Custom Event ID: -1, Message: VM TestPoolAuto-1 was restarted on Host kvm01 as stateless 2015-07-27 12:16:42,758 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-15) [2994ee4] Setting new tasks map. The map contains now 0 tasks 2015-07-27 12:16:42,759 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-15) [2994ee4] Cleared all tasks of pool 00000002-0002-0002-0002-00000000005e. 2015-07-27 12:16:46,746 INFO [org.ovirt.engine.core.bll.SetVmTicketCommand] (ajp--127.0.0.1-8702-6) [46c9878e] Running command: SetVmTicketCommand internal: false. Entities affected : ID: bc628809-6018-48d9-a0d0-793d8e2ae60b Type: VMAction group CONNECT_TO_VM with role type USER 2015-07-27 12:16:46,753 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (ajp--127.0.0.1-8702-6) [46c9878e] START, SetVmTicketVDSCommand(HostName = kvm01, HostId = d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe, vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, ticket=XEwZCmrBC8fS, validTime=120,m userName=admin, userId=fdfc627c-d875-11e0-90f0-83df133b58cc), log id: 4f208f2c 2015-07-27 12:16:46,814 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (ajp--127.0.0.1-8702-6) [46c9878e] FINISH, SetVmTicketVDSCommand, log id: 4f208f2c 2015-07-27 12:16:46,829 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) [46c9878e] Correlation ID: 46c9878e, Call Stack: null, Custom Event ID: -1, Message: user admin@internal initiated console session for VM TestPoolAuto-1 2015-07-27 12:17:33,917 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-21) [1f94e1d1] START, FullListVdsCommand(HostName = kvm01, HostId = d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe, vds=Host[kvm01,d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe], vmIds=[bc628809-6018-48d9-a0d0-793d8e2ae60b]), log id: 1cb36bbe 2015-07-27 12:17:33,939 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-21) [1f94e1d1] FINISH, FullListVdsCommand, return: [{acpiEnable=true, emulatedMachine=rhel6.5.0, vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, memGuaranteedSize=1024, transparentHugePages=true, displaySecurePort=5900, spiceSslCipherSuite=DEFAULT, cpuType=Conroe, smp=2, pauseCode=NOERR, smartcardEnable=false, hypervEnable=true, custom={device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1ac=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=0d2383cf-4790-4d3a-b62d-c78d1ec8e1ac, 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=ide0, customProperties={}, snapshotId=null, logicalName=null}, device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1acdevice_5726451e-8bd2-4869-90e4-58dd83e0f707device_38f7dd0b-94be-4eba-9792-8978fadce286device_7fa37687-1772-4aee-9018-5f121e12e717=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=7fa37687-1772-4aee-9018-5f121e12e717, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=1}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null, logicalName=null}, device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1acdevice_5726451e-8bd2-4869-90e4-58dd83e0f707device_38f7dd0b-94be-4eba-9792-8978fadce286=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=38f7dd0b-94be-4eba-9792-8978fadce286, 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}, device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1acdevice_5726451e-8bd2-4869-90e4-58dd83e0f707=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=5726451e-8bd2-4869-90e4-58dd83e0f707, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=2}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null, logicalName=null}}, vmType=kvm, memSize=4096, smpCoresPerSocket=1, vmName=TestPoolAuto-1, nice=0, status=Up, bootMenuEnable=false, pid=18291, copyPasteEnable=true, displayIp=192.168.0.55, displayPort=-1, guestDiskMapping={}, clientIp=, fileTransferEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, kvmEnable=true, displayNetwork=ovirtmgmt, devices=[Ljava.lang.Object;@54e913b4, timeOffset=7200, maxVCpus=16, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, display=qxl}], log id: 1cb36bbe 2015-07-27 12:17:34,000 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-21) [1f94e1d1] Received a memballoon Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {device=memballoon, specParams={model=none}, deviceType=balloon, type=balloon, alias=balloon0} 2015-07-27 12:17:34,011 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-21) [1f94e1d1] Received a spicevmc Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {bus=usb, specParams={}, deviceType=redir, deviceId=9526bf90-1421-4d66-a55b-4999725347d1, device=spicevmc, type=redir} 2015-07-27 12:17:34,022 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-21) [1f94e1d1] Received a spicevmc Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {bus=usb, specParams={}, deviceType=redir, deviceId=00a043f7-7d19-40b8-a674-c1d0addf3b23, device=spicevmc, type=redir} 2015-07-27 12:17:34,039 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-21) [1f94e1d1] Received a spicevmc Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {bus=usb, specParams={}, deviceType=redir, deviceId=330d6439-46b5-4924-88a5-752aaafc42a0, device=spicevmc, type=redir} 2015-07-27 12:17:34,050 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-21) [1f94e1d1] Received a spicevmc Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {bus=usb, specParams={}, deviceType=redir, deviceId=4678aa61-99ea-47ec-a34e-47923f8a857d, device=spicevmc, type=redir} 2015-07-27 12:17:34,074 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-21) [1f94e1d1] Received a spice Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {device=spice, specParams={displayNetwork=ovirtmgmt, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, keyMap=en-us, displayIp=192.168.0.55, copyPasteEnable=true}, deviceType=graphics, type=graphics, tlsPort=5900} 2015-07-27 12:19:36,015 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-19) [3ec2eaa1] VM TestPoolAuto-1 bc628809-6018-48d9-a0d0-793d8e2ae60b moved from Up --> RebootInProgress 2015-07-27 12:19:36,023 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-19) [3ec2eaa1] START, FullListVdsCommand(HostName = kvm01, HostId = d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe, vds=Host[kvm01,d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe], vmIds=[bc628809-6018-48d9-a0d0-793d8e2ae60b]), log id: 4f3a82f4 2015-07-27 12:19:36,191 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-19) [3ec2eaa1] FINISH, FullListVdsCommand, return: [{acpiEnable=true, emulatedMachine=rhel6.5.0, vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, memGuaranteedSize=1024, transparentHugePages=true, displaySecurePort=5900, spiceSslCipherSuite=DEFAULT, cpuType=Conroe, smp=2, pauseCode=NOERR, smartcardEnable=false, hypervEnable=true, custom={device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1ac=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=0d2383cf-4790-4d3a-b62d-c78d1ec8e1ac, 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=ide0, customProperties={}, snapshotId=null, logicalName=null}, device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1acdevice_5726451e-8bd2-4869-90e4-58dd83e0f707device_38f7dd0b-94be-4eba-9792-8978fadce286device_7fa37687-1772-4aee-9018-5f121e12e717=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=7fa37687-1772-4aee-9018-5f121e12e717, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=1}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null, logicalName=null}, device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1acdevice_5726451e-8bd2-4869-90e4-58dd83e0f707device_38f7dd0b-94be-4eba-9792-8978fadce286=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=38f7dd0b-94be-4eba-9792-8978fadce286, 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}, device_0d2383cf-4790-4d3a-b62d-c78d1ec8e1acdevice_5726451e-8bd2-4869-90e4-58dd83e0f707=VmDevice {vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, deviceId=5726451e-8bd2-4869-90e4-58dd83e0f707, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=2}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null, logicalName=null}}, vmType=kvm, memSize=4096, smpCoresPerSocket=1, vmName=TestPoolAuto-1, nice=0, status=Up, bootMenuEnable=false, pid=18291, copyPasteEnable=true, displayIp=192.168.0.55, displayPort=-1, guestDiskMapping={}, clientIp=, fileTransferEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, kvmEnable=true, displayNetwork=ovirtmgmt, devices=[Ljava.lang.Object;@a6b89cf, timeOffset=14400, maxVCpus=16, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, display=qxl}], log id: 4f3a82f4 2015-07-27 12:19:36,281 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-19) [3ec2eaa1] Received a memballoon Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {device=memballoon, specParams={model=none}, deviceType=balloon, type=balloon, alias=balloon0} 2015-07-27 12:19:36,282 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-19) [3ec2eaa1] Received a spicevmc Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {bus=usb, specParams={}, deviceType=redir, deviceId=9526bf90-1421-4d66-a55b-4999725347d1, device=spicevmc, type=redir} 2015-07-27 12:19:36,284 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-19) [3ec2eaa1] Received a spicevmc Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {bus=usb, specParams={}, deviceType=redir, deviceId=00a043f7-7d19-40b8-a674-c1d0addf3b23, device=spicevmc, type=redir} 2015-07-27 12:19:36,286 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-19) [3ec2eaa1] Received a spicevmc Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {bus=usb, specParams={}, deviceType=redir, deviceId=330d6439-46b5-4924-88a5-752aaafc42a0, device=spicevmc, type=redir} 2015-07-27 12:19:36,288 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-19) [3ec2eaa1] Received a spicevmc Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {bus=usb, specParams={}, deviceType=redir, deviceId=4678aa61-99ea-47ec-a34e-47923f8a857d, device=spicevmc, type=redir} 2015-07-27 12:19:36,290 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-19) [3ec2eaa1] Received a spice Device without an address when processing VM bc628809-6018-48d9-a0d0-793d8e2ae60b devices, skipping device: {device=spice, specParams={displayNetwork=ovirtmgmt, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, keyMap=en-us, displayIp=192.168.0.55, copyPasteEnable=true}, deviceType=graphics, type=graphics, tlsPort=5900} 2015-07-27 12:21:20,949 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-82) [50c1bbd6] VM TestPoolAuto-1 bc628809-6018-48d9-a0d0-793d8e2ae60b moved from RebootInProgress --> Up 2015-07-27 12:21:24,021 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-74) [62ecfb7d] VM TestPoolAuto-1 bc628809-6018-48d9-a0d0-793d8e2ae60b moved from Up --> RebootInProgress 2015-07-27 12:21:51,889 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-43) [5cceecd8] VM TestPoolAuto-1 bc628809-6018-48d9-a0d0-793d8e2ae60b moved from RebootInProgress --> Up 2015-07-27 12:24:26,557 WARN [org.ovirt.engine.core.bll.SetVmTicketCommand] (ajp--127.0.0.1-8702-3) [515006c1] User "d69d8d20-68b7-4fed-9c08-5c2ecb257583" is trying to take the console of virtual machine "bc628809-6018-48d9-a0d0-793d8e2ae60b", but the console is already taken by user "fdfc627c-d875-11e0-90f0-83df133b58cc". 2015-07-27 12:24:26,561 WARN [org.ovirt.engine.core.bll.SetVmTicketCommand] (ajp--127.0.0.1-8702-3) [515006c1] User "d69d8d20-68b7-4fed-9c08-5c2ecb257583" is trying to take the console of virtual machine "bc628809-6018-48d9-a0d0-793d8e2ae60b", but the console is already taken by user "fdfc627c-d875-11e0-90f0-83df133b58cc". 2015-07-27 12:24:26,563 INFO [org.ovirt.engine.core.bll.SetVmTicketCommand] (ajp--127.0.0.1-8702-3) [515006c1] Running command: SetVmTicketCommand internal: false. Entities affected : ID: bc628809-6018-48d9-a0d0-793d8e2ae60b Type: VMAction group CONNECT_TO_VM with role type USER, ID: bc628809-6018-48d9-a0d0-793d8e2ae60b Type: VMAction group RECONNECT_TO_VM with role type USER 2015-07-27 12:24:26,570 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (ajp--127.0.0.1-8702-3) [515006c1] START, SetVmTicketVDSCommand(HostName = kvm01, HostId = d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe, vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, ticket=0y6CBeWQshBn, validTime=120,m userName=c.mammoli, userId=d69d8d20-68b7-4fed-9c08-5c2ecb257583), log id: 4532bed0 2015-07-27 12:24:26,606 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (ajp--127.0.0.1-8702-3) [515006c1] FINISH, SetVmTicketVDSCommand, log id: 4532bed0 2015-07-27 12:24:26,628 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [515006c1] Correlation ID: 515006c1, Call Stack: null, Custom Event ID: -1, Message: user c.mammoli@apra.it initiated console session for VM TestPoolAuto-1 2015-07-27 12:24:26,681 WARN [org.ovirt.engine.core.dal.job.ExecutionMessageDirector] (ajp--127.0.0.1-8702-7) [532d1bbb] The message key VmLogon is missing from bundles/ExecutionMessages 2015-07-27 12:24:26,789 INFO [org.ovirt.engine.core.bll.VmLogonCommand] (ajp--127.0.0.1-8702-7) [532d1bbb] Running command: VmLogonCommand internal: false. Entities affected : ID: bc628809-6018-48d9-a0d0-793d8e2ae60b Type: VMAction group CONNECT_TO_VM with role type USER 2015-07-27 12:24:26,794 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmLogonVDSCommand] (ajp--127.0.0.1-8702-7) [532d1bbb] START, VmLogonVDSCommand(HostName = kvm01, HostId = d2b7c9d1-6e5b-4222-a5ee-9a37ba8abcfe, vmId=bc628809-6018-48d9-a0d0-793d8e2ae60b, domain=apra.it, password=******, userName=c.mammoli@apra.it), log id: 3915ba19 2015-07-27 12:24:26,819 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmLogonVDSCommand] (ajp--127.0.0.1-8702-7) [532d1bbb] FINISH, VmLogonVDSCommand, log id: 3915ba19 --