Attachment 640643 Details for Bug 874443 – backend log

backend log

engine.log (text/x-log), 10.33 KB, created by Jakub Libosvar on 2012-11-08 08:25:45 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Jakub Libosvar

Created: 2012-11-08 08:25:45 UTC

Size: 10.33 KB

patch

obsolete

>2012-11-08 09:14:01,691 INFO  [org.ovirt.engine.core.bll.AddDiskCommand] (ajp-/127.0.0.1:8702-14) Lock Acquired to object EngineLock [exclusiveLocks= , sharedLocks= key: 66037876-4485-499b-8c77-90c04c7f68a3 value: VM
>]
>2012-11-08 09:14:01,697 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] (ajp-/127.0.0.1:8702-14) START, IsValidVDSCommand( storagePoolId = f0b3cc08-6a6e-4b06-bbda-add16f7e0bcb, ignoreFailoverLimit = false, compatabilityVersion = null), log id: 2885775f
>2012-11-08 09:14:01,699 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] (ajp-/127.0.0.1:8702-14) FINISH, IsValidVDSCommand, return: true, log id: 2885775f
>2012-11-08 09:14:01,725 INFO  [org.ovirt.engine.core.bll.AddDiskCommand] (pool-4-thread-48) [5a1e084a] Running command: AddDiskCommand internal: false. Entities affected :  ID: 66037876-4485-499b-8c77-90c04c7f68a3 Type: VM,  ID: 521dab9f-7c49-4598-99ff-d309873670de Type: Storage
>2012-11-08 09:14:01,787 INFO  [org.ovirt.engine.core.bll.AddImageFromScratchCommand] (pool-4-thread-48) [226b70e4] Running command: AddImageFromScratchCommand internal: true. Entities affected :  ID: 521dab9f-7c49-4598-99ff-d309873670de Type: Storage
>2012-11-08 09:14:01,797 INFO  [org.ovirt.engine.core.bll.AddImageFromScratchCommand] (pool-4-thread-48) [226b70e4] Lock freed to object EngineLock [exclusiveLocks= , sharedLocks= key: 66037876-4485-499b-8c77-90c04c7f68a3 value: VM
>]
>2012-11-08 09:14:01,799 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (pool-4-thread-48) [226b70e4] START, CreateImageVDSCommand( storagePoolId = f0b3cc08-6a6e-4b06-bbda-add16f7e0bcb, ignoreFailoverLimit = false, compatabilityVersion = 3.1, storageDomainId = 521dab9f-7c49-4598-99ff-d309873670de, imageGroupId = d5500cb7-c2fd-45b8-9bab-ea9f081d4467, imageSizeInBytes = 2147483648, volumeFormat = RAW, newImageId = 812ae405-eb6b-4385-9265-6e724ec3c70e, newImageDescription = ), log id: 22672074
>2012-11-08 09:14:01,799 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (pool-4-thread-48) [226b70e4] -- CreateImageVDSCommand::ExecuteIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
>2012-11-08 09:14:01,799 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (pool-4-thread-48) [226b70e4] -- createVolume parameters:
>                sdUUID=521dab9f-7c49-4598-99ff-d309873670de
>                spUUID=f0b3cc08-6a6e-4b06-bbda-add16f7e0bcb
>                imgGUID=d5500cb7-c2fd-45b8-9bab-ea9f081d4467
>                size=2,147,483,648 bytes
>                volFormat=RAW
>                volType=Preallocated
>                volUUID=812ae405-eb6b-4385-9265-6e724ec3c70e
>                descr=
>                srcImgGUID=00000000-0000-0000-0000-000000000000
>                srcVolUUID=00000000-0000-0000-0000-000000000000
>                
>2012-11-08 09:14:02,376 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (pool-4-thread-48) [226b70e4] FINISH, CreateImageVDSCommand, return: 812ae405-eb6b-4385-9265-6e724ec3c70e, log id: 22672074
>2012-11-08 09:14:02,382 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-48) [226b70e4] EntityAsyncTask::Adding EntityMultiAsyncTasks object for entity d5500cb7-c2fd-45b8-9bab-ea9f081d4467
>2012-11-08 09:14:02,382 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (pool-4-thread-48) [226b70e4] EntityMultiAsyncTasks::AttachTask: Attaching task 298eacc9-7a0b-4a79-9877-2e76c20930e4 to entity d5500cb7-c2fd-45b8-9bab-ea9f081d4467.
>2012-11-08 09:14:02,383 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskUtils] (pool-4-thread-48) [226b70e4] Adding task 298eacc9-7a0b-4a79-9877-2e76c20930e4 to DataBase
>2012-11-08 09:14:02,405 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (pool-4-thread-48) [226b70e4] Adding task 298eacc9-7a0b-4a79-9877-2e76c20930e4 (Parent Command AddDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2012-11-08 09:14:02,428 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-4-thread-48) [226b70e4] BaseAsyncTask::StartPollingTask: Starting to poll task 298eacc9-7a0b-4a79-9877-2e76c20930e4.
>2012-11-08 09:14:02,428 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (pool-4-thread-48) [226b70e4] EntityMultiAsyncTasks::StartPollingTask: Current Action Type for entity d5500cb7-c2fd-45b8-9bab-ea9f081d4467 is AddDisk (determined by task 298eacc9-7a0b-4a79-9877-2e76c20930e4)
>2012-11-08 09:14:02,821 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (ajp-/127.0.0.1:8702-8) Lock Acquired to object EngineLock [exclusiveLocks= key: 66037876-4485-499b-8c77-90c04c7f68a3 value: VM
>, sharedLocks= ]
>2012-11-08 09:14:02,829 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] (ajp-/127.0.0.1:8702-8) START, IsValidVDSCommand( storagePoolId = f0b3cc08-6a6e-4b06-bbda-add16f7e0bcb, ignoreFailoverLimit = false, compatabilityVersion = null), log id: 39db43c3
>2012-11-08 09:14:02,830 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] (ajp-/127.0.0.1:8702-8) FINISH, IsValidVDSCommand, return: true, log id: 39db43c3
>2012-11-08 09:14:02,830 WARN  [org.ovirt.engine.core.bll.RunVmCommand] (ajp-/127.0.0.1:8702-8) CanDoAction of action RunVm failed. Reasons:VAR__ACTION__RUN,VAR__TYPE__VM,ACTION_TYPE_FAILED_DISKS_ARE_LOCKED,$diskAliases vm_Disk2
>2012-11-08 09:14:02,831 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (ajp-/127.0.0.1:8702-8) Lock freed to object EngineLock [exclusiveLocks= key: 66037876-4485-499b-8c77-90c04c7f68a3 value: VM
>, sharedLocks= ]
>2012-11-08 09:14:05,668 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-36) Polling and updating Async Tasks: 2 tasks, 1 tasks to poll now
>2012-11-08 09:14:05,685 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-36) SPMAsyncTask::PollTask: Polling task 298eacc9-7a0b-4a79-9877-2e76c20930e4 (Parent Command AddDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2012-11-08 09:14:05,694 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-36) BaseAsyncTask::OnTaskEndSuccess: Task 298eacc9-7a0b-4a79-9877-2e76c20930e4 (Parent Command AddDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2012-11-08 09:14:05,695 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-36) EntityAsyncTask::EndActionIfNecessary: All tasks of entity d5500cb7-c2fd-45b8-9bab-ea9f081d4467 has ended -> executing EndAction
>2012-11-08 09:14:05,695 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-36) EntityAsyncTask::EndAction: Ending action for 1 tasks (entity ID: d5500cb7-c2fd-45b8-9bab-ea9f081d4467): calling EndAction for action type AddDisk.
>2012-11-08 09:14:05,695 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-48) EntityAsyncTask::EndCommandAction [within thread] context: Attempting to EndAction AddDisk, executionIndex: 0
>2012-11-08 09:14:05,706 INFO  [org.ovirt.engine.core.bll.AddDiskCommand] (pool-4-thread-48) Ending command successfully: org.ovirt.engine.core.bll.AddDiskCommand
>2012-11-08 09:14:05,706 INFO  [org.ovirt.engine.core.bll.AddImageFromScratchCommand] (pool-4-thread-48) [226b70e4] Ending command successfully: org.ovirt.engine.core.bll.AddImageFromScratchCommand
>2012-11-08 09:14:05,714 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (pool-4-thread-48) [226b70e4] START, GetImageInfoVDSCommand( storagePoolId = f0b3cc08-6a6e-4b06-bbda-add16f7e0bcb, ignoreFailoverLimit = false, compatabilityVersion = null, storageDomainId = 521dab9f-7c49-4598-99ff-d309873670de, imageGroupId = d5500cb7-c2fd-45b8-9bab-ea9f081d4467, imageId = 812ae405-eb6b-4385-9265-6e724ec3c70e), log id: 21cbc953
>2012-11-08 09:14:06,055 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (pool-4-thread-48) [226b70e4] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@dfeac900, log id: 21cbc953
>2012-11-08 09:14:06,083 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UpdateVMVDSCommand] (pool-4-thread-48) START, UpdateVMVDSCommand( storagePoolId = f0b3cc08-6a6e-4b06-bbda-add16f7e0bcb, ignoreFailoverLimit = false, compatabilityVersion = null, storageDomainId = 00000000-0000-0000-0000-000000000000, infoDictionary.size = 1), log id: 11e68d3f
>2012-11-08 09:14:06,099 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UpdateVMVDSCommand] (pool-4-thread-48) FINISH, UpdateVMVDSCommand, log id: 11e68d3f
>2012-11-08 09:14:06,115 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-48) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type AddDisk completed, handling the result.
>2012-11-08 09:14:06,115 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-48) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type AddDisk succeeded, clearing tasks.
>2012-11-08 09:14:06,119 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-4-thread-48) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 298eacc9-7a0b-4a79-9877-2e76c20930e4
>2012-11-08 09:14:06,119 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-4-thread-48) START, SPMClearTaskVDSCommand( storagePoolId = f0b3cc08-6a6e-4b06-bbda-add16f7e0bcb, ignoreFailoverLimit = false, compatabilityVersion = null, taskId = 298eacc9-7a0b-4a79-9877-2e76c20930e4), log id: 171b53bd
>2012-11-08 09:14:06,122 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-4-thread-48) START, HSMClearTaskVDSCommand(HostName = 10.34.63.135, HostId = d89888a0-297b-11e2-8324-001a4a013f09, taskId=298eacc9-7a0b-4a79-9877-2e76c20930e4), log id: 7a2594bf
>2012-11-08 09:14:06,130 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-4-thread-48) FINISH, HSMClearTaskVDSCommand, log id: 7a2594bf
>2012-11-08 09:14:06,130 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-4-thread-48) FINISH, SPMClearTaskVDSCommand, log id: 171b53bd
>2012-11-08 09:14:06,134 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-4-thread-48) BaseAsyncTask::RemoveTaskFromDB: Removed task 298eacc9-7a0b-4a79-9877-2e76c20930e4 from DataBase
>2012-11-08 09:14:06,134 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-4-thread-48) EntityAsyncTask::HandleEndActionResult [within thread]: Removing EntityMultiAsyncTasks object for entity d5500cb7-c2fd-45b8-9bab-ea9f081d4467

Actions: View

Attachments on bug 874443: 640643