Attachment 632810 Details for Bug 869660 – engine log

engine log

engine.log (text/x-log), 11.60 KB, created by Jakub Libosvar on 2012-10-24 13:53:20 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Jakub Libosvar

Created: 2012-10-24 13:53:20 UTC

Size: 11.60 KB

patch

obsolete

>2012-10-24 15:41:39,257 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-8) Checking if user admin@internal is an admin, result true
>2012-10-24 15:41:39,257 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-8) Running command: LoginUserCommand internal: false.
>2012-10-24 15:41:39,267 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-8) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2012-10-24 15:41:39,268 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-8) calling GetConfigurationValueQuery (VdcVersion) with null version, using default general for version
>2012-10-24 15:41:39,270 INFO  [org.ovirt.engine.core.bll.LogoutUserCommand] (ajp-/127.0.0.1:8702-8) [2ef35ebf] Running command: LogoutUserCommand internal: false.
>2012-10-24 15:43:44,776 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-4) Checking if user admin@internal is an admin, result true
>2012-10-24 15:43:44,776 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-4) Running command: LoginUserCommand internal: false.
>2012-10-24 15:43:44,788 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-4) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2012-10-24 15:43:44,852 INFO  [org.ovirt.engine.core.bll.MoveOrCopyDiskCommand] (ajp-/127.0.0.1:8702-4) [3e9dc582] Lock Acquired to object EngineLock [exclusiveLocks= key: e7fdb94e-9de4-4a59-aab8-05265cca3970 value: DISK
>, sharedLocks= key: b6c796c7-293f-4a49-b6f7-eaa423790cda value: TEMPLATE
>]
>2012-10-24 15:43:44,870 INFO  [org.ovirt.engine.core.bll.MoveOrCopyDiskCommand] (ajp-/127.0.0.1:8702-4) [3e9dc582] Running command: MoveOrCopyDiskCommand internal: false. Entities affected :  ID: e7fdb94e-9de4-4a59-aab8-05265cca3970 Type: Disk
>2012-10-24 15:43:44,875 INFO  [org.ovirt.engine.core.bll.MoveOrCopyImageGroupCommand] (ajp-/127.0.0.1:8702-4) [3e9dc582] Running command: MoveOrCopyImageGroupCommand internal: true. Entities affected :  ID: c7fc28ce-85f8-4cbf-8f8f-71c82ef9e191 Type: Storage
>2012-10-24 15:43:44,881 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (ajp-/127.0.0.1:8702-4) [3e9dc582] START, CopyImageVDSCommand( storagePoolId = 7b2b05c6-e221-4ded-bd57-0e08bdba0022, ignoreFailoverLimit = false, compatabilityVersion = 3.1, storageDomainId = fc59298b-c119-4191-b79a-9936abd0a123, imageGroupId = e7fdb94e-9de4-4a59-aab8-05265cca3970, imageId = 18f2bab5-dcf2-4e7f-9135-159de8149503, dstImageGroupId = e7fdb94e-9de4-4a59-aab8-05265cca3970, vmId = 00000000-0000-0000-0000-000000000000, dstImageId = 18f2bab5-dcf2-4e7f-9135-159de8149503, imageDescription = , dstStorageDomainId = c7fc28ce-85f8-4cbf-8f8f-71c82ef9e191, copyVolumeType = SharedVol, volumeFormat = COW, preallocate = Sparse, postZero = false, force = false), log id: 357509c7
>2012-10-24 15:43:44,881 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (ajp-/127.0.0.1:8702-4) [3e9dc582] -- CopyImageVDSCommand::ExecuteIrsBrokerCommand: calling 'copyImage' with two new parameters: description and UUID
>2012-10-24 15:43:44,881 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (ajp-/127.0.0.1:8702-4) [3e9dc582] -- copyImage parameters:
>                sdUUID=fc59298b-c119-4191-b79a-9936abd0a123
>                spUUID=7b2b05c6-e221-4ded-bd57-0e08bdba0022
>                vmGUID=00000000-0000-0000-0000-000000000000
>                srcImageGUID=e7fdb94e-9de4-4a59-aab8-05265cca3970
>                srcVolUUID=18f2bab5-dcf2-4e7f-9135-159de8149503
>                dstImageGUID=e7fdb94e-9de4-4a59-aab8-05265cca3970
>                dstVolUUID=18f2bab5-dcf2-4e7f-9135-159de8149503
>                descr=
>                
>2012-10-24 15:43:46,537 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (ajp-/127.0.0.1:8702-4) [3e9dc582] FINISH, CopyImageVDSCommand, return: 00000000-0000-0000-0000-000000000000, log id: 357509c7
>2012-10-24 15:43:46,542 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (ajp-/127.0.0.1:8702-4) [3e9dc582] EntityAsyncTask::Adding EntityMultiAsyncTasks object for entity 18f2bab5-dcf2-4e7f-9135-159de8149503
>2012-10-24 15:43:46,542 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (ajp-/127.0.0.1:8702-4) [3e9dc582] EntityMultiAsyncTasks::AttachTask: Attaching task 8c6fa57b-f959-444a-9ab1-22516464cca1 to entity 18f2bab5-dcf2-4e7f-9135-159de8149503.
>2012-10-24 15:43:46,544 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskUtils] (ajp-/127.0.0.1:8702-4) [3e9dc582] Adding task 8c6fa57b-f959-444a-9ab1-22516464cca1 to DataBase
>2012-10-24 15:43:46,558 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (ajp-/127.0.0.1:8702-4) [3e9dc582] Adding task 8c6fa57b-f959-444a-9ab1-22516464cca1 (Parent Command MoveOrCopyDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2012-10-24 15:43:46,567 INFO  [org.ovirt.engine.core.bll.MoveOrCopyDiskCommand] (ajp-/127.0.0.1:8702-4) [3e9dc582] Lock freed to object EngineLock [exclusiveLocks= key: e7fdb94e-9de4-4a59-aab8-05265cca3970 value: DISK
>, sharedLocks= key: b6c796c7-293f-4a49-b6f7-eaa423790cda value: TEMPLATE
>]
>2012-10-24 15:43:46,575 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (ajp-/127.0.0.1:8702-4) [3e9dc582] BaseAsyncTask::StartPollingTask: Starting to poll task 8c6fa57b-f959-444a-9ab1-22516464cca1.
>2012-10-24 15:43:46,575 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (ajp-/127.0.0.1:8702-4) [3e9dc582] EntityMultiAsyncTasks::StartPollingTask: Current Action Type for entity 18f2bab5-dcf2-4e7f-9135-159de8149503 is MoveOrCopyDisk (determined by task 8c6fa57b-f959-444a-9ab1-22516464cca1)
>2012-10-24 15:43:46,577 INFO  [org.ovirt.engine.core.bll.LogoutUserCommand] (ajp-/127.0.0.1:8702-4) [7b532781] Running command: LogoutUserCommand internal: false.
>2012-10-24 15:43:48,792 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-14) Polling and updating Async Tasks: 1 tasks, 1 tasks to poll now
>2012-10-24 15:43:48,804 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-14) SPMAsyncTask::PollTask: Polling task 8c6fa57b-f959-444a-9ab1-22516464cca1 (Parent Command MoveOrCopyDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status running.
>2012-10-24 15:43:48,804 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-14) Finished polling Tasks, will poll again in 10 seconds.
>2012-10-24 15:44:38,890 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-62) SPMAsyncTask::PollTask: Polling task 8c6fa57b-f959-444a-9ab1-22516464cca1 (Parent Command MoveOrCopyDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2012-10-24 15:44:38,895 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-62) BaseAsyncTask::OnTaskEndSuccess: Task 8c6fa57b-f959-444a-9ab1-22516464cca1 (Parent Command MoveOrCopyDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2012-10-24 15:44:38,896 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-62) EntityAsyncTask::EndActionIfNecessary: All tasks of entity 18f2bab5-dcf2-4e7f-9135-159de8149503 has ended -> executing EndAction
>2012-10-24 15:44:38,896 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-62) EntityAsyncTask::EndAction: Ending action for 1 tasks (entity ID: 18f2bab5-dcf2-4e7f-9135-159de8149503): calling EndAction for action type MoveOrCopyDisk.
>2012-10-24 15:44:38,896 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-49) EntityAsyncTask::EndCommandAction [within thread]context: Attempting to EndAction MoveOrCopyDisk
>2012-10-24 15:44:38,914 INFO  [org.ovirt.engine.core.bll.MoveOrCopyDiskCommand] (pool-4-thread-49) [3e9dc582] Ending command successfully: org.ovirt.engine.core.bll.MoveOrCopyDiskCommand
>2012-10-24 15:44:38,917 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (pool-4-thread-49) [3e9dc582] START, GetImageInfoVDSCommand( storagePoolId = 7b2b05c6-e221-4ded-bd57-0e08bdba0022, ignoreFailoverLimit = false, compatabilityVersion = null, storageDomainId = fc59298b-c119-4191-b79a-9936abd0a123, imageGroupId = e7fdb94e-9de4-4a59-aab8-05265cca3970, imageId = 18f2bab5-dcf2-4e7f-9135-159de8149503), log id: 164aa79b
>2012-10-24 15:44:39,215 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (pool-4-thread-49) [3e9dc582] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@ccb55872, log id: 164aa79b
>2012-10-24 15:44:39,245 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-49) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type MoveOrCopyDisk completed, handling the result.
>2012-10-24 15:44:39,245 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-49) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type MoveOrCopyDisk succeeded, clearing tasks.
>2012-10-24 15:44:39,249 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-4-thread-49) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 8c6fa57b-f959-444a-9ab1-22516464cca1
>2012-10-24 15:44:39,249 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-4-thread-49) START, SPMClearTaskVDSCommand( storagePoolId = 7b2b05c6-e221-4ded-bd57-0e08bdba0022, ignoreFailoverLimit = false, compatabilityVersion = null, taskId = 8c6fa57b-f959-444a-9ab1-22516464cca1), log id: 7c620215
>2012-10-24 15:44:39,270 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-4-thread-49) START, HSMClearTaskVDSCommand(HostName = 10.34.63.135, HostId = 174840d6-1dd8-11e2-8d50-001a4a013f09, taskId=8c6fa57b-f959-444a-9ab1-22516464cca1), log id: 5f76a5f7
>2012-10-24 15:44:39,279 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-4-thread-49) FINISH, HSMClearTaskVDSCommand, log id: 5f76a5f7
>2012-10-24 15:44:39,279 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-4-thread-49) FINISH, SPMClearTaskVDSCommand, log id: 7c620215
>2012-10-24 15:44:39,283 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-4-thread-49) BaseAsyncTask::RemoveTaskFromDB: Removed task 8c6fa57b-f959-444a-9ab1-22516464cca1 from DataBase
>2012-10-24 15:44:39,283 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-49) EntityAsyncTask::HandleEndActionResult [within thread]: Removing EntityMultiAsyncTasks object for entity 18f2bab5-dcf2-4e7f-9135-159de8149503
>2012-10-24 15:45:00,000 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-82) Autorecovering hosts is disabled, skipping
>2012-10-24 15:45:00,001 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-82) Autorecovering storage domains is disabled, skipping
>2012-10-24 15:46:08,315 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-47) Setting new tasks map. The map contains now 0 tasks
>2012-10-24 15:46:08,316 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-47) Cleared all tasks of pool 7b2b05c6-e221-4ded-bd57-0e08bdba0022.
>2012-10-24 15:46:08,319 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-47) Could not find vds that is spm and non-operational.
>2012-10-24 15:50:00,001 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-68) Autorecovering hosts is disabled, skipping
>2012-10-24 15:50:00,001 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-68) Autorecovering storage domains is disabled, skipping

Actions: View

Attachments on bug 869660: 632810