Attachment 691643 Details for Bug 906858 – engine.log

engine.log

engine.log (text/x-log), 84.60 KB, created by Jiri Belka on 2013-02-01 17:44:47 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Jiri Belka

Created: 2013-02-01 17:44:47 UTC

Size: 84.60 KB

patch

obsolete

>2013-02-01 18:33:22,772 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (ajp-/127.0.0.1:8702-6) [27d9f081] Lock Acquired to object EngineLock [exclusiveLocks= key: 5a96a5c4-3af2-4e46-a832-aaadebdba09e value: VM
>, sharedLocks= ]
>2013-02-01 18:33:22,800 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (ajp-/127.0.0.1:8702-6) [27d9f081] Running command: RemoveVmCommand internal: false. Entities affected :  ID: 5a96a5c4-3af2-4e46-a832-aaadebdba09e Type: VM
>2013-02-01 18:33:22,801 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (ajp-/127.0.0.1:8702-6) [27d9f081] START, SetVmStatusVDSCommand( vmId = 5a96a5c4-3af2-4e46-a832-aaadebdba09e, status = ImageLocked), log id: 31ea5bf4
>2013-02-01 18:33:22,805 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (ajp-/127.0.0.1:8702-6) [27d9f081] FINISH, SetVmStatusVDSCommand, log id: 31ea5bf4
>2013-02-01 18:33:22,831 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (ajp-/127.0.0.1:8702-6) [27d9f081] Lock freed to object EngineLock [exclusiveLocks= key: 5a96a5c4-3af2-4e46-a832-aaadebdba09e value: VM
>, sharedLocks= ]
>2013-02-01 18:33:22,835 INFO  [org.ovirt.engine.core.bll.RemoveAllVmImagesCommand] (ajp-/127.0.0.1:8702-6) [ee28186] Running command: RemoveAllVmImagesCommand internal: true. Entities affected :  ID: 5a96a5c4-3af2-4e46-a832-aaadebdba09e Type: VM
>2013-02-01 18:33:22,840 INFO  [org.ovirt.engine.core.bll.RemoveImageCommand] (ajp-/127.0.0.1:8702-6) [5db2b0cb] Running command: RemoveImageCommand internal: true. Entities affected :  ID: 00000000-0000-0000-0000-000000000000 Type: Storage
>2013-02-01 18:33:22,860 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (ajp-/127.0.0.1:8702-6) [5db2b0cb] START, DeleteImageGroupVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = 3.2, storageDomainId = cc4d884d-15d9-4e35-b869-4330245c1b94, imageGroupId = 0518c80f-afcf-45b1-be5f-393a29cebeaa, postZeros = false, forceDelete = false), log id: 29b1ecb
>2013-02-01 18:33:22,937 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (ajp-/127.0.0.1:8702-6) [5db2b0cb] FINISH, DeleteImageGroupVDSCommand, log id: 29b1ecb
>2013-02-01 18:33:22,952 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (ajp-/127.0.0.1:8702-6) [5db2b0cb] EntityAsyncTask::Adding EntityMultiAsyncTasks object for entity 5a96a5c4-3af2-4e46-a832-aaadebdba09e
>2013-02-01 18:33:22,952 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (ajp-/127.0.0.1:8702-6) [5db2b0cb] EntityMultiAsyncTasks::AttachTask: Attaching task 60cb18a7-431a-489b-9e03-f665efd22695 to entity 5a96a5c4-3af2-4e46-a832-aaadebdba09e.
>2013-02-01 18:33:22,967 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (ajp-/127.0.0.1:8702-6) [5db2b0cb] Adding task 60cb18a7-431a-489b-9e03-f665efd22695 (Parent Command RemoveVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2013-02-01 18:33:23,118 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (ajp-/127.0.0.1:8702-6) [5db2b0cb] BaseAsyncTask::StartPollingTask: Starting to poll task 60cb18a7-431a-489b-9e03-f665efd22695.
>2013-02-01 18:33:23,118 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (ajp-/127.0.0.1:8702-6) [5db2b0cb] EntityMultiAsyncTasks::StartPollingTask: Current Action Type for entity 5a96a5c4-3af2-4e46-a832-aaadebdba09e is RemoveVm (determined by task 60cb18a7-431a-489b-9e03-f665efd22695)
>2013-02-01 18:33:25,287 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-3) [22f540f] Polling and updating Async Tasks: 1 tasks, 1 tasks to poll now
>2013-02-01 18:33:25,308 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-3) [22f540f] SPMAsyncTask::PollTask: Polling task 60cb18a7-431a-489b-9e03-f665efd22695 (Parent Command RemoveVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2013-02-01 18:33:25,326 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-3) [22f540f] BaseAsyncTask::OnTaskEndSuccess: Task 60cb18a7-431a-489b-9e03-f665efd22695 (Parent Command RemoveVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2013-02-01 18:33:25,326 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-3) [22f540f] EntityAsyncTask::EndActionIfNecessary: All tasks of entity 5a96a5c4-3af2-4e46-a832-aaadebdba09e has ended -> executing EndAction
>2013-02-01 18:33:25,326 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-3) [22f540f] EntityAsyncTask::EndAction: Ending action for 1 tasks (entity ID: 5a96a5c4-3af2-4e46-a832-aaadebdba09e): calling EndAction for action type RemoveVm.
>2013-02-01 18:33:25,326 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) [22f540f] EntityAsyncTask::EndCommandAction [within thread] context: Attempting to EndAction RemoveVm, executionIndex: 0
>2013-02-01 18:33:25,351 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (pool-3-thread-43) [27d9f081] Ending command successfully: org.ovirt.engine.core.bll.RemoveVmCommand
>2013-02-01 18:33:25,351 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (pool-3-thread-43) [27d9f081] Lock Acquired to object EngineLock [exclusiveLocks= key: 5a96a5c4-3af2-4e46-a832-aaadebdba09e value: VM
>, sharedLocks= ]
>2013-02-01 18:33:25,357 INFO  [org.ovirt.engine.core.bll.network.MacPoolManager] (pool-3-thread-43) [27d9f081] MacPoolManager::freeMac(mac = 00:1a:4a:e0:3f:c7) - entered
>2013-02-01 18:33:25,361 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (pool-3-thread-43) [27d9f081] Lock freed to object EngineLock [exclusiveLocks= key: 5a96a5c4-3af2-4e46-a832-aaadebdba09e value: VM
>, sharedLocks= ]
>2013-02-01 18:33:25,407 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type RemoveVm completed, handling the result.
>2013-02-01 18:33:25,407 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type RemoveVm succeeded, clearing tasks.
>2013-02-01 18:33:25,417 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-43) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 60cb18a7-431a-489b-9e03-f665efd22695
>2013-02-01 18:33:25,417 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-3-thread-43) START, SPMClearTaskVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = null, taskId = 60cb18a7-431a-489b-9e03-f665efd22695), log id: 5a154085
>2013-02-01 18:33:25,419 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-3-thread-43) START, HSMClearTaskVDSCommand(HostName = dell-r210ii-04, HostId = 1d600f47-a7f6-45b7-a537-8ccfdaab3ace, taskId=60cb18a7-431a-489b-9e03-f665efd22695), log id: 1c6322fd
>2013-02-01 18:33:25,473 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-3-thread-43) FINISH, HSMClearTaskVDSCommand, log id: 1c6322fd
>2013-02-01 18:33:25,474 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-3-thread-43) FINISH, SPMClearTaskVDSCommand, log id: 5a154085
>2013-02-01 18:33:25,484 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-43) BaseAsyncTask::RemoveTaskFromDB: Removed task 60cb18a7-431a-489b-9e03-f665efd22695 from DataBase
>2013-02-01 18:33:25,484 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) EntityAsyncTask::HandleEndActionResult [within thread]: Removing EntityMultiAsyncTasks object for entity 5a96a5c4-3af2-4e46-a832-aaadebdba09e
>2013-02-01 18:33:27,639 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (ajp-/127.0.0.1:8702-10) [1435c85d] Lock Acquired to object EngineLock [exclusiveLocks= key: 55e31d33-22fd-4f3d-a0cc-490d092e1347 value: VM
>, sharedLocks= ]
>2013-02-01 18:33:27,683 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (ajp-/127.0.0.1:8702-10) [1435c85d] Running command: RemoveVmCommand internal: false. Entities affected :  ID: 55e31d33-22fd-4f3d-a0cc-490d092e1347 Type: VM
>2013-02-01 18:33:27,684 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (ajp-/127.0.0.1:8702-10) [1435c85d] START, SetVmStatusVDSCommand( vmId = 55e31d33-22fd-4f3d-a0cc-490d092e1347, status = ImageLocked), log id: 38859983
>2013-02-01 18:33:27,688 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (ajp-/127.0.0.1:8702-10) [1435c85d] FINISH, SetVmStatusVDSCommand, log id: 38859983
>2013-02-01 18:33:27,699 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (ajp-/127.0.0.1:8702-10) [1435c85d] Lock freed to object EngineLock [exclusiveLocks= key: 55e31d33-22fd-4f3d-a0cc-490d092e1347 value: VM
>, sharedLocks= ]
>2013-02-01 18:33:27,704 INFO  [org.ovirt.engine.core.bll.RemoveAllVmImagesCommand] (ajp-/127.0.0.1:8702-10) [16248f2d] Running command: RemoveAllVmImagesCommand internal: true. Entities affected :  ID: 55e31d33-22fd-4f3d-a0cc-490d092e1347 Type: VM
>2013-02-01 18:33:27,715 INFO  [org.ovirt.engine.core.bll.RemoveImageCommand] (ajp-/127.0.0.1:8702-10) [205eea86] Running command: RemoveImageCommand internal: true. Entities affected :  ID: 00000000-0000-0000-0000-000000000000 Type: Storage
>2013-02-01 18:33:27,734 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (ajp-/127.0.0.1:8702-10) [205eea86] START, DeleteImageGroupVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = 3.2, storageDomainId = cc4d884d-15d9-4e35-b869-4330245c1b94, imageGroupId = dbee349b-00a5-4d33-8a32-0a888c39d799, postZeros = false, forceDelete = false), log id: 19f1a6f9
>2013-02-01 18:33:27,884 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (ajp-/127.0.0.1:8702-10) [205eea86] FINISH, DeleteImageGroupVDSCommand, log id: 19f1a6f9
>2013-02-01 18:33:27,900 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (ajp-/127.0.0.1:8702-10) [205eea86] EntityAsyncTask::Adding EntityMultiAsyncTasks object for entity 55e31d33-22fd-4f3d-a0cc-490d092e1347
>2013-02-01 18:33:27,900 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (ajp-/127.0.0.1:8702-10) [205eea86] EntityMultiAsyncTasks::AttachTask: Attaching task c975a19f-a061-4ebb-be23-a575ac74a1b0 to entity 55e31d33-22fd-4f3d-a0cc-490d092e1347.
>2013-02-01 18:33:27,916 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (ajp-/127.0.0.1:8702-10) [205eea86] Adding task c975a19f-a061-4ebb-be23-a575ac74a1b0 (Parent Command RemoveVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2013-02-01 18:33:28,067 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (ajp-/127.0.0.1:8702-10) [205eea86] BaseAsyncTask::StartPollingTask: Starting to poll task c975a19f-a061-4ebb-be23-a575ac74a1b0.
>2013-02-01 18:33:28,067 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (ajp-/127.0.0.1:8702-10) [205eea86] EntityMultiAsyncTasks::StartPollingTask: Current Action Type for entity 55e31d33-22fd-4f3d-a0cc-490d092e1347 is RemoveVm (determined by task c975a19f-a061-4ebb-be23-a575ac74a1b0)
>2013-02-01 18:33:31,116 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (ajp-/127.0.0.1:8702-2) [35539fa] Lock Acquired to object EngineLock [exclusiveLocks= key: 4cf3a3b1-1974-405a-bb3a-84e955b6d18f value: VM
>, sharedLocks= ]
>2013-02-01 18:33:31,156 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (ajp-/127.0.0.1:8702-2) [35539fa] Running command: RemoveVmCommand internal: false. Entities affected :  ID: 4cf3a3b1-1974-405a-bb3a-84e955b6d18f Type: VM
>2013-02-01 18:33:31,157 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (ajp-/127.0.0.1:8702-2) [35539fa] START, SetVmStatusVDSCommand( vmId = 4cf3a3b1-1974-405a-bb3a-84e955b6d18f, status = ImageLocked), log id: 190e7e45
>2013-02-01 18:33:31,161 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (ajp-/127.0.0.1:8702-2) [35539fa] FINISH, SetVmStatusVDSCommand, log id: 190e7e45
>2013-02-01 18:33:31,174 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (ajp-/127.0.0.1:8702-2) [35539fa] Lock freed to object EngineLock [exclusiveLocks= key: 4cf3a3b1-1974-405a-bb3a-84e955b6d18f value: VM
>, sharedLocks= ]
>2013-02-01 18:33:31,177 INFO  [org.ovirt.engine.core.bll.RemoveAllVmImagesCommand] (ajp-/127.0.0.1:8702-2) [6b167454] Running command: RemoveAllVmImagesCommand internal: true. Entities affected :  ID: 4cf3a3b1-1974-405a-bb3a-84e955b6d18f Type: VM
>2013-02-01 18:33:31,184 INFO  [org.ovirt.engine.core.bll.RemoveImageCommand] (ajp-/127.0.0.1:8702-2) [277b99e0] Running command: RemoveImageCommand internal: true. Entities affected :  ID: 00000000-0000-0000-0000-000000000000 Type: Storage
>2013-02-01 18:33:31,200 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (ajp-/127.0.0.1:8702-2) [277b99e0] START, DeleteImageGroupVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = 3.2, storageDomainId = cc4d884d-15d9-4e35-b869-4330245c1b94, imageGroupId = b47656ef-c4f2-4d45-88a8-db4c9e91a285, postZeros = false, forceDelete = false), log id: 20228e90
>2013-02-01 18:33:31,273 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (ajp-/127.0.0.1:8702-2) [277b99e0] FINISH, DeleteImageGroupVDSCommand, log id: 20228e90
>2013-02-01 18:33:31,290 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (ajp-/127.0.0.1:8702-2) [277b99e0] EntityAsyncTask::Adding EntityMultiAsyncTasks object for entity 4cf3a3b1-1974-405a-bb3a-84e955b6d18f
>2013-02-01 18:33:31,290 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (ajp-/127.0.0.1:8702-2) [277b99e0] EntityMultiAsyncTasks::AttachTask: Attaching task 1139e555-87f1-40e9-8abb-028a2e43e928 to entity 4cf3a3b1-1974-405a-bb3a-84e955b6d18f.
>2013-02-01 18:33:31,307 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (ajp-/127.0.0.1:8702-2) [277b99e0] Adding task 1139e555-87f1-40e9-8abb-028a2e43e928 (Parent Command RemoveVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2013-02-01 18:33:31,391 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (ajp-/127.0.0.1:8702-2) [277b99e0] BaseAsyncTask::StartPollingTask: Starting to poll task 1139e555-87f1-40e9-8abb-028a2e43e928.
>2013-02-01 18:33:31,391 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (ajp-/127.0.0.1:8702-2) [277b99e0] EntityMultiAsyncTasks::StartPollingTask: Current Action Type for entity 4cf3a3b1-1974-405a-bb3a-84e955b6d18f is RemoveVm (determined by task 1139e555-87f1-40e9-8abb-028a2e43e928)
>2013-02-01 18:33:32,884 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-9) Running command: LoginUserCommand internal: false.
>2013-02-01 18:33:32,923 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-9) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:33:32,923 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-9) calling GetConfigurationValueQuery (VdcVersion) with null version, using default general for version
>2013-02-01 18:33:35,327 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-18) Polling and updating Async Tasks: 3 tasks, 2 tasks to poll now
>2013-02-01 18:33:35,348 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-18) SPMAsyncTask::PollTask: Polling task 1139e555-87f1-40e9-8abb-028a2e43e928 (Parent Command RemoveVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2013-02-01 18:33:35,389 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-18) BaseAsyncTask::OnTaskEndSuccess: Task 1139e555-87f1-40e9-8abb-028a2e43e928 (Parent Command RemoveVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2013-02-01 18:33:35,389 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-18) EntityAsyncTask::EndActionIfNecessary: All tasks of entity 4cf3a3b1-1974-405a-bb3a-84e955b6d18f has ended -> executing EndAction
>2013-02-01 18:33:35,389 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-18) EntityAsyncTask::EndAction: Ending action for 1 tasks (entity ID: 4cf3a3b1-1974-405a-bb3a-84e955b6d18f): calling EndAction for action type RemoveVm.
>2013-02-01 18:33:35,389 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-18) SPMAsyncTask::PollTask: Polling task c975a19f-a061-4ebb-be23-a575ac74a1b0 (Parent Command RemoveVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2013-02-01 18:33:35,389 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) EntityAsyncTask::EndCommandAction [within thread] context: Attempting to EndAction RemoveVm, executionIndex: 0
>2013-02-01 18:33:35,413 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-18) BaseAsyncTask::OnTaskEndSuccess: Task c975a19f-a061-4ebb-be23-a575ac74a1b0 (Parent Command RemoveVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2013-02-01 18:33:35,414 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-18) EntityAsyncTask::EndActionIfNecessary: All tasks of entity 55e31d33-22fd-4f3d-a0cc-490d092e1347 has ended -> executing EndAction
>2013-02-01 18:33:35,414 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-18) EntityAsyncTask::EndAction: Ending action for 1 tasks (entity ID: 55e31d33-22fd-4f3d-a0cc-490d092e1347): calling EndAction for action type RemoveVm.
>2013-02-01 18:33:35,414 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-46) EntityAsyncTask::EndCommandAction [within thread] context: Attempting to EndAction RemoveVm, executionIndex: 0
>2013-02-01 18:33:35,422 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (pool-3-thread-43) [35539fa] Ending command successfully: org.ovirt.engine.core.bll.RemoveVmCommand
>2013-02-01 18:33:35,422 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (pool-3-thread-43) [35539fa] Lock Acquired to object EngineLock [exclusiveLocks= key: 4cf3a3b1-1974-405a-bb3a-84e955b6d18f value: VM
>, sharedLocks= ]
>2013-02-01 18:33:35,428 INFO  [org.ovirt.engine.core.bll.network.MacPoolManager] (pool-3-thread-43) [35539fa] MacPoolManager::freeMac(mac = 00:1a:4a:e0:3f:c1) - entered
>2013-02-01 18:33:35,433 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (pool-3-thread-43) [35539fa] Lock freed to object EngineLock [exclusiveLocks= key: 4cf3a3b1-1974-405a-bb3a-84e955b6d18f value: VM
>, sharedLocks= ]
>2013-02-01 18:33:35,439 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (pool-3-thread-46) [1435c85d] Ending command successfully: org.ovirt.engine.core.bll.RemoveVmCommand
>2013-02-01 18:33:35,439 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (pool-3-thread-46) [1435c85d] Lock Acquired to object EngineLock [exclusiveLocks= key: 55e31d33-22fd-4f3d-a0cc-490d092e1347 value: VM
>, sharedLocks= ]
>2013-02-01 18:33:35,445 INFO  [org.ovirt.engine.core.bll.network.MacPoolManager] (pool-3-thread-46) [1435c85d] MacPoolManager::freeMac(mac = 00:1a:4a:e0:3f:c4) - entered
>2013-02-01 18:33:35,447 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (pool-3-thread-46) [1435c85d] Lock freed to object EngineLock [exclusiveLocks= key: 55e31d33-22fd-4f3d-a0cc-490d092e1347 value: VM
>, sharedLocks= ]
>2013-02-01 18:33:35,472 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-46) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type RemoveVm completed, handling the result.
>2013-02-01 18:33:35,472 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-46) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type RemoveVm succeeded, clearing tasks.
>2013-02-01 18:33:35,473 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type RemoveVm completed, handling the result.
>2013-02-01 18:33:35,473 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type RemoveVm succeeded, clearing tasks.
>2013-02-01 18:33:35,489 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-46) SPMAsyncTask::ClearAsyncTask: Attempting to clear task c975a19f-a061-4ebb-be23-a575ac74a1b0
>2013-02-01 18:33:35,489 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-3-thread-46) START, SPMClearTaskVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = null, taskId = c975a19f-a061-4ebb-be23-a575ac74a1b0), log id: 5da554c4
>2013-02-01 18:33:35,491 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-3-thread-46) START, HSMClearTaskVDSCommand(HostName = dell-r210ii-04, HostId = 1d600f47-a7f6-45b7-a537-8ccfdaab3ace, taskId=c975a19f-a061-4ebb-be23-a575ac74a1b0), log id: 74724f7a
>2013-02-01 18:33:35,506 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-43) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 1139e555-87f1-40e9-8abb-028a2e43e928
>2013-02-01 18:33:35,506 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-3-thread-43) START, SPMClearTaskVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = null, taskId = 1139e555-87f1-40e9-8abb-028a2e43e928), log id: 7cc00e4f
>2013-02-01 18:33:35,515 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-3-thread-46) FINISH, HSMClearTaskVDSCommand, log id: 74724f7a
>2013-02-01 18:33:35,515 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-3-thread-46) FINISH, SPMClearTaskVDSCommand, log id: 5da554c4
>2013-02-01 18:33:35,517 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-3-thread-43) START, HSMClearTaskVDSCommand(HostName = dell-r210ii-04, HostId = 1d600f47-a7f6-45b7-a537-8ccfdaab3ace, taskId=1139e555-87f1-40e9-8abb-028a2e43e928), log id: 326a3c56
>2013-02-01 18:33:35,530 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-46) BaseAsyncTask::RemoveTaskFromDB: Removed task c975a19f-a061-4ebb-be23-a575ac74a1b0 from DataBase
>2013-02-01 18:33:35,530 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-46) EntityAsyncTask::HandleEndActionResult [within thread]: Removing EntityMultiAsyncTasks object for entity 55e31d33-22fd-4f3d-a0cc-490d092e1347
>2013-02-01 18:33:35,541 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-3-thread-43) FINISH, HSMClearTaskVDSCommand, log id: 326a3c56
>2013-02-01 18:33:35,541 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-3-thread-43) FINISH, SPMClearTaskVDSCommand, log id: 7cc00e4f
>2013-02-01 18:33:35,555 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-43) BaseAsyncTask::RemoveTaskFromDB: Removed task 1139e555-87f1-40e9-8abb-028a2e43e928 from DataBase
>2013-02-01 18:33:35,556 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) EntityAsyncTask::HandleEndActionResult [within thread]: Removing EntityMultiAsyncTasks object for entity 4cf3a3b1-1974-405a-bb3a-84e955b6d18f
>2013-02-01 18:33:37,961 INFO  [org.ovirt.engine.core.bll.RemoveVmTemplateCommand] (ajp-/127.0.0.1:8702-8) Lock Acquired to object EngineLock [exclusiveLocks= key: a300f4fa-22e8-4b76-a6a3-f1e794da7de5 value: TEMPLATE
>, sharedLocks= ]
>2013-02-01 18:33:38,071 INFO  [org.ovirt.engine.core.bll.RemoveVmTemplateCommand] (pool-3-thread-43) [47137ed4] Running command: RemoveVmTemplateCommand internal: false. Entities affected :  ID: a300f4fa-22e8-4b76-a6a3-f1e794da7de5 Type: VmTemplate
>2013-02-01 18:33:38,088 INFO  [org.ovirt.engine.core.bll.RemoveVmTemplateCommand] (pool-3-thread-43) [47137ed4] Lock freed to object EngineLock [exclusiveLocks= key: a300f4fa-22e8-4b76-a6a3-f1e794da7de5 value: TEMPLATE
>, sharedLocks= ]
>2013-02-01 18:33:38,091 INFO  [org.ovirt.engine.core.bll.RemoveAllVmTemplateImageTemplatesCommand] (pool-3-thread-43) [47137ed4] Running command: RemoveAllVmTemplateImageTemplatesCommand internal: true. Entities affected :  ID: a300f4fa-22e8-4b76-a6a3-f1e794da7de5 Type: VmTemplate
>2013-02-01 18:33:38,097 INFO  [org.ovirt.engine.core.bll.RemoveTemplateSnapshotCommand] (pool-3-thread-43) [71f976f4] Running command: RemoveTemplateSnapshotCommand internal: true. Entities affected :  ID: cc4d884d-15d9-4e35-b869-4330245c1b94 Type: Storage
>2013-02-01 18:33:38,099 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (pool-3-thread-43) [71f976f4] START, DeleteImageGroupVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = 3.2, storageDomainId = cc4d884d-15d9-4e35-b869-4330245c1b94, imageGroupId = ca4b3d8b-26df-4beb-9c12-d864697b9cb5, postZeros = false, forceDelete = false), log id: 7e81dd74
>2013-02-01 18:33:38,232 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (pool-3-thread-43) [71f976f4] FINISH, DeleteImageGroupVDSCommand, log id: 7e81dd74
>2013-02-01 18:33:38,246 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) [71f976f4] EntityAsyncTask::Adding EntityMultiAsyncTasks object for entity a300f4fa-22e8-4b76-a6a3-f1e794da7de5
>2013-02-01 18:33:38,247 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (pool-3-thread-43) [71f976f4] EntityMultiAsyncTasks::AttachTask: Attaching task c79e6f74-6cc1-4fbf-8e85-2c1b70008a42 to entity a300f4fa-22e8-4b76-a6a3-f1e794da7de5.
>2013-02-01 18:33:38,263 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (pool-3-thread-43) [71f976f4] Adding task c79e6f74-6cc1-4fbf-8e85-2c1b70008a42 (Parent Command RemoveVmTemplate, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2013-02-01 18:33:38,314 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-43) [71f976f4] BaseAsyncTask::StartPollingTask: Starting to poll task c79e6f74-6cc1-4fbf-8e85-2c1b70008a42.
>2013-02-01 18:33:38,314 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (pool-3-thread-43) [71f976f4] EntityMultiAsyncTasks::StartPollingTask: Current Action Type for entity a300f4fa-22e8-4b76-a6a3-f1e794da7de5 is RemoveVmTemplate (determined by task c79e6f74-6cc1-4fbf-8e85-2c1b70008a42)
>2013-02-01 18:33:41,428 INFO  [org.ovirt.engine.core.bll.RemoveVmTemplateCommand] (ajp-/127.0.0.1:8702-9) Lock Acquired to object EngineLock [exclusiveLocks= key: 1d6b28d4-c8a3-4d9f-8f97-de487f36fff6 value: TEMPLATE
>, sharedLocks= ]
>2013-02-01 18:33:41,503 INFO  [org.ovirt.engine.core.bll.RemoveVmTemplateCommand] (pool-3-thread-43) [4d59547f] Running command: RemoveVmTemplateCommand internal: false. Entities affected :  ID: 1d6b28d4-c8a3-4d9f-8f97-de487f36fff6 Type: VmTemplate
>2013-02-01 18:33:41,520 INFO  [org.ovirt.engine.core.bll.RemoveVmTemplateCommand] (pool-3-thread-43) [4d59547f] Lock freed to object EngineLock [exclusiveLocks= key: 1d6b28d4-c8a3-4d9f-8f97-de487f36fff6 value: TEMPLATE
>, sharedLocks= ]
>2013-02-01 18:33:41,523 INFO  [org.ovirt.engine.core.bll.RemoveAllVmTemplateImageTemplatesCommand] (pool-3-thread-43) [4d59547f] Running command: RemoveAllVmTemplateImageTemplatesCommand internal: true. Entities affected :  ID: 1d6b28d4-c8a3-4d9f-8f97-de487f36fff6 Type: VmTemplate
>2013-02-01 18:33:41,528 INFO  [org.ovirt.engine.core.bll.RemoveTemplateSnapshotCommand] (pool-3-thread-43) [33220c7b] Running command: RemoveTemplateSnapshotCommand internal: true. Entities affected :  ID: cc4d884d-15d9-4e35-b869-4330245c1b94 Type: Storage
>2013-02-01 18:33:41,529 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (pool-3-thread-43) [33220c7b] START, DeleteImageGroupVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = 3.2, storageDomainId = cc4d884d-15d9-4e35-b869-4330245c1b94, imageGroupId = dbdc3b48-5d85-410f-a953-63c59394f8c8, postZeros = false, forceDelete = false), log id: 49b4b042
>2013-02-01 18:33:41,599 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (pool-3-thread-43) [33220c7b] FINISH, DeleteImageGroupVDSCommand, log id: 49b4b042
>2013-02-01 18:33:41,612 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) [33220c7b] EntityAsyncTask::Adding EntityMultiAsyncTasks object for entity 1d6b28d4-c8a3-4d9f-8f97-de487f36fff6
>2013-02-01 18:33:41,612 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (pool-3-thread-43) [33220c7b] EntityMultiAsyncTasks::AttachTask: Attaching task 90b2dbad-17c8-4189-aadf-2c6c73a1c90b to entity 1d6b28d4-c8a3-4d9f-8f97-de487f36fff6.
>2013-02-01 18:33:41,628 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (pool-3-thread-43) [33220c7b] Adding task 90b2dbad-17c8-4189-aadf-2c6c73a1c90b (Parent Command RemoveVmTemplate, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2013-02-01 18:33:41,690 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-43) [33220c7b] BaseAsyncTask::StartPollingTask: Starting to poll task 90b2dbad-17c8-4189-aadf-2c6c73a1c90b.
>2013-02-01 18:33:41,690 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (pool-3-thread-43) [33220c7b] EntityMultiAsyncTasks::StartPollingTask: Current Action Type for entity 1d6b28d4-c8a3-4d9f-8f97-de487f36fff6 is RemoveVmTemplate (determined by task 90b2dbad-17c8-4189-aadf-2c6c73a1c90b)
>2013-02-01 18:33:45,415 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-31) Polling and updating Async Tasks: 5 tasks, 2 tasks to poll now
>2013-02-01 18:33:45,435 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-31) SPMAsyncTask::PollTask: Polling task c79e6f74-6cc1-4fbf-8e85-2c1b70008a42 (Parent Command RemoveVmTemplate, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2013-02-01 18:33:45,463 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-31) BaseAsyncTask::OnTaskEndSuccess: Task c79e6f74-6cc1-4fbf-8e85-2c1b70008a42 (Parent Command RemoveVmTemplate, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2013-02-01 18:33:45,464 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-31) EntityAsyncTask::EndActionIfNecessary: All tasks of entity a300f4fa-22e8-4b76-a6a3-f1e794da7de5 has ended -> executing EndAction
>2013-02-01 18:33:45,464 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-31) EntityAsyncTask::EndAction: Ending action for 1 tasks (entity ID: a300f4fa-22e8-4b76-a6a3-f1e794da7de5): calling EndAction for action type RemoveVmTemplate.
>2013-02-01 18:33:45,464 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-31) SPMAsyncTask::PollTask: Polling task 90b2dbad-17c8-4189-aadf-2c6c73a1c90b (Parent Command RemoveVmTemplate, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2013-02-01 18:33:45,464 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) EntityAsyncTask::EndCommandAction [within thread] context: Attempting to EndAction RemoveVmTemplate, executionIndex: 0
>2013-02-01 18:33:45,479 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-31) BaseAsyncTask::OnTaskEndSuccess: Task 90b2dbad-17c8-4189-aadf-2c6c73a1c90b (Parent Command RemoveVmTemplate, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2013-02-01 18:33:45,480 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-31) EntityAsyncTask::EndActionIfNecessary: All tasks of entity 1d6b28d4-c8a3-4d9f-8f97-de487f36fff6 has ended -> executing EndAction
>2013-02-01 18:33:45,480 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-31) EntityAsyncTask::EndAction: Ending action for 1 tasks (entity ID: 1d6b28d4-c8a3-4d9f-8f97-de487f36fff6): calling EndAction for action type RemoveVmTemplate.
>2013-02-01 18:33:45,480 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-46) EntityAsyncTask::EndCommandAction [within thread] context: Attempting to EndAction RemoveVmTemplate, executionIndex: 0
>2013-02-01 18:33:45,497 INFO  [org.ovirt.engine.core.bll.RemoveVmTemplateCommand] (pool-3-thread-43) Ending command successfully: org.ovirt.engine.core.bll.RemoveVmTemplateCommand
>2013-02-01 18:33:45,504 INFO  [org.ovirt.engine.core.bll.RemoveVmTemplateCommand] (pool-3-thread-46) Ending command successfully: org.ovirt.engine.core.bll.RemoveVmTemplateCommand
>2013-02-01 18:33:45,538 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-46) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type RemoveVmTemplate completed, handling the result.
>2013-02-01 18:33:45,538 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-46) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type RemoveVmTemplate succeeded, clearing tasks.
>2013-02-01 18:33:45,554 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-46) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 90b2dbad-17c8-4189-aadf-2c6c73a1c90b
>2013-02-01 18:33:45,555 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-3-thread-46) START, SPMClearTaskVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = null, taskId = 90b2dbad-17c8-4189-aadf-2c6c73a1c90b), log id: 3f30d316
>2013-02-01 18:33:45,556 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-3-thread-46) START, HSMClearTaskVDSCommand(HostName = dell-r210ii-04, HostId = 1d600f47-a7f6-45b7-a537-8ccfdaab3ace, taskId=90b2dbad-17c8-4189-aadf-2c6c73a1c90b), log id: 5a3fb5a8
>2013-02-01 18:33:45,571 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type RemoveVmTemplate completed, handling the result.
>2013-02-01 18:33:45,571 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type RemoveVmTemplate succeeded, clearing tasks.
>2013-02-01 18:33:45,581 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-3-thread-46) FINISH, HSMClearTaskVDSCommand, log id: 5a3fb5a8
>2013-02-01 18:33:45,581 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-3-thread-46) FINISH, SPMClearTaskVDSCommand, log id: 3f30d316
>2013-02-01 18:33:45,588 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-43) SPMAsyncTask::ClearAsyncTask: Attempting to clear task c79e6f74-6cc1-4fbf-8e85-2c1b70008a42
>2013-02-01 18:33:45,588 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-3-thread-43) START, SPMClearTaskVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = null, taskId = c79e6f74-6cc1-4fbf-8e85-2c1b70008a42), log id: 61e64df6
>2013-02-01 18:33:45,590 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-3-thread-43) START, HSMClearTaskVDSCommand(HostName = dell-r210ii-04, HostId = 1d600f47-a7f6-45b7-a537-8ccfdaab3ace, taskId=c79e6f74-6cc1-4fbf-8e85-2c1b70008a42), log id: 6b84035e
>2013-02-01 18:33:45,595 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-46) BaseAsyncTask::RemoveTaskFromDB: Removed task 90b2dbad-17c8-4189-aadf-2c6c73a1c90b from DataBase
>2013-02-01 18:33:45,595 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-46) EntityAsyncTask::HandleEndActionResult [within thread]: Removing EntityMultiAsyncTasks object for entity 1d6b28d4-c8a3-4d9f-8f97-de487f36fff6
>2013-02-01 18:33:45,613 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-3-thread-43) FINISH, HSMClearTaskVDSCommand, log id: 6b84035e
>2013-02-01 18:33:45,613 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-3-thread-43) FINISH, SPMClearTaskVDSCommand, log id: 61e64df6
>2013-02-01 18:33:45,630 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-43) BaseAsyncTask::RemoveTaskFromDB: Removed task c79e6f74-6cc1-4fbf-8e85-2c1b70008a42 from DataBase
>2013-02-01 18:33:45,630 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) EntityAsyncTask::HandleEndActionResult [within thread]: Removing EntityMultiAsyncTasks object for entity a300f4fa-22e8-4b76-a6a3-f1e794da7de5
>2013-02-01 18:33:58,342 INFO  [org.ovirt.engine.core.bll.AddVmFromScratchCommand] (ajp-/127.0.0.1:8702-4) [2437ccc0] Lock Acquired to object EngineLock [exclusiveLocks= key: test00 value: VM_NAME
>, sharedLocks= ]
>2013-02-01 18:33:58,477 INFO  [org.ovirt.engine.core.bll.AddVmFromScratchCommand] (ajp-/127.0.0.1:8702-4) [2437ccc0] Running command: AddVmFromScratchCommand internal: false. Entities affected :  ID: 99408929-82cf-4dc7-a532-9d998063fa95 Type: VdsGroups
>2013-02-01 18:33:58,511 INFO  [org.ovirt.engine.core.bll.AddVmFromScratchCommand] (ajp-/127.0.0.1:8702-4) [2437ccc0] Lock freed to object EngineLock [exclusiveLocks= key: test00 value: VM_NAME
>, sharedLocks= ]
>2013-02-01 18:34:06,209 INFO  [org.ovirt.engine.core.bll.network.vm.AddVmInterfaceCommand] (ajp-/127.0.0.1:8702-5) [1514acdb] Running command: AddVmInterfaceCommand internal: false. Entities affected :  ID: be7c09d6-6c4b-4653-aff8-655e5e24bb4d Type: VM,  ID: 97aacfca-13f4-4851-b868-1deac44c9878 Type: Network
>2013-02-01 18:34:06,210 INFO  [org.ovirt.engine.core.bll.network.MacPoolManager] (ajp-/127.0.0.1:8702-5) [1514acdb] MacPoolManager::allocateNewMac entered
>2013-02-01 18:34:06,210 INFO  [org.ovirt.engine.core.bll.network.MacPoolManager] (ajp-/127.0.0.1:8702-5) [1514acdb] MacPoolManager::allocateNewMac allocated mac = 00:1a:4a:e0:3f:c4
>2013-02-01 18:34:06,271 INFO  [org.ovirt.engine.core.bll.network.vm.ActivateDeactivateVmNicCommand] (ajp-/127.0.0.1:8702-5) [11cc09a] Running command: ActivateDeactivateVmNicCommand internal: true. Entities affected :  ID: be7c09d6-6c4b-4653-aff8-655e5e24bb4d Type: VM
>2013-02-01 18:34:20,880 INFO  [org.ovirt.engine.core.bll.AddDiskCommand] (ajp-/127.0.0.1:8702-1) [2625c77c] Lock Acquired to object EngineLock [exclusiveLocks= key: be7c09d6-6c4b-4653-aff8-655e5e24bb4d value: VM_DISK_BOOT
>, sharedLocks= key: be7c09d6-6c4b-4653-aff8-655e5e24bb4d value: VM
>]
>2013-02-01 18:34:20,909 INFO  [org.ovirt.engine.core.bll.AddDiskCommand] (ajp-/127.0.0.1:8702-1) [2625c77c] Running command: AddDiskCommand internal: false. Entities affected :  ID: be7c09d6-6c4b-4653-aff8-655e5e24bb4d Type: VM,  ID: cc4d884d-15d9-4e35-b869-4330245c1b94 Type: Storage
>2013-02-01 18:34:21,018 INFO  [org.ovirt.engine.core.bll.AddImageFromScratchCommand] (ajp-/127.0.0.1:8702-1) [55f738c8] Running command: AddImageFromScratchCommand internal: true. Entities affected :  ID: cc4d884d-15d9-4e35-b869-4330245c1b94 Type: Storage
>2013-02-01 18:34:21,033 INFO  [org.ovirt.engine.core.bll.AddImageFromScratchCommand] (ajp-/127.0.0.1:8702-1) [55f738c8] Lock freed to object EngineLock [exclusiveLocks= key: be7c09d6-6c4b-4653-aff8-655e5e24bb4d value: VM_DISK_BOOT
>, sharedLocks= key: be7c09d6-6c4b-4653-aff8-655e5e24bb4d value: VM
>]
>2013-02-01 18:34:21,035 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (ajp-/127.0.0.1:8702-1) [55f738c8] START, CreateImageVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = 3.2, storageDomainId = cc4d884d-15d9-4e35-b869-4330245c1b94, imageGroupId = bdd6c0c1-2e90-45bf-8740-52186f33ac20, imageSizeInBytes = 1073741824, volumeFormat = RAW, newImageId = 13545c35-eec0-4ac3-bb25-b73221c7977f, newImageDescription = ), log id: 48dd0b44
>2013-02-01 18:34:21,035 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (ajp-/127.0.0.1:8702-1) [55f738c8] -- CreateImageVDSCommand::ExecuteIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
>2013-02-01 18:34:21,035 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (ajp-/127.0.0.1:8702-1) [55f738c8] -- createVolume parameters:
>                sdUUID=cc4d884d-15d9-4e35-b869-4330245c1b94
>                spUUID=a05c6f22-2a40-4f39-a2a8-aa91b539b217
>                imgGUID=bdd6c0c1-2e90-45bf-8740-52186f33ac20
>                size=1,073,741,824 bytes
>                volFormat=RAW
>                volType=Sparse
>                volUUID=13545c35-eec0-4ac3-bb25-b73221c7977f
>                descr=
>                srcImgGUID=00000000-0000-0000-0000-000000000000
>                srcVolUUID=00000000-0000-0000-0000-000000000000
>                
>2013-02-01 18:34:21,091 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (ajp-/127.0.0.1:8702-1) [55f738c8] FINISH, CreateImageVDSCommand, return: 13545c35-eec0-4ac3-bb25-b73221c7977f, log id: 48dd0b44
>2013-02-01 18:34:21,101 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (ajp-/127.0.0.1:8702-1) [55f738c8] EntityAsyncTask::Adding EntityMultiAsyncTasks object for entity bdd6c0c1-2e90-45bf-8740-52186f33ac20
>2013-02-01 18:34:21,101 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (ajp-/127.0.0.1:8702-1) [55f738c8] EntityMultiAsyncTasks::AttachTask: Attaching task 767d14bb-3ae0-4a51-9ae4-b844c8ab7f4d to entity bdd6c0c1-2e90-45bf-8740-52186f33ac20.
>2013-02-01 18:34:21,117 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (ajp-/127.0.0.1:8702-1) [55f738c8] Adding task 767d14bb-3ae0-4a51-9ae4-b844c8ab7f4d (Parent Command AddDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2013-02-01 18:34:21,191 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (ajp-/127.0.0.1:8702-1) [55f738c8] BaseAsyncTask::StartPollingTask: Starting to poll task 767d14bb-3ae0-4a51-9ae4-b844c8ab7f4d.
>2013-02-01 18:34:21,191 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (ajp-/127.0.0.1:8702-1) [55f738c8] EntityMultiAsyncTasks::StartPollingTask: Current Action Type for entity bdd6c0c1-2e90-45bf-8740-52186f33ac20 is AddDisk (determined by task 767d14bb-3ae0-4a51-9ae4-b844c8ab7f4d)
>2013-02-01 18:34:25,489 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-71) Polling and updating Async Tasks: 6 tasks, 1 tasks to poll now
>2013-02-01 18:34:25,510 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-71) SPMAsyncTask::PollTask: Polling task 767d14bb-3ae0-4a51-9ae4-b844c8ab7f4d (Parent Command AddDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2013-02-01 18:34:25,538 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-71) BaseAsyncTask::OnTaskEndSuccess: Task 767d14bb-3ae0-4a51-9ae4-b844c8ab7f4d (Parent Command AddDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2013-02-01 18:34:25,539 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-71) EntityAsyncTask::EndActionIfNecessary: All tasks of entity bdd6c0c1-2e90-45bf-8740-52186f33ac20 has ended -> executing EndAction
>2013-02-01 18:34:25,539 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-71) EntityAsyncTask::EndAction: Ending action for 1 tasks (entity ID: bdd6c0c1-2e90-45bf-8740-52186f33ac20): calling EndAction for action type AddDisk.
>2013-02-01 18:34:25,539 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) EntityAsyncTask::EndCommandAction [within thread] context: Attempting to EndAction AddDisk, executionIndex: 0
>2013-02-01 18:34:25,565 INFO  [org.ovirt.engine.core.bll.AddDiskCommand] (pool-3-thread-43) [2625c77c] Ending command successfully: org.ovirt.engine.core.bll.AddDiskCommand
>2013-02-01 18:34:25,569 INFO  [org.ovirt.engine.core.bll.AddImageFromScratchCommand] (pool-3-thread-43) [55f738c8] Ending command successfully: org.ovirt.engine.core.bll.AddImageFromScratchCommand
>2013-02-01 18:34:25,573 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (pool-3-thread-43) [55f738c8] START, GetImageInfoVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = null, storageDomainId = cc4d884d-15d9-4e35-b869-4330245c1b94, imageGroupId = bdd6c0c1-2e90-45bf-8740-52186f33ac20, imageId = 13545c35-eec0-4ac3-bb25-b73221c7977f), log id: 71007421
>2013-02-01 18:34:25,605 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (pool-3-thread-43) [55f738c8] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@4cee0c, log id: 71007421
>2013-02-01 18:34:25,657 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type AddDisk completed, handling the result.
>2013-02-01 18:34:25,657 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type AddDisk succeeded, clearing tasks.
>2013-02-01 18:34:25,674 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-43) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 767d14bb-3ae0-4a51-9ae4-b844c8ab7f4d
>2013-02-01 18:34:25,674 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-3-thread-43) START, SPMClearTaskVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = null, taskId = 767d14bb-3ae0-4a51-9ae4-b844c8ab7f4d), log id: 4001938e
>2013-02-01 18:34:25,676 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-3-thread-43) START, HSMClearTaskVDSCommand(HostName = dell-r210ii-04, HostId = 1d600f47-a7f6-45b7-a537-8ccfdaab3ace, taskId=767d14bb-3ae0-4a51-9ae4-b844c8ab7f4d), log id: 6439f8b0
>2013-02-01 18:34:25,701 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-3-thread-43) FINISH, HSMClearTaskVDSCommand, log id: 6439f8b0
>2013-02-01 18:34:25,701 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-3-thread-43) FINISH, SPMClearTaskVDSCommand, log id: 4001938e
>2013-02-01 18:34:25,715 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-43) BaseAsyncTask::RemoveTaskFromDB: Removed task 767d14bb-3ae0-4a51-9ae4-b844c8ab7f4d from DataBase
>2013-02-01 18:34:25,715 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-43) EntityAsyncTask::HandleEndActionResult [within thread]: Removing EntityMultiAsyncTasks object for entity bdd6c0c1-2e90-45bf-8740-52186f33ac20
>2013-02-01 18:34:27,884 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-81) Setting new tasks map. The map contains now 5 tasks
>2013-02-01 18:34:32,871 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-11) Running command: LoginUserCommand internal: false.
>2013-02-01 18:34:32,921 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-11) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:34:32,921 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-11) calling GetConfigurationValueQuery (VdcVersion) with null version, using default general for version
>2013-02-01 18:34:37,837 INFO  [org.ovirt.engine.core.bll.AddPermissionCommand] (pool-3-thread-44) [41957816] Running command: AddPermissionCommand internal: false. Entities affected :  ID: be7c09d6-6c4b-4653-aff8-655e5e24bb4d Type: VM
>2013-02-01 18:34:55,768 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (ajp-/127.0.0.1:8702-1) [78d912d0] START, GetImageInfoVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = null, storageDomainId = cc4d884d-15d9-4e35-b869-4330245c1b94, imageGroupId = bdd6c0c1-2e90-45bf-8740-52186f33ac20, imageId = 13545c35-eec0-4ac3-bb25-b73221c7977f), log id: 48f47ae0
>2013-02-01 18:34:55,798 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (ajp-/127.0.0.1:8702-1) [78d912d0] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@4cee0c, log id: 48f47ae0
>2013-02-01 18:34:55,851 INFO  [org.ovirt.engine.core.bll.AddVmTemplateCommand] (ajp-/127.0.0.1:8702-1) [78d912d0] Running command: AddVmTemplateCommand internal: false. Entities affected :  ID: a05c6f22-2a40-4f39-a2a8-aa91b539b217 Type: StoragePool
>2013-02-01 18:34:55,853 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (ajp-/127.0.0.1:8702-1) [78d912d0] START, SetVmStatusVDSCommand( vmId = be7c09d6-6c4b-4653-aff8-655e5e24bb4d, status = ImageLocked), log id: 17298c8
>2013-02-01 18:34:55,856 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (ajp-/127.0.0.1:8702-1) [78d912d0] FINISH, SetVmStatusVDSCommand, log id: 17298c8
>2013-02-01 18:34:55,889 INFO  [org.ovirt.engine.core.bll.CreateImageTemplateCommand] (ajp-/127.0.0.1:8702-1) [3840bbb1] Running command: CreateImageTemplateCommand internal: true. Entities affected :  ID: cc4d884d-15d9-4e35-b869-4330245c1b94 Type: Storage
>2013-02-01 18:34:55,894 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (ajp-/127.0.0.1:8702-1) [3840bbb1] START, GetImageInfoVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = null, storageDomainId = cc4d884d-15d9-4e35-b869-4330245c1b94, imageGroupId = bdd6c0c1-2e90-45bf-8740-52186f33ac20, imageId = 13545c35-eec0-4ac3-bb25-b73221c7977f), log id: 26fc7c6
>2013-02-01 18:34:55,925 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (ajp-/127.0.0.1:8702-1) [3840bbb1] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@4cee0c, log id: 26fc7c6
>2013-02-01 18:34:55,942 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (ajp-/127.0.0.1:8702-1) [3840bbb1] START, CopyImageVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = 3.2, storageDomainId = cc4d884d-15d9-4e35-b869-4330245c1b94, imageGroupId = bdd6c0c1-2e90-45bf-8740-52186f33ac20, imageId = 13545c35-eec0-4ac3-bb25-b73221c7977f, dstImageGroupId = 2b1b6474-42da-40dc-bb50-395046335aa4, vmId = be7c09d6-6c4b-4653-aff8-655e5e24bb4d, dstImageId = 182f850e-1e52-43d7-bcf4-fd1d3ce1bf08, imageDescription = Active VM, dstStorageDomainId = cc4d884d-15d9-4e35-b869-4330245c1b94, copyVolumeType = SharedVol, volumeFormat = RAW, preallocate = Sparse, postZero = false, force = false), log id: 6e0facc1
>2013-02-01 18:34:55,942 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (ajp-/127.0.0.1:8702-1) [3840bbb1] -- CopyImageVDSCommand::ExecuteIrsBrokerCommand: calling 'copyImage' with two new parameters: description and UUID
>2013-02-01 18:34:55,942 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (ajp-/127.0.0.1:8702-1) [3840bbb1] -- copyImage parameters:
>                sdUUID=cc4d884d-15d9-4e35-b869-4330245c1b94
>                spUUID=a05c6f22-2a40-4f39-a2a8-aa91b539b217
>                vmGUID=be7c09d6-6c4b-4653-aff8-655e5e24bb4d
>                srcImageGUID=bdd6c0c1-2e90-45bf-8740-52186f33ac20
>                srcVolUUID=13545c35-eec0-4ac3-bb25-b73221c7977f
>                dstImageGUID=2b1b6474-42da-40dc-bb50-395046335aa4
>                dstVolUUID=182f850e-1e52-43d7-bcf4-fd1d3ce1bf08
>                descr=Active VM
>                
>2013-02-01 18:34:56,013 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (ajp-/127.0.0.1:8702-1) [3840bbb1] FINISH, CopyImageVDSCommand, return: 00000000-0000-0000-0000-000000000000, log id: 6e0facc1
>2013-02-01 18:34:56,027 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (ajp-/127.0.0.1:8702-1) [3840bbb1] EntityAsyncTask::Adding EntityMultiAsyncTasks object for entity bca820e0-b3fe-4ef4-aab9-a84a9c09dc0e
>2013-02-01 18:34:56,027 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (ajp-/127.0.0.1:8702-1) [3840bbb1] EntityMultiAsyncTasks::AttachTask: Attaching task c17be3de-4efa-4b32-a347-d6e2eafe225a to entity bca820e0-b3fe-4ef4-aab9-a84a9c09dc0e.
>2013-02-01 18:34:56,044 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (ajp-/127.0.0.1:8702-1) [3840bbb1] Adding task c17be3de-4efa-4b32-a347-d6e2eafe225a (Parent Command AddVmTemplate, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2013-02-01 18:34:56,119 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (ajp-/127.0.0.1:8702-1) [3840bbb1] BaseAsyncTask::StartPollingTask: Starting to poll task c17be3de-4efa-4b32-a347-d6e2eafe225a.
>2013-02-01 18:34:56,119 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (ajp-/127.0.0.1:8702-1) [3840bbb1] EntityMultiAsyncTasks::StartPollingTask: Current Action Type for entity bca820e0-b3fe-4ef4-aab9-a84a9c09dc0e is AddVmTemplate (determined by task c17be3de-4efa-4b32-a347-d6e2eafe225a)
>2013-02-01 18:34:57,884 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-6) Setting new tasks map. The map contains now 2 tasks
>2013-02-01 18:35:00,018 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-3) [22f540f] Autorecovering 0 hosts
>2013-02-01 18:35:00,019 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-3) [22f540f] Autorecovering 0 storage domains
>2013-02-01 18:35:05,540 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-16) Polling and updating Async Tasks: 2 tasks, 1 tasks to poll now
>2013-02-01 18:35:05,564 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-16) SPMAsyncTask::PollTask: Polling task c17be3de-4efa-4b32-a347-d6e2eafe225a (Parent Command AddVmTemplate, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status running.
>2013-02-01 18:35:05,564 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-16) Finished polling Tasks, will poll again in 10 seconds.
>2013-02-01 18:35:15,586 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-11) [25f2324c] SPMAsyncTask::PollTask: Polling task c17be3de-4efa-4b32-a347-d6e2eafe225a (Parent Command AddVmTemplate, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2013-02-01 18:35:15,600 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-11) [25f2324c] BaseAsyncTask::OnTaskEndSuccess: Task c17be3de-4efa-4b32-a347-d6e2eafe225a (Parent Command AddVmTemplate, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2013-02-01 18:35:15,601 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-11) [25f2324c] EntityAsyncTask::EndActionIfNecessary: All tasks of entity bca820e0-b3fe-4ef4-aab9-a84a9c09dc0e has ended -> executing EndAction
>2013-02-01 18:35:15,601 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-11) [25f2324c] EntityAsyncTask::EndAction: Ending action for 1 tasks (entity ID: bca820e0-b3fe-4ef4-aab9-a84a9c09dc0e): calling EndAction for action type AddVmTemplate.
>2013-02-01 18:35:15,602 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-44) [25f2324c] EntityAsyncTask::EndCommandAction [within thread] context: Attempting to EndAction AddVmTemplate, executionIndex: 0
>2013-02-01 18:35:15,642 INFO  [org.ovirt.engine.core.bll.AddVmTemplateCommand] (pool-3-thread-44) [78d912d0] Ending command successfully: org.ovirt.engine.core.bll.AddVmTemplateCommand
>2013-02-01 18:35:15,644 INFO  [org.ovirt.engine.core.bll.CreateImageTemplateCommand] (pool-3-thread-44) [3840bbb1] Ending command successfully: org.ovirt.engine.core.bll.CreateImageTemplateCommand
>2013-02-01 18:35:15,646 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (pool-3-thread-44) [3840bbb1] START, GetImageInfoVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = null, storageDomainId = cc4d884d-15d9-4e35-b869-4330245c1b94, imageGroupId = 2b1b6474-42da-40dc-bb50-395046335aa4, imageId = 182f850e-1e52-43d7-bcf4-fd1d3ce1bf08), log id: afef8ac
>2013-02-01 18:35:15,679 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (pool-3-thread-44) [3840bbb1] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@abdf0522, log id: afef8ac
>2013-02-01 18:35:15,685 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (pool-3-thread-44) START, SetVmStatusVDSCommand( vmId = be7c09d6-6c4b-4653-aff8-655e5e24bb4d, status = Down), log id: 58208bfa
>2013-02-01 18:35:15,688 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (pool-3-thread-44) FINISH, SetVmStatusVDSCommand, log id: 58208bfa
>2013-02-01 18:35:15,718 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-44) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type AddVmTemplate completed, handling the result.
>2013-02-01 18:35:15,718 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-44) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type AddVmTemplate succeeded, clearing tasks.
>2013-02-01 18:35:15,734 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-44) SPMAsyncTask::ClearAsyncTask: Attempting to clear task c17be3de-4efa-4b32-a347-d6e2eafe225a
>2013-02-01 18:35:15,734 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-3-thread-44) START, SPMClearTaskVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = null, taskId = c17be3de-4efa-4b32-a347-d6e2eafe225a), log id: 5bc342db
>2013-02-01 18:35:15,737 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-3-thread-44) START, HSMClearTaskVDSCommand(HostName = dell-r210ii-04, HostId = 1d600f47-a7f6-45b7-a537-8ccfdaab3ace, taskId=c17be3de-4efa-4b32-a347-d6e2eafe225a), log id: 10b459b7
>2013-02-01 18:35:15,763 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-3-thread-44) FINISH, HSMClearTaskVDSCommand, log id: 10b459b7
>2013-02-01 18:35:15,764 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-3-thread-44) FINISH, SPMClearTaskVDSCommand, log id: 5bc342db
>2013-02-01 18:35:15,776 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-44) BaseAsyncTask::RemoveTaskFromDB: Removed task c17be3de-4efa-4b32-a347-d6e2eafe225a from DataBase
>2013-02-01 18:35:15,776 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-44) EntityAsyncTask::HandleEndActionResult [within thread]: Removing EntityMultiAsyncTasks object for entity bca820e0-b3fe-4ef4-aab9-a84a9c09dc0e
>2013-02-01 18:35:24,657 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetFloppyListVDSCommand] (pool-3-thread-43) START, GetFloppyListVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = null), log id: 71085de1
>2013-02-01 18:35:24,659 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetIsoListVDSCommand] (pool-3-thread-44) START, GetIsoListVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = null), log id: 5680d3e8
>2013-02-01 18:35:24,705 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetFloppyListVDSCommand] (pool-3-thread-43) FINISH, GetFloppyListVDSCommand, return: [virtio-drivers-1.0.2-52454.vfd, win2003-32-unattended.vfd, virtio-win-1.3.1.vfd, winxp.vfd, win2k3x64.vfd, virtio-win-1.5.3.vfd, win2000-Pro-unattended.vfd, winXP-Pro-SP2-32-unattended.vfd, virtio-drivers.vfd, virtio-drivers-1.0.0-8.vfd, virtio-win-1.1.16.vfd, winXP-x64-unattended.vfd, virtio-drivers-1.0.0-45801.vfd, win2003-x64-unattended.vfd], log id: 71085de1
>2013-02-01 18:35:24,707 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HsmGetIsoListVDSCommand] (pool-3-thread-44) START, HsmGetIsoListVDSCommand(HostName = dell-r210ii-04, HostId = 1d600f47-a7f6-45b7-a537-8ccfdaab3ace, storagePoolId=a05c6f22-2a40-4f39-a2a8-aa91b539b217), log id: 18083149
>2013-02-01 18:35:24,762 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HsmGetIsoListVDSCommand] (pool-3-thread-44) FINISH, HsmGetIsoListVDSCommand, return: [openbsd-install52.iso, fakeISO01.iso, debian-6.0.6-amd64-netinst.iso, RHEV-toolsSetup_2.3_327.iso, RHEV-toolsSetup_2.2_52976.iso, en_windows_server_2008_r2_standard_enterprise_datacenter_and_web_x64_dvd_x15-59754.iso, RHEV-toolsSetup_2.3_359.iso, Windows2003-r2-std-32-bit.iso, RHEV-toolsSetup_3.1_9.iso, RHEV-toolsSetup_2.3_360-fake.iso, Windows2008-x86.iso, virtio-win-1.0.2-52454.iso, .install52.iso, RHEV-toolsSetup_3.2_1.iso, Fedora-17-x86_64-Live-Desktop.iso, EnglishWindowsServer2003R2withSP2VLPStandard64bitDISC1.iso, RHEV-toolsSetup_2.3_276.iso, UOB-keyboard-en-1.iso, RHEV-toolsSetup_2.3_395.iso, RHEV-toolsSetup_3.0_37_ic156.iso, Windows2008-x64.iso, RHEV-toolsSetup_3.1_1.iso, RHEV-toolsSetup_2.3_298.iso, RHEV-toolsSetup_3.0_10.iso, RHEV-toolsSetup_3.0_39.iso, fakeISO1.iso, IT_WINXP_PRO_VL_ISO.iso, RHEL6.2-20111117.0-Server-x86_64-DVD1.iso, RHEV-toolsSetup_3.0_17.iso, WANemv2.3.iso, virtio-win-1.3.1.iso, virtio-win-1.3.3.iso, en_windows_7_enterprise_x86_dvd_x15-70745.iso, RHEV-toolsSetup_3.1_8.iso, RHEV-toolsSetup_2.2_46140.iso, FreeBSD-8.2-RELEASE-amd64-dvd1.iso, en_windows_xp_professional_with_service_pack_3_x86_cd_vl_x14-73974.iso, en_windows_7_enterprise_x64_dvd_x15-70749.iso, slax-English-US-7.0-x86_64.iso, RHEV-toolsSetup_3.0_8.iso, Fedora-17-x86_64-DVD.iso, RHEV-toolsSetup_2.2_47513.iso, crunchbang-10-20120207-amd64.bpo.iso, fakeISO02.iso, RHEV-toolsSetup_2.2_52832.iso, RHEV-toolsSetup_2.2_52998.iso, EnglishWindowsServer2003R2withSP2VLPStandard64bitDISC2.iso, MUI_Windows_server_2003_r2_cd1.iso, RHEV-toolsSetup_2.3_338.iso, RHEV-toolsSetup_2.2_53011.iso, RHEV-toolsSetup_2.2_52985.iso, cd52.iso, RHEV-toolsSetup_2.3_317.iso], log id: 18083149
>2013-02-01 18:35:24,762 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetIsoListVDSCommand] (pool-3-thread-44) FINISH, GetIsoListVDSCommand, return: [openbsd-install52.iso, fakeISO01.iso, debian-6.0.6-amd64-netinst.iso, RHEV-toolsSetup_2.3_327.iso, RHEV-toolsSetup_2.2_52976.iso, en_windows_server_2008_r2_standard_enterprise_datacenter_and_web_x64_dvd_x15-59754.iso, RHEV-toolsSetup_2.3_359.iso, Windows2003-r2-std-32-bit.iso, RHEV-toolsSetup_3.1_9.iso, RHEV-toolsSetup_2.3_360-fake.iso, Windows2008-x86.iso, virtio-win-1.0.2-52454.iso, .install52.iso, RHEV-toolsSetup_3.2_1.iso, Fedora-17-x86_64-Live-Desktop.iso, EnglishWindowsServer2003R2withSP2VLPStandard64bitDISC1.iso, RHEV-toolsSetup_2.3_276.iso, UOB-keyboard-en-1.iso, RHEV-toolsSetup_2.3_395.iso, RHEV-toolsSetup_3.0_37_ic156.iso, Windows2008-x64.iso, RHEV-toolsSetup_3.1_1.iso, RHEV-toolsSetup_2.3_298.iso, RHEV-toolsSetup_3.0_10.iso, RHEV-toolsSetup_3.0_39.iso, fakeISO1.iso, IT_WINXP_PRO_VL_ISO.iso, RHEL6.2-20111117.0-Server-x86_64-DVD1.iso, RHEV-toolsSetup_3.0_17.iso, WANemv2.3.iso, virtio-win-1.3.1.iso, virtio-win-1.3.3.iso, en_windows_7_enterprise_x86_dvd_x15-70745.iso, RHEV-toolsSetup_3.1_8.iso, RHEV-toolsSetup_2.2_46140.iso, FreeBSD-8.2-RELEASE-amd64-dvd1.iso, en_windows_xp_professional_with_service_pack_3_x86_cd_vl_x14-73974.iso, en_windows_7_enterprise_x64_dvd_x15-70749.iso, slax-English-US-7.0-x86_64.iso, RHEV-toolsSetup_3.0_8.iso, Fedora-17-x86_64-DVD.iso, RHEV-toolsSetup_2.2_47513.iso, crunchbang-10-20120207-amd64.bpo.iso, fakeISO02.iso, RHEV-toolsSetup_2.2_52832.iso, RHEV-toolsSetup_2.2_52998.iso, EnglishWindowsServer2003R2withSP2VLPStandard64bitDISC2.iso, MUI_Windows_server_2003_r2_cd1.iso, RHEV-toolsSetup_2.3_338.iso, RHEV-toolsSetup_2.2_53011.iso, RHEV-toolsSetup_2.2_52985.iso, cd52.iso, RHEV-toolsSetup_2.3_317.iso], log id: 5680d3e8
>2013-02-01 18:35:24,768 INFO  [org.ovirt.engine.core.bll.IsoDomainListSyncronizer] (pool-3-thread-43) Finished automatic refresh process for Floppy file type with success, for storage domain id a7e5f59c-2877-475b-8afc-f760ba63defb.
>2013-02-01 18:35:24,806 INFO  [org.ovirt.engine.core.bll.IsoDomainListSyncronizer] (pool-3-thread-44) Finished automatic refresh process for ISO file type with success, for storage domain id a7e5f59c-2877-475b-8afc-f760ba63defb.
>2013-02-01 18:35:27,884 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-56) Setting new tasks map. The map contains now 1 tasks
>2013-02-01 18:35:32,170 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (ajp-/127.0.0.1:8702-2) Lock Acquired to object EngineLock [exclusiveLocks= key: test01 value: VM_NAME
>, sharedLocks= ]
>2013-02-01 18:35:32,262 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (pool-3-thread-44) [3ee8f272] Running command: AddVmCommand internal: false. Entities affected :  ID: 99408929-82cf-4dc7-a532-9d998063fa95 Type: VdsGroups,  ID: bca820e0-b3fe-4ef4-aab9-a84a9c09dc0e Type: VmTemplate,  ID: cc4d884d-15d9-4e35-b869-4330245c1b94 Type: Storage
>2013-02-01 18:35:32,269 INFO  [org.ovirt.engine.core.bll.network.MacPoolManager] (pool-3-thread-44) [3ee8f272] MacPoolManager::allocateNewMac entered
>2013-02-01 18:35:32,269 INFO  [org.ovirt.engine.core.bll.network.MacPoolManager] (pool-3-thread-44) [3ee8f272] MacPoolManager::allocateNewMac allocated mac = 00:1a:4a:e0:3f:c1
>2013-02-01 18:35:32,295 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (pool-3-thread-44) [3ee8f272] Lock freed to object EngineLock [exclusiveLocks= key: test01 value: VM_NAME
>, sharedLocks= ]
>2013-02-01 18:35:32,295 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (pool-3-thread-44) [3ee8f272] START, SetVmStatusVDSCommand( vmId = 2d2606cc-92b9-4d21-9f53-14c56a57d284, status = ImageLocked), log id: 2e20939d
>2013-02-01 18:35:32,298 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (pool-3-thread-44) [3ee8f272] FINISH, SetVmStatusVDSCommand, log id: 2e20939d
>2013-02-01 18:35:32,299 INFO  [org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand] (pool-3-thread-44) [7b733a17] Running command: CreateSnapshotFromTemplateCommand internal: true. Entities affected :  ID: cc4d884d-15d9-4e35-b869-4330245c1b94 Type: Storage
>2013-02-01 18:35:32,300 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (pool-3-thread-44) [7b733a17] START, GetImageInfoVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = null, storageDomainId = cc4d884d-15d9-4e35-b869-4330245c1b94, imageGroupId = 2b1b6474-42da-40dc-bb50-395046335aa4, imageId = 182f850e-1e52-43d7-bcf4-fd1d3ce1bf08), log id: 4b3a0cde
>2013-02-01 18:35:32,332 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (pool-3-thread-44) [7b733a17] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@abdf0522, log id: 4b3a0cde
>2013-02-01 18:35:32,334 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (pool-3-thread-44) [7b733a17] START, CreateSnapshotVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = 3.2, storageDomainId = cc4d884d-15d9-4e35-b869-4330245c1b94, imageGroupId = 1dee59db-a148-4af4-9850-bb501b30e0cc, imageSizeInBytes = 1073741824, volumeFormat = COW, newImageId = 5b5bd26a-0c9b-4a24-b38e-f9cf3f80c265, newImageDescription = , imageId = 182f850e-1e52-43d7-bcf4-fd1d3ce1bf08, sourceImageGroupId = 2b1b6474-42da-40dc-bb50-395046335aa4), log id: 5808f465
>2013-02-01 18:35:32,334 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (pool-3-thread-44) [7b733a17] -- CreateSnapshotVDSCommand::ExecuteIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
>2013-02-01 18:35:32,334 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (pool-3-thread-44) [7b733a17] -- createVolume parameters:
>                sdUUID=cc4d884d-15d9-4e35-b869-4330245c1b94
>                spUUID=a05c6f22-2a40-4f39-a2a8-aa91b539b217
>                imgGUID=1dee59db-a148-4af4-9850-bb501b30e0cc
>                size=1,073,741,824 bytes
>                volFormat=COW
>                volType=Sparse
>                volUUID=5b5bd26a-0c9b-4a24-b38e-f9cf3f80c265
>                descr=
>                srcImgGUID=2b1b6474-42da-40dc-bb50-395046335aa4
>                srcVolUUID=182f850e-1e52-43d7-bcf4-fd1d3ce1bf08
>                
>2013-02-01 18:35:32,400 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (pool-3-thread-44) [7b733a17] FINISH, CreateSnapshotVDSCommand, return: 5b5bd26a-0c9b-4a24-b38e-f9cf3f80c265, log id: 5808f465
>2013-02-01 18:35:32,411 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-44) [7b733a17] EntityAsyncTask::Adding EntityMultiAsyncTasks object for entity 2d2606cc-92b9-4d21-9f53-14c56a57d284
>2013-02-01 18:35:32,411 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (pool-3-thread-44) [7b733a17] EntityMultiAsyncTasks::AttachTask: Attaching task 33a3071f-aee1-4ac3-902a-f72dbd366b96 to entity 2d2606cc-92b9-4d21-9f53-14c56a57d284.
>2013-02-01 18:35:32,435 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (pool-3-thread-44) [7b733a17] Adding task 33a3071f-aee1-4ac3-902a-f72dbd366b96 (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2013-02-01 18:35:32,537 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-44) [7b733a17] BaseAsyncTask::StartPollingTask: Starting to poll task 33a3071f-aee1-4ac3-902a-f72dbd366b96.
>2013-02-01 18:35:32,537 INFO  [org.ovirt.engine.core.bll.EntityMultiAsyncTasks] (pool-3-thread-44) [7b733a17] EntityMultiAsyncTasks::StartPollingTask: Current Action Type for entity 2d2606cc-92b9-4d21-9f53-14c56a57d284 is AddVm (determined by task 33a3071f-aee1-4ac3-902a-f72dbd366b96)
>2013-02-01 18:35:32,857 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-7) Running command: LoginUserCommand internal: false.
>2013-02-01 18:35:32,903 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-7) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:35:32,903 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-7) calling GetConfigurationValueQuery (VdcVersion) with null version, using default general for version
>2013-02-01 18:35:35,601 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-51) Polling and updating Async Tasks: 2 tasks, 1 tasks to poll now
>2013-02-01 18:35:35,621 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-51) SPMAsyncTask::PollTask: Polling task 33a3071f-aee1-4ac3-902a-f72dbd366b96 (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2013-02-01 18:35:35,665 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (QuartzScheduler_Worker-51) BaseAsyncTask::OnTaskEndSuccess: Task 33a3071f-aee1-4ac3-902a-f72dbd366b96 (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2013-02-01 18:35:35,666 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-51) EntityAsyncTask::EndActionIfNecessary: All tasks of entity 2d2606cc-92b9-4d21-9f53-14c56a57d284 has ended -> executing EndAction
>2013-02-01 18:35:35,666 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (QuartzScheduler_Worker-51) EntityAsyncTask::EndAction: Ending action for 1 tasks (entity ID: 2d2606cc-92b9-4d21-9f53-14c56a57d284): calling EndAction for action type AddVm.
>2013-02-01 18:35:35,666 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-44) EntityAsyncTask::EndCommandAction [within thread] context: Attempting to EndAction AddVm, executionIndex: 0
>2013-02-01 18:35:35,693 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (pool-3-thread-44) Ending command successfully: org.ovirt.engine.core.bll.AddVmCommand
>2013-02-01 18:35:35,698 INFO  [org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand] (pool-3-thread-44) [7b733a17] Ending command successfully: org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand
>2013-02-01 18:35:35,699 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (pool-3-thread-44) [7b733a17] START, GetImageInfoVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = null, storageDomainId = cc4d884d-15d9-4e35-b869-4330245c1b94, imageGroupId = 1dee59db-a148-4af4-9850-bb501b30e0cc, imageId = 5b5bd26a-0c9b-4a24-b38e-f9cf3f80c265), log id: 6a1a6242
>2013-02-01 18:35:35,732 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (pool-3-thread-44) [7b733a17] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@164a2cee, log id: 6a1a6242
>2013-02-01 18:35:35,738 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (pool-3-thread-44) START, SetVmStatusVDSCommand( vmId = 2d2606cc-92b9-4d21-9f53-14c56a57d284, status = Down), log id: 583659e4
>2013-02-01 18:35:35,740 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (pool-3-thread-44) FINISH, SetVmStatusVDSCommand, log id: 583659e4
>2013-02-01 18:35:35,785 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-44) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type AddVm completed, handling the result.
>2013-02-01 18:35:35,785 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-44) EntityAsyncTask::HandleEndActionResult [within thread]: EndAction for action type AddVm succeeded, clearing tasks.
>2013-02-01 18:35:35,802 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-44) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 33a3071f-aee1-4ac3-902a-f72dbd366b96
>2013-02-01 18:35:35,802 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-3-thread-44) START, SPMClearTaskVDSCommand( storagePoolId = a05c6f22-2a40-4f39-a2a8-aa91b539b217, ignoreFailoverLimit = false, compatabilityVersion = null, taskId = 33a3071f-aee1-4ac3-902a-f72dbd366b96), log id: 5d70614
>2013-02-01 18:35:35,804 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-3-thread-44) START, HSMClearTaskVDSCommand(HostName = dell-r210ii-04, HostId = 1d600f47-a7f6-45b7-a537-8ccfdaab3ace, taskId=33a3071f-aee1-4ac3-902a-f72dbd366b96), log id: e92104
>2013-02-01 18:35:35,839 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-3-thread-44) FINISH, HSMClearTaskVDSCommand, log id: e92104
>2013-02-01 18:35:35,839 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-3-thread-44) FINISH, SPMClearTaskVDSCommand, log id: 5d70614
>2013-02-01 18:35:35,852 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-3-thread-44) BaseAsyncTask::RemoveTaskFromDB: Removed task 33a3071f-aee1-4ac3-902a-f72dbd366b96 from DataBase
>2013-02-01 18:35:35,852 INFO  [org.ovirt.engine.core.bll.EntityAsyncTask] (pool-3-thread-44) EntityAsyncTask::HandleEndActionResult [within thread]: Removing EntityMultiAsyncTasks object for entity 2d2606cc-92b9-4d21-9f53-14c56a57d284
>2013-02-01 18:35:46,090 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-9) Running command: LoginUserCommand internal: false.
>2013-02-01 18:35:46,147 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-9) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:35:46,208 INFO  [org.ovirt.engine.core.bll.LogoutUserCommand] (ajp-/127.0.0.1:8702-9) [1c2ab9d6] Running command: LogoutUserCommand internal: false.
>2013-02-01 18:36:09,250 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-5) Running command: LoginUserCommand internal: false.
>2013-02-01 18:36:09,344 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-5) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:36:09,354 INFO  [org.ovirt.engine.core.bll.LogoutUserCommand] (ajp-/127.0.0.1:8702-5) [75911230] Running command: LogoutUserCommand internal: false.
>2013-02-01 18:36:16,521 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-8) Running command: LoginUserCommand internal: false.
>2013-02-01 18:36:16,591 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
>2013-02-01 18:36:16,642 INFO  [org.ovirt.engine.core.bll.LogoutUserCommand] (ajp-/127.0.0.1:8702-8) [3a6c8564] Running command: LogoutUserCommand internal: false.
>2013-02-01 18:36:27,884 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-12) Setting new tasks map. The map contains now 1 tasks
>2013-02-01 18:36:32,860 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-11) Running command: LoginUserCommand internal: false.
>2013-02-01 18:36:32,908 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-11) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:36:32,908 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-11) calling GetConfigurationValueQuery (VdcVersion) with null version, using default general for version
>2013-02-01 18:36:38,088 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-9) Running command: LoginUserCommand internal: false.
>2013-02-01 18:36:38,122 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-9) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:36:38,132 INFO  [org.ovirt.engine.core.bll.LogoutUserCommand] (ajp-/127.0.0.1:8702-9) [330076b0] Running command: LogoutUserCommand internal: false.
>2013-02-01 18:36:56,376 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-1) Running command: LoginUserCommand internal: false.
>2013-02-01 18:36:56,438 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-1) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:36:56,502 INFO  [org.ovirt.engine.core.bll.LogoutUserCommand] (ajp-/127.0.0.1:8702-1) [5bdcffaf] Running command: LogoutUserCommand internal: false.
>2013-02-01 18:36:57,885 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-28) Setting new tasks map. The map contains now 0 tasks
>2013-02-01 18:36:57,885 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-28) Cleared all tasks of pool a05c6f22-2a40-4f39-a2a8-aa91b539b217.
>2013-02-01 18:36:57,888 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (QuartzScheduler_Worker-28) Could not find vds that is spm and non-operational.
>2013-02-01 18:37:23,032 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-5) Running command: LoginUserCommand internal: false.
>2013-02-01 18:37:23,122 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-5) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:37:23,132 INFO  [org.ovirt.engine.core.bll.LogoutUserCommand] (ajp-/127.0.0.1:8702-5) [5e7182fd] Running command: LogoutUserCommand internal: false.
>2013-02-01 18:37:29,525 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-10) Running command: LoginUserCommand internal: false.
>2013-02-01 18:37:29,582 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-10) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:37:29,590 INFO  [org.ovirt.engine.core.bll.LogoutUserCommand] (ajp-/127.0.0.1:8702-10) [12fa696d] Running command: LogoutUserCommand internal: false.
>2013-02-01 18:37:32,857 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-5) Running command: LoginUserCommand internal: false.
>2013-02-01 18:37:32,907 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-5) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:37:32,907 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-5) calling GetConfigurationValueQuery (VdcVersion) with null version, using default general for version
>2013-02-01 18:37:59,478 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-9) Running command: LoginUserCommand internal: false.
>2013-02-01 18:37:59,521 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-9) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:37:59,531 INFO  [org.ovirt.engine.core.bll.LogoutUserCommand] (ajp-/127.0.0.1:8702-9) [430f1baf] Running command: LogoutUserCommand internal: false.
>2013-02-01 18:38:02,766 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-7) Running command: LoginUserCommand internal: false.
>2013-02-01 18:38:02,801 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-7) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:38:02,809 INFO  [org.ovirt.engine.core.bll.LogoutUserCommand] (ajp-/127.0.0.1:8702-7) [6846e381] Running command: LogoutUserCommand internal: false.
>2013-02-01 18:38:32,861 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-2) Running command: LoginUserCommand internal: false.
>2013-02-01 18:38:32,896 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-2) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:38:32,896 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-2) calling GetConfigurationValueQuery (VdcVersion) with null version, using default general for version
>2013-02-01 18:39:20,446 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-9) Running command: LoginUserCommand internal: false.
>2013-02-01 18:39:20,484 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-9) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:39:20,491 INFO  [org.ovirt.engine.core.bll.LogoutUserCommand] (ajp-/127.0.0.1:8702-9) [50726aad] Running command: LogoutUserCommand internal: false.
>2013-02-01 18:39:29,392 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-11) Running command: LoginUserCommand internal: false.
>2013-02-01 18:39:29,480 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-11) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:39:29,489 INFO  [org.ovirt.engine.core.bll.LogoutUserCommand] (ajp-/127.0.0.1:8702-11) [64ce686b] Running command: LogoutUserCommand internal: false.
>2013-02-01 18:39:32,861 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-8) Running command: LoginUserCommand internal: false.
>2013-02-01 18:39:32,895 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
>2013-02-01 18:39:32,895 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
>2013-02-01 18:40:00,002 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-19) Autorecovering 0 hosts
>2013-02-01 18:40:00,003 INFO  [org.ovirt.engine.core.bll.AutoRecoveryManager] (QuartzScheduler_Worker-19) Autorecovering 0 storage domains
>2013-02-01 18:40:32,866 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-11) Running command: LoginUserCommand internal: false.
>2013-02-01 18:40:32,910 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-11) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:40:32,910 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-11) calling GetConfigurationValueQuery (VdcVersion) with null version, using default general for version
>2013-02-01 18:41:32,866 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-10) Running command: LoginUserCommand internal: false.
>2013-02-01 18:41:32,923 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-10) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
>2013-02-01 18:41:32,924 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-10) calling GetConfigurationValueQuery (VdcVersion) with null version, using default general for version
>2013-02-01 18:42:32,870 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-8) Running command: LoginUserCommand internal: false.
>2013-02-01 18:42:32,945 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
>2013-02-01 18:42:32,945 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

Actions: View

Attachments on bug 906858: 691643