Attachment 940644 Details for Bug 1145582 – log got from rhevm server:/var/log/ovirt-engine/engine.log

log got from rhevm server:/var/log/ovirt-engine/engine.log

engine.log (text/plain), 15.39 KB, created by zhoujunqin on 2014-09-24 02:07:04 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: zhoujunqin

Created: 2014-09-24 02:07:04 UTC

Size: 15.39 KB

patch

obsolete

>2014-09-24 02:38:35,451 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (ajp-/127.0.0.1:8702-16) START, GetVmsInfoVDSCommand( storagePoolId = 00000002-0002-0002-0002-0000000002c4, ignoreFailoverLimit = false, storageDomainId = 46adae8a-63c1-40f8-b25a-f02deb1a5160, vmIdList = null), log id: 4a3bdac4
>2014-09-24 02:38:35,762 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (ajp-/127.0.0.1:8702-16) FINISH, GetVmsInfoVDSCommand, log id: 4a3bdac4
>2014-09-24 02:42:30,796 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (ajp-/127.0.0.1:8702-10) START, GetVmsInfoVDSCommand( storagePoolId = 00000002-0002-0002-0002-0000000002c4, ignoreFailoverLimit = false, storageDomainId = 46adae8a-63c1-40f8-b25a-f02deb1a5160, vmIdList = null), log id: 1e0b814b
>2014-09-24 02:42:31,110 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (ajp-/127.0.0.1:8702-10) FINISH, GetVmsInfoVDSCommand, log id: 1e0b814b
>2014-09-24 02:42:43,268 INFO  [org.ovirt.engine.core.bll.ImportVmCommand] (ajp-/127.0.0.1:8702-3) [6989a513] Lock Acquired to object EngineLock [exclusiveLocks= key: rhel7new-new value: VM_NAME
>, sharedLocks= key: f0900074-ac38-44a2-a07c-09b4dbf12f18 value: REMOTE_VM
>]
>2014-09-24 02:42:43,282 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (ajp-/127.0.0.1:8702-3) [6989a513] START, GetVmsInfoVDSCommand( storagePoolId = 00000002-0002-0002-0002-0000000002c4, ignoreFailoverLimit = false, storageDomainId = 46adae8a-63c1-40f8-b25a-f02deb1a5160, vmIdList = null), log id: 77912273
>2014-09-24 02:42:43,583 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetVmsInfoVDSCommand] (ajp-/127.0.0.1:8702-3) [6989a513] FINISH, GetVmsInfoVDSCommand, log id: 77912273
>2014-09-24 02:42:44,394 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImagesListVDSCommand] (ajp-/127.0.0.1:8702-3) [6989a513] START, GetImagesListVDSCommand( storagePoolId = 00000002-0002-0002-0002-0000000002c4, ignoreFailoverLimit = false, sdUUID = 946b78c7-b21e-4d88-b4ee-fee464cc4ce9), log id: c03a688
>2014-09-24 02:42:44,427 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImagesListVDSCommand] (ajp-/127.0.0.1:8702-3) [6989a513] FINISH, GetImagesListVDSCommand, return: [8e3a6396-060f-4ecc-9201-84c5b035a076, b47408a1-79e2-48b3-9d24-a777c815ca0f, ae2709dd-acec-4342-8c6b-baf3252dd9a3, 809a0238-fed4-4254-8cfe-9c31062bfcbe, 1bbfa4fd-3372-41b6-8065-e46033ca8587, a7710d12-d546-4d1c-a493-9462ef600ed9], log id: c03a688
>2014-09-24 02:42:44,427 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DoesImageExistVDSCommand] (ajp-/127.0.0.1:8702-3) [6989a513] START, DoesImageExistVDSCommand( storagePoolId = 00000002-0002-0002-0002-0000000002c4, ignoreFailoverLimit = false, storageDomainId = 46adae8a-63c1-40f8-b25a-f02deb1a5160, imageGroupId = d53e2187-c391-4360-a881-68a9af8867b2, imageId = f0259f2a-f717-4a3a-b2b5-04dc6e2f600b), log id: 43aa30e1
>2014-09-24 02:42:44,504 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DoesImageExistVDSCommand] (ajp-/127.0.0.1:8702-3) [6989a513] FINISH, DoesImageExistVDSCommand, return: true, log id: 43aa30e1
>2014-09-24 02:42:44,576 INFO  [org.ovirt.engine.core.bll.ImportVmCommand] (org.ovirt.thread.pool-4-thread-18) [6989a513] Running command: ImportVmCommand internal: false. Entities affected :  ID: 946b78c7-b21e-4d88-b4ee-fee464cc4ce9 Type: Storage
>2014-09-24 02:42:44,641 INFO  [org.ovirt.engine.core.bll.ImagesHandler] (org.ovirt.thread.pool-4-thread-18) [6989a513] Disk alias retrieved from the client is null or empty, the suggested default disk alias to be used is rhel7new-new_Disk1
>2014-09-24 02:42:44,646 WARN  [org.ovirt.engine.core.bll.ImportVmCommand] (org.ovirt.thread.pool-4-thread-18) [6989a513] VM f0900074-ac38-44a2-a07c-09b4dbf12f18 doesnt have active snapshot in export domain
>2014-09-24 02:42:44,654 INFO  [org.ovirt.engine.core.bll.CopyImageGroupCommand] (org.ovirt.thread.pool-4-thread-18) [2da7b0ab] Running command: CopyImageGroupCommand internal: true. Entities affected :  ID: 946b78c7-b21e-4d88-b4ee-fee464cc4ce9 Type: Storage
>2014-09-24 02:42:44,682 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (org.ovirt.thread.pool-4-thread-18) [2da7b0ab] START, CopyImageVDSCommand( storagePoolId = 00000002-0002-0002-0002-0000000002c4, ignoreFailoverLimit = false, storageDomainId = 46adae8a-63c1-40f8-b25a-f02deb1a5160, imageGroupId = d53e2187-c391-4360-a881-68a9af8867b2, imageId = f0259f2a-f717-4a3a-b2b5-04dc6e2f600b, dstImageGroupId = d53e2187-c391-4360-a881-68a9af8867b2, vmId = f0900074-ac38-44a2-a07c-09b4dbf12f18, dstImageId = f0259f2a-f717-4a3a-b2b5-04dc6e2f600b, imageDescription = , dstStorageDomainId = 946b78c7-b21e-4d88-b4ee-fee464cc4ce9, copyVolumeType = LeafVol, volumeFormat = RAW, preallocate = Sparse, postZero = false, force = true), log id: 405564d1
>2014-09-24 02:42:44,682 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (org.ovirt.thread.pool-4-thread-18) [2da7b0ab] -- executeIrsBrokerCommand: calling 'copyImage' with two new parameters: description and UUID
>2014-09-24 02:42:44,683 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (org.ovirt.thread.pool-4-thread-18) [2da7b0ab] -- copyImage parameters:
>                sdUUID=46adae8a-63c1-40f8-b25a-f02deb1a5160
>                spUUID=00000002-0002-0002-0002-0000000002c4
>                vmGUID=f0900074-ac38-44a2-a07c-09b4dbf12f18
>                srcImageGUID=d53e2187-c391-4360-a881-68a9af8867b2
>                srcVolUUID=f0259f2a-f717-4a3a-b2b5-04dc6e2f600b
>                dstImageGUID=d53e2187-c391-4360-a881-68a9af8867b2
>                dstVolUUID=f0259f2a-f717-4a3a-b2b5-04dc6e2f600b
>                descr=
>                dstSdUUID=946b78c7-b21e-4d88-b4ee-fee464cc4ce9
>2014-09-24 02:42:44,855 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (org.ovirt.thread.pool-4-thread-18) [2da7b0ab] FINISH, CopyImageVDSCommand, return: 00000000-0000-0000-0000-000000000000, log id: 405564d1
>2014-09-24 02:42:44,893 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-4-thread-18) [2da7b0ab] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 36b8454d-c44f-4f49-ba9c-3228503c0b5d
>2014-09-24 02:42:44,893 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-4-thread-18) [2da7b0ab] CommandMultiAsyncTasks::AttachTask: Attaching task e8c80284-758c-476b-b21e-a3356ddb463b to command 36b8454d-c44f-4f49-ba9c-3228503c0b5d.
>2014-09-24 02:42:44,943 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (org.ovirt.thread.pool-4-thread-18) [2da7b0ab] Adding task e8c80284-758c-476b-b21e-a3356ddb463b (Parent Command ImportVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-09-24 02:42:45,176 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-4-thread-18) [2da7b0ab] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Network Interface eth0 has MAC address 52:54:00:6b:53:76 which is in use, therefore it is being unplugged from VM rhel7new-new.
>2014-09-24 02:42:45,176 WARN  [org.ovirt.engine.core.bll.network.VmInterfaceManager] (org.ovirt.thread.pool-4-thread-18) [2da7b0ab] Network Interface eth0 has MAC address 52:54:00:6b:53:76 which is in use, therefore it is being unplugged from VM f0900074-ac38-44a2-a07c-09b4dbf12f18.
>2014-09-24 02:42:45,220 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-4-thread-18) [2da7b0ab] START, SetVmStatusVDSCommand( vmId = f0900074-ac38-44a2-a07c-09b4dbf12f18, status = ImageLocked, exit status = Normal), log id: 24d16c5a
>2014-09-24 02:42:45,242 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-4-thread-18) [2da7b0ab] FINISH, SetVmStatusVDSCommand, log id: 24d16c5a
>2014-09-24 02:42:45,302 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-4-thread-18) [2da7b0ab] Correlation ID: 6989a513, Job ID: dc8dd277-02e7-432f-b336-5314a13c31f0, Call Stack: null, Custom Event ID: -1, Message: Starting to import Vm rhel7new-new to Data Center Default, Cluster Default
>2014-09-24 02:42:45,302 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-4-thread-18) [2da7b0ab] BaseAsyncTask::startPollingTask: Starting to poll task e8c80284-758c-476b-b21e-a3356ddb463b.
>2014-09-24 02:42:53,813 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-78) [3b6f4b0d] Polling and updating Async Tasks: 1 tasks, 1 tasks to poll now
>2014-09-24 02:42:53,866 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (DefaultQuartzScheduler_Worker-78) [3b6f4b0d] Failed in HSMGetAllTasksStatusesVDS method
>2014-09-24 02:42:53,866 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-78) [3b6f4b0d] SPMAsyncTask::PollTask: Polling task e8c80284-758c-476b-b21e-a3356ddb463b (Parent Command ImportVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'cleanSuccess'.
>2014-09-24 02:42:53,891 ERROR [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-78) [3b6f4b0d] BaseAsyncTask::LogEndTaskFailure: Task e8c80284-758c-476b-b21e-a3356ddb463b (Parent Command ImportVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended with failure:
>-- Result: cleanSuccess
>-- Message: VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = low level Image copy failed, code = 261,
>-- Exception: VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = low level Image copy failed, code = 261
>2014-09-24 02:42:53,892 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-78) [3b6f4b0d] CommandAsyncTask::EndActionIfNecessary: All tasks of command 36b8454d-c44f-4f49-ba9c-3228503c0b5d has ended -> executing endAction
>2014-09-24 02:42:53,893 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-78) [3b6f4b0d] CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: 36b8454d-c44f-4f49-ba9c-3228503c0b5d): calling endAction .
>2014-09-24 02:42:53,893 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-4-thread-46) [3b6f4b0d] CommandAsyncTask::EndCommandAction [within thread] context: Attempting to endAction ImportVm, executionIndex: 0
>2014-09-24 02:42:53,932 ERROR [org.ovirt.engine.core.bll.ImportVmCommand] (org.ovirt.thread.pool-4-thread-46) [3b6f4b0d] Ending command with failure: org.ovirt.engine.core.bll.ImportVmCommand
>2014-09-24 02:42:53,957 ERROR [org.ovirt.engine.core.bll.CopyImageGroupCommand] (org.ovirt.thread.pool-4-thread-46) [2da7b0ab] Ending command with failure: org.ovirt.engine.core.bll.CopyImageGroupCommand
>2014-09-24 02:42:53,966 INFO  [org.ovirt.engine.core.bll.RemoveImageCommand] (org.ovirt.thread.pool-4-thread-46) [2688cf38] Running command: RemoveImageCommand internal: true. Entities affected :  ID: 946b78c7-b21e-4d88-b4ee-fee464cc4ce9 Type: Storage
>2014-09-24 02:42:54,016 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-4-thread-46) [2688cf38] START, DeleteImageGroupVDSCommand( storagePoolId = 00000002-0002-0002-0002-0000000002c4, ignoreFailoverLimit = false, storageDomainId = 946b78c7-b21e-4d88-b4ee-fee464cc4ce9, imageGroupId = d53e2187-c391-4360-a881-68a9af8867b2, postZeros = false, forceDelete = false), log id: 5b00e38a
>2014-09-24 02:42:54,120 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-4-thread-46) [2688cf38] Command DeleteImageGroupVDSCommand( storagePoolId = 00000002-0002-0002-0002-0000000002c4, ignoreFailoverLimit = false, storageDomainId = 946b78c7-b21e-4d88-b4ee-fee464cc4ce9, imageGroupId = d53e2187-c391-4360-a881-68a9af8867b2, postZeros = false, forceDelete = false) execution failed. Exception: IrsOperationFailedNoFailoverException: IRSGenericException: IRSErrorException: Image does not exist in domain: 'image=d53e2187-c391-4360-a881-68a9af8867b2, domain=946b78c7-b21e-4d88-b4ee-fee464cc4ce9'
>2014-09-24 02:42:54,120 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-4-thread-46) [2688cf38] FINISH, DeleteImageGroupVDSCommand, log id: 5b00e38a
>2014-09-24 02:42:54,121 INFO  [org.ovirt.engine.core.bll.RemoveImageCommand] (org.ovirt.thread.pool-4-thread-46) [2688cf38] Disk d53e2187-c391-4360-a881-68a9af8867b2 doesnt exist on storage domain 946b78c7-b21e-4d88-b4ee-fee464cc4ce9, rolling forward
>2014-09-24 02:42:54,305 INFO  [org.ovirt.engine.core.bll.ImportVmCommand] (org.ovirt.thread.pool-4-thread-46) Lock freed to object EngineLock [exclusiveLocks= key: rhel7new-new value: VM_NAME
>, sharedLocks= key: f0900074-ac38-44a2-a07c-09b4dbf12f18 value: REMOTE_VM
>]
>2014-09-24 02:42:54,341 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-4-thread-46) Correlation ID: 6989a513, Job ID: dc8dd277-02e7-432f-b336-5314a13c31f0, Call Stack: null, Custom Event ID: -1, Message: Failed to import Vm rhel7new-new to Data Center Default, Cluster Default
>2014-09-24 02:42:54,341 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-4-thread-46) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type ImportVm completed, handling the result.
>2014-09-24 02:42:54,341 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-4-thread-46) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type ImportVm succeeded, clearing tasks.
>2014-09-24 02:42:54,357 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-4-thread-46) SPMAsyncTask::ClearAsyncTask: Attempting to clear task e8c80284-758c-476b-b21e-a3356ddb463b
>2014-09-24 02:42:54,358 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-4-thread-46) START, SPMClearTaskVDSCommand( storagePoolId = 00000002-0002-0002-0002-0000000002c4, ignoreFailoverLimit = false, taskId = e8c80284-758c-476b-b21e-a3356ddb463b), log id: 389ff6c9
>2014-09-24 02:42:54,361 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-4-thread-46) START, HSMClearTaskVDSCommand(HostName = dell-op780-04.qe.lab.eng.nay.redhat.com, HostId = 2958841c-19cb-457d-8e83-fe794e6e2c38, taskId=e8c80284-758c-476b-b21e-a3356ddb463b), log id: e03232a
>2014-09-24 02:42:54,420 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-4-thread-46) FINISH, HSMClearTaskVDSCommand, log id: e03232a
>2014-09-24 02:42:54,421 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-4-thread-46) FINISH, SPMClearTaskVDSCommand, log id: 389ff6c9
>2014-09-24 02:42:54,432 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-4-thread-46) BaseAsyncTask::RemoveTaskFromDB: Removed task e8c80284-758c-476b-b21e-a3356ddb463b from DataBase
>2014-09-24 02:42:54,433 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-4-thread-46) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 36b8454d-c44f-4f49-ba9c-3228503c0b5d
>2014-09-24 02:44:22,213 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-60) [170000cc] Setting new tasks map. The map contains now 0 tasks
>2014-09-24 02:44:22,213 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-60) [170000cc] Cleared all tasks of pool 00000002-0002-0002-0002-0000000002c4.

Actions: View

Attachments on bug 1145582: 940368 | 940369 | 940644 | 940985 | 940986 | 940987 | 941372