Attachment 889444 Details for Bug 1091094 – engine log

engine log

engine.log (text/plain), 75.07 KB, created by Adam Litke on 2014-04-24 21:09:41 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Adam Litke

Created: 2014-04-24 21:09:41 UTC

Size: 75.07 KB

patch

obsolete

>2014-04-24 16:53:39,896 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-32) [54191756] START, SetVmStatusVDSCommand( vmId = bc41fa36-53a1-4c8b-a6a6-97442e643a32, status = ImageLocked, exit status = Normal), log id: 776b1970
>2014-04-24 16:53:39,913 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-32) [54191756] FINISH, SetVmStatusVDSCommand, log id: 776b1970
>2014-04-24 16:53:39,921 INFO  [org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand] (org.ovirt.thread.pool-6-thread-32) [57474f6f] Running command: CreateSnapshotFromTemplateCommand internal: true. Entities affected :  ID: 0ee18e0e-b9c5-493a-a835-32017c6cafc3 Type: Storage
>2014-04-24 16:53:39,925 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-32) [57474f6f] START, CreateSnapshotVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, storageDomainId = 0ee18e0e-b9c5-493a-a835-32017c6cafc3, imageGroupId = d54e52f2-9ea4-4df1-9f28-fa2cb3c1aec3, imageSizeInBytes = 2147483648, volumeFormat = COW, newImageId = 0e67176b-827d-4ce2-a5cc-f49240c7474a, newImageDescription = , imageId = ef8bd5d2-6bcd-48e3-aad0-d6a1abcd2a44, sourceImageGroupId = 7065f804-3926-47af-88a2-433afc492592), log id: 2b60c289
>2014-04-24 16:53:39,926 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-32) [57474f6f] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
>2014-04-24 16:53:40,334 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-32) [57474f6f] FINISH, CreateSnapshotVDSCommand, return: 0e67176b-827d-4ce2-a5cc-f49240c7474a, log id: 2b60c289
>2014-04-24 16:53:40,339 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-32) [57474f6f] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 52f62422-49ee-4f1d-9214-d5ed9f5f3722
>2014-04-24 16:53:40,340 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-32) [57474f6f] CommandMultiAsyncTasks::AttachTask: Attaching task 6b730eb0-724c-4990-9936-3d3d43d2642b to command 52f62422-49ee-4f1d-9214-d5ed9f5f3722.
>2014-04-24 16:53:40,346 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (org.ovirt.thread.pool-6-thread-32) [57474f6f] Adding task 6b730eb0-724c-4990-9936-3d3d43d2642b (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-04-24 16:53:40,397 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-32) [57474f6f] Correlation ID: 54191756, Call Stack: null, Custom Event ID: -1, Message: VM block-1 creation was initiated by admin.
>2014-04-24 16:53:40,397 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-32) [57474f6f] BaseAsyncTask::startPollingTask: Starting to poll task 6b730eb0-724c-4990-9936-3d3d43d2642b.
>2014-04-24 16:53:40,401 INFO  [org.ovirt.engine.core.bll.AddVmToPoolCommand] (org.ovirt.thread.pool-6-thread-32) [63dd2bb5] Running command: AddVmToPoolCommand internal: true. Entities affected :  ID: b862e91a-e531-4159-8a1a-9ace8a0d27a8 Type: VmPool
>2014-04-24 16:53:40,455 INFO  [org.ovirt.engine.core.bll.AddVmAndAttachToPoolCommand] (org.ovirt.thread.pool-6-thread-32) [3991575b] Running command: AddVmAndAttachToPoolCommand internal: true. Entities affected :  ID: 7e9fae25-662e-48a3-9530-ffdbacb1179c Type: VdsGroups,  ID: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 Type: VmTemplate,  ID: 0ee18e0e-b9c5-493a-a835-32017c6cafc3 Type: Storage,  ID: 7e9fae25-662e-48a3-9530-ffdbacb1179c Type: VdsGroups
>2014-04-24 16:53:40,461 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-32) [54147d0d] Lock Acquired to object EngineLock [exclusiveLocks= key: block-2 value: VM_NAME
>, sharedLocks= key: 7065f804-3926-47af-88a2-433afc492592 value: DISK
>key: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 value: TEMPLATE
>]
>2014-04-24 16:53:40,474 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-32) [54147d0d] Running command: AddVmCommand internal: true. Entities affected :  ID: 7e9fae25-662e-48a3-9530-ffdbacb1179c Type: VdsGroups,  ID: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 Type: VmTemplate,  ID: 0ee18e0e-b9c5-493a-a835-32017c6cafc3 Type: Storage,  ID: 7e9fae25-662e-48a3-9530-ffdbacb1179c Type: VdsGroups
>2014-04-24 16:53:40,489 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-32) [54147d0d] START, SetVmStatusVDSCommand( vmId = 1248f347-cd1c-4719-baae-e4af3eea7a8a, status = ImageLocked, exit status = Normal), log id: 4e4bad99
>2014-04-24 16:53:40,505 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-32) [54147d0d] FINISH, SetVmStatusVDSCommand, log id: 4e4bad99
>2014-04-24 16:53:40,514 INFO  [org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand] (org.ovirt.thread.pool-6-thread-32) [4f3c4bc3] Running command: CreateSnapshotFromTemplateCommand internal: true. Entities affected :  ID: 0ee18e0e-b9c5-493a-a835-32017c6cafc3 Type: Storage
>2014-04-24 16:53:40,516 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-32) [4f3c4bc3] START, CreateSnapshotVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, storageDomainId = 0ee18e0e-b9c5-493a-a835-32017c6cafc3, imageGroupId = 58e5b479-4155-4973-934c-fe9f41ae70f9, imageSizeInBytes = 2147483648, volumeFormat = COW, newImageId = 1063aa35-b3d8-4ca2-a165-4355f3afc970, newImageDescription = , imageId = ef8bd5d2-6bcd-48e3-aad0-d6a1abcd2a44, sourceImageGroupId = 7065f804-3926-47af-88a2-433afc492592), log id: 3e4d6c01
>2014-04-24 16:53:40,517 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-32) [4f3c4bc3] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
>2014-04-24 16:53:40,905 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-32) [4f3c4bc3] FINISH, CreateSnapshotVDSCommand, return: 1063aa35-b3d8-4ca2-a165-4355f3afc970, log id: 3e4d6c01
>2014-04-24 16:53:40,933 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-32) [4f3c4bc3] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 46a22858-4c0f-4e3a-89b3-5ba5c46b06e3
>2014-04-24 16:53:40,933 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-32) [4f3c4bc3] CommandMultiAsyncTasks::AttachTask: Attaching task 32ecc6cc-cdcd-48c6-8095-38a3a8b8b093 to command 46a22858-4c0f-4e3a-89b3-5ba5c46b06e3.
>2014-04-24 16:53:41,042 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (org.ovirt.thread.pool-6-thread-32) [4f3c4bc3] Adding task 32ecc6cc-cdcd-48c6-8095-38a3a8b8b093 (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-04-24 16:53:41,114 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-32) [4f3c4bc3] Correlation ID: 54147d0d, Call Stack: null, Custom Event ID: -1, Message: VM block-2 creation was initiated by admin.
>2014-04-24 16:53:41,115 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-32) [4f3c4bc3] BaseAsyncTask::startPollingTask: Starting to poll task 32ecc6cc-cdcd-48c6-8095-38a3a8b8b093.
>2014-04-24 16:53:41,115 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-83) Polling and updating Async Tasks: 7 tasks, 2 tasks to poll now
>2014-04-24 16:53:41,120 INFO  [org.ovirt.engine.core.bll.AddVmToPoolCommand] (org.ovirt.thread.pool-6-thread-32) [21d2f57f] Running command: AddVmToPoolCommand internal: true. Entities affected :  ID: b862e91a-e531-4159-8a1a-9ace8a0d27a8 Type: VmPool
>2014-04-24 16:53:41,133 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-83) SPMAsyncTask::PollTask: Polling task 32ecc6cc-cdcd-48c6-8095-38a3a8b8b093 (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status running.
>2014-04-24 16:53:41,134 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-83) SPMAsyncTask::PollTask: Polling task 6b730eb0-724c-4990-9936-3d3d43d2642b (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status running.
>2014-04-24 16:53:41,134 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-83) Finished polling Tasks, will poll again in 10 seconds.
>2014-04-24 16:53:41,198 INFO  [org.ovirt.engine.core.bll.AddVmAndAttachToPoolCommand] (org.ovirt.thread.pool-6-thread-32) [133098ab] Running command: AddVmAndAttachToPoolCommand internal: true. Entities affected :  ID: 7e9fae25-662e-48a3-9530-ffdbacb1179c Type: VdsGroups,  ID: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 Type: VmTemplate,  ID: 0ee18e0e-b9c5-493a-a835-32017c6cafc3 Type: Storage,  ID: 7e9fae25-662e-48a3-9530-ffdbacb1179c Type: VdsGroups
>2014-04-24 16:53:41,203 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-32) [e796c52] Lock Acquired to object EngineLock [exclusiveLocks= key: block-3 value: VM_NAME
>, sharedLocks= key: 7065f804-3926-47af-88a2-433afc492592 value: DISK
>key: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 value: TEMPLATE
>]
>2014-04-24 16:53:41,214 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-32) [e796c52] Running command: AddVmCommand internal: true. Entities affected :  ID: 7e9fae25-662e-48a3-9530-ffdbacb1179c Type: VdsGroups,  ID: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 Type: VmTemplate,  ID: 0ee18e0e-b9c5-493a-a835-32017c6cafc3 Type: Storage,  ID: 7e9fae25-662e-48a3-9530-ffdbacb1179c Type: VdsGroups
>2014-04-24 16:53:41,231 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-32) [e796c52] START, SetVmStatusVDSCommand( vmId = ee70f071-b4e8-4d28-a81e-d33391fe5abf, status = ImageLocked, exit status = Normal), log id: 5e328472
>2014-04-24 16:53:41,256 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-32) [e796c52] FINISH, SetVmStatusVDSCommand, log id: 5e328472
>2014-04-24 16:53:41,264 INFO  [org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand] (org.ovirt.thread.pool-6-thread-32) [53b8324] Running command: CreateSnapshotFromTemplateCommand internal: true. Entities affected :  ID: 0ee18e0e-b9c5-493a-a835-32017c6cafc3 Type: Storage
>2014-04-24 16:53:41,266 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-32) [53b8324] START, CreateSnapshotVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, storageDomainId = 0ee18e0e-b9c5-493a-a835-32017c6cafc3, imageGroupId = fa5b8f07-9356-4588-9d55-8c0802693e22, imageSizeInBytes = 2147483648, volumeFormat = COW, newImageId = 1e38b27f-c091-4aa4-a918-d8c1706620ab, newImageDescription = , imageId = ef8bd5d2-6bcd-48e3-aad0-d6a1abcd2a44, sourceImageGroupId = 7065f804-3926-47af-88a2-433afc492592), log id: 44e70a2c
>2014-04-24 16:53:41,267 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-32) [53b8324] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
>2014-04-24 16:53:41,698 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-32) [53b8324] FINISH, CreateSnapshotVDSCommand, return: 1e38b27f-c091-4aa4-a918-d8c1706620ab, log id: 44e70a2c
>2014-04-24 16:53:41,725 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-32) [53b8324] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command b9994ad8-b8c8-4f42-b501-3cf893dae55a
>2014-04-24 16:53:41,725 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-32) [53b8324] CommandMultiAsyncTasks::AttachTask: Attaching task 3a1957f1-4baf-4e3d-810e-05a36a6d45bf to command b9994ad8-b8c8-4f42-b501-3cf893dae55a.
>2014-04-24 16:53:41,740 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (org.ovirt.thread.pool-6-thread-32) [53b8324] Adding task 3a1957f1-4baf-4e3d-810e-05a36a6d45bf (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-04-24 16:53:41,815 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-32) [53b8324] Correlation ID: e796c52, Call Stack: null, Custom Event ID: -1, Message: VM block-3 creation was initiated by admin.
>2014-04-24 16:53:41,815 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-32) [53b8324] BaseAsyncTask::startPollingTask: Starting to poll task 3a1957f1-4baf-4e3d-810e-05a36a6d45bf.
>2014-04-24 16:53:41,820 INFO  [org.ovirt.engine.core.bll.AddVmToPoolCommand] (org.ovirt.thread.pool-6-thread-32) [8a136b3] Running command: AddVmToPoolCommand internal: true. Entities affected :  ID: b862e91a-e531-4159-8a1a-9ace8a0d27a8 Type: VmPool
>2014-04-24 16:53:41,890 INFO  [org.ovirt.engine.core.bll.AddVmAndAttachToPoolCommand] (org.ovirt.thread.pool-6-thread-32) [197a966b] Running command: AddVmAndAttachToPoolCommand internal: true. Entities affected :  ID: 7e9fae25-662e-48a3-9530-ffdbacb1179c Type: VdsGroups,  ID: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 Type: VmTemplate,  ID: 0ee18e0e-b9c5-493a-a835-32017c6cafc3 Type: Storage,  ID: 7e9fae25-662e-48a3-9530-ffdbacb1179c Type: VdsGroups
>2014-04-24 16:53:41,894 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-32) [889e12c] Lock Acquired to object EngineLock [exclusiveLocks= key: block-4 value: VM_NAME
>, sharedLocks= key: 7065f804-3926-47af-88a2-433afc492592 value: DISK
>key: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 value: TEMPLATE
>]
>2014-04-24 16:53:41,906 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-32) [889e12c] Running command: AddVmCommand internal: true. Entities affected :  ID: 7e9fae25-662e-48a3-9530-ffdbacb1179c Type: VdsGroups,  ID: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 Type: VmTemplate,  ID: 0ee18e0e-b9c5-493a-a835-32017c6cafc3 Type: Storage,  ID: 7e9fae25-662e-48a3-9530-ffdbacb1179c Type: VdsGroups
>2014-04-24 16:53:41,923 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-32) [889e12c] START, SetVmStatusVDSCommand( vmId = 121498e8-1c68-4814-bded-957de5be700f, status = ImageLocked, exit status = Normal), log id: 361dca7a
>2014-04-24 16:53:41,940 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-32) [889e12c] FINISH, SetVmStatusVDSCommand, log id: 361dca7a
>2014-04-24 16:53:41,948 INFO  [org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand] (org.ovirt.thread.pool-6-thread-32) [6fd153e1] Running command: CreateSnapshotFromTemplateCommand internal: true. Entities affected :  ID: 0ee18e0e-b9c5-493a-a835-32017c6cafc3 Type: Storage
>2014-04-24 16:53:41,950 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-32) [6fd153e1] START, CreateSnapshotVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, storageDomainId = 0ee18e0e-b9c5-493a-a835-32017c6cafc3, imageGroupId = e71dc725-52d4-4873-9eb3-eae59665c97c, imageSizeInBytes = 2147483648, volumeFormat = COW, newImageId = 3ce9ed7b-ee18-4975-ae04-03c2e9f99b36, newImageDescription = , imageId = ef8bd5d2-6bcd-48e3-aad0-d6a1abcd2a44, sourceImageGroupId = 7065f804-3926-47af-88a2-433afc492592), log id: 22eda29e
>2014-04-24 16:53:41,952 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-32) [6fd153e1] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
>2014-04-24 16:53:42,357 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-32) [6fd153e1] FINISH, CreateSnapshotVDSCommand, return: 3ce9ed7b-ee18-4975-ae04-03c2e9f99b36, log id: 22eda29e
>2014-04-24 16:53:42,374 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-32) [6fd153e1] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 7b3407b8-6f0b-404d-9066-def1e2c64786
>2014-04-24 16:53:42,374 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-32) [6fd153e1] CommandMultiAsyncTasks::AttachTask: Attaching task aed67a63-d70b-4d52-aa8b-9c7db5380822 to command 7b3407b8-6f0b-404d-9066-def1e2c64786.
>2014-04-24 16:53:42,390 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (org.ovirt.thread.pool-6-thread-32) [6fd153e1] Adding task aed67a63-d70b-4d52-aa8b-9c7db5380822 (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-04-24 16:53:42,448 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-32) [6fd153e1] Correlation ID: 889e12c, Call Stack: null, Custom Event ID: -1, Message: VM block-4 creation was initiated by admin.
>2014-04-24 16:53:42,449 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-32) [6fd153e1] BaseAsyncTask::startPollingTask: Starting to poll task aed67a63-d70b-4d52-aa8b-9c7db5380822.
>2014-04-24 16:53:42,453 INFO  [org.ovirt.engine.core.bll.AddVmToPoolCommand] (org.ovirt.thread.pool-6-thread-32) [2042f04a] Running command: AddVmToPoolCommand internal: true. Entities affected :  ID: b862e91a-e531-4159-8a1a-9ace8a0d27a8 Type: VmPool
>2014-04-24 16:53:42,507 INFO  [org.ovirt.engine.core.bll.AddVmAndAttachToPoolCommand] (org.ovirt.thread.pool-6-thread-32) [1ee04cf3] Running command: AddVmAndAttachToPoolCommand internal: true. Entities affected :  ID: 7e9fae25-662e-48a3-9530-ffdbacb1179c Type: VdsGroups,  ID: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 Type: VmTemplate,  ID: 0ee18e0e-b9c5-493a-a835-32017c6cafc3 Type: Storage,  ID: 7e9fae25-662e-48a3-9530-ffdbacb1179c Type: VdsGroups
>2014-04-24 16:53:42,511 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-32) [60fd3133] Lock Acquired to object EngineLock [exclusiveLocks= key: block-5 value: VM_NAME
>, sharedLocks= key: 7065f804-3926-47af-88a2-433afc492592 value: DISK
>key: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 value: TEMPLATE
>]
>2014-04-24 16:53:42,522 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-32) [60fd3133] Running command: AddVmCommand internal: true. Entities affected :  ID: 7e9fae25-662e-48a3-9530-ffdbacb1179c Type: VdsGroups,  ID: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 Type: VmTemplate,  ID: 0ee18e0e-b9c5-493a-a835-32017c6cafc3 Type: Storage,  ID: 7e9fae25-662e-48a3-9530-ffdbacb1179c Type: VdsGroups
>2014-04-24 16:53:42,532 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-32) [60fd3133] START, SetVmStatusVDSCommand( vmId = 869511e0-1169-4b29-b8b4-d9b76c46d917, status = ImageLocked, exit status = Normal), log id: 64847735
>2014-04-24 16:53:42,548 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-32) [60fd3133] FINISH, SetVmStatusVDSCommand, log id: 64847735
>2014-04-24 16:53:42,557 INFO  [org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand] (org.ovirt.thread.pool-6-thread-32) [5c39f12d] Running command: CreateSnapshotFromTemplateCommand internal: true. Entities affected :  ID: 0ee18e0e-b9c5-493a-a835-32017c6cafc3 Type: Storage
>2014-04-24 16:53:42,558 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-32) [5c39f12d] START, CreateSnapshotVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, storageDomainId = 0ee18e0e-b9c5-493a-a835-32017c6cafc3, imageGroupId = a24362b9-604f-4181-832f-90c507b702af, imageSizeInBytes = 2147483648, volumeFormat = COW, newImageId = 9864f2cb-756c-4f2b-aeb4-dbf4d3b394ae, newImageDescription = , imageId = ef8bd5d2-6bcd-48e3-aad0-d6a1abcd2a44, sourceImageGroupId = 7065f804-3926-47af-88a2-433afc492592), log id: 23d660f3
>2014-04-24 16:53:42,559 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-32) [5c39f12d] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
>2014-04-24 16:53:42,959 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-32) [5c39f12d] FINISH, CreateSnapshotVDSCommand, return: 9864f2cb-756c-4f2b-aeb4-dbf4d3b394ae, log id: 23d660f3
>2014-04-24 16:53:42,975 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-32) [5c39f12d] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 69c41add-e640-434f-8f39-a5e9c417268b
>2014-04-24 16:53:42,976 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-32) [5c39f12d] CommandMultiAsyncTasks::AttachTask: Attaching task d2692815-a6e2-445d-a00f-25836c054af3 to command 69c41add-e640-434f-8f39-a5e9c417268b.
>2014-04-24 16:53:42,982 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (org.ovirt.thread.pool-6-thread-32) [5c39f12d] Adding task d2692815-a6e2-445d-a00f-25836c054af3 (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-04-24 16:53:43,032 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-32) [5c39f12d] Correlation ID: 60fd3133, Call Stack: null, Custom Event ID: -1, Message: VM block-5 creation was initiated by admin.
>2014-04-24 16:53:43,033 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-32) [5c39f12d] BaseAsyncTask::startPollingTask: Starting to poll task d2692815-a6e2-445d-a00f-25836c054af3.
>2014-04-24 16:53:43,036 INFO  [org.ovirt.engine.core.bll.AddVmToPoolCommand] (org.ovirt.thread.pool-6-thread-32) [7ad08794] Running command: AddVmToPoolCommand internal: true. Entities affected :  ID: b862e91a-e531-4159-8a1a-9ace8a0d27a8 Type: VmPool
>2014-04-24 16:53:43,066 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-32) [7ad08794] Correlation ID: 2c158985, Job ID: 61a86bc7-58f9-4a6e-89d6-cd17b1c8ebb1, Call Stack: null, Custom Event ID: -1, Message: VM Pool block was updated by admin, 5 VMs were added.
>2014-04-24 16:53:51,134 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-20) Polling and updating Async Tasks: 10 tasks, 5 tasks to poll now
>2014-04-24 16:53:51,151 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-20) SPMAsyncTask::PollTask: Polling task d2692815-a6e2-445d-a00f-25836c054af3 (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-04-24 16:53:51,175 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-20) BaseAsyncTask::OnTaskEndSuccess: Task d2692815-a6e2-445d-a00f-25836c054af3 (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-04-24 16:53:51,175 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-20) CommandAsyncTask::EndActionIfNecessary: All tasks of command 69c41add-e640-434f-8f39-a5e9c417268b has ended -> executing endAction
>2014-04-24 16:53:51,176 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-20) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: 69c41add-e640-434f-8f39-a5e9c417268b): calling endAction .
>2014-04-24 16:53:51,176 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-20) SPMAsyncTask::PollTask: Polling task aed67a63-d70b-4d52-aa8b-9c7db5380822 (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-04-24 16:53:51,176 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-18) CommandAsyncTask::EndCommandAction [within thread] context: Attempting to endAction AddVm, executionIndex: 0
>2014-04-24 16:53:51,183 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-20) BaseAsyncTask::OnTaskEndSuccess: Task aed67a63-d70b-4d52-aa8b-9c7db5380822 (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-04-24 16:53:51,184 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-20) CommandAsyncTask::EndActionIfNecessary: All tasks of command 7b3407b8-6f0b-404d-9066-def1e2c64786 has ended -> executing endAction
>2014-04-24 16:53:51,184 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-20) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: 7b3407b8-6f0b-404d-9066-def1e2c64786): calling endAction .
>2014-04-24 16:53:51,185 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-20) SPMAsyncTask::PollTask: Polling task 32ecc6cc-cdcd-48c6-8095-38a3a8b8b093 (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-04-24 16:53:51,185 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-7) CommandAsyncTask::EndCommandAction [within thread] context: Attempting to endAction AddVm, executionIndex: 0
>2014-04-24 16:53:51,191 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-18) [60fd3133] Ending command successfully: org.ovirt.engine.core.bll.AddVmCommand
>2014-04-24 16:53:51,200 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-20) BaseAsyncTask::OnTaskEndSuccess: Task 32ecc6cc-cdcd-48c6-8095-38a3a8b8b093 (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-04-24 16:53:51,201 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-20) CommandAsyncTask::EndActionIfNecessary: All tasks of command 46a22858-4c0f-4e3a-89b3-5ba5c46b06e3 has ended -> executing endAction
>2014-04-24 16:53:51,201 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-20) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: 46a22858-4c0f-4e3a-89b3-5ba5c46b06e3): calling endAction .
>2014-04-24 16:53:51,201 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-20) SPMAsyncTask::PollTask: Polling task 6b730eb0-724c-4990-9936-3d3d43d2642b (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-04-24 16:53:51,201 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-21) CommandAsyncTask::EndCommandAction [within thread] context: Attempting to endAction AddVm, executionIndex: 0
>2014-04-24 16:53:51,208 INFO  [org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand] (org.ovirt.thread.pool-6-thread-18) [5c39f12d] Ending command successfully: org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand
>2014-04-24 16:53:51,209 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-18) [5c39f12d] START, GetImageInfoVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, storageDomainId = 0ee18e0e-b9c5-493a-a835-32017c6cafc3, imageGroupId = a24362b9-604f-4181-832f-90c507b702af, imageId = 9864f2cb-756c-4f2b-aeb4-dbf4d3b394ae), log id: 11defc14
>2014-04-24 16:53:51,217 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-7) [889e12c] Ending command successfully: org.ovirt.engine.core.bll.AddVmCommand
>2014-04-24 16:53:51,225 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-20) BaseAsyncTask::OnTaskEndSuccess: Task 6b730eb0-724c-4990-9936-3d3d43d2642b (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-04-24 16:53:51,225 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-20) CommandAsyncTask::EndActionIfNecessary: All tasks of command 52f62422-49ee-4f1d-9214-d5ed9f5f3722 has ended -> executing endAction
>2014-04-24 16:53:51,226 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-20) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: 52f62422-49ee-4f1d-9214-d5ed9f5f3722): calling endAction .
>2014-04-24 16:53:51,226 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-20) SPMAsyncTask::PollTask: Polling task 3a1957f1-4baf-4e3d-810e-05a36a6d45bf (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-04-24 16:53:51,226 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-15) CommandAsyncTask::EndCommandAction [within thread] context: Attempting to endAction AddVm, executionIndex: 0
>2014-04-24 16:53:51,234 INFO  [org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand] (org.ovirt.thread.pool-6-thread-7) [6fd153e1] Ending command successfully: org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand
>2014-04-24 16:53:51,237 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-7) [6fd153e1] START, GetImageInfoVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, storageDomainId = 0ee18e0e-b9c5-493a-a835-32017c6cafc3, imageGroupId = e71dc725-52d4-4873-9eb3-eae59665c97c, imageId = 3ce9ed7b-ee18-4975-ae04-03c2e9f99b36), log id: 67a4e3a5
>2014-04-24 16:53:51,241 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-21) [54147d0d] Ending command successfully: org.ovirt.engine.core.bll.AddVmCommand
>2014-04-24 16:53:51,249 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-18) [5c39f12d] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@1b2db91a, log id: 11defc14
>2014-04-24 16:53:51,250 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-20) BaseAsyncTask::OnTaskEndSuccess: Task 3a1957f1-4baf-4e3d-810e-05a36a6d45bf (Parent Command AddVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-04-24 16:53:51,250 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-20) CommandAsyncTask::EndActionIfNecessary: All tasks of command b9994ad8-b8c8-4f42-b501-3cf893dae55a has ended -> executing endAction
>2014-04-24 16:53:51,251 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-20) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: b9994ad8-b8c8-4f42-b501-3cf893dae55a): calling endAction .
>2014-04-24 16:53:51,251 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-48) CommandAsyncTask::EndCommandAction [within thread] context: Attempting to endAction AddVm, executionIndex: 0
>2014-04-24 16:53:51,258 INFO  [org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand] (org.ovirt.thread.pool-6-thread-21) [4f3c4bc3] Ending command successfully: org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand
>2014-04-24 16:53:51,260 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-21) [4f3c4bc3] START, GetImageInfoVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, storageDomainId = 0ee18e0e-b9c5-493a-a835-32017c6cafc3, imageGroupId = 58e5b479-4155-4973-934c-fe9f41ae70f9, imageId = 1063aa35-b3d8-4ca2-a165-4355f3afc970), log id: 41cb1957
>2014-04-24 16:53:51,266 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-7) [6fd153e1] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@35d087d, log id: 67a4e3a5
>2014-04-24 16:53:51,267 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-15) [54191756] Ending command successfully: org.ovirt.engine.core.bll.AddVmCommand
>2014-04-24 16:53:51,267 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-18) START, SetVmStatusVDSCommand( vmId = 869511e0-1169-4b29-b8b4-d9b76c46d917, status = Down, exit status = Normal), log id: 4b1d57d
>2014-04-24 16:53:51,270 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-18) FINISH, SetVmStatusVDSCommand, log id: 4b1d57d
>2014-04-24 16:53:51,275 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-48) [e796c52] Ending command successfully: org.ovirt.engine.core.bll.AddVmCommand
>2014-04-24 16:53:51,284 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-21) [4f3c4bc3] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@33299648, log id: 41cb1957
>2014-04-24 16:53:51,335 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-18) Lock freed to object EngineLock [exclusiveLocks= key: block-5 value: VM_NAME
>, sharedLocks= key: 7065f804-3926-47af-88a2-433afc492592 value: DISK
>key: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 value: TEMPLATE
>]
>2014-04-24 16:53:51,336 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-7) START, SetVmStatusVDSCommand( vmId = 121498e8-1c68-4814-bded-957de5be700f, status = Down, exit status = Normal), log id: 25232ef
>2014-04-24 16:53:51,336 INFO  [org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand] (org.ovirt.thread.pool-6-thread-15) [57474f6f] Ending command successfully: org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand
>2014-04-24 16:53:51,338 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-15) [57474f6f] START, GetImageInfoVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, storageDomainId = 0ee18e0e-b9c5-493a-a835-32017c6cafc3, imageGroupId = d54e52f2-9ea4-4df1-9f28-fa2cb3c1aec3, imageId = 0e67176b-827d-4ce2-a5cc-f49240c7474a), log id: 6c38951f
>2014-04-24 16:53:51,339 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-7) FINISH, SetVmStatusVDSCommand, log id: 25232ef
>2014-04-24 16:53:51,345 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-21) START, SetVmStatusVDSCommand( vmId = 1248f347-cd1c-4719-baae-e4af3eea7a8a, status = Down, exit status = Normal), log id: 5a56f8ac
>2014-04-24 16:53:51,345 INFO  [org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand] (org.ovirt.thread.pool-6-thread-48) [53b8324] Ending command successfully: org.ovirt.engine.core.bll.CreateSnapshotFromTemplateCommand
>2014-04-24 16:53:51,347 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-48) [53b8324] START, GetImageInfoVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, storageDomainId = 0ee18e0e-b9c5-493a-a835-32017c6cafc3, imageGroupId = fa5b8f07-9356-4588-9d55-8c0802693e22, imageId = 1e38b27f-c091-4aa4-a918-d8c1706620ab), log id: 439dbf3d
>2014-04-24 16:53:51,347 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-21) FINISH, SetVmStatusVDSCommand, log id: 5a56f8ac
>2014-04-24 16:53:51,353 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-18) Correlation ID: 60fd3133, Job ID: 61a86bc7-58f9-4a6e-89d6-cd17b1c8ebb1, Call Stack: null, Custom Event ID: -1, Message: VM block-5 creation has been completed.
>2014-04-24 16:53:51,353 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-7) Lock freed to object EngineLock [exclusiveLocks= key: block-4 value: VM_NAME
>, sharedLocks= key: 7065f804-3926-47af-88a2-433afc492592 value: DISK
>key: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 value: TEMPLATE
>]
>2014-04-24 16:53:51,353 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-18) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type AddVm completed, handling the result.
>2014-04-24 16:53:51,354 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-18) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type AddVm succeeded, clearing tasks.
>2014-04-24 16:53:51,354 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-15) [57474f6f] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@d6b6db89, log id: 6c38951f
>2014-04-24 16:53:51,361 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-21) Lock freed to object EngineLock [exclusiveLocks= key: block-2 value: VM_NAME
>, sharedLocks= key: 7065f804-3926-47af-88a2-433afc492592 value: DISK
>key: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 value: TEMPLATE
>]
>2014-04-24 16:53:51,370 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-7) Correlation ID: 889e12c, Job ID: 61a86bc7-58f9-4a6e-89d6-cd17b1c8ebb1, Call Stack: null, Custom Event ID: -1, Message: VM block-4 creation has been completed.
>2014-04-24 16:53:51,370 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-15) START, SetVmStatusVDSCommand( vmId = bc41fa36-53a1-4c8b-a6a6-97442e643a32, status = Down, exit status = Normal), log id: 5356c769
>2014-04-24 16:53:51,371 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-48) [53b8324] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@62901910, log id: 439dbf3d
>2014-04-24 16:53:51,370 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-7) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type AddVm completed, handling the result.
>2014-04-24 16:53:51,371 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-7) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type AddVm succeeded, clearing tasks.
>2014-04-24 16:53:51,372 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-15) FINISH, SetVmStatusVDSCommand, log id: 5356c769
>2014-04-24 16:53:51,378 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-21) Correlation ID: 54147d0d, Job ID: 61a86bc7-58f9-4a6e-89d6-cd17b1c8ebb1, Call Stack: null, Custom Event ID: -1, Message: VM block-2 creation has been completed.
>2014-04-24 16:53:51,378 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-21) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type AddVm completed, handling the result.
>2014-04-24 16:53:51,379 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-21) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type AddVm succeeded, clearing tasks.
>2014-04-24 16:53:51,386 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-15) Lock freed to object EngineLock [exclusiveLocks= key: block-1 value: VM_NAME
>, sharedLocks= key: 7065f804-3926-47af-88a2-433afc492592 value: DISK
>key: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 value: TEMPLATE
>]
>2014-04-24 16:53:51,386 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-48) START, SetVmStatusVDSCommand( vmId = ee70f071-b4e8-4d28-a81e-d33391fe5abf, status = Down, exit status = Normal), log id: 4432110
>2014-04-24 16:53:51,387 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-18) SPMAsyncTask::ClearAsyncTask: Attempting to clear task d2692815-a6e2-445d-a00f-25836c054af3
>2014-04-24 16:53:51,388 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-18) START, SPMClearTaskVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, taskId = d2692815-a6e2-445d-a00f-25836c054af3), log id: 4c007a66
>2014-04-24 16:53:51,389 INFO  [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-48) FINISH, SetVmStatusVDSCommand, log id: 4432110
>2014-04-24 16:53:51,389 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-18) START, HSMClearTaskVDSCommand(HostName = ale, HostId = 6a67c07a-db78-4af7-8a96-5e4be1c54483, taskId=d2692815-a6e2-445d-a00f-25836c054af3), log id: 10ded61b
>2014-04-24 16:53:51,394 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-18) FINISH, HSMClearTaskVDSCommand, log id: 10ded61b
>2014-04-24 16:53:51,394 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-18) FINISH, SPMClearTaskVDSCommand, log id: 4c007a66
>2014-04-24 16:53:51,403 INFO  [org.ovirt.engine.core.bll.AddVmCommand] (org.ovirt.thread.pool-6-thread-48) Lock freed to object EngineLock [exclusiveLocks= key: block-3 value: VM_NAME
>, sharedLocks= key: 7065f804-3926-47af-88a2-433afc492592 value: DISK
>key: b9fdb798-6fe2-4112-9709-4ec372ce1ec3 value: TEMPLATE
>]
>2014-04-24 16:53:51,404 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-15) Correlation ID: 54191756, Job ID: 61a86bc7-58f9-4a6e-89d6-cd17b1c8ebb1, Call Stack: null, Custom Event ID: -1, Message: VM block-1 creation has been completed.
>2014-04-24 16:53:51,404 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-15) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type AddVm completed, handling the result.
>2014-04-24 16:53:51,405 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-15) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type AddVm succeeded, clearing tasks.
>2014-04-24 16:53:51,411 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-18) BaseAsyncTask::RemoveTaskFromDB: Removed task d2692815-a6e2-445d-a00f-25836c054af3 from DataBase
>2014-04-24 16:53:51,412 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-18) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 69c41add-e640-434f-8f39-a5e9c417268b
>2014-04-24 16:53:51,420 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-48) Correlation ID: e796c52, Job ID: 61a86bc7-58f9-4a6e-89d6-cd17b1c8ebb1, Call Stack: null, Custom Event ID: -1, Message: VM block-3 creation has been completed.
>2014-04-24 16:53:51,420 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-48) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type AddVm completed, handling the result.
>2014-04-24 16:53:51,420 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-48) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type AddVm succeeded, clearing tasks.
>2014-04-24 16:53:51,429 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-7) SPMAsyncTask::ClearAsyncTask: Attempting to clear task aed67a63-d70b-4d52-aa8b-9c7db5380822
>2014-04-24 16:53:51,429 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-7) START, SPMClearTaskVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, taskId = aed67a63-d70b-4d52-aa8b-9c7db5380822), log id: 769edd33
>2014-04-24 16:53:51,430 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-7) START, HSMClearTaskVDSCommand(HostName = ale, HostId = 6a67c07a-db78-4af7-8a96-5e4be1c54483, taskId=aed67a63-d70b-4d52-aa8b-9c7db5380822), log id: 37cc7c1c
>2014-04-24 16:53:51,435 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-7) FINISH, HSMClearTaskVDSCommand, log id: 37cc7c1c
>2014-04-24 16:53:51,435 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-7) FINISH, SPMClearTaskVDSCommand, log id: 769edd33
>2014-04-24 16:53:51,445 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-7) BaseAsyncTask::RemoveTaskFromDB: Removed task aed67a63-d70b-4d52-aa8b-9c7db5380822 from DataBase
>2014-04-24 16:53:51,445 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-7) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 7b3407b8-6f0b-404d-9066-def1e2c64786
>2014-04-24 16:53:51,462 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-21) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 32ecc6cc-cdcd-48c6-8095-38a3a8b8b093
>2014-04-24 16:53:51,463 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-21) START, SPMClearTaskVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, taskId = 32ecc6cc-cdcd-48c6-8095-38a3a8b8b093), log id: 1604d6c3
>2014-04-24 16:53:51,464 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-21) START, HSMClearTaskVDSCommand(HostName = ale, HostId = 6a67c07a-db78-4af7-8a96-5e4be1c54483, taskId=32ecc6cc-cdcd-48c6-8095-38a3a8b8b093), log id: 17afa780
>2014-04-24 16:53:51,469 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-21) FINISH, HSMClearTaskVDSCommand, log id: 17afa780
>2014-04-24 16:53:51,469 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-21) FINISH, SPMClearTaskVDSCommand, log id: 1604d6c3
>2014-04-24 16:53:51,471 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-15) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 6b730eb0-724c-4990-9936-3d3d43d2642b
>2014-04-24 16:53:51,471 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-15) START, SPMClearTaskVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, taskId = 6b730eb0-724c-4990-9936-3d3d43d2642b), log id: 3b0549c4
>2014-04-24 16:53:51,472 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-15) START, HSMClearTaskVDSCommand(HostName = ale, HostId = 6a67c07a-db78-4af7-8a96-5e4be1c54483, taskId=6b730eb0-724c-4990-9936-3d3d43d2642b), log id: 582e0121
>2014-04-24 16:53:51,477 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-15) FINISH, HSMClearTaskVDSCommand, log id: 582e0121
>2014-04-24 16:53:51,478 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-15) FINISH, SPMClearTaskVDSCommand, log id: 3b0549c4
>2014-04-24 16:53:51,478 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-21) BaseAsyncTask::RemoveTaskFromDB: Removed task 32ecc6cc-cdcd-48c6-8095-38a3a8b8b093 from DataBase
>2014-04-24 16:53:51,478 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-21) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 46a22858-4c0f-4e3a-89b3-5ba5c46b06e3
>2014-04-24 16:53:51,495 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-15) BaseAsyncTask::RemoveTaskFromDB: Removed task 6b730eb0-724c-4990-9936-3d3d43d2642b from DataBase
>2014-04-24 16:53:51,495 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-15) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 52f62422-49ee-4f1d-9214-d5ed9f5f3722
>2014-04-24 16:53:51,503 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-48) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 3a1957f1-4baf-4e3d-810e-05a36a6d45bf
>2014-04-24 16:53:51,503 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-48) START, SPMClearTaskVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, taskId = 3a1957f1-4baf-4e3d-810e-05a36a6d45bf), log id: aa31f13
>2014-04-24 16:53:51,505 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-48) START, HSMClearTaskVDSCommand(HostName = ale, HostId = 6a67c07a-db78-4af7-8a96-5e4be1c54483, taskId=3a1957f1-4baf-4e3d-810e-05a36a6d45bf), log id: 5b4d1dd9
>2014-04-24 16:53:51,509 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-48) FINISH, HSMClearTaskVDSCommand, log id: 5b4d1dd9
>2014-04-24 16:53:51,510 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-48) FINISH, SPMClearTaskVDSCommand, log id: aa31f13
>2014-04-24 16:53:51,520 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-48) BaseAsyncTask::RemoveTaskFromDB: Removed task 3a1957f1-4baf-4e3d-810e-05a36a6d45bf from DataBase
>2014-04-24 16:53:51,520 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-48) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity b9994ad8-b8c8-4f42-b501-3cf893dae55a
>2014-04-24 16:53:56,996 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (http--0.0.0.0-8080-1) [190b6e9b] Lock Acquired to object EngineLock [exclusiveLocks= key: bc41fa36-53a1-4c8b-a6a6-97442e643a32 value: VM
>, sharedLocks= ]
>2014-04-24 16:53:57,045 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (http--0.0.0.0-8080-1) [190b6e9b] START, IsVmDuringInitiatingVDSCommand( vmId = bc41fa36-53a1-4c8b-a6a6-97442e643a32), log id: 39e224ec
>2014-04-24 16:53:57,046 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (http--0.0.0.0-8080-1) [190b6e9b] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 39e224ec
>2014-04-24 16:53:57,113 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-6-thread-8) [190b6e9b] Running command: RunVmCommand internal: false. Entities affected :  ID: bc41fa36-53a1-4c8b-a6a6-97442e643a32 Type: VM
>2014-04-24 16:53:57,188 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-6-thread-8) [190b6e9b] Running VM with attached cd CorePlus-current.iso
>2014-04-24 16:53:57,191 INFO  [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-6-thread-8) [190b6e9b] START, UpdateVmDynamicDataVDSCommand(HostName = lager, HostId = d91ce44f-dba7-4c9e-9d8d-f21857f15e28, vmDynamic=org.ovirt.engine.core.common.businessentities.VmDynamic@104c9817), log id: 35d2cab0
>2014-04-24 16:53:57,221 INFO  [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-6-thread-8) [190b6e9b] FINISH, UpdateVmDynamicDataVDSCommand, log id: 35d2cab0
>2014-04-24 16:53:57,222 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (org.ovirt.thread.pool-6-thread-8) [190b6e9b] START, IsoPrefixVDSCommand(HostName = lager, HostId = d91ce44f-dba7-4c9e-9d8d-f21857f15e28, storagePoolId=7b90a9ec-ecb3-4105-b817-306ffc0b8245), log id: 350ac2a4
>2014-04-24 16:53:57,223 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (org.ovirt.thread.pool-6-thread-8) [190b6e9b] FINISH, IsoPrefixVDSCommand, return: /rhev/data-center/mnt/192.168.2.1:_home_storage_iso/e453999e-ec9f-420b-941c-a9f9cc4432bb/images/11111111-1111-1111-1111-111111111111, log id: 350ac2a4
>2014-04-24 16:53:57,224 INFO  [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-6-thread-8) [190b6e9b] START, CreateVmVDSCommand(HostName = lager, HostId = d91ce44f-dba7-4c9e-9d8d-f21857f15e28, vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, vm=VM [block-1]), log id: 132b855c
>2014-04-24 16:53:57,227 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-6-thread-8) [190b6e9b] START, CreateVDSCommand(HostName = lager, HostId = d91ce44f-dba7-4c9e-9d8d-f21857f15e28, vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, vm=VM [block-1]), log id: 3707930f
>2014-04-24 16:53:57,236 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-6-thread-8) [190b6e9b] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand spiceSslCipherSuite=DEFAULT,memSize=1024,kvmEnable=true,smp=1,vmType=kvm,emulatedMachine=pc-1.0,keyboardLayout=en-us,memGuaranteedSize=1024,nice=0,display=qxl,smartcardEnable=false,bootMenuEnable=false,smpCoresPerSocket=1,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,maxVCpus=160,displayNetwork=ovirtmgmt,timeOffset=0,transparentHugePages=true,vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32,devices=[{specParams={vram=32768, heads=1}, device=qxl, type=video, deviceId=70044eee-e31f-461d-9ac7-e7e4021ecb4c}, {shared=false, iface=ide, index=2, address={unit=0, bus=1, target=0, controller=0, type=drive}, specParams={path=CorePlus-current.iso}, path=/rhev/data-center/mnt/192.168.2.1:_home_storage_iso/e453999e-ec9f-420b-941c-a9f9cc4432bb/images/11111111-1111-1111-1111-111111111111/CorePlus-current.iso, device=cdrom, type=disk, readonly=true, deviceId=604b0dc9-5c95-4f2b-8b4b-2f26bdd730a4}, {shared=false, index=0, volumeID=0e67176b-827d-4ce2-a5cc-f49240c7474a, propagateErrors=off, format=cow, type=disk, iface=virtio, bootOrder=1, address={bus=0x00, domain=0x0000, slot=0x06, type=pci, function=0x0}, domainID=0ee18e0e-b9c5-493a-a835-32017c6cafc3, imageID=d54e52f2-9ea4-4df1-9f28-fa2cb3c1aec3, specParams={}, optional=false, device=disk, poolID=7b90a9ec-ecb3-4105-b817-306ffc0b8245, readonly=false, deviceId=d54e52f2-9ea4-4df1-9f28-fa2cb3c1aec3}, {nicModel=pv, address={bus=0x00, domain=0x0000, slot=0x03, type=pci, function=0x0}, specParams={}, macAddr=00:1a:4a:3f:44:b2, device=bridge, linkActive=true, type=interface, filter=vdsm-no-mac-spoofing, network=ovirtmgmt, deviceId=8b29be52-8c67-4afa-9b87-6173faeec72f}, {specParams={model=virtio}, device=memballoon, type=balloon, deviceId=f76c0dba-0c69-46a2-a3f4-1e8aaa1c923e}, {index=0, model=virtio-scsi, address={bus=0x00, domain=0x0000, slot=0x04, type=pci, function=0x0}, specParams={}, device=scsi, type=controller, deviceId=8ead67b7-e9e6-49fe-a8d2-fa710d471df9}],acpiEnable=true,vmName=block-1,cpuType=SandyBridge,custom={device_0dd51265-cccf-4059-bb2f-ef1faf1c7ef4device_4b0c1d02-acd2-4a23-94ce-7335d41b995bdevice_515bd1ee-a47d-4719-9f8a-ee6784a512f6device_e784eebc-b041-40bd-a215-7cac5d441548device_ecbec207-58bf-40d7-8997-1e9ed5f8d425=VmDevice {vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, deviceId=ecbec207-58bf-40d7-8997-1e9ed5f8d425, device=virtio-serial, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x05, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=virtio-serial0, customProperties={}, snapshotId=null}, device_0dd51265-cccf-4059-bb2f-ef1faf1c7ef4device_4b0c1d02-acd2-4a23-94ce-7335d41b995bdevice_515bd1ee-a47d-4719-9f8a-ee6784a512f6=VmDevice {vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, deviceId=515bd1ee-a47d-4719-9f8a-ee6784a512f6, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}, device_0dd51265-cccf-4059-bb2f-ef1faf1c7ef4=VmDevice {vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, deviceId=0dd51265-cccf-4059-bb2f-ef1faf1c7ef4, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}, device_0dd51265-cccf-4059-bb2f-ef1faf1c7ef4device_4b0c1d02-acd2-4a23-94ce-7335d41b995bdevice_515bd1ee-a47d-4719-9f8a-ee6784a512f6device_e784eebc-b041-40bd-a215-7cac5d441548=VmDevice {vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, deviceId=e784eebc-b041-40bd-a215-7cac5d441548, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}, device_0dd51265-cccf-4059-bb2f-ef1faf1c7ef4device_4b0c1d02-acd2-4a23-94ce-7335d41b995b=VmDevice {vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, deviceId=4b0c1d02-acd2-4a23-94ce-7335d41b995b, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}}
>2014-04-24 16:53:57,271 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-6-thread-8) [190b6e9b] FINISH, CreateVDSCommand, log id: 3707930f
>2014-04-24 16:53:57,331 INFO  [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-6-thread-8) [190b6e9b] FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 132b855c
>2014-04-24 16:53:57,331 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-6-thread-8) [190b6e9b] Lock freed to object EngineLock [exclusiveLocks= key: bc41fa36-53a1-4c8b-a6a6-97442e643a32 value: VM
>, sharedLocks= ]
>2014-04-24 16:53:57,348 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-8) [190b6e9b] Correlation ID: 190b6e9b, Job ID: e753525d-1003-4bdb-911f-db85ab7170f2, Call Stack: null, Custom Event ID: -1, Message: VM block-1 was started by admin (Host: lager).
>2014-04-24 16:54:00,452 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-33) VM block-1 bc41fa36-53a1-4c8b-a6a6-97442e643a32 moved from WaitForLaunch --> PoweringUp
>2014-04-24 16:54:00,453 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-33) START, FullListVdsCommand(HostName = lager, HostId = d91ce44f-dba7-4c9e-9d8d-f21857f15e28, vds=Host[lager], vmIds=[bc41fa36-53a1-4c8b-a6a6-97442e643a32]), log id: 7b1444d3
>2014-04-24 16:54:00,459 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-33) FINISH, FullListVdsCommand, return: [{displaySecurePort=5900, kvmEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, displayIp=192.168.2.101, pauseCode=NOERR, nice=0, displayNetwork=ovirtmgmt, timeOffset=0, transparentHugePages=true, vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, acpiEnable=true, custom={device_0dd51265-cccf-4059-bb2f-ef1faf1c7ef4device_4b0c1d02-acd2-4a23-94ce-7335d41b995bdevice_515bd1ee-a47d-4719-9f8a-ee6784a512f6device_e784eebc-b041-40bd-a215-7cac5d441548device_ecbec207-58bf-40d7-8997-1e9ed5f8d425=VmDevice {vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, deviceId=ecbec207-58bf-40d7-8997-1e9ed5f8d425, device=virtio-serial, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x05, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=virtio-serial0, customProperties={}, snapshotId=null}, device_0dd51265-cccf-4059-bb2f-ef1faf1c7ef4device_4b0c1d02-acd2-4a23-94ce-7335d41b995bdevice_515bd1ee-a47d-4719-9f8a-ee6784a512f6=VmDevice {vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, deviceId=515bd1ee-a47d-4719-9f8a-ee6784a512f6, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}, device_0dd51265-cccf-4059-bb2f-ef1faf1c7ef4=VmDevice {vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, deviceId=0dd51265-cccf-4059-bb2f-ef1faf1c7ef4, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}, device_0dd51265-cccf-4059-bb2f-ef1faf1c7ef4device_4b0c1d02-acd2-4a23-94ce-7335d41b995bdevice_515bd1ee-a47d-4719-9f8a-ee6784a512f6device_e784eebc-b041-40bd-a215-7cac5d441548=VmDevice {vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, deviceId=e784eebc-b041-40bd-a215-7cac5d441548, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}, device_0dd51265-cccf-4059-bb2f-ef1faf1c7ef4device_4b0c1d02-acd2-4a23-94ce-7335d41b995b=VmDevice {vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, deviceId=4b0c1d02-acd2-4a23-94ce-7335d41b995b, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}}, spiceSslCipherSuite=DEFAULT, memSize=1024, displayPort=-1, smp=1, emulatedMachine=pc-1.0, status=Up, vmType=kvm, memGuaranteedSize=1024, display=qxl, pid=31232, smartcardEnable=false, bootMenuEnable=false, smpCoresPerSocket=1, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, maxVCpus=160, clientIp=, devices=[Ljava.lang.Object;@6fb2b7c5, vmName=block-1, cpuType=SandyBridge}], log id: 7b1444d3
>2014-04-24 16:54:35,930 INFO  [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (http--0.0.0.0-8080-2) [73c87c1c] Lock Acquired to object EngineLock [exclusiveLocks= key: bc41fa36-53a1-4c8b-a6a6-97442e643a32 value: VM
>, sharedLocks= ]
>2014-04-24 16:54:36,035 INFO  [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (org.ovirt.thread.pool-6-thread-47) Running command: CreateAllSnapshotsFromVmCommand internal: false. Entities affected :  ID: bc41fa36-53a1-4c8b-a6a6-97442e643a32 Type: VM
>2014-04-24 16:54:36,041 INFO  [org.ovirt.engine.core.bll.CreateSnapshotCommand] (org.ovirt.thread.pool-6-thread-47) [317857a6] Running command: CreateSnapshotCommand internal: true. Entities affected :  ID: 00000000-0000-0000-0000-000000000000 Type: Storage
>2014-04-24 16:54:36,045 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-47) [317857a6] START, CreateSnapshotVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, storageDomainId = 0ee18e0e-b9c5-493a-a835-32017c6cafc3, imageGroupId = d54e52f2-9ea4-4df1-9f28-fa2cb3c1aec3, imageSizeInBytes = 2147483648, volumeFormat = COW, newImageId = 6e3c42c5-b154-4287-8734-5bde55655e2f, newImageDescription = , imageId = 0e67176b-827d-4ce2-a5cc-f49240c7474a, sourceImageGroupId = d54e52f2-9ea4-4df1-9f28-fa2cb3c1aec3), log id: 1d8f2cc1
>2014-04-24 16:54:36,046 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-47) [317857a6] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
>2014-04-24 16:54:36,278 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-47) [317857a6] FINISH, CreateSnapshotVDSCommand, return: 6e3c42c5-b154-4287-8734-5bde55655e2f, log id: 1d8f2cc1
>2014-04-24 16:54:36,294 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-47) [317857a6] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 076a9987-4a94-4af1-b9ac-e70a1d8bb3d8
>2014-04-24 16:54:36,294 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-47) [317857a6] CommandMultiAsyncTasks::AttachTask: Attaching task a873eef9-7977-4408-bc12-d7d56e977908 to command 076a9987-4a94-4af1-b9ac-e70a1d8bb3d8.
>2014-04-24 16:54:36,302 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (org.ovirt.thread.pool-6-thread-47) [317857a6] Adding task a873eef9-7977-4408-bc12-d7d56e977908 (Parent Command CreateAllSnapshotsFromVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-04-24 16:54:36,335 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-47) Correlation ID: 73c87c1c, Job ID: 17106fd1-38a7-485b-b6fb-431f55b74946, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'test' creation for VM 'block-1' was initiated by admin.
>2014-04-24 16:54:36,336 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-47) BaseAsyncTask::startPollingTask: Starting to poll task a873eef9-7977-4408-bc12-d7d56e977908.
>2014-04-24 16:54:38,897 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-22) [6221de17] Setting new tasks map. The map contains now 6 tasks
>2014-04-24 16:54:41,253 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-27) Polling and updating Async Tasks: 6 tasks, 1 tasks to poll now
>2014-04-24 16:54:41,258 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-27) SPMAsyncTask::PollTask: Polling task a873eef9-7977-4408-bc12-d7d56e977908 (Parent Command CreateAllSnapshotsFromVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-04-24 16:54:41,294 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-27) BaseAsyncTask::OnTaskEndSuccess: Task a873eef9-7977-4408-bc12-d7d56e977908 (Parent Command CreateAllSnapshotsFromVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-04-24 16:54:41,295 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-27) CommandAsyncTask::EndActionIfNecessary: All tasks of command 076a9987-4a94-4af1-b9ac-e70a1d8bb3d8 has ended -> executing endAction
>2014-04-24 16:54:41,295 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-27) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: 076a9987-4a94-4af1-b9ac-e70a1d8bb3d8): calling endAction .
>2014-04-24 16:54:41,295 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-50) CommandAsyncTask::EndCommandAction [within thread] context: Attempting to endAction CreateAllSnapshotsFromVm, executionIndex: 0
>2014-04-24 16:54:41,311 INFO  [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (org.ovirt.thread.pool-6-thread-50) Ending command successfully: org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand
>2014-04-24 16:54:41,317 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-50) START, SnapshotVDSCommand(HostName = lager, HostId = d91ce44f-dba7-4c9e-9d8d-f21857f15e28, vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32), log id: f6c36ec
>2014-04-24 16:54:51,046 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-50) FINISH, SnapshotVDSCommand, log id: f6c36ec
>2014-04-24 16:54:51,048 INFO  [org.ovirt.engine.core.bll.CreateSnapshotCommand] (org.ovirt.thread.pool-6-thread-50) [317857a6] Ending command successfully: org.ovirt.engine.core.bll.CreateSnapshotCommand
>2014-04-24 16:54:51,051 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-50) [317857a6] START, GetImageInfoVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, storageDomainId = 0ee18e0e-b9c5-493a-a835-32017c6cafc3, imageGroupId = d54e52f2-9ea4-4df1-9f28-fa2cb3c1aec3, imageId = 6e3c42c5-b154-4287-8734-5bde55655e2f), log id: 46791069
>2014-04-24 16:54:51,096 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-50) [317857a6] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@3d810a4, log id: 46791069
>2014-04-24 16:54:51,131 INFO  [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (org.ovirt.thread.pool-6-thread-50) Lock freed to object EngineLock [exclusiveLocks= key: bc41fa36-53a1-4c8b-a6a6-97442e643a32 value: VM
>, sharedLocks= ]
>2014-04-24 16:54:51,145 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-50) Correlation ID: 73c87c1c, Job ID: 17106fd1-38a7-485b-b6fb-431f55b74946, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'test' creation for VM 'block-1' has been completed.
>2014-04-24 16:54:51,145 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-50) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type CreateAllSnapshotsFromVm completed, handling the result.
>2014-04-24 16:54:51,145 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-50) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type CreateAllSnapshotsFromVm succeeded, clearing tasks.
>2014-04-24 16:54:51,153 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-50) SPMAsyncTask::ClearAsyncTask: Attempting to clear task a873eef9-7977-4408-bc12-d7d56e977908
>2014-04-24 16:54:51,153 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-50) START, SPMClearTaskVDSCommand( storagePoolId = 7b90a9ec-ecb3-4105-b817-306ffc0b8245, ignoreFailoverLimit = false, taskId = a873eef9-7977-4408-bc12-d7d56e977908), log id: 3cb6c4d4
>2014-04-24 16:54:51,154 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-50) START, HSMClearTaskVDSCommand(HostName = ale, HostId = 6a67c07a-db78-4af7-8a96-5e4be1c54483, taskId=a873eef9-7977-4408-bc12-d7d56e977908), log id: 3345970
>2014-04-24 16:54:51,160 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-50) FINISH, HSMClearTaskVDSCommand, log id: 3345970
>2014-04-24 16:54:51,160 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-50) FINISH, SPMClearTaskVDSCommand, log id: 3cb6c4d4
>2014-04-24 16:54:51,170 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-50) BaseAsyncTask::RemoveTaskFromDB: Removed task a873eef9-7977-4408-bc12-d7d56e977908 from DataBase
>2014-04-24 16:54:51,170 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-50) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 076a9987-4a94-4af1-b9ac-e70a1d8bb3d8
>2014-04-24 16:54:52,859 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-54) START, FullListVdsCommand(HostName = lager, HostId = d91ce44f-dba7-4c9e-9d8d-f21857f15e28, vds=Host[lager], vmIds=[bc41fa36-53a1-4c8b-a6a6-97442e643a32]), log id: 6cf22961
>2014-04-24 16:54:52,888 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-54) FINISH, FullListVdsCommand, return: [{displaySecurePort=5900, kvmEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, displayIp=192.168.2.101, pauseCode=NOERR, nice=0, displayNetwork=ovirtmgmt, timeOffset=0, transparentHugePages=true, vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, acpiEnable=true, custom={device_0dd51265-cccf-4059-bb2f-ef1faf1c7ef4device_4b0c1d02-acd2-4a23-94ce-7335d41b995bdevice_515bd1ee-a47d-4719-9f8a-ee6784a512f6device_e784eebc-b041-40bd-a215-7cac5d441548device_ecbec207-58bf-40d7-8997-1e9ed5f8d425=VmDevice {vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, deviceId=ecbec207-58bf-40d7-8997-1e9ed5f8d425, device=virtio-serial, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x05, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=virtio-serial0, customProperties={}, snapshotId=null}, device_0dd51265-cccf-4059-bb2f-ef1faf1c7ef4device_4b0c1d02-acd2-4a23-94ce-7335d41b995bdevice_515bd1ee-a47d-4719-9f8a-ee6784a512f6=VmDevice {vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, deviceId=515bd1ee-a47d-4719-9f8a-ee6784a512f6, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}, device_0dd51265-cccf-4059-bb2f-ef1faf1c7ef4=VmDevice {vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, deviceId=0dd51265-cccf-4059-bb2f-ef1faf1c7ef4, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}, device_0dd51265-cccf-4059-bb2f-ef1faf1c7ef4device_4b0c1d02-acd2-4a23-94ce-7335d41b995bdevice_515bd1ee-a47d-4719-9f8a-ee6784a512f6device_e784eebc-b041-40bd-a215-7cac5d441548=VmDevice {vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, deviceId=e784eebc-b041-40bd-a215-7cac5d441548, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}, device_0dd51265-cccf-4059-bb2f-ef1faf1c7ef4device_4b0c1d02-acd2-4a23-94ce-7335d41b995b=VmDevice {vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, deviceId=4b0c1d02-acd2-4a23-94ce-7335d41b995b, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}}, spiceSslCipherSuite=DEFAULT, memSize=1024, displayPort=-1, smp=1, emulatedMachine=pc-1.0, status=Up, vmType=kvm, memGuaranteedSize=1024, display=qxl, pid=31232, smartcardEnable=false, bootMenuEnable=false, smpCoresPerSocket=1, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, maxVCpus=160, clientIp=, devices=[Ljava.lang.Object;@27382973, vmName=block-1, cpuType=SandyBridge}], log id: 6cf22961
>2014-04-24 16:54:58,990 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-76) VM block-1 bc41fa36-53a1-4c8b-a6a6-97442e643a32 moved from PoweringUp --> Up
>2014-04-24 16:54:59,012 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-76) Correlation ID: 190b6e9b, Job ID: e753525d-1003-4bdb-911f-db85ab7170f2, Call Stack: null, Custom Event ID: -1, Message: VM block-1 started on Host lager
>2014-04-24 16:55:08,898 INFO  [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-95) Setting new tasks map. The map contains now 1 tasks
>2014-04-24 16:55:36,499 INFO  [org.ovirt.engine.core.bll.StopVmCommand] (org.ovirt.thread.pool-6-thread-39) [6db87fea] Running command: StopVmCommand internal: false. Entities affected :  ID: bc41fa36-53a1-4c8b-a6a6-97442e643a32 Type: VM
>2014-04-24 16:55:36,503 INFO  [org.ovirt.engine.core.vdsbroker.DestroyVmVDSCommand] (org.ovirt.thread.pool-6-thread-39) [6db87fea] START, DestroyVmVDSCommand(HostName = lager, HostId = d91ce44f-dba7-4c9e-9d8d-f21857f15e28, vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, force=false, secondsToWait=0, gracefully=false, reason=), log id: 7a4b91e6
>2014-04-24 16:55:36,506 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (org.ovirt.thread.pool-6-thread-39) [6db87fea] START, DestroyVDSCommand(HostName = lager, HostId = d91ce44f-dba7-4c9e-9d8d-f21857f15e28, vmId=bc41fa36-53a1-4c8b-a6a6-97442e643a32, force=false, secondsToWait=0, gracefully=false, reason=), log id: 6e904277

Actions: View

Attachments on bug 1091094: 889443 | 889444