Attachment 839449 Details for Bug 1045350 – engine.log

engine.log

vm_setup_through_rest_engine.log (text/plain), 12.21 KB, created by Sven Kieske on 2013-12-20 08:46:12 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Sven Kieske

Created: 2013-12-20 08:46:12 UTC

Size: 12.21 KB

patch

obsolete

>2013-12-20 09:59:26,288 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp--127.0.0.1-8702-10) Running command: LoginUserCommand internal: false.
>2013-12-20 09:59:26,305 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-10) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin@internal logged in.
>2013-12-20 09:59:45,528 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp--127.0.0.1-8702-10) Running command: LoginUserCommand internal: false.
>2013-12-20 09:59:45,554 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-10) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin@internal logged in.
>2013-12-20 09:59:45,585 INFO  [org.ovirt.engine.core.bll.LogoutUserCommand] (ajp--127.0.0.1-8702-10) [56ae868a] Running command: LogoutUserCommand internal: false.
>2013-12-20 09:59:45,595 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-10) [56ae868a] Correlation ID: 56ae868a, Call Stack: null, Custom Event ID: -1, Message: User admin@internal logged out.
>2013-12-20 09:59:45,787 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp--127.0.0.1-8702-5) Running command: LoginUserCommand internal: false.
>2013-12-20 09:59:45,804 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin@internal logged in.
>2013-12-20 09:59:45,835 INFO  [org.ovirt.engine.core.bll.LogoutUserCommand] (ajp--127.0.0.1-8702-5) [4927e2ae] Running command: LogoutUserCommand internal: false.
>2013-12-20 09:59:45,845 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [4927e2ae] Correlation ID: 4927e2ae, Call Stack: null, Custom Event ID: -1, Message: User admin@internal logged out.
>2013-12-20 10:03:26,185 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp--127.0.0.1-8702-10) Running command: LoginUserCommand internal: false.
>2013-12-20 10:03:26,204 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-10) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin@internal logged in.
>2013-12-20 10:03:26,256 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (ajp--127.0.0.1-8702-10) [29d40132] Lock Acquired to object EngineLock [exclusiveLocks= key: vr00001-1 value: VM_NAME
>, sharedLocks= key: 6b0430e3-430d-4f77-82de-4896cfc48892 value: DISK
>key: 10080414-d017-490b-b212-e02cee6a7b6e value: TEMPLATE
>]
>2013-12-20 10:03:26,301 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (ajp--127.0.0.1-8702-10) [29d40132] Running command: AddVmCommand internal: false. Entities affected :  ID: 2ad11b5e-9e74-499a-b317-5a9a3027cfca Type: VdsGroups,  ID: 10080414-d017-490b-b212-e02cee6a7b6e Type: VmTemplate,  ID: cd9f7816-e107-4ada-a930-75a52f852ab1 Type: Storage
>2013-12-20 10:03:26,318 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (ajp--127.0.0.1-8702-10) [29d40132] START, SetVmStatusVDSCommand( vmId = 676e7358-c757-480a-b6e9-9ec9bbdde785, status = ImageLocked), log id: 2ce2a441
>2013-12-20 10:03:26,335 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (ajp--127.0.0.1-8702-10) [29d40132] FINISH, SetVmStatusVDSCommand, log id: 2ce2a441
>2013-12-20 10:03:26,347 INFO  [org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand] (ajp--127.0.0.1-8702-10) [3667b8be] Running command: CreateSnapshotFromTemplateCommand internal: true. Entities affected :  ID: cd9f7816-e107-4ada-a930-75a52f852ab1 Type: Storage
>2013-12-20 10:03:26,352 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (ajp--127.0.0.1-8702-10) [3667b8be] START, CreateSnapshotVDSCommand( storagePoolId = a555f4aa-d962-425c-91c1-6ee5c4da4a23, ignoreFailoverLimit = false, storageDomainId = cd9f7816-e107-4ada-a930-75a52f852ab1, imageGroupId = 451aa2c0-a33c-408f-a0f2-aa9779837ba8, imageSizeInBytes = 53687091200, volumeFormat = COW, newImageId = 9ad3fb0b-2810-4be3-a86a-0bfcc9b42b49, newImageDescription = , imageId = 1b50d715-4e94-4ea3-9b65-80d8e1624aee, sourceImageGroupId = 6b0430e3-430d-4f77-82de-4896cfc48892), log id: dfe1e23
>2013-12-20 10:03:26,354 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (ajp--127.0.0.1-8702-10) [3667b8be] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
>2013-12-20 10:03:26,355 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (ajp--127.0.0.1-8702-10) [3667b8be] -- createVolume parameters:
>                sdUUID=cd9f7816-e107-4ada-a930-75a52f852ab1
>                spUUID=a555f4aa-d962-425c-91c1-6ee5c4da4a23
>                imgGUID=451aa2c0-a33c-408f-a0f2-aa9779837ba8
>                size=53,687,091,200 bytes
>                volFormat=COW
>                volType=Sparse
>                volUUID=9ad3fb0b-2810-4be3-a86a-0bfcc9b42b49
>                descr=
>                srcImgGUID=6b0430e3-430d-4f77-82de-4896cfc48892
>                srcVolUUID=1b50d715-4e94-4ea3-9b65-80d8e1624aee
>                
>2013-12-20 10:03:26,802 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (ajp--127.0.0.1-8702-10) [3667b8be] FINISH, CreateSnapshotVDSCommand, return: 9ad3fb0b-2810-4be3-a86a-0bfcc9b42b49, log id: dfe1e23
>2013-12-20 10:03:26,811 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (ajp--127.0.0.1-8702-10) [3667b8be] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 84da30d8-d671-468c-bbbf-89b79f723257
>2013-12-20 10:03:26,812 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (ajp--127.0.0.1-8702-10) [3667b8be] CommandMultiAsyncTasks::AttachTask: Attaching task f7bca445-669c-40ec-bb62-00a827a3ec8d to command 84da30d8-d671-468c-bbbf-89b79f723257.
>2013-12-20 10:03:26,821 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (ajp--127.0.0.1-8702-10) [3667b8be] Adding task f7bca445-669c-40ec-bb62-00a827a3ec8d (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2013-12-20 10:03:26,947 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-10) [3667b8be] Correlation ID: 29d40132, Job ID: 1ca6b189-d3c5-400a-bfd8-11cbd5f5f8cb, Call Stack: null, Custom Event ID: -1, Message: VM vr00001-1 creation was initiated by admin@internal.
>2013-12-20 10:03:26,948 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (ajp--127.0.0.1-8702-10) [3667b8be] BaseAsyncTask::StartPollingTask: Starting to poll task f7bca445-669c-40ec-bb62-00a827a3ec8d.
>2013-12-20 10:03:26,970 INFO  [org.ovirt.engine.core.bll.LogoutUserCommand] (ajp--127.0.0.1-8702-10) [5fed387a] Running command: LogoutUserCommand internal: false.
>2013-12-20 10:03:26,980 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-10) [5fed387a] Correlation ID: 5fed387a, Call Stack: null, Custom Event ID: -1, Message: User admin@internal logged out.
>2013-12-20 10:03:27,346 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-46) Polling and updating Async Tasks: 1 tasks, 1 tasks to poll now
>2013-12-20 10:03:27,351 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-46) SPMAsyncTask::PollTask: Polling task f7bca445-669c-40ec-bb62-00a827a3ec8d (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2013-12-20 10:03:27,372 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-46) BaseAsyncTask::OnTaskEndSuccess: Task f7bca445-669c-40ec-bb62-00a827a3ec8d (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2013-12-20 10:03:27,373 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-46) CommandAsyncTask::EndActionIfNecessary: All tasks of command 84da30d8-d671-468c-bbbf-89b79f723257 has ended -> executing EndAction
>2013-12-20 10:03:27,374 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-46) CommandAsyncTask::EndAction: Ending action for 1 tasks (command ID: 84da30d8-d671-468c-bbbf-89b79f723257): calling EndAction .
>2013-12-20 10:03:27,375 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (pool-6-thread-48) CommandAsyncTask::EndCommandAction [within thread] context: Attempting to EndAction AddVm, executionIndex: 0
>2013-12-20 10:03:27,397 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (pool-6-thread-48) [29d40132] Ending command successfully: org.ovirt.engine.core.bll.AddVmCommand
>2013-12-20 10:03:27,406 INFO  [org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand] (pool-6-thread-48) [3667b8be] Ending command successfully: org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand
>2013-12-20 10:03:27,407 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (pool-6-thread-48) [3667b8be] START, GetImageInfoVDSCommand( storagePoolId = a555f4aa-d962-425c-91c1-6ee5c4da4a23, ignoreFailoverLimit = false, storageDomainId = cd9f7816-e107-4ada-a930-75a52f852ab1, imageGroupId = 451aa2c0-a33c-408f-a0f2-aa9779837ba8, imageId = 9ad3fb0b-2810-4be3-a86a-0bfcc9b42b49), log id: 7e0e51cf
>2013-12-20 10:03:27,441 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (pool-6-thread-48) [3667b8be] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@bbe93375, log id: 7e0e51cf
>2013-12-20 10:03:27,452 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (pool-6-thread-48) START, SetVmStatusVDSCommand( vmId = 676e7358-c757-480a-b6e9-9ec9bbdde785, status = Down), log id: 228331f9
>2013-12-20 10:03:27,454 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (pool-6-thread-48) FINISH, SetVmStatusVDSCommand, log id: 228331f9
>2013-12-20 10:03:27,464 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (pool-6-thread-48) Lock freed to object EngineLock [exclusiveLocks= key: vr00001-1 value: VM_NAME
>, sharedLocks= key: 6b0430e3-430d-4f77-82de-4896cfc48892 value: DISK
>key: 10080414-d017-490b-b212-e02cee6a7b6e value: TEMPLATE
>]
>2013-12-20 10:03:27,472 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (pool-6-thread-48) Correlation ID: 29d40132, Job ID: 1ca6b189-d3c5-400a-bfd8-11cbd5f5f8cb, Call Stack: null, Custom Event ID: -1, Message: VM vr00001-1 creation has been completed.
>2013-12-20 10:03:27,473 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (pool-6-thread-48) CommandAsyncTask::HandleEndActionResult [within thread]: EndAction for action type AddVm completed, handling the result.
>2013-12-20 10:03:27,474 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (pool-6-thread-48) CommandAsyncTask::HandleEndActionResult [within thread]: EndAction for action type AddVm succeeded, clearing tasks.
>2013-12-20 10:03:27,480 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-6-thread-48) SPMAsyncTask::ClearAsyncTask: Attempting to clear task f7bca445-669c-40ec-bb62-00a827a3ec8d
>2013-12-20 10:03:27,481 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-6-thread-48) START, SPMClearTaskVDSCommand( storagePoolId = a555f4aa-d962-425c-91c1-6ee5c4da4a23, ignoreFailoverLimit = false, taskId = f7bca445-669c-40ec-bb62-00a827a3ec8d), log id: 4b5abf22
>2013-12-20 10:03:27,495 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-6-thread-48) START, HSMClearTaskVDSCommand(HostName = host3.test, HostId = 9b4bbf22-0655-4b0a-b792-3cdca91d5b6b, taskId=f7bca445-669c-40ec-bb62-00a827a3ec8d), log id: 32ba77d4
>2013-12-20 10:03:27,499 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-6-thread-48) FINISH, HSMClearTaskVDSCommand, log id: 32ba77d4
>2013-12-20 10:03:27,500 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-6-thread-48) FINISH, SPMClearTaskVDSCommand, log id: 4b5abf22
>2013-12-20 10:03:27,510 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-6-thread-48) BaseAsyncTask::RemoveTaskFromDB: Removed task f7bca445-669c-40ec-bb62-00a827a3ec8d from DataBase
>2013-12-20 10:03:27,511 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (pool-6-thread-48) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 84da30d8-d671-468c-bbbf-89b79f723257

Actions: View

Attachments on bug 1045350: 839449