2014-04-24 13:11:36,241 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-20) [1a138258] Correlation ID: 1a138258, Call Stack: null, Custom Event ID: -1, Message: Invalid status on Data Center Default. Setting status to Non Responsive.
2014-04-24 13:11:36,255 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (DefaultQuartzScheduler_Worker-20) [1a138258] hostFromVds::selectedVds - srv-0202, spmStatus Free, storage pool Default
2014-04-24 13:11:36,258 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (DefaultQuartzScheduler_Worker-20) [1a138258] starting spm on vds srv-0202, storage pool Default, prevId -1, LVER -1
2014-04-24 13:11:36,259 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (DefaultQuartzScheduler_Worker-20) [1a138258] START, SpmStartVDSCommand(HostName = srv-0202, HostId = fbdf0655-6560-4e12-a95a-875592f62cb5, storagePoolId = 5849b030-626e-47cb-ad90-3ce782d831b3, prevId=-1, prevLVER=-1, storagePoolFormatType=V3, recoveryMode=Manual, SCSIFencing=false), log id: 778a334c
2014-04-24 13:11:36,310 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (DefaultQuartzScheduler_Worker-20) [1a138258] spmStart polling started: taskId = 198c7765-38cb-42e7-9349-93ca43be7066
2014-04-24 13:11:37,315 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetTaskStatusVDSCommand] (DefaultQuartzScheduler_Worker-20) [1a138258] Failed in HSMGetTaskStatusVDS method
2014-04-24 13:11:37,316 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (DefaultQuartzScheduler_Worker-20) [1a138258] spmStart polling ended: taskId = 198c7765-38cb-42e7-9349-93ca43be7066 task status = finished
2014-04-24 13:11:37,316 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (DefaultQuartzScheduler_Worker-20) [1a138258] Start SPM Task failed - result: cleanSuccess, message: VDSGenericException: VDSErrorException: Failed to HSMGetTaskStatusVDS, error = Storage domain does not exist, code = 358
2014-04-24 13:11:37,363 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (DefaultQuartzScheduler_Worker-20) [1a138258] spmStart polling ended, spm status: Free
2014-04-24 13:11:37,364 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (DefaultQuartzScheduler_Worker-20) [1a138258] START, HSMClearTaskVDSCommand(HostName = srv-0202, HostId = fbdf0655-6560-4e12-a95a-875592f62cb5, taskId=198c7765-38cb-42e7-9349-93ca43be7066), log id: 6e6ad022
2014-04-24 13:11:37,409 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (DefaultQuartzScheduler_Worker-20) [1a138258] FINISH, HSMClearTaskVDSCommand, log id: 6e6ad022
2014-04-24 13:11:37,409 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (DefaultQuartzScheduler_Worker-20) [1a138258] FINISH, SpmStartVDSCommand, return: org.ovirt.engine.core.common.businessentities.SpmStatusResult@dfe925d, log id: 778a334c
2014-04-24 13:11:37,411 INFO [org.ovirt.engine.core.bll.storage.SetStoragePoolStatusCommand] (DefaultQuartzScheduler_Worker-20) [443b1ed8] Running command: SetStoragePoolStatusCommand internal: true. Entities affected : ID: 5849b030-626e-47cb-ad90-3ce782d831b3 Type: StoragePool
2014-04-24 13:11:37,416 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-20) [443b1ed8] Correlation ID: 443b1ed8, Call Stack: null, Custom Event ID: -1, Message: Invalid status on Data Center Default. Setting status to Non Responsive.
2014-04-24 13:11:37,418 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (DefaultQuartzScheduler_Worker-20) [443b1ed8] IrsBroker::Failed::GetStoragePoolInfoVDS due to: IrsSpmStartFailedException: IRSGenericException: IRSErrorException: SpmStart failed
2014-04-24 13:11:37,466 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (DefaultQuartzScheduler_Worker-20) [443b1ed8] Irs placed on server fbdf0655-6560-4e12-a95a-875592f62cb5 failed. Proceed Failover
2014-04-24 13:11:37,528 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (DefaultQuartzScheduler_Worker-20) [443b1ed8] hostFromVds::selectedVds - srv-0203, spmStatus Free, storage pool Default
2014-04-24 13:11:37,530 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (DefaultQuartzScheduler_Worker-20) [443b1ed8] starting spm on vds srv-0203, storage pool Default, prevId -1, LVER -1
2014-04-24 13:11:37,531 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (DefaultQuartzScheduler_Worker-20) [443b1ed8] START, SpmStartVDSCommand(HostName = srv-0203, HostId = 6e86beba-ee71-4bae-88d5-b95b74095c2f, storagePoolId = 5849b030-626e-47cb-ad90-3ce782d831b3, prevId=-1, prevLVER=-1, storagePoolFormatType=V3, recoveryMode=Manual, SCSIFencing=false), log id: 77e0918
2014-04-24 13:11:37,589 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (DefaultQuartzScheduler_Worker-20) [443b1ed8] spmStart polling started: taskId = 81164899-b8b5-4ea5-9c82-94b66a3df741
2014-04-24 13:11:38,595 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (DefaultQuartzScheduler_Worker-20) [443b1ed8] spmStart polling ended: taskId = 81164899-b8b5-4ea5-9c82-94b66a3df741 task status = finished
2014-04-24 13:11:38,652 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (DefaultQuartzScheduler_Worker-20) [443b1ed8] spmStart polling ended, spm status: SPM
2014-04-24 13:11:38,653 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (DefaultQuartzScheduler_Worker-20) [443b1ed8] START, HSMClearTaskVDSCommand(HostName = srv-0203, HostId = 6e86beba-ee71-4bae-88d5-b95b74095c2f, taskId=81164899-b8b5-4ea5-9c82-94b66a3df741), log id: 71e2abc
2014-04-24 13:11:38,698 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (DefaultQuartzScheduler_Worker-20) [443b1ed8] FINISH, HSMClearTaskVDSCommand, log id: 71e2abc
2014-04-24 13:11:38,698 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (DefaultQuartzScheduler_Worker-20) [443b1ed8] FINISH, SpmStartVDSCommand, return: org.ovirt.engine.core.common.businessentities.SpmStatusResult@67238f8a, log id: 77e0918
2014-04-24 13:11:38,699 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (DefaultQuartzScheduler_Worker-20) [443b1ed8] Initialize Irs proxy from vds:
srv-0203.lttd.br
2014-04-24 13:11:38,703 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-20) [443b1ed8] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Storage Pool Manager runs on Host srv-0203 (Address:
srv-0203.lttd.br).
2014-04-24 13:11:38,703 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-48) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue.
2014-04-24 13:11:38,711 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-6-thread-48) [443b1ed8] START, SPMGetAllTasksInfoVDSCommand( storagePoolId = 5849b030-626e-47cb-ad90-3ce782d831b3, ignoreFailoverLimit = false), log id: 710a52c9
2014-04-24 13:11:38,735 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-6-thread-48) [443b1ed8] -- executeIrsBrokerCommand: Attempting on storage pool 5849b030-626e-47cb-ad90-3ce782d831b3
2014-04-24 13:11:38,736 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-6-thread-48) [443b1ed8] START, HSMGetAllTasksInfoVDSCommand(HostName = srv-0203, HostId = 6e86beba-ee71-4bae-88d5-b95b74095c2f), log id: 14a15273
2014-04-24 13:11:38,741 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-6-thread-48) [443b1ed8] FINISH, HSMGetAllTasksInfoVDSCommand, return: [], log id: 14a15273
2014-04-24 13:11:38,741 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-6-thread-48) [443b1ed8] FINISH, SPMGetAllTasksInfoVDSCommand, return: [], log id: 710a52c9
2014-04-24 13:11:38,741 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (org.ovirt.thread.pool-6-thread-48) [443b1ed8] Discovered no tasks on Storage Pool Default
2014-04-24 13:14:52,094 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-11) starting processDomainRecovery for domain 6c6178c6-f7cf-4f2c-b8f9-73cf8f18bb4d:ISO_DOMAIN
2014-04-24 13:14:52,097 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-11) Storage domain 6c6178c6-f7cf-4f2c-b8f9-73cf8f18bb4d:ISO_DOMAIN is not visible to one or more hosts. Since the domains type is ISO, hosts status will not be changed to non-operational
2014-04-24 13:14:54,923 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-37) domain 6c6178c6-f7cf-4f2c-b8f9-73cf8f18bb4d:ISO_DOMAIN in problem. vds: srv-0202
2014-04-24 13:17:59,281 INFO [org.ovirt.engine.core.bll.AddVmFromTemplateCommand] (ajp--127.0.0.1-8702-9) [7fb59186] Lock Acquired to object EngineLock [exclusiveLocks= key: servidor-teste value: VM_NAME
, sharedLocks= key: 1f08d35a-adf0-4734-9ce6-1431406096ba value: TEMPLATE
key: c8e52f2a-5384-41ee-af77-7ee37bf54355 value: DISK
]
2014-04-24 13:17:59,302 INFO [org.ovirt.engine.core.bll.AddVmFromTemplateCommand] (ajp--127.0.0.1-8702-9) [7fb59186] Running command: AddVmFromTemplateCommand internal: false. Entities affected : ID: 99408929-82cf-4dc7-a532-9d998063fa95 Type: VdsGroups, ID: 1f08d35a-adf0-4734-9ce6-1431406096ba Type: VmTemplate, ID: 3410b593-dbd0-4ab8-9a21-3e3c51fe8e90 Type: Storage, ID: 99408929-82cf-4dc7-a532-9d998063fa95 Type: VdsGroups
2014-04-24 13:17:59,336 INFO [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (ajp--127.0.0.1-8702-9) [7fb59186] START, SetVmStatusVDSCommand( vmId = 8a94d957-621e-4cd6-b94d-64a0572cb759, status = ImageLocked), log id: 6ada3a4a
2014-04-24 13:17:59,339 INFO [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (ajp--127.0.0.1-8702-9) [7fb59186] FINISH, SetVmStatusVDSCommand, log id: 6ada3a4a
2014-04-24 13:17:59,344 INFO [org.ovirt.engine.core.bll.CreateCloneOfTemplateCommand] (ajp--127.0.0.1-8702-9) [48e79aaf] Running command: CreateCloneOfTemplateCommand internal: true. Entities affected : ID: 3410b593-dbd0-4ab8-9a21-3e3c51fe8e90 Type: Storage
2014-04-24 13:17:59,371 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (ajp--127.0.0.1-8702-9) [48e79aaf] START, CopyImageVDSCommand( storagePoolId = 5849b030-626e-47cb-ad90-3ce782d831b3, ignoreFailoverLimit = false, storageDomainId = 3410b593-dbd0-4ab8-9a21-3e3c51fe8e90, imageGroupId = c8e52f2a-5384-41ee-af77-7ee37bf54355, imageId = 5c642d47-4f03-4a81-8a10-067b98e068f4, dstImageGroupId = 5a09cae5-c7a1-466d-9b69-ff8ad739d71c, vmId = 1f08d35a-adf0-4734-9ce6-1431406096ba, dstImageId = 2d82ce92-96f1-482c-b8fe-c21d9dfb23e6, imageDescription = , dstStorageDomainId = 3410b593-dbd0-4ab8-9a21-3e3c51fe8e90, copyVolumeType = LeafVol, volumeFormat = RAW, preallocate = Sparse, postZero = false, force = false), log id: 4a480fe7
2014-04-24 13:17:59,372 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (ajp--127.0.0.1-8702-9) [48e79aaf] -- executeIrsBrokerCommand: calling 'copyImage' with two new parameters: description and UUID
2014-04-24 13:17:59,373 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (ajp--127.0.0.1-8702-9) [48e79aaf] -- copyImage parameters:
sdUUID=3410b593-dbd0-4ab8-9a21-3e3c51fe8e90
spUUID=5849b030-626e-47cb-ad90-3ce782d831b3
vmGUID=1f08d35a-adf0-4734-9ce6-1431406096ba
srcImageGUID=c8e52f2a-5384-41ee-af77-7ee37bf54355
srcVolUUID=5c642d47-4f03-4a81-8a10-067b98e068f4
dstImageGUID=5a09cae5-c7a1-466d-9b69-ff8ad739d71c
dstVolUUID=2d82ce92-96f1-482c-b8fe-c21d9dfb23e6
descr=
dstSdUUID=3410b593-dbd0-4ab8-9a21-3e3c51fe8e90
2014-04-24 13:17:59,442 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (ajp--127.0.0.1-8702-9) [48e79aaf] FINISH, CopyImageVDSCommand, return: 00000000-0000-0000-0000-000000000000, log id: 4a480fe7
2014-04-24 13:17:59,446 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (ajp--127.0.0.1-8702-9) [48e79aaf] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 755c7619-60e6-4899-b772-17c56cdec057
2014-04-24 13:17:59,447 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (ajp--127.0.0.1-8702-9) [48e79aaf] CommandMultiAsyncTasks::AttachTask: Attaching task e8726bad-05ff-4f89-a127-146a3f8bceb2 to command 755c7619-60e6-4899-b772-17c56cdec057.
2014-04-24 13:17:59,451 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (ajp--127.0.0.1-8702-9) [48e79aaf] Adding task e8726bad-05ff-4f89-a127-146a3f8bceb2 (Parent Command AddVmFromTemplate, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
2014-04-24 13:17:59,497 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-9) [48e79aaf] Correlation ID: 7fb59186, Job ID: aeb08ac5-d157-40ae-bcd5-ec68d9cc5ae8, Call Stack: null, Custom Event ID: -1, Message: VM servidor-teste creation was initiated by admin.
2014-04-24 13:17:59,497 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (ajp--127.0.0.1-8702-9) [48e79aaf] BaseAsyncTask::startPollingTask: Starting to poll task e8726bad-05ff-4f89-a127-146a3f8bceb2.
2014-04-24 13:17:59,560 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-99) Polling and updating Async Tasks: 1 tasks, 1 tasks to poll now
2014-04-24 13:17:59,566 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-99) SPMAsyncTask::PollTask: Polling task e8726bad-05ff-4f89-a127-146a3f8bceb2 (Parent Command AddVmFromTemplate, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status running.
2014-04-24 13:17:59,567 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-99) Finished polling Tasks, will poll again in 10 seconds.
2014-04-24 13:17:59,653 INFO [org.ovirt.engine.core.bll.network.vm.ReorderVmNicsCommand] (ajp--127.0.0.1-8702-5) [601e9dcb] Running command: ReorderVmNicsCommand internal: false. Entities affected : ID: 8a94d957-621e-4cd6-b94d-64a0572cb759 Type: VM
2014-04-24 13:18:11,746 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-82) [1bb7dfd0] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Used Network resources of host srv-0202 [96%] exceeded defined threshold [95%].
2014-04-24 13:18:22,578 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-60) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Used Network resources of host srv-0203 [98%] exceeded defined threshold [95%].
2014-04-24 13:19:54,926 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-28) starting processDomainRecovery for domain 6c6178c6-f7cf-4f2c-b8f9-73cf8f18bb4d:ISO_DOMAIN
2014-04-24 13:19:54,929 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-28) Storage domain 6c6178c6-f7cf-4f2c-b8f9-73cf8f18bb4d:ISO_DOMAIN is not visible to one or more hosts. Since the domains type is ISO, hosts status will not be changed to non-operational
2014-04-24 13:19:57,802 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-36) domain 6c6178c6-f7cf-4f2c-b8f9-73cf8f18bb4d:ISO_DOMAIN in problem. vds: srv-0202
^C