Attachment 674037 Details for Bug 892642 – engine.log

engine.log

e.log (text/x-log), 15.28 KB, created by Ondra Machacek on 2013-01-07 13:48:36 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Ondra Machacek

Created: 2013-01-07 13:48:36 UTC

Size: 15.28 KB

patch

obsolete

>
>2013-01-07 14:45:45,553 INFO  [org.ovirt.engine.core.bll.AddDiskCommand] (pool-4-thread-47) [1bd9650e] Running command: AddDiskCommand internal: false. Entities affected :  ID: 5f88fda2-5d86-4010-a704-7fbcc3cf4137 Type: Storage
>2013-01-07 14:45:45,554 INFO  [org.ovirt.engine.core.bll.AddImageFromScratchCommand] (pool-4-thread-47) [26db9d52] Running command: AddImageFromScratchCommand internal: true. Entities affected :  ID: 5f88fda2-5d86-4010-a704-7fbcc3cf4137 Type: Storage
>2013-01-07 14:45:45,566 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (pool-4-thread-47) [26db9d52] START, CreateImageVDSCommand( storagePoolId = ccac6e83-9ff5-41e4-9606-069dbeb8904a, ignoreFailoverLimit = false, compatabilityVersion = 3.1, storageDomainId = 5f88fda2-5d86-4010-a704-7fbcc3cf4137, imageGroupId = 59c18b91-aab5-4c79-ac48-96302eb1977c, imageSizeInBytes = 1073741824, volumeFormat = RAW, newImageId = cd1249f3-60d5-4fba-b06a-ce8ad93ab559, newImageDescription = ), log id: 513fede8
>2013-01-07 14:45:45,567 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (pool-4-thread-47) [26db9d52] -- CreateImageVDSCommand::ExecuteIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
>2013-01-07 14:45:45,567 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (pool-4-thread-47) [26db9d52] -- createVolume parameters:
>                sdUUID=5f88fda2-5d86-4010-a704-7fbcc3cf4137
>                spUUID=ccac6e83-9ff5-41e4-9606-069dbeb8904a
>                imgGUID=59c18b91-aab5-4c79-ac48-96302eb1977c
>                size=1,073,741,824 bytes
>                volFormat=RAW
>                volType=Sparse
>                volUUID=cd1249f3-60d5-4fba-b06a-ce8ad93ab559
>                descr=
>                srcImgGUID=00000000-0000-0000-0000-000000000000
>                srcVolUUID=00000000-0000-0000-0000-000000000000
>                
>2013-01-07 14:45:45,642 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (pool-4-thread-47) [26db9d52] FINISH, CreateImageVDSCommand, return: cd1249f3-60d5-4fba-b06a-ce8ad93ab559, log id: 513fede8
>2013-01-07 14:45:45,649 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-47) [26db9d52] EntityAsyncTask::Adding EntityMultiAsyncTasks object for entity 59c18b91-aab5-4c79-ac48-96302eb1977c
>2013-01-07 14:45:45,649 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (pool-4-thread-47) [26db9d52] EntityMultiAsyncTasks::AttachTask: Attaching task f25f87b0-3fc8-4ed7-8adf-426099ea002f to entity 59c18b91-aab5-4c79-ac48-96302eb1977c.
>2013-01-07 14:45:45,650 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskUtils] (pool-4-thread-47) [26db9d52] Adding task f25f87b0-3fc8-4ed7-8adf-426099ea002f to DataBase
>2013-01-07 14:45:45,659 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (pool-4-thread-47) [26db9d52] Adding task f25f87b0-3fc8-4ed7-8adf-426099ea002f (Parent Command AddDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2013-01-07 14:45:45,680 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-4-thread-47) [26db9d52] BaseAsyncTask::StartPollingTask: Starting to poll task f25f87b0-3fc8-4ed7-8adf-426099ea002f.
>2013-01-07 14:45:45,680 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (pool-4-thread-47) [26db9d52] EntityMultiAsyncTasks::StartPollingTask: Current Action Type for entity 59c18b91-aab5-4c79-ac48-96302eb1977c is AddDisk (determined by task f25f87b0-3fc8-4ed7-8adf-426099ea002f)
>2013-01-07 14:45:53,317 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-53) Polling and updating Async Tasks: 3 tasks, 1 tasks to poll now
>2013-01-07 14:45:53,332 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-53) SPMAsyncTask::PollTask: Polling task f25f87b0-3fc8-4ed7-8adf-426099ea002f (Parent Command AddDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2013-01-07 14:45:53,337 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-53) BaseAsyncTask::OnTaskEndSuccess: Task f25f87b0-3fc8-4ed7-8adf-426099ea002f (Parent Command AddDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2013-01-07 14:45:53,338 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-53) EntityAsyncTask::EndActionIfNecessary: All tasks of entity 59c18b91-aab5-4c79-ac48-96302eb1977c has ended -> executing EndAction
>2013-01-07 14:45:53,338 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-53) EntityAsyncTask::EndAction: Ending action for 1 tasks (entity ID: 59c18b91-aab5-4c79-ac48-96302eb1977c): calling EndAction for action type AddDisk.
>2013-01-07 14:45:53,338 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-47) EntityAsyncTask::EndCommandAction [within thread] context: Attempting to EndAction AddDisk, executionIndex: 0
>2013-01-07 14:45:53,347 INFO  [org.ovirt.engine.core.bll.AddDiskCommand] (pool-4-thread-47) Ending command successfully: org.ovirt.engine.core.bll.AddDiskCommand
>2013-01-07 14:45:53,347 INFO  [org.ovirt.engine.core.bll.AddImageFromScratchCommand] (pool-4-thread-47) [26db9d52] Ending command successfully: org.ovirt.engine.core.bll.AddImageFromScratchCommand
>2013-01-07 14:45:53,354 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (pool-4-thread-47) [26db9d52] START, GetImageInfoVDSCommand( storagePoolId = ccac6e83-9ff5-41e4-9606-069dbeb8904a, ignoreFailoverLimit = false, compatabilityVersion = null, storageDomainId = 5f88fda2-5d86-4010-a704-7fbcc3cf4137, imageGroupId = 59c18b91-aab5-4c79-ac48-96302eb1977c, imageId = cd1249f3-60d5-4fba-b06a-ce8ad93ab559), log id: 7169340a
>2013-01-07 14:45:53,384 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (pool-4-thread-47) [26db9d52] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@68e765be, log id: 7169340a
>2013-01-07 14:45:53,387 WARN  [org.ovirt.engine.core.bll.AddDiskCommand] (pool-4-thread-47) VmCommand::EndVmCommand: Vm is null - not performing EndAction on Vm
>2013-01-07 14:45:53,389 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-47) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type AddDisk completed, handling the result.
>2013-01-07 14:45:53,389 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-47) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type AddDisk succeeded, clearing tasks.
>2013-01-07 14:45:53,393 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-4-thread-47) SPMAsyncTask::ClearAsyncTask: Attempting to clear task f25f87b0-3fc8-4ed7-8adf-426099ea002f
>2013-01-07 14:45:53,393 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-4-thread-47) START, SPMClearTaskVDSCommand( storagePoolId = ccac6e83-9ff5-41e4-9606-069dbeb8904a, ignoreFailoverLimit = false, compatabilityVersion = null, taskId = f25f87b0-3fc8-4ed7-8adf-426099ea002f), log id: 10ad58e0
>2013-01-07 14:45:53,395 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-4-thread-47) START, HSMClearTaskVDSCommand(HostName = user_api_tests__host, HostId = 1400a454-5776-11e2-8d4f-001a4a013f66, taskId=f25f87b0-3fc8-4ed7-8adf-426099ea002f), log id: 7aa137ba
>2013-01-07 14:45:53,415 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-4-thread-47) FINISH, HSMClearTaskVDSCommand, log id: 7aa137ba
>2013-01-07 14:45:53,415 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-4-thread-47) FINISH, SPMClearTaskVDSCommand, log id: 10ad58e0
>2013-01-07 14:45:53,418 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-4-thread-47) BaseAsyncTask::RemoveTaskFromDB: Removed task f25f87b0-3fc8-4ed7-8adf-426099ea002f from DataBase
>2013-01-07 14:45:53,418 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-47) EntityAsyncTask::HandleEndActionResult [within thread]: Removing EntityMultiAsyncTasks object for entity 59c18b91-aab5-4c79-ac48-96302eb1977c
>2013-01-07 14:45:55,197 INFO  [org.ovirt.engine.core.bll.AddPermissionCommand] (pool-4-thread-47) [72f80786] Running command: AddPermissionCommand internal: false. Entities affected :  ID: 59c18b91-aab5-4c79-ac48-96302eb1977c Type: Disk
>2013-01-07 14:46:06,395 INFO  [org.ovirt.engine.core.bll.RemoveDiskCommand] (ajp-/127.0.0.1:8702-4) Lock Acquired to object EngineLock [exclusiveLocks= key: 59c18b91-aab5-4c79-ac48-96302eb1977c value: DISK
>, sharedLocks= ]
>2013-01-07 14:46:06,419 INFO  [org.ovirt.engine.core.bll.RemoveDiskCommand] (pool-4-thread-47) [675cde14] Running command: RemoveDiskCommand internal: false. Entities affected :  ID: 59c18b91-aab5-4c79-ac48-96302eb1977c Type: Disk
>2013-01-07 14:46:06,422 INFO  [org.ovirt.engine.core.bll.RemoveImageCommand] (pool-4-thread-47) [41968d4] Running command: RemoveImageCommand internal: true. Entities affected :  ID: 5f88fda2-5d86-4010-a704-7fbcc3cf4137 Type: Storage
>2013-01-07 14:46:06,425 INFO  [org.ovirt.engine.core.bll.RemoveImageCommand] (pool-4-thread-47) [41968d4] Lock freed to object EngineLock [exclusiveLocks= key: 59c18b91-aab5-4c79-ac48-96302eb1977c value: DISK
>, sharedLocks= ]
>2013-01-07 14:46:06,426 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (pool-4-thread-47) [41968d4] START, DeleteImageGroupVDSCommand( storagePoolId = ccac6e83-9ff5-41e4-9606-069dbeb8904a, ignoreFailoverLimit = false, compatabilityVersion = 3.1, storageDomainId = 5f88fda2-5d86-4010-a704-7fbcc3cf4137, imageGroupId = 59c18b91-aab5-4c79-ac48-96302eb1977c, postZeros = false, forceDelete = false), log id: 67b041cd
>2013-01-07 14:46:06,500 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (pool-4-thread-47) [41968d4] FINISH, DeleteImageGroupVDSCommand, log id: 67b041cd
>2013-01-07 14:46:06,503 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-47) [41968d4] EntityAsyncTask::Adding EntityMultiAsyncTasks object for entity 59c18b91-aab5-4c79-ac48-96302eb1977c
>2013-01-07 14:46:06,503 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (pool-4-thread-47) [41968d4] EntityMultiAsyncTasks::AttachTask: Attaching task 13c7be9c-83d4-4ccf-a770-285c06d0bfe0 to entity 59c18b91-aab5-4c79-ac48-96302eb1977c.
>2013-01-07 14:46:06,505 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskUtils] (pool-4-thread-47) [41968d4] Adding task 13c7be9c-83d4-4ccf-a770-285c06d0bfe0 to DataBase
>2013-01-07 14:46:06,509 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (pool-4-thread-47) [41968d4] Adding task 13c7be9c-83d4-4ccf-a770-285c06d0bfe0 (Parent Command RemoveDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2013-01-07 14:46:06,517 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-4-thread-47) [41968d4] BaseAsyncTask::StartPollingTask: Starting to poll task 13c7be9c-83d4-4ccf-a770-285c06d0bfe0.
>2013-01-07 14:46:06,517 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (pool-4-thread-47) [41968d4] EntityMultiAsyncTasks::StartPollingTask: Current Action Type for entity 59c18b91-aab5-4c79-ac48-96302eb1977c is RemoveDisk (determined by task 13c7be9c-83d4-4ccf-a770-285c06d0bfe0)
>2013-01-07 14:46:13,338 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-42) Polling and updating Async Tasks: 4 tasks, 1 tasks to poll now
>2013-01-07 14:46:13,353 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-42) SPMAsyncTask::PollTask: Polling task 13c7be9c-83d4-4ccf-a770-285c06d0bfe0 (Parent Command RemoveDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2013-01-07 14:46:13,358 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-42) BaseAsyncTask::OnTaskEndSuccess: Task 13c7be9c-83d4-4ccf-a770-285c06d0bfe0 (Parent Command RemoveDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2013-01-07 14:46:13,359 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-42) EntityAsyncTask::EndActionIfNecessary: All tasks of entity 59c18b91-aab5-4c79-ac48-96302eb1977c has ended -> executing EndAction
>2013-01-07 14:46:13,359 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-42) EntityAsyncTask::EndAction: Ending action for 1 tasks (entity ID: 59c18b91-aab5-4c79-ac48-96302eb1977c): calling EndAction for action type RemoveDisk.
>2013-01-07 14:46:13,359 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-47) EntityAsyncTask::EndCommandAction [within thread] context: Attempting to EndAction RemoveDisk, executionIndex: 0
>2013-01-07 14:46:13,371 INFO  [org.ovirt.engine.core.bll.RemoveDiskCommand] (pool-4-thread-47) Ending command successfully: org.ovirt.engine.core.bll.RemoveDiskCommand
>2013-01-07 14:46:13,375 INFO  [org.ovirt.engine.core.bll.RemoveImageCommand] (pool-4-thread-47) [41968d4] Ending command successfully: org.ovirt.engine.core.bll.RemoveImageCommand
>2013-01-07 14:46:13,400 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UpdateVMVDSCommand] (pool-4-thread-47) START, UpdateVMVDSCommand( storagePoolId = ccac6e83-9ff5-41e4-9606-069dbeb8904a, ignoreFailoverLimit = false, compatabilityVersion = null, storageDomainId = 00000000-0000-0000-0000-000000000000, infoDictionary.size = 0), log id: 4c24e702
>2013-01-07 14:46:13,414 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UpdateVMVDSCommand] (pool-4-thread-47) FINISH, UpdateVMVDSCommand, log id: 4c24e702
>2013-01-07 14:46:13,420 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-47) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type RemoveDisk completed, handling the result.
>2013-01-07 14:46:13,420 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-47) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type RemoveDisk succeeded, clearing tasks.
>2013-01-07 14:46:13,424 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-4-thread-47) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 13c7be9c-83d4-4ccf-a770-285c06d0bfe0
>2013-01-07 14:46:13,424 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-4-thread-47) START, SPMClearTaskVDSCommand( storagePoolId = ccac6e83-9ff5-41e4-9606-069dbeb8904a, ignoreFailoverLimit = false, compatabilityVersion = null, taskId = 13c7be9c-83d4-4ccf-a770-285c06d0bfe0), log id: 5fdb4dbd
>2013-01-07 14:46:13,426 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-4-thread-47) START, HSMClearTaskVDSCommand(HostName = user_api_tests__host, HostId = 1400a454-5776-11e2-8d4f-001a4a013f66, taskId=13c7be9c-83d4-4ccf-a770-285c06d0bfe0), log id: 76379173
>2013-01-07 14:46:13,443 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-4-thread-47) FINISH, HSMClearTaskVDSCommand, log id: 76379173
>2013-01-07 14:46:13,443 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-4-thread-47) FINISH, SPMClearTaskVDSCommand, log id: 5fdb4dbd
>2013-01-07 14:46:13,446 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-4-thread-47) BaseAsyncTask::RemoveTaskFromDB: Removed task 13c7be9c-83d4-4ccf-a770-285c06d0bfe0 from DataBase
>2013-01-07 14:46:13,446 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-47) EntityAsyncTask::HandleEndActionResult [within thread]: Removing EntityMultiAsyncTasks object for entity 59c18b91-aab5-4c79-ac48-96302eb1977c
>

Actions: View

Attachments on bug 892642: 674037