> Please attach any exceptions you see in engine.log and vdsm.log. > > Best wishes, > Greg >
There has same question when stared Win10_liug Thanks 2018-08-15 06:27:04,202+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2018-08-15 06:27:04,202+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 8 threads waiting for tasks and 0 tasks in queue. 2018-08-15 06:27:04,202+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks. 2018-08-15 06:27:04,202+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2018-08-15 06:27:04,202+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads waiting for tasks. 2018-08-15 06:27:43,300+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [2e149598] Lock Acquired to object 'EngineLock:{exclusiveLocks='[182dd9de-fbd0-432a-992f-ea3cf8fcb365=PROVIDER]', sharedLocks=''}' 2018-08-15 06:27:43,310+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [2e149598] Running command: SyncNetworkProviderCommand internal: true. 2018-08-15 06:27:43,421+08 INFO [org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default task-80) [] User admin@internal successfully logged in with scopes: ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:public-authz-search ovirt-ext=token-info:validate ovirt-ext=token:password-access 2018-08-15 06:27:43,572+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-17) [2e149598] Lock freed to object 'EngineLock:{exclusiveLocks='[182dd9de-fbd0-432a-992f-ea3cf8fcb365=PROVIDER]', sharedLocks=''}' 2018-08-15 06:28:18,377+08 INFO [org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default task-80) [] User admin@internal successfully logged in with scopes: ovirt-app-admin ovirt-app-api ovirt-app-portal ovirt-ext=auth:sequence-priority=~ ovirt-ext=revoke:revoke-all ovirt-ext=token-info:authz-search ovirt-ext=token-info:public-authz-search ovirt-ext=token-info:validate ovirt-ext=token:password-access 2018-08-15 06:28:18,447+08 INFO [org.ovirt.engine.core.bll.aaa.CreateUserSessionCommand] (default task-80) [29a87bce] Running command: CreateUserSessionCommand internal: false. 2018-08-15 06:28:18,454+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-80) [29a87bce] EVENT_ID: USER_VDC_LOGIN(30), User admin@internal-authz connecting from '172.21.137.229' using session 'oCxyNNW8A2141gvHc8tLY1ye0UMyPv9Q446Cd/64r6YvPv5zsP40t5A/yBBWoyGwEi+NF26cqxMWWKAgcYoywQ==' logged in. 2018-08-15 06:29:00,033+08 INFO [org.ovirt.engine.core.bll.SetVmTicketCommand] (default task-80) [6cce3ceb] Running command: SetVmTicketCommand internal: false. Entities affected : ID: 3157ba6d-2758-4052-8d29-c3e0d2cb53eb Type: VMAction group CONNECT_TO_VM with role type USER 2018-08-15 06:29:00,041+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (default task-80) [6cce3ceb] START, SetVmTicketVDSCommand(HostName = h4, SetVmTicketVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmId='3157ba6d-2758-4052-8d29-c3e0d2cb53eb', protocol='VNC', ticket='aiq/vTbB7kJM', validTime='120', userName='admin', userId='6303e0de-9faf-11e8-b20b-00163e6e2f69', disconnectAction='NONE'}), log id: 6fbb73b0 2018-08-15 06:29:00,072+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (default task-80) [6cce3ceb] FINISH, SetVmTicketVDSCommand, log id: 6fbb73b0 2018-08-15 06:29:00,082+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-80) [6cce3ceb] EVENT_ID: VM_SET_TICKET(164), User admin@internal-authz initiated console session for VM win10_admin2 2018-08-15 06:29:10,961+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-35) [] EVENT_ID: VM_CONSOLE_CONNECTED(167), User admin@internal-authz is connected to VM win10_admin2. 2018-08-15 06:29:26,057+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-6) [] EVENT_ID: VM_CONSOLE_DISCONNECTED(168), User admin@internal-authz got disconnected from VM win10_admin2. 2018-08-15 06:29:34,487+08 INFO [org.ovirt.engine.core.bll.HibernateVmCommand] (default task-80) [2fa69451-4baf-44b1-8a8b-e948b88346db] Lock Acquired to object 'EngineLock:{exclusiveLocks='[3157ba6d-2758-4052-8d29-c3e0d2cb53eb=VM]', sharedLocks=''}' 2018-08-15 06:29:34,565+08 INFO [org.ovirt.engine.core.bll.memory.MemoryStorageHandler] (default task-80) [2fa69451-4baf-44b1-8a8b-e948b88346db] The memory volumes of VM (name 'win10_admin2', id '3157ba6d-2758-4052-8d29-c3e0d2cb53eb') will be stored in storage domain (name 'uos', id 'de72f436-2d2f-4478-b962-fcae0070d400') 2018-08-15 06:29:34,577+08 INFO [org.ovirt.engine.core.bll.HibernateVmCommand] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] Running command: HibernateVmCommand internal: false. Entities affected : ID: 3157ba6d-2758-4052-8d29-c3e0d2cb53eb Type: VMAction group HIBERNATE_VM with role type USER 2018-08-15 06:29:34,607+08 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] Running command: AddDiskCommand internal: true. Entities affected : ID: de72f436-2d2f-4478-b962-fcae0070d400 Type: StorageAction group CREATE_DISK with role type USER 2018-08-15 06:29:34,611+08 INFO [org.ovirt.engine.core.bll.storage.disk.image.AddImageFromScratchCommand] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] Running command: AddImageFromScratchCommand internal: true. Entities affected : ID: de72f436-2d2f-4478-b962-fcae0070d400 Type: Storage 2018-08-15 06:29:34,635+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] START, CreateImageVDSCommand( CreateImageVDSCommandParameters:{storagePoolId='4e05a820-9faf-11e8-ad4e-00163e6e2f69', ignoreFailoverLimit='false', storageDomainId='de72f436-2d2f-4478-b962-fcae0070d400', imageGroupId='17ebb2d8-41d5-4a64-a5ea-5bf590cfd6a0', imageSizeInBytes='3506438144', volumeFormat='RAW', newImageId='e182ef47-5583-4616-94ba-c6806ec8e462', imageType='Preallocated', newImageDescription='{"DiskAlias":"win10_admin2_hibernation_memory","DiskDescription":"memory dump for VM hibernation"}', imageInitialSizeInBytes='0'}), log id: 5aad5b27 2018-08-15 06:29:34,635+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID 2018-08-15 06:29:34,723+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] FINISH, CreateImageVDSCommand, return: e182ef47-5583-4616-94ba-c6806ec8e462, log id: 5aad5b27 2018-08-15 06:29:34,727+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 'a931a16a-993a-48a1-bb44-3f00c6bf81b6' 2018-08-15 06:29:34,727+08 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] CommandMultiAsyncTasks::attachTask: Attaching task '636308af-8d23-4e25-8fa5-bceb20355da6' to command 'a931a16a-993a-48a1-bb44-3f00c6bf81b6'. 2018-08-15 06:29:34,735+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] Adding task '636308af-8d23-4e25-8fa5-bceb20355da6' (Parent Command 'HibernateVm', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet.. 2018-08-15 06:29:34,756+08 INFO [org.ovirt.engine.core.bll.storage.disk.AddDiskCommand] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] Running command: AddDiskCommand internal: true. Entities affected : ID: de72f436-2d2f-4478-b962-fcae0070d400 Type: StorageAction group CREATE_DISK with role type USER 2018-08-15 06:29:34,760+08 INFO [org.ovirt.engine.core.bll.storage.disk.image.AddImageFromScratchCommand] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] Running command: AddImageFromScratchCommand internal: true. Entities affected : ID: de72f436-2d2f-4478-b962-fcae0070d400 Type: Storage 2018-08-15 06:29:34,779+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] START, CreateImageVDSCommand( CreateImageVDSCommandParameters:{storagePoolId='4e05a820-9faf-11e8-ad4e-00163e6e2f69', ignoreFailoverLimit='false', storageDomainId='de72f436-2d2f-4478-b962-fcae0070d400', imageGroupId='7e9152b6-3780-4ad9-bb79-1f8bb8df304e', imageSizeInBytes='10240', volumeFormat='RAW', newImageId='7fb3b645-891f-4069-9911-f99c193430c2', imageType='Preallocated', newImageDescription='{"DiskAlias":"win10_admin2_hibernation_metadata","DiskDescription":"metadata for VM hibernation"}', imageInitialSizeInBytes='0'}), log id: 6ea33656 2018-08-15 06:29:34,779+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID 2018-08-15 06:29:34,813+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] FINISH, CreateImageVDSCommand, return: 7fb3b645-891f-4069-9911-f99c193430c2, log id: 6ea33656 2018-08-15 06:29:34,816+08 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] CommandMultiAsyncTasks::attachTask: Attaching task '225c5c6d-1fc9-43f3-951c-b2c766161279' to command 'a931a16a-993a-48a1-bb44-3f00c6bf81b6'. 2018-08-15 06:29:34,823+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] Adding task '225c5c6d-1fc9-43f3-951c-b2c766161279' (Parent Command 'HibernateVm', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet.. 2018-08-15 06:29:34,843+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] EVENT_ID: USER_SUSPEND_VM(501), Suspending VM win10_admin2 was initiated by User admin@internal-authz (Host: h4). 2018-08-15 06:29:34,843+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] BaseAsyncTask::startPollingTask: Starting to poll task '636308af-8d23-4e25-8fa5-bceb20355da6'. 2018-08-15 06:29:34,843+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5855) [2fa69451-4baf-44b1-8a8b-e948b88346db] BaseAsyncTask::startPollingTask: Starting to poll task '225c5c6d-1fc9-43f3-951c-b2c766161279'. 2018-08-15 06:29:39,950+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-51) [] Polling and updating Async Tasks: 2 tasks, 2 tasks to poll now 2018-08-15 06:29:39,957+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-51) [] SPMAsyncTask::PollTask: Polling task '636308af-8d23-4e25-8fa5-bceb20355da6' (Parent Command 'HibernateVm', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'. 2018-08-15 06:29:39,961+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-51) [] BaseAsyncTask::onTaskEndSuccess: Task '636308af-8d23-4e25-8fa5-bceb20355da6' (Parent Command 'HibernateVm', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully. 2018-08-15 06:29:39,962+08 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (EE-ManagedThreadFactory-engineScheduled-Thread-51) [] Task with DB Task ID '853102c7-a283-4483-9c52-2ea1a9c11b4d' and VDSM Task ID '225c5c6d-1fc9-43f3-951c-b2c766161279' is in state Polling. End action for command a931a16a-993a-48a1-bb44-3f00c6bf81b6 will proceed when all the entity's tasks are completed. 2018-08-15 06:29:39,962+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-51) [] SPMAsyncTask::PollTask: Polling task '225c5c6d-1fc9-43f3-951c-b2c766161279' (Parent Command 'HibernateVm', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'. 2018-08-15 06:29:39,965+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-51) [] BaseAsyncTask::onTaskEndSuccess: Task '225c5c6d-1fc9-43f3-951c-b2c766161279' (Parent Command 'HibernateVm', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully. 2018-08-15 06:29:39,968+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-51) [] CommandAsyncTask::endActionIfNecessary: All tasks of command 'a931a16a-993a-48a1-bb44-3f00c6bf81b6' has ended -> executing 'endAction' 2018-08-15 06:29:39,968+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-51) [] CommandAsyncTask::endAction: Ending action for '2' tasks (command ID: 'a931a16a-993a-48a1-bb44-3f00c6bf81b6'): calling endAction '. 2018-08-15 06:29:39,968+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5856) [] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'HibernateVm', 2018-08-15 06:29:40,025+08 INFO [org.ovirt.engine.core.bll.HibernateVmCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [] Ending command 'org.ovirt.engine.core.bll.HibernateVmCommand' successfully. 2018-08-15 06:29:40,030+08 INFO [org.ovirt.engine.core.bll.storage.disk.image.AddImageFromScratchCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [2fa69451-4baf-44b1-8a8b-e948b88346db] Ending command 'org.ovirt.engine.core.bll.storage.disk.image.AddImageFromScratchCommand' successfully. 2018-08-15 06:29:40,038+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [2fa69451-4baf-44b1-8a8b-e948b88346db] START, GetImageInfoVDSCommand( GetImageInfoVDSCommandParameters:{storagePoolId='4e05a820-9faf-11e8-ad4e-00163e6e2f69', ignoreFailoverLimit='false', storageDomainId='de72f436-2d2f-4478-b962-fcae0070d400', imageGroupId='17ebb2d8-41d5-4a64-a5ea-5bf590cfd6a0', imageId='e182ef47-5583-4616-94ba-c6806ec8e462'}), log id: 2d2b0b62 2018-08-15 06:29:40,040+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [2fa69451-4baf-44b1-8a8b-e948b88346db] START, GetVolumeInfoVDSCommand(HostName = h4, GetVolumeInfoVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', storagePoolId='4e05a820-9faf-11e8-ad4e-00163e6e2f69', storageDomainId='de72f436-2d2f-4478-b962-fcae0070d400', imageGroupId='17ebb2d8-41d5-4a64-a5ea-5bf590cfd6a0', imageId='e182ef47-5583-4616-94ba-c6806ec8e462'}), log id: 4bda0dd9 2018-08-15 06:29:40,076+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [2fa69451-4baf-44b1-8a8b-e948b88346db] FINISH, GetVolumeInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.DiskImage@bc3e4faa, log id: 4bda0dd9 2018-08-15 06:29:40,076+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [2fa69451-4baf-44b1-8a8b-e948b88346db] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.DiskImage@bc3e4faa, log id: 2d2b0b62 2018-08-15 06:29:40,088+08 INFO [org.ovirt.engine.core.bll.storage.disk.image.AddImageFromScratchCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [2fa69451-4baf-44b1-8a8b-e948b88346db] Ending command 'org.ovirt.engine.core.bll.storage.disk.image.AddImageFromScratchCommand' successfully. 2018-08-15 06:29:40,090+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [2fa69451-4baf-44b1-8a8b-e948b88346db] START, GetImageInfoVDSCommand( GetImageInfoVDSCommandParameters:{storagePoolId='4e05a820-9faf-11e8-ad4e-00163e6e2f69', ignoreFailoverLimit='false', storageDomainId='de72f436-2d2f-4478-b962-fcae0070d400', imageGroupId='7e9152b6-3780-4ad9-bb79-1f8bb8df304e', imageId='7fb3b645-891f-4069-9911-f99c193430c2'}), log id: 39975e36 2018-08-15 06:29:40,092+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [2fa69451-4baf-44b1-8a8b-e948b88346db] START, GetVolumeInfoVDSCommand(HostName = h4, GetVolumeInfoVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', storagePoolId='4e05a820-9faf-11e8-ad4e-00163e6e2f69', storageDomainId='de72f436-2d2f-4478-b962-fcae0070d400', imageGroupId='7e9152b6-3780-4ad9-bb79-1f8bb8df304e', imageId='7fb3b645-891f-4069-9911-f99c193430c2'}), log id: 74f6476f 2018-08-15 06:29:40,118+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [2fa69451-4baf-44b1-8a8b-e948b88346db] FINISH, GetVolumeInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.DiskImage@d95d0882, log id: 74f6476f 2018-08-15 06:29:40,118+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [2fa69451-4baf-44b1-8a8b-e948b88346db] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.DiskImage@d95d0882, log id: 39975e36 2018-08-15 06:29:40,138+08 INFO [org.ovirt.engine.core.bll.memory.MemoryStorageHandler] (EE-ManagedThreadFactory-engine-Thread-5856) [] The memory volumes of VM (name 'win10_admin2', id '3157ba6d-2758-4052-8d29-c3e0d2cb53eb') will be stored in storage domain (name 'uos', id 'de72f436-2d2f-4478-b962-fcae0070d400') 2018-08-15 06:29:40,139+08 INFO [org.ovirt.engine.core.vdsbroker.HibernateVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [] START, HibernateVDSCommand( HibernateVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmId='3157ba6d-2758-4052-8d29-c3e0d2cb53eb', hibernationVolHandle='de72f436-2d2f-4478-b962-fcae0070d400,4e05a820-9faf-11e8-ad4e-00163e6e2f69,17ebb2d8-41d5-4a64-a5ea-5bf590cfd6a0,e182ef47-5583-4616-94ba-c6806ec8e462,7e9152b6-3780-4ad9-bb79-1f8bb8df304e,7fb3b645-891f-4069-9911-f99c193430c2'}), log id: 87d866c 2018-08-15 06:29:40,140+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HibernateBrokerVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [] START, HibernateBrokerVDSCommand(HostName = h4, HibernateVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmId='3157ba6d-2758-4052-8d29-c3e0d2cb53eb', hibernationVolHandle='de72f436-2d2f-4478-b962-fcae0070d400,4e05a820-9faf-11e8-ad4e-00163e6e2f69,17ebb2d8-41d5-4a64-a5ea-5bf590cfd6a0,e182ef47-5583-4616-94ba-c6806ec8e462,7e9152b6-3780-4ad9-bb79-1f8bb8df304e,7fb3b645-891f-4069-9911-f99c193430c2'}), log id: 6b020dff 2018-08-15 06:29:40,183+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HibernateBrokerVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [] FINISH, HibernateBrokerVDSCommand, log id: 6b020dff 2018-08-15 06:29:40,186+08 INFO [org.ovirt.engine.core.vdsbroker.HibernateVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [] FINISH, HibernateVDSCommand, log id: 87d866c 2018-08-15 06:29:40,190+08 INFO [org.ovirt.engine.core.bll.HibernateVmCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [] Lock freed to object 'EngineLock:{exclusiveLocks='[3157ba6d-2758-4052-8d29-c3e0d2cb53eb=VM]', sharedLocks=''}' 2018-08-15 06:29:40,190+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5856) [] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'HibernateVm' completed, handling the result. 2018-08-15 06:29:40,190+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5856) [] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'HibernateVm' succeeded, clearing tasks. 2018-08-15 06:29:40,190+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5856) [] SPMAsyncTask::ClearAsyncTask: Attempting to clear task '636308af-8d23-4e25-8fa5-bceb20355da6' 2018-08-15 06:29:40,191+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{storagePoolId='4e05a820-9faf-11e8-ad4e-00163e6e2f69', ignoreFailoverLimit='false', taskId='636308af-8d23-4e25-8fa5-bceb20355da6'}), log id: 1d68c2cd 2018-08-15 06:29:40,192+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [] START, HSMClearTaskVDSCommand(HostName = h4, HSMTaskGuidBaseVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', taskId='636308af-8d23-4e25-8fa5-bceb20355da6'}), log id: 75913543 2018-08-15 06:29:40,199+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [] FINISH, HSMClearTaskVDSCommand, log id: 75913543 2018-08-15 06:29:40,199+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [] FINISH, SPMClearTaskVDSCommand, log id: 1d68c2cd 2018-08-15 06:29:40,203+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5856) [] BaseAsyncTask::removeTaskFromDB: Removed task '636308af-8d23-4e25-8fa5-bceb20355da6' from DataBase 2018-08-15 06:29:40,203+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5856) [] SPMAsyncTask::ClearAsyncTask: Attempting to clear task '225c5c6d-1fc9-43f3-951c-b2c766161279' 2018-08-15 06:29:40,203+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{storagePoolId='4e05a820-9faf-11e8-ad4e-00163e6e2f69', ignoreFailoverLimit='false', taskId='225c5c6d-1fc9-43f3-951c-b2c766161279'}), log id: 4db22759 2018-08-15 06:29:40,204+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [] START, HSMClearTaskVDSCommand(HostName = h4, HSMTaskGuidBaseVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', taskId='225c5c6d-1fc9-43f3-951c-b2c766161279'}), log id: 58dd1b8a 2018-08-15 06:29:40,211+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [] FINISH, HSMClearTaskVDSCommand, log id: 58dd1b8a 2018-08-15 06:29:40,211+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5856) [] FINISH, SPMClearTaskVDSCommand, log id: 4db22759 2018-08-15 06:29:40,214+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5856) [] BaseAsyncTask::removeTaskFromDB: Removed task '225c5c6d-1fc9-43f3-951c-b2c766161279' from DataBase 2018-08-15 06:29:40,214+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5856) [] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 'a931a16a-993a-48a1-bb44-3f00c6bf81b6' 2018-08-15 06:29:50,745+08 INFO [org.ovirt.engine.core.bll.SetVmTicketCommand] (default task-80) [68ad18ed] Running command: SetVmTicketCommand internal: false. Entities affected : ID: c326468b-ac01-4b8d-8eab-2129ccd8b0d8 Type: VMAction group CONNECT_TO_VM with role type USER 2018-08-15 06:29:50,753+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (default task-80) [68ad18ed] START, SetVmTicketVDSCommand(HostName = h4, SetVmTicketVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmId='c326468b-ac01-4b8d-8eab-2129ccd8b0d8', protocol='SPICE', ticket='IcDJe0MdaeIl', validTime='120', userName='admin', userId='6303e0de-9faf-11e8-b20b-00163e6e2f69', disconnectAction='LOCK_SCREEN'}), log id: 51123bc 2018-08-15 06:29:50,795+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (default task-80) [68ad18ed] FINISH, SetVmTicketVDSCommand, log id: 51123bc 2018-08-15 06:29:50,805+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-80) [68ad18ed] EVENT_ID: VM_SET_TICKET(164), User admin@internal-authz initiated console session for VM yumServer 2018-08-15 06:29:56,160+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-34) [] EVENT_ID: VM_CONSOLE_CONNECTED(167), User admin@internal-authz is connected to VM yumServer. 2018-08-15 06:30:08,263+08 INFO [org.ovirt.engine.core.bll.SetVmTicketCommand] (default task-80) [ed9ab4e] Running command: SetVmTicketCommand internal: false. Entities affected : ID: c326468b-ac01-4b8d-8eab-2129ccd8b0d8 Type: VMAction group CONNECT_TO_VM with role type USER 2018-08-15 06:30:08,270+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (default task-80) [ed9ab4e] START, SetVmTicketVDSCommand(HostName = h4, SetVmTicketVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmId='c326468b-ac01-4b8d-8eab-2129ccd8b0d8', protocol='SPICE', ticket='cwRAhnwEuKOA', validTime='120', userName='admin', userId='6303e0de-9faf-11e8-b20b-00163e6e2f69', disconnectAction='LOCK_SCREEN'}), log id: 3e0b4989 2018-08-15 06:30:08,301+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (default task-80) [ed9ab4e] FINISH, SetVmTicketVDSCommand, log id: 3e0b4989 2018-08-15 06:30:08,310+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-80) [ed9ab4e] EVENT_ID: VM_SET_TICKET(164), User admin@internal-authz initiated console session for VM yumServer 2018-08-15 06:30:11,198+08 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [] VM '3157ba6d-2758-4052-8d29-c3e0d2cb53eb' was reported as Down on VDS 'a8f6210a-fce4-4fec-bb87-4ccddb82a232'(h4) 2018-08-15 06:30:11,199+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [] START, DestroyVDSCommand(HostName = h4, DestroyVmVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmId='3157ba6d-2758-4052-8d29-c3e0d2cb53eb', secondsToWait='0', gracefully='false', reason='', ignoreNoVm='true'}), log id: 53cc67 2018-08-15 06:30:12,537+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [] FINISH, DestroyVDSCommand, log id: 53cc67 2018-08-15 06:30:12,538+08 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [] VM '3157ba6d-2758-4052-8d29-c3e0d2cb53eb'(win10_admin2) moved from 'SavingState' --> 'Down' 2018-08-15 06:30:12,588+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [] EVENT_ID: USER_SUSPEND_VM_OK(503), VM win10_admin2 on Host h4 is suspended. 2018-08-15 06:30:12,603+08 INFO [org.ovirt.engine.core.bll.ProcessDownVmCommand] (EE-ManagedThreadFactory-engine-Thread-5861) [66addd18] Running command: ProcessDownVmCommand internal: true. 2018-08-15 06:30:27,625+08 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher] (EE-ManagedThreadFactory-engineScheduled-Thread-97) [] Fetched 9 VMs from VDS 'a8f6210a-fce4-4fec-bb87-4ccddb82a232' 2018-08-15 06:30:27,639+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-97) [] EVENT_ID: VM_CONSOLE_DISCONNECTED(168), User admin@internal-authz got disconnected from VM yumServer. 2018-08-15 06:30:28,413+08 INFO [org.ovirt.engine.core.bll.RunVmCommand] (default task-80) [408cddc1-9309-4553-a732-05239879d301] Lock Acquired to object 'EngineLock:{exclusiveLocks='[3157ba6d-2758-4052-8d29-c3e0d2cb53eb=VM]', sharedLocks=''}' 2018-08-15 06:30:28,430+08 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (default task-80) [408cddc1-9309-4553-a732-05239879d301] START, IsVmDuringInitiatingVDSCommand( IsVmDuringInitiatingVDSCommandParameters:{vmId='3157ba6d-2758-4052-8d29-c3e0d2cb53eb'}), log id: 5a30cd3b 2018-08-15 06:30:28,430+08 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (default task-80) [408cddc1-9309-4553-a732-05239879d301] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 5a30cd3b 2018-08-15 06:30:28,469+08 INFO [org.ovirt.engine.core.bll.RunVmCommand] (EE-ManagedThreadFactory-engine-Thread-5864) [408cddc1-9309-4553-a732-05239879d301] Running command: RunVmCommand internal: false. Entities affected : ID: 3157ba6d-2758-4052-8d29-c3e0d2cb53eb Type: VMAction group RUN_VM with role type USER 2018-08-15 06:30:28,493+08 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5864) [408cddc1-9309-4553-a732-05239879d301] START, UpdateVmDynamicDataVDSCommand( UpdateVmDynamicDataVDSCommandParameters:{hostId='null', vmId='3157ba6d-2758-4052-8d29-c3e0d2cb53eb', vmDynamic='org.ovirt.engine.core.common.businessentities.VmDynamic@3829bf01'}), log id: 288a3b77 2018-08-15 06:30:28,495+08 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5864) [408cddc1-9309-4553-a732-05239879d301] FINISH, UpdateVmDynamicDataVDSCommand, log id: 288a3b77 2018-08-15 06:30:28,522+08 INFO [org.ovirt.engine.core.vdsbroker.CreateVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5864) [408cddc1-9309-4553-a732-05239879d301] START, CreateVDSCommand( CreateVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmId='3157ba6d-2758-4052-8d29-c3e0d2cb53eb', vm='VM [win10_admin2]'}), log id: 367b163 2018-08-15 06:30:28,522+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5864) [408cddc1-9309-4553-a732-05239879d301] START, CreateBrokerVDSCommand(HostName = h4, CreateVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmId='3157ba6d-2758-4052-8d29-c3e0d2cb53eb', vm='VM [win10_admin2]'}), log id: 5b68ed26 2018-08-15 06:30:28,535+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5864) [408cddc1-9309-4553-a732-05239879d301] VM <?xml version="1.0" encoding="UTF-8"?><domain type="kvm" xmlns:ovirt-tune="http://ovirt.org/vm/tune/1.0" xmlns:ovirt-vm="http://ovirt.org/vm/1.0"> <name>win10_admin2</name> <uuid>3157ba6d-2758-4052-8d29-c3e0d2cb53eb</uuid> <memory>3145728</memory> <currentMemory>3145728</currentMemory> <iothreads>1</iothreads> <maxMemory slots="16">12582912</maxMemory> <vcpu current="2">16</vcpu> <sysinfo type="smbios"> <system> <entry name="manufacturer">oVirt</entry> <entry name="product">OS-NAME:</entry> <entry name="version">OS-VERSION:</entry> <entry name="serial">HOST-SERIAL:</entry> <entry name="uuid">3157ba6d-2758-4052-8d29-c3e0d2cb53eb</entry> </system> </sysinfo> <clock offset="variable" adjustment="3600"> <timer name="hypervclock" present="yes"/> <timer name="rtc" tickpolicy="catchup"/> <timer name="pit" tickpolicy="delay"/> <timer name="hpet" present="no"/> </clock> <features> <acpi/> <hyperv> <relaxed state="on"/> <vapic state="on"/> <spinlocks state="on" retries="8191"/> </hyperv> </features> <cpu match="exact"> <model>Haswell</model> <topology cores="1" threads="1" sockets="16"/> <numa> <cell id="0" cpus="0,1" memory="3145728"/> </numa> </cpu> <cputune/> <devices> <input type="tablet" bus="usb"/> <channel type="unix"> <target type="virtio" name="ovirt-guest-agent.0"/> <source mode="bind" path="/var/lib/libvirt/qemu/channels/3157ba6d-2758-4052-8d29-c3e0d2cb53eb.ovirt-guest-agent.0"/> </channel> <channel type="unix"> <target type="virtio" name="org.qemu.guest_agent.0"/> <source mode="bind" path="/var/lib/libvirt/qemu/channels/3157ba6d-2758-4052-8d29-c3e0d2cb53eb.org.qemu.guest_agent.0"/> </channel> <controller type="scsi" model="virtio-scsi" index="0"> <driver iothread="1"/> <alias name="ua-0c573b63-ff17-4f1d-aa2f-52a04f1444a7"/> <address bus="0x00" domain="0x0000" function="0x0" slot="0x04" type="pci"/> </controller> <graphics type="vnc" port="-1" autoport="yes" passwd="*****" passwdValidTo="1970-01-01T00:00:01" keymap="en-us"> <listen type="network" network="vdsm-wan"/> </graphics> <video> <model type="qxl" vram="8192" heads="1" ram="65536" vgamem="16384"/> <alias name="ua-3eaf17ab-6938-4cb6-8f2d-239dde553be5"/> <address bus="0x00" domain="0x0000" function="0x0" slot="0x02" type="pci"/> </video> <controller type="virtio-serial" index="0" ports="16"> <alias name="ua-4c206e20-6380-45b2-a9ce-81caa82a9170"/> <address bus="0x00" domain="0x0000" function="0x0" slot="0x05" type="pci"/> </controller> <controller type="ide"> <address bus="0x00" domain="0x0000" function="0x1" slot="0x01" type="pci"/> </controller> <controller type="usb" model="piix3-uhci" index="0"> <address bus="0x00" domain="0x0000" function="0x2" slot="0x01" type="pci"/> </controller> <rng model="virtio"> <backend model="random">/dev/urandom</backend> <alias name="ua-e6cbd1fb-394d-467b-9c35-0636fbe07faf"/> </rng> <memballoon model="none"/> <interface type="bridge"> <model type="virtio"/> <link state="up"/> <source bridge="tvlan2870"/> <driver queues="2" name="vhost"/> <alias name="ua-2c27c79d-cd54-41b3-ab96-0ccb75d2d312"/> <address bus="0x00" domain="0x0000" function="0x0" slot="0x03" type="pci"/> <mac address="00:1a:4a:16:01:13"/> <mtu size="1500"/> <filterref filter="vdsm-no-mac-spoofing"/> <bandwidth/> </interface> <disk type="file" device="cdrom" snapshot="no"> <driver name="qemu" type="raw" error_policy="report"/> <source file="" startupPolicy="optional"/> <target dev="hdc" bus="ide"/> <readonly/> <alias name="ua-801eaa49-b1b9-4c16-af8e-aa9547f04adc"/> <address bus="1" controller="0" unit="0" type="drive" target="0"/> </disk> <disk snapshot="no" type="block" device="disk"> <target dev="sda" bus="scsi"/> <source dev="/rhev/data-center/mnt/blockSD/de72f436-2d2f-4478-b962-fcae0070d400/images/4ee5bb0d-6b51-43d0-a398-665ec9d0abdf/deb2d695-84d2-413e-9546-3de6a2d3055b"/> <driver name="qemu" io="native" type="qcow2" error_policy="stop" cache="none"/> <alias name="ua-4ee5bb0d-6b51-43d0-a398-665ec9d0abdf"/> <address bus="0" controller="0" unit="0" type="drive" target="0"/> <boot order="1"/> <serial>4ee5bb0d-6b51-43d0-a398-665ec9d0abdf</serial> </disk> </devices> <pm> <suspend-to-disk enabled="no"/> <suspend-to-mem enabled="no"/> </pm> <os> <type arch="x86_64" machine="pc-i440fx-rhel7.3.0">hvm</type> <smbios mode="sysinfo"/> </os> <metadata> <ovirt-tune:qos/> <ovirt-vm:vm> <minGuaranteedMemoryMb type="int">3072</minGuaranteedMemoryMb> <clusterVersion>4.2</clusterVersion> <ovirt-vm:custom/> <ovirt-vm:device mac_address="00:1a:4a:16:01:13"> <ovirt-vm:custom/> </ovirt-vm:device> <ovirt-vm:device devtype="disk" name="sda"> <ovirt-vm:poolID>4e05a820-9faf-11e8-ad4e-00163e6e2f69</ovirt-vm:poolID> <ovirt-vm:volumeID>deb2d695-84d2-413e-9546-3de6a2d3055b</ovirt-vm:volumeID> <ovirt-vm:imageID>4ee5bb0d-6b51-43d0-a398-665ec9d0abdf</ovirt-vm:imageID> <ovirt-vm:domainID>de72f436-2d2f-4478-b962-fcae0070d400</ovirt-vm:domainID> </ovirt-vm:device> <launchPaused>false</launchPaused> <resumeBehavior>auto_resume</resumeBehavior> </ovirt-vm:vm> </metadata> </domain> 2018-08-15 06:30:29,322+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5864) [408cddc1-9309-4553-a732-05239879d301] FINISH, CreateBrokerVDSCommand, log id: 5b68ed26 2018-08-15 06:30:29,324+08 INFO [org.ovirt.engine.core.vdsbroker.CreateVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5864) [408cddc1-9309-4553-a732-05239879d301] FINISH, CreateVDSCommand, return: RestoringState, log id: 367b163 2018-08-15 06:30:29,325+08 INFO [org.ovirt.engine.core.bll.RunVmCommand] (EE-ManagedThreadFactory-engine-Thread-5864) [408cddc1-9309-4553-a732-05239879d301] Lock freed to object 'EngineLock:{exclusiveLocks='[3157ba6d-2758-4052-8d29-c3e0d2cb53eb=VM]', sharedLocks=''}' 2018-08-15 06:30:29,329+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-5864) [408cddc1-9309-4553-a732-05239879d301] EVENT_ID: USER_STARTED_VM(153), VM win10_admin2 was started by admin@internal-authz (Host: h4). 2018-08-15 06:30:41,604+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-29) [] Setting new tasks map. The map contains now 0 tasks 2018-08-15 06:30:41,604+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-29) [] Cleared all tasks of pool '4e05a820-9faf-11e8-ad4e-00163e6e2f69'. 2018-08-15 06:30:42,675+08 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher] (EE-ManagedThreadFactory-engineScheduled-Thread-6) [] Fetched 10 VMs from VDS 'a8f6210a-fce4-4fec-bb87-4ccddb82a232' 2018-08-15 06:30:42,686+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DumpXmlsVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-6) [] START, DumpXmlsVDSCommand(HostName = h4, Params:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmIds='[3157ba6d-2758-4052-8d29-c3e0d2cb53eb]'}), log id: 4acb6f39 2018-08-15 06:30:42,708+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DumpXmlsVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-6) [] FINISH, DumpXmlsVDSCommand, return: [{vmId=3157ba6d-2758-4052-8d29-c3e0d2cb53eb, devices=[Ljava.util.Map;@5fa8f608, guestDiskMapping={4ee5bb0d-6b51-43d0-a398-665ec9d0abdf={name=\\.\PHYSICALDRIVE0}}}], log id: 4acb6f39 2018-08-15 06:30:59,778+08 INFO [org.ovirt.engine.core.bll.RunVmCommand] (default task-80) [0004457d-5f69-4c0d-9f9c-6fa081049f4b] Lock Acquired to object 'EngineLock:{exclusiveLocks='[8471050b-7dda-466f-aecb-5b35e4aa8d2f=VM]', sharedLocks=''}' 2018-08-15 06:30:59,795+08 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (default task-80) [0004457d-5f69-4c0d-9f9c-6fa081049f4b] START, IsVmDuringInitiatingVDSCommand( IsVmDuringInitiatingVDSCommandParameters:{vmId='8471050b-7dda-466f-aecb-5b35e4aa8d2f'}), log id: 4acbf477 2018-08-15 06:30:59,795+08 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (default task-80) [0004457d-5f69-4c0d-9f9c-6fa081049f4b] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 4acbf477 2018-08-15 06:30:59,834+08 INFO [org.ovirt.engine.core.bll.RunVmCommand] (EE-ManagedThreadFactory-engine-Thread-5869) [0004457d-5f69-4c0d-9f9c-6fa081049f4b] Running command: RunVmCommand internal: false. Entities affected : ID: 8471050b-7dda-466f-aecb-5b35e4aa8d2f Type: VMAction group RUN_VM with role type USER 2018-08-15 06:30:59,860+08 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5869) [0004457d-5f69-4c0d-9f9c-6fa081049f4b] START, UpdateVmDynamicDataVDSCommand( UpdateVmDynamicDataVDSCommandParameters:{hostId='null', vmId='8471050b-7dda-466f-aecb-5b35e4aa8d2f', vmDynamic='org.ovirt.engine.core.common.businessentities.VmDynamic@b54b5578'}), log id: 433c6d3c 2018-08-15 06:30:59,863+08 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5869) [0004457d-5f69-4c0d-9f9c-6fa081049f4b] FINISH, UpdateVmDynamicDataVDSCommand, log id: 433c6d3c 2018-08-15 06:30:59,888+08 INFO [org.ovirt.engine.core.vdsbroker.CreateVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5869) [0004457d-5f69-4c0d-9f9c-6fa081049f4b] START, CreateVDSCommand( CreateVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmId='8471050b-7dda-466f-aecb-5b35e4aa8d2f', vm='VM [win10_liug]'}), log id: 6fe2c3d 2018-08-15 06:30:59,889+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5869) [0004457d-5f69-4c0d-9f9c-6fa081049f4b] START, CreateBrokerVDSCommand(HostName = h4, CreateVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmId='8471050b-7dda-466f-aecb-5b35e4aa8d2f', vm='VM [win10_liug]'}), log id: 38d7bec6 2018-08-15 06:30:59,903+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5869) [0004457d-5f69-4c0d-9f9c-6fa081049f4b] VM <?xml version="1.0" encoding="UTF-8"?><domain type="kvm" xmlns:ovirt-tune="http://ovirt.org/vm/tune/1.0" xmlns:ovirt-vm="http://ovirt.org/vm/1.0"> <name>win10_liug</name> <uuid>8471050b-7dda-466f-aecb-5b35e4aa8d2f</uuid> <memory>3145728</memory> <currentMemory>3145728</currentMemory> <iothreads>1</iothreads> <maxMemory slots="16">12582912</maxMemory> <vcpu current="2">16</vcpu> <sysinfo type="smbios"> <system> <entry name="manufacturer">oVirt</entry> <entry name="product">OS-NAME:</entry> <entry name="version">OS-VERSION:</entry> <entry name="serial">HOST-SERIAL:</entry> <entry name="uuid">8471050b-7dda-466f-aecb-5b35e4aa8d2f</entry> </system> </sysinfo> <clock offset="variable" adjustment="3600"> <timer name="hypervclock" present="yes"/> <timer name="rtc" tickpolicy="catchup"/> <timer name="pit" tickpolicy="delay"/> <timer name="hpet" present="no"/> </clock> <features> <acpi/> <hyperv> <relaxed state="on"/> <vapic state="on"/> <spinlocks state="on" retries="8191"/> </hyperv> </features> <cpu match="exact"> <model>Haswell</model> <topology cores="1" threads="1" sockets="16"/> <numa> <cell id="0" cpus="0,1" memory="3145728"/> </numa> </cpu> <cputune/> <devices> <input type="tablet" bus="usb"/> <channel type="unix"> <target type="virtio" name="ovirt-guest-agent.0"/> <source mode="bind" path="/var/lib/libvirt/qemu/channels/8471050b-7dda-466f-aecb-5b35e4aa8d2f.ovirt-guest-agent.0"/> </channel> <channel type="unix"> <target type="virtio" name="org.qemu.guest_agent.0"/> <source mode="bind" path="/var/lib/libvirt/qemu/channels/8471050b-7dda-466f-aecb-5b35e4aa8d2f.org.qemu.guest_agent.0"/> </channel> <controller type="scsi" model="virtio-scsi" index="0"> <driver iothread="1"/> <alias name="ua-03e3abbd-cf49-4f89-9d70-e44c15a54e57"/> <address bus="0x00" domain="0x0000" function="0x0" slot="0x04" type="pci"/> </controller> <video> <model type="qxl" vram="8192" heads="1" ram="65536" vgamem="16384"/> <alias name="ua-0e78fe1f-decf-4f70-a623-d70f533556a5"/> <address bus="0x00" domain="0x0000" function="0x0" slot="0x02" type="pci"/> </video> <controller type="usb" model="piix3-uhci" index="0"> <address bus="0x00" domain="0x0000" function="0x2" slot="0x01" type="pci"/> </controller> <graphics type="vnc" port="-1" autoport="yes" passwd="*****" passwdValidTo="1970-01-01T00:00:01" keymap="en-us"> <listen type="network" network="vdsm-wan"/> </graphics> <controller type="ide"> <address bus="0x00" domain="0x0000" function="0x1" slot="0x01" type="pci"/> </controller> <controller type="virtio-serial" index="0" ports="16"> <alias name="ua-c97f1593-773c-4f30-be1e-0f7dc12fca1b"/> <address bus="0x00" domain="0x0000" function="0x0" slot="0x05" type="pci"/> </controller> <rng model="virtio"> <backend model="random">/dev/urandom</backend> <alias name="ua-e6cbd1fb-394d-467b-9c35-0636fbe07faf"/> </rng> <memballoon model="none"/> <interface type="bridge"> <model type="virtio"/> <link state="up"/> <source bridge="tvlan2870"/> <driver queues="2" name="vhost"/> <alias name="ua-44bae05b-6547-4f70-b66f-f6e1b70089e2"/> <address bus="0x00" domain="0x0000" function="0x0" slot="0x03" type="pci"/> <mac address="00:1a:4a:16:01:17"/> <mtu size="1500"/> <filterref filter="vdsm-no-mac-spoofing"/> <bandwidth/> </interface> <disk type="file" device="cdrom" snapshot="no"> <driver name="qemu" type="raw" error_policy="report"/> <source file="" startupPolicy="optional"/> <target dev="hdc" bus="ide"/> <readonly/> <alias name="ua-2f925984-53c1-41c3-8878-6f02bc495c62"/> <address bus="1" controller="0" unit="0" type="drive" target="0"/> </disk> <disk snapshot="no" type="block" device="disk"> <target dev="sda" bus="scsi"/> <source dev="/rhev/data-center/mnt/blockSD/de72f436-2d2f-4478-b962-fcae0070d400/images/0348e1f1-ed58-48ea-ae07-f5177f59b48c/7517e930-673e-49b3-9901-81bce3f94375"/> <driver name="qemu" io="native" type="qcow2" error_policy="stop" cache="none"/> <alias name="ua-0348e1f1-ed58-48ea-ae07-f5177f59b48c"/> <address bus="0" controller="0" unit="0" type="drive" target="0"/> <boot order="1"/> <serial>0348e1f1-ed58-48ea-ae07-f5177f59b48c</serial> </disk> </devices> <pm> <suspend-to-disk enabled="no"/> <suspend-to-mem enabled="no"/> </pm> <os> <type arch="x86_64" machine="pc-i440fx-rhel7.3.0">hvm</type> <smbios mode="sysinfo"/> </os> <metadata> <ovirt-tune:qos/> <ovirt-vm:vm> <minGuaranteedMemoryMb type="int">3072</minGuaranteedMemoryMb> <clusterVersion>4.2</clusterVersion> <ovirt-vm:custom/> <ovirt-vm:device mac_address="00:1a:4a:16:01:17"> <ovirt-vm:custom/> </ovirt-vm:device> <ovirt-vm:device devtype="disk" name="sda"> <ovirt-vm:poolID>4e05a820-9faf-11e8-ad4e-00163e6e2f69</ovirt-vm:poolID> <ovirt-vm:volumeID>7517e930-673e-49b3-9901-81bce3f94375</ovirt-vm:volumeID> <ovirt-vm:imageID>0348e1f1-ed58-48ea-ae07-f5177f59b48c</ovirt-vm:imageID> <ovirt-vm:domainID>de72f436-2d2f-4478-b962-fcae0070d400</ovirt-vm:domainID> </ovirt-vm:device> <launchPaused>false</launchPaused> <resumeBehavior>auto_resume</resumeBehavior> </ovirt-vm:vm> </metadata> </domain> 2018-08-15 06:31:00,761+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5869) [0004457d-5f69-4c0d-9f9c-6fa081049f4b] FINISH, CreateBrokerVDSCommand, log id: 38d7bec6 2018-08-15 06:31:00,763+08 INFO [org.ovirt.engine.core.vdsbroker.CreateVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5869) [0004457d-5f69-4c0d-9f9c-6fa081049f4b] FINISH, CreateVDSCommand, return: RestoringState, log id: 6fe2c3d 2018-08-15 06:31:00,764+08 INFO [org.ovirt.engine.core.bll.RunVmCommand] (EE-ManagedThreadFactory-engine-Thread-5869) [0004457d-5f69-4c0d-9f9c-6fa081049f4b] Lock freed to object 'EngineLock:{exclusiveLocks='[8471050b-7dda-466f-aecb-5b35e4aa8d2f=VM]', sharedLocks=''}' 2018-08-15 06:31:00,767+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-5869) [0004457d-5f69-4c0d-9f9c-6fa081049f4b] EVENT_ID: USER_STARTED_VM(153), VM win10_liug was started by admin@internal-authz (Host: h4). 2018-08-15 06:31:13,773+08 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher] (EE-ManagedThreadFactory-engineScheduled-Thread-68) [] Fetched 11 VMs from VDS 'a8f6210a-fce4-4fec-bb87-4ccddb82a232' 2018-08-15 06:31:13,775+08 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (EE-ManagedThreadFactory-engineScheduled-Thread-68) [] VM '8471050b-7dda-466f-aecb-5b35e4aa8d2f' was reported as Down on VDS 'a8f6210a-fce4-4fec-bb87-4ccddb82a232'(h4) 2018-08-15 06:31:13,776+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-68) [] START, DestroyVDSCommand(HostName = h4, DestroyVmVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmId='8471050b-7dda-466f-aecb-5b35e4aa8d2f', secondsToWait='0', gracefully='false', reason='', ignoreNoVm='true'}), log id: 7ff1c305 2018-08-15 06:31:15,026+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-68) [] FINISH, DestroyVDSCommand, log id: 7ff1c305 2018-08-15 06:31:15,026+08 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (EE-ManagedThreadFactory-engineScheduled-Thread-68) [] VM '8471050b-7dda-466f-aecb-5b35e4aa8d2f'(win10_liug) moved from 'RestoringState' --> 'Down' 2018-08-15 06:31:15,037+08 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-68) [] EVENT_ID: VM_DOWN_ERROR(119), VM win10_liug is down with error. Exit message: Wake up from hibernation failed:(<Element 'disk' at 0x7f8b8c602990>, 'source'). 2018-08-15 06:31:15,037+08 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (EE-ManagedThreadFactory-engineScheduled-Thread-68) [] add VM '8471050b-7dda-466f-aecb-5b35e4aa8d2f'(win10_liug) to rerun treatment 2018-08-15 06:31:15,047+08 ERROR [org.ovirt.engine.core.vdsbroker.monitoring.VmsMonitoring] (EE-ManagedThreadFactory-engineScheduled-Thread-68) [] Rerun VM '8471050b-7dda-466f-aecb-5b35e4aa8d2f'. Called from VDS 'h4' 2018-08-15 06:31:15,057+08 WARN [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-5872) [] EVENT_ID: USER_INITIATED_RUN_VM_FAILED(151), Failed to run VM win10_liug on Host h4. 2018-08-15 06:31:15,061+08 INFO [org.ovirt.engine.core.bll.RunVmCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [] Lock Acquired to object 'EngineLock:{exclusiveLocks='[8471050b-7dda-466f-aecb-5b35e4aa8d2f=VM]', sharedLocks=''}' 2018-08-15 06:31:15,079+08 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [] START, IsVmDuringInitiatingVDSCommand( IsVmDuringInitiatingVDSCommandParameters:{vmId='8471050b-7dda-466f-aecb-5b35e4aa8d2f'}), log id: 2e0a8a81 2018-08-15 06:31:15,079+08 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 2e0a8a81 2018-08-15 06:31:15,084+08 WARN [org.ovirt.engine.core.bll.RunVmCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [] Validation of action 'RunVm' failed for user admin@internal-authz. Reasons: VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,SCHEDULING_NO_HOSTS 2018-08-15 06:31:15,084+08 INFO [org.ovirt.engine.core.bll.RunVmCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [] Lock freed to object 'EngineLock:{exclusiveLocks='[8471050b-7dda-466f-aecb-5b35e4aa8d2f=VM]', sharedLocks=''}' 2018-08-15 06:31:15,097+08 INFO [org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [790b75cc] Lock Acquired to object 'EngineLock:{exclusiveLocks='[5b1067a8-8d10-42b4-b2ba-b5a9e316e004=DISK]', sharedLocks=''}' 2018-08-15 06:31:15,103+08 INFO [org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [790b75cc] Running command: RemoveDiskCommand internal: true. Entities affected : ID: 5b1067a8-8d10-42b4-b2ba-b5a9e316e004 Type: DiskAction group DELETE_DISK with role type USER 2018-08-15 06:31:15,115+08 INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [790b75cc] Running command: RemoveImageCommand internal: true. Entities affected : ID: de72f436-2d2f-4478-b962-fcae0070d400 Type: Storage 2018-08-15 06:31:15,167+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [790b75cc] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{storagePoolId='4e05a820-9faf-11e8-ad4e-00163e6e2f69', ignoreFailoverLimit='false', storageDomainId='de72f436-2d2f-4478-b962-fcae0070d400', imageGroupId='5b1067a8-8d10-42b4-b2ba-b5a9e316e004', postZeros='false', discard='true', forceDelete='false'}), log id: 15127276 2018-08-15 06:31:15,523+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [790b75cc] FINISH, DeleteImageGroupVDSCommand, log id: 15127276 2018-08-15 06:31:15,526+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5872) [790b75cc] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 'd74476b7-e512-4a56-ab30-dbae4ec4057a' 2018-08-15 06:31:15,526+08 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (EE-ManagedThreadFactory-engine-Thread-5872) [790b75cc] CommandMultiAsyncTasks::attachTask: Attaching task 'cef7b7dd-ea68-4fa4-9603-ff81f1105dd5' to command 'd74476b7-e512-4a56-ab30-dbae4ec4057a'. 2018-08-15 06:31:15,534+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engine-Thread-5872) [790b75cc] Adding task 'cef7b7dd-ea68-4fa4-9603-ff81f1105dd5' (Parent Command 'RemoveDisk', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet.. 2018-08-15 06:31:15,648+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5872) [790b75cc] BaseAsyncTask::startPollingTask: Starting to poll task 'cef7b7dd-ea68-4fa4-9603-ff81f1105dd5'. 2018-08-15 06:31:15,648+08 INFO [org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [790b75cc] Lock freed to object 'EngineLock:{exclusiveLocks='[5b1067a8-8d10-42b4-b2ba-b5a9e316e004=DISK]', sharedLocks=''}' 2018-08-15 06:31:15,654+08 INFO [org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [2bf8691e] Lock Acquired to object 'EngineLock:{exclusiveLocks='[8b7936b3-dc4b-4f84-b132-e57844667093=DISK]', sharedLocks=''}' 2018-08-15 06:31:15,670+08 INFO [org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [2bf8691e] Running command: RemoveDiskCommand internal: true. Entities affected : ID: 8b7936b3-dc4b-4f84-b132-e57844667093 Type: DiskAction group DELETE_DISK with role type USER 2018-08-15 06:31:15,675+08 INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [2bf8691e] Running command: RemoveImageCommand internal: true. Entities affected : ID: de72f436-2d2f-4478-b962-fcae0070d400 Type: Storage 2018-08-15 06:31:15,709+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [2bf8691e] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{storagePoolId='4e05a820-9faf-11e8-ad4e-00163e6e2f69', ignoreFailoverLimit='false', storageDomainId='de72f436-2d2f-4478-b962-fcae0070d400', imageGroupId='8b7936b3-dc4b-4f84-b132-e57844667093', postZeros='false', discard='true', forceDelete='false'}), log id: 27ee9e44 2018-08-15 06:31:19,970+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-92) [] Polling and updating Async Tasks: 1 tasks, 1 tasks to poll now 2018-08-15 06:31:21,093+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [2bf8691e] FINISH, DeleteImageGroupVDSCommand, log id: 27ee9e44 2018-08-15 06:31:21,097+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5872) [2bf8691e] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command '8bf17c42-1292-4e4d-a3e6-beeec059638f' 2018-08-15 06:31:21,097+08 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (EE-ManagedThreadFactory-engine-Thread-5872) [2bf8691e] CommandMultiAsyncTasks::attachTask: Attaching task '736f8e97-bf2e-4532-bb59-de7475f57d86' to command '8bf17c42-1292-4e4d-a3e6-beeec059638f'. 2018-08-15 06:31:21,145+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-92) [] SPMAsyncTask::PollTask: Polling task 'cef7b7dd-ea68-4fa4-9603-ff81f1105dd5' (Parent Command 'RemoveDisk', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'running'. 2018-08-15 06:31:21,145+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-92) [] Finished polling Tasks, will poll again in 10 seconds. 2018-08-15 06:31:21,145+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engine-Thread-5872) [2bf8691e] Adding task '736f8e97-bf2e-4532-bb59-de7475f57d86' (Parent Command 'RemoveDisk', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet.. 2018-08-15 06:31:21,221+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5872) [2bf8691e] BaseAsyncTask::startPollingTask: Starting to poll task '736f8e97-bf2e-4532-bb59-de7475f57d86'. 2018-08-15 06:31:21,222+08 INFO [org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand] (EE-ManagedThreadFactory-engine-Thread-5872) [2bf8691e] Lock freed to object 'EngineLock:{exclusiveLocks='[8b7936b3-dc4b-4f84-b132-e57844667093=DISK]', sharedLocks=''}' 2018-08-15 06:31:21,224+08 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-5872) [2bf8691e] EVENT_ID: USER_FAILED_RUN_VM(54), Failed to run VM win10_liug (User: admin@internal-authz). 2018-08-15 06:31:21,265+08 INFO [org.ovirt.engine.core.bll.ProcessDownVmCommand] (EE-ManagedThreadFactory-engine-Thread-5875) [60ef8c41] Running command: ProcessDownVmCommand internal: true. 2018-08-15 06:31:30,072+08 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher] (EE-ManagedThreadFactory-engineScheduled-Thread-8) [] Fetched 10 VMs from VDS 'a8f6210a-fce4-4fec-bb87-4ccddb82a232' 2018-08-15 06:31:31,145+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [] Polling and updating Async Tasks: 2 tasks, 2 tasks to poll now 2018-08-15 06:31:31,174+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [] SPMAsyncTask::PollTask: Polling task 'cef7b7dd-ea68-4fa4-9603-ff81f1105dd5' (Parent Command 'RemoveDisk', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'. 2018-08-15 06:31:31,176+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [] BaseAsyncTask::onTaskEndSuccess: Task 'cef7b7dd-ea68-4fa4-9603-ff81f1105dd5' (Parent Command 'RemoveDisk', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully. 2018-08-15 06:31:31,179+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [] CommandAsyncTask::endActionIfNecessary: All tasks of command 'd74476b7-e512-4a56-ab30-dbae4ec4057a' has ended -> executing 'endAction' 2018-08-15 06:31:31,179+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [] CommandAsyncTask::endAction: Ending action for '1' tasks (command ID: 'd74476b7-e512-4a56-ab30-dbae4ec4057a'): calling endAction '. 2018-08-15 06:31:31,180+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [] SPMAsyncTask::PollTask: Polling task '736f8e97-bf2e-4532-bb59-de7475f57d86' (Parent Command 'RemoveDisk', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'. 2018-08-15 06:31:31,180+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5876) [] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'RemoveDisk', 2018-08-15 06:31:31,181+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [] BaseAsyncTask::onTaskEndSuccess: Task '736f8e97-bf2e-4532-bb59-de7475f57d86' (Parent Command 'RemoveDisk', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully. 2018-08-15 06:31:31,183+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [] CommandAsyncTask::endActionIfNecessary: All tasks of command '8bf17c42-1292-4e4d-a3e6-beeec059638f' has ended -> executing 'endAction' 2018-08-15 06:31:31,183+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-16) [] CommandAsyncTask::endAction: Ending action for '1' tasks (command ID: '8bf17c42-1292-4e4d-a3e6-beeec059638f'): calling endAction '. 2018-08-15 06:31:31,183+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5877) [] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'RemoveDisk', 2018-08-15 06:31:31,185+08 INFO [org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand] (EE-ManagedThreadFactory-engine-Thread-5876) [790b75cc] Ending command 'org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand' successfully. 2018-08-15 06:31:31,188+08 INFO [org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand] (EE-ManagedThreadFactory-engine-Thread-5877) [2bf8691e] Ending command 'org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand' successfully. 2018-08-15 06:31:31,190+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5876) [790b75cc] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'RemoveDisk' completed, handling the result. 2018-08-15 06:31:31,190+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5876) [790b75cc] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'RemoveDisk' succeeded, clearing tasks. 2018-08-15 06:31:31,190+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5876) [790b75cc] SPMAsyncTask::ClearAsyncTask: Attempting to clear task 'cef7b7dd-ea68-4fa4-9603-ff81f1105dd5' 2018-08-15 06:31:31,190+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5876) [790b75cc] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{storagePoolId='4e05a820-9faf-11e8-ad4e-00163e6e2f69', ignoreFailoverLimit='false', taskId='cef7b7dd-ea68-4fa4-9603-ff81f1105dd5'}), log id: 17450a43 2018-08-15 06:31:31,191+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5877) [2bf8691e] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'RemoveDisk' completed, handling the result. 2018-08-15 06:31:31,191+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5877) [2bf8691e] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'RemoveDisk' succeeded, clearing tasks. 2018-08-15 06:31:31,191+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5877) [2bf8691e] SPMAsyncTask::ClearAsyncTask: Attempting to clear task '736f8e97-bf2e-4532-bb59-de7475f57d86' 2018-08-15 06:31:31,191+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5876) [790b75cc] START, HSMClearTaskVDSCommand(HostName = h4, HSMTaskGuidBaseVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', taskId='cef7b7dd-ea68-4fa4-9603-ff81f1105dd5'}), log id: 817b10d 2018-08-15 06:31:31,192+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5877) [2bf8691e] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{storagePoolId='4e05a820-9faf-11e8-ad4e-00163e6e2f69', ignoreFailoverLimit='false', taskId='736f8e97-bf2e-4532-bb59-de7475f57d86'}), log id: 4eb5cbde 2018-08-15 06:31:31,198+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5876) [790b75cc] FINISH, HSMClearTaskVDSCommand, log id: 817b10d 2018-08-15 06:31:31,198+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5876) [790b75cc] FINISH, SPMClearTaskVDSCommand, log id: 17450a43 2018-08-15 06:31:31,198+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5877) [2bf8691e] START, HSMClearTaskVDSCommand(HostName = h4, HSMTaskGuidBaseVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', taskId='736f8e97-bf2e-4532-bb59-de7475f57d86'}), log id: 57b4b85e 2018-08-15 06:31:31,200+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5876) [790b75cc] BaseAsyncTask::removeTaskFromDB: Removed task 'cef7b7dd-ea68-4fa4-9603-ff81f1105dd5' from DataBase 2018-08-15 06:31:31,200+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5876) [790b75cc] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 'd74476b7-e512-4a56-ab30-dbae4ec4057a' 2018-08-15 06:31:31,203+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5877) [2bf8691e] FINISH, HSMClearTaskVDSCommand, log id: 57b4b85e 2018-08-15 06:31:31,204+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5877) [2bf8691e] FINISH, SPMClearTaskVDSCommand, log id: 4eb5cbde 2018-08-15 06:31:31,206+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5877) [2bf8691e] BaseAsyncTask::removeTaskFromDB: Removed task '736f8e97-bf2e-4532-bb59-de7475f57d86' from DataBase 2018-08-15 06:31:31,206+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-5877) [2bf8691e] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity '8bf17c42-1292-4e4d-a3e6-beeec059638f' 2018-08-15 06:31:53,480+08 INFO [org.ovirt.engine.core.bll.RunVmCommand] (default task-80) [bb8b67ea-c0fb-44ce-b7b3-3116c7c7d835] Lock Acquired to object 'EngineLock:{exclusiveLocks='[8471050b-7dda-466f-aecb-5b35e4aa8d2f=VM]', sharedLocks=''}' 2018-08-15 06:31:53,502+08 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (default task-80) [bb8b67ea-c0fb-44ce-b7b3-3116c7c7d835] START, IsVmDuringInitiatingVDSCommand( IsVmDuringInitiatingVDSCommandParameters:{vmId='8471050b-7dda-466f-aecb-5b35e4aa8d2f'}), log id: 32034a6f 2018-08-15 06:31:53,503+08 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (default task-80) [bb8b67ea-c0fb-44ce-b7b3-3116c7c7d835] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 32034a6f 2018-08-15 06:31:53,546+08 INFO [org.ovirt.engine.core.bll.RunVmCommand] (EE-ManagedThreadFactory-engine-Thread-5882) [bb8b67ea-c0fb-44ce-b7b3-3116c7c7d835] Running command: RunVmCommand internal: false. Entities affected : ID: 8471050b-7dda-466f-aecb-5b35e4aa8d2f Type: VMAction group RUN_VM with role type USER 2018-08-15 06:31:53,573+08 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5882) [bb8b67ea-c0fb-44ce-b7b3-3116c7c7d835] START, UpdateVmDynamicDataVDSCommand( UpdateVmDynamicDataVDSCommandParameters:{hostId='null', vmId='8471050b-7dda-466f-aecb-5b35e4aa8d2f', vmDynamic='org.ovirt.engine.core.common.businessentities.VmDynamic@3a1e1008'}), log id: 6ae1eac3 2018-08-15 06:31:53,575+08 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5882) [bb8b67ea-c0fb-44ce-b7b3-3116c7c7d835] FINISH, UpdateVmDynamicDataVDSCommand, log id: 6ae1eac3 2018-08-15 06:31:53,577+08 INFO [org.ovirt.engine.core.vdsbroker.CreateVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5882) [bb8b67ea-c0fb-44ce-b7b3-3116c7c7d835] START, CreateVDSCommand( CreateVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmId='8471050b-7dda-466f-aecb-5b35e4aa8d2f', vm='VM [win10_liug]'}), log id: 22f8dbb6 2018-08-15 06:31:53,578+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5882) [bb8b67ea-c0fb-44ce-b7b3-3116c7c7d835] START, CreateBrokerVDSCommand(HostName = h4, CreateVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmId='8471050b-7dda-466f-aecb-5b35e4aa8d2f', vm='VM [win10_liug]'}), log id: 1edb8509 2018-08-15 06:31:53,588+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5882) [bb8b67ea-c0fb-44ce-b7b3-3116c7c7d835] VM <?xml version="1.0" encoding="UTF-8"?><domain type="kvm" xmlns:ovirt-tune="http://ovirt.org/vm/tune/1.0" xmlns:ovirt-vm="http://ovirt.org/vm/1.0"> <name>win10_liug</name> <uuid>8471050b-7dda-466f-aecb-5b35e4aa8d2f</uuid> <memory>3145728</memory> <currentMemory>3145728</currentMemory> <iothreads>1</iothreads> <maxMemory slots="16">12582912</maxMemory> <vcpu current="2">16</vcpu> <sysinfo type="smbios"> <system> <entry name="manufacturer">oVirt</entry> <entry name="product">OS-NAME:</entry> <entry name="version">OS-VERSION:</entry> <entry name="serial">HOST-SERIAL:</entry> <entry name="uuid">8471050b-7dda-466f-aecb-5b35e4aa8d2f</entry> </system> </sysinfo> <clock offset="variable" adjustment="3600"> <timer name="hypervclock" present="yes"/> <timer name="rtc" tickpolicy="catchup"/> <timer name="pit" tickpolicy="delay"/> <timer name="hpet" present="no"/> </clock> <features> <acpi/> <hyperv> <relaxed state="on"/> <vapic state="on"/> <spinlocks state="on" retries="8191"/> </hyperv> </features> <cpu match="exact"> <model>Haswell</model> <topology cores="1" threads="1" sockets="16"/> <numa> <cell id="0" cpus="0,1" memory="3145728"/> </numa> </cpu> <cputune/> <devices> <input type="tablet" bus="usb"/> <channel type="unix"> <target type="virtio" name="ovirt-guest-agent.0"/> <source mode="bind" path="/var/lib/libvirt/qemu/channels/8471050b-7dda-466f-aecb-5b35e4aa8d2f.ovirt-guest-agent.0"/> </channel> <channel type="unix"> <target type="virtio" name="org.qemu.guest_agent.0"/> <source mode="bind" path="/var/lib/libvirt/qemu/channels/8471050b-7dda-466f-aecb-5b35e4aa8d2f.org.qemu.guest_agent.0"/> </channel> <controller type="scsi" model="virtio-scsi" index="0"> <driver iothread="1"/> <alias name="ua-03e3abbd-cf49-4f89-9d70-e44c15a54e57"/> <address bus="0x00" domain="0x0000" function="0x0" slot="0x04" type="pci"/> </controller> <video> <model type="qxl" vram="8192" heads="1" ram="65536" vgamem="16384"/> <alias name="ua-0e78fe1f-decf-4f70-a623-d70f533556a5"/> <address bus="0x00" domain="0x0000" function="0x0" slot="0x02" type="pci"/> </video> <controller type="usb" model="piix3-uhci" index="0"> <address bus="0x00" domain="0x0000" function="0x2" slot="0x01" type="pci"/> </controller> <graphics type="vnc" port="-1" autoport="yes" passwd="*****" passwdValidTo="1970-01-01T00:00:01" keymap="en-us"> <listen type="network" network="vdsm-wan"/> </graphics> <controller type="ide"> <address bus="0x00" domain="0x0000" function="0x1" slot="0x01" type="pci"/> </controller> <controller type="virtio-serial" index="0" ports="16"> <alias name="ua-c97f1593-773c-4f30-be1e-0f7dc12fca1b"/> <address bus="0x00" domain="0x0000" function="0x0" slot="0x05" type="pci"/> </controller> <rng model="virtio"> <backend model="random">/dev/urandom</backend> <alias name="ua-e6cbd1fb-394d-467b-9c35-0636fbe07faf"/> </rng> <memballoon model="none"/> <interface type="bridge"> <model type="virtio"/> <link state="up"/> <source bridge="tvlan2870"/> <driver queues="2" name="vhost"/> <alias name="ua-44bae05b-6547-4f70-b66f-f6e1b70089e2"/> <address bus="0x00" domain="0x0000" function="0x0" slot="0x03" type="pci"/> <mac address="00:1a:4a:16:01:17"/> <mtu size="1500"/> <filterref filter="vdsm-no-mac-spoofing"/> <bandwidth/> </interface> <disk type="file" device="cdrom" snapshot="no"> <driver name="qemu" type="raw" error_policy="report"/> <source file="" startupPolicy="optional"/> <target dev="hdc" bus="ide"/> <readonly/> <alias name="ua-2f925984-53c1-41c3-8878-6f02bc495c62"/> <address bus="1" controller="0" unit="0" type="drive" target="0"/> </disk> <disk snapshot="no" type="block" device="disk"> <target dev="sda" bus="scsi"/> <source dev="/rhev/data-center/mnt/blockSD/de72f436-2d2f-4478-b962-fcae0070d400/images/0348e1f1-ed58-48ea-ae07-f5177f59b48c/7517e930-673e-49b3-9901-81bce3f94375"/> <driver name="qemu" io="native" type="qcow2" error_policy="stop" cache="none"/> <alias name="ua-0348e1f1-ed58-48ea-ae07-f5177f59b48c"/> <address bus="0" controller="0" unit="0" type="drive" target="0"/> <boot order="1"/> <serial>0348e1f1-ed58-48ea-ae07-f5177f59b48c</serial> </disk> </devices> <pm> <suspend-to-disk enabled="no"/> <suspend-to-mem enabled="no"/> </pm> <os> <type arch="x86_64" machine="pc-i440fx-rhel7.3.0">hvm</type> <smbios mode="sysinfo"/> </os> <metadata> <ovirt-tune:qos/> <ovirt-vm:vm> <minGuaranteedMemoryMb type="int">3072</minGuaranteedMemoryMb> <clusterVersion>4.2</clusterVersion> <ovirt-vm:custom/> <ovirt-vm:device mac_address="00:1a:4a:16:01:17"> <ovirt-vm:custom/> </ovirt-vm:device> <ovirt-vm:device devtype="disk" name="sda"> <ovirt-vm:poolID>4e05a820-9faf-11e8-ad4e-00163e6e2f69</ovirt-vm:poolID> <ovirt-vm:volumeID>7517e930-673e-49b3-9901-81bce3f94375</ovirt-vm:volumeID> <ovirt-vm:imageID>0348e1f1-ed58-48ea-ae07-f5177f59b48c</ovirt-vm:imageID> <ovirt-vm:domainID>de72f436-2d2f-4478-b962-fcae0070d400</ovirt-vm:domainID> </ovirt-vm:device> <launchPaused>false</launchPaused> <resumeBehavior>auto_resume</resumeBehavior> </ovirt-vm:vm> </metadata> </domain> 2018-08-15 06:31:53,609+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5882) [bb8b67ea-c0fb-44ce-b7b3-3116c7c7d835] FINISH, CreateBrokerVDSCommand, log id: 1edb8509 2018-08-15 06:31:53,610+08 INFO [org.ovirt.engine.core.vdsbroker.CreateVDSCommand] (EE-ManagedThreadFactory-engine-Thread-5882) [bb8b67ea-c0fb-44ce-b7b3-3116c7c7d835] FINISH, CreateVDSCommand, return: WaitForLaunch, log id: 22f8dbb6 2018-08-15 06:31:53,611+08 INFO [org.ovirt.engine.core.bll.RunVmCommand] (EE-ManagedThreadFactory-engine-Thread-5882) [bb8b67ea-c0fb-44ce-b7b3-3116c7c7d835] Lock freed to object 'EngineLock:{exclusiveLocks='[8471050b-7dda-466f-aecb-5b35e4aa8d2f=VM]', sharedLocks=''}' 2018-08-15 06:31:53,615+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-5882) [bb8b67ea-c0fb-44ce-b7b3-3116c7c7d835] EVENT_ID: USER_STARTED_VM(153), VM win10_liug was started by admin@internal-authz (Host: h4). 2018-08-15 06:32:00,145+08 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher] (EE-ManagedThreadFactory-engineScheduled-Thread-14) [] Fetched 11 VMs from VDS 'a8f6210a-fce4-4fec-bb87-4ccddb82a232' 2018-08-15 06:32:00,147+08 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (EE-ManagedThreadFactory-engineScheduled-Thread-14) [] VM '8471050b-7dda-466f-aecb-5b35e4aa8d2f'(win10_liug) moved from 'WaitForLaunch' --> 'PoweringUp' 2018-08-15 06:32:00,163+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DumpXmlsVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-14) [] START, DumpXmlsVDSCommand(HostName = h4, Params:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmIds='[8471050b-7dda-466f-aecb-5b35e4aa8d2f]'}), log id: 7ade4bb7 2018-08-15 06:32:00,188+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DumpXmlsVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-14) [] FINISH, DumpXmlsVDSCommand, return: [{vmId=8471050b-7dda-466f-aecb-5b35e4aa8d2f, devices=[Ljava.util.Map;@3ce7f1f8, guestDiskMapping={}}], log id: 7ade4bb7 2018-08-15 06:32:09,427+08 INFO [org.ovirt.engine.core.bll.SetVmTicketCommand] (default task-80) [249eec9d] Running command: SetVmTicketCommand internal: false. Entities affected : ID: 8471050b-7dda-466f-aecb-5b35e4aa8d2f Type: VMAction group CONNECT_TO_VM with role type USER 2018-08-15 06:32:09,437+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (default task-80) [249eec9d] START, SetVmTicketVDSCommand(HostName = h4, SetVmTicketVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmId='8471050b-7dda-466f-aecb-5b35e4aa8d2f', protocol='VNC', ticket='5gnaNySkYhdh', validTime='120', userName='admin', userId='6303e0de-9faf-11e8-b20b-00163e6e2f69', disconnectAction='NONE'}), log id: 7e378132 2018-08-15 06:32:09,464+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (default task-80) [249eec9d] FINISH, SetVmTicketVDSCommand, log id: 7e378132 2018-08-15 06:32:09,476+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-80) [249eec9d] EVENT_ID: VM_SET_TICKET(164), User admin@internal-authz initiated console session for VM win10_liug 2018-08-15 06:32:15,233+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-54) [] EVENT_ID: VM_CONSOLE_CONNECTED(167), User admin@internal-authz is connected to VM win10_liug. 2018-08-15 06:32:41,605+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-7) [] Setting new tasks map. The map contains now 0 tasks 2018-08-15 06:32:41,605+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-7) [] Cleared all tasks of pool '4e05a820-9faf-11e8-ad4e-00163e6e2f69'. 2018-08-15 06:32:43,584+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-90) [5c45e79d] Lock Acquired to object 'EngineLock:{exclusiveLocks='[182dd9de-fbd0-432a-992f-ea3cf8fcb365=PROVIDER]', sharedLocks=''}' 2018-08-15 06:32:43,593+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-90) [5c45e79d] Running command: SyncNetworkProviderCommand internal: true. 2018-08-15 06:32:43,693+08 INFO [org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default task-80) [] User admin@internal successfully logged in with scopes: ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:public-authz-search ovirt-ext=token-info:validate ovirt-ext=token:password-access 2018-08-15 06:32:43,834+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-90) [5c45e79d] Lock freed to object 'EngineLock:{exclusiveLocks='[182dd9de-fbd0-432a-992f-ea3cf8fcb365=PROVIDER]', sharedLocks=''}' 2018-08-15 06:33:00,356+08 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (EE-ManagedThreadFactory-engineScheduled-Thread-67) [] VM '8471050b-7dda-466f-aecb-5b35e4aa8d2f'(win10_liug) moved from 'PoweringUp' --> 'Up' 2018-08-15 06:33:00,374+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-67) [] EVENT_ID: USER_RUN_VM(32), VM win10_liug started on Host h4 2018-08-15 06:33:30,470+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DumpXmlsVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-54) [] START, DumpXmlsVDSCommand(HostName = h4, Params:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmIds='[8471050b-7dda-466f-aecb-5b35e4aa8d2f]'}), log id: d776c77 2018-08-15 06:33:30,498+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DumpXmlsVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-54) [] FINISH, DumpXmlsVDSCommand, return: [{vmId=8471050b-7dda-466f-aecb-5b35e4aa8d2f, devices=[Ljava.util.Map;@545a3148, guestDiskMapping={0348e1f1-ed58-48ea-ae07-f5177f59b48c={name=\\.\PHYSICALDRIVE0}}}], log id: d776c77 2018-08-15 06:33:45,533+08 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (EE-ManagedThreadFactory-engineScheduled-Thread-28) [] VM '8471050b-7dda-466f-aecb-5b35e4aa8d2f'(win10_liug) moved from 'Up' --> 'RebootInProgress' 2018-08-15 06:33:45,545+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DumpXmlsVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-28) [] START, DumpXmlsVDSCommand(HostName = h4, Params:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmIds='[8471050b-7dda-466f-aecb-5b35e4aa8d2f]'}), log id: 2e501272 2018-08-15 06:33:45,567+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DumpXmlsVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-28) [] FINISH, DumpXmlsVDSCommand, return: [{vmId=8471050b-7dda-466f-aecb-5b35e4aa8d2f, devices=[Ljava.util.Map;@33ced8a9, guestDiskMapping={0348e1f1-ed58-48ea-ae07-f5177f59b48c={name=\\.\PHYSICALDRIVE0}}}], log id: 2e501272 2018-08-15 06:34:15,642+08 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [] VM '8471050b-7dda-466f-aecb-5b35e4aa8d2f'(win10_liug) moved from 'RebootInProgress' --> 'Up' 2018-08-15 06:37:04,203+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2018-08-15 06:37:04,203+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 8 threads waiting for tasks and 0 tasks in queue. 2018-08-15 06:37:04,203+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks. 2018-08-15 06:37:04,203+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2018-08-15 06:37:04,203+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads waiting for tasks. 2018-08-15 06:37:43,846+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-31) [55d07a0d] Lock Acquired to object 'EngineLock:{exclusiveLocks='[182dd9de-fbd0-432a-992f-ea3cf8fcb365=PROVIDER]', sharedLocks=''}' 2018-08-15 06:37:43,857+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-31) [55d07a0d] Running command: SyncNetworkProviderCommand internal: true. 2018-08-15 06:37:43,958+08 INFO [org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default task-80) [] User admin@internal successfully logged in with scopes: ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:public-authz-search ovirt-ext=token-info:validate ovirt-ext=token:password-access 2018-08-15 06:37:44,096+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-31) [55d07a0d] Lock freed to object 'EngineLock:{exclusiveLocks='[182dd9de-fbd0-432a-992f-ea3cf8fcb365=PROVIDER]', sharedLocks=''}' 2018-08-15 06:42:16,964+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [] EVENT_ID: VM_CONSOLE_DISCONNECTED(168), User admin@internal-authz got disconnected from VM win10_liug. 2018-08-15 06:42:44,107+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [5d4a34fa] Lock Acquired to object 'EngineLock:{exclusiveLocks='[182dd9de-fbd0-432a-992f-ea3cf8fcb365=PROVIDER]', sharedLocks=''}' 2018-08-15 06:42:44,116+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [5d4a34fa] Running command: SyncNetworkProviderCommand internal: true. 2018-08-15 06:42:44,214+08 INFO [org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default task-80) [] User admin@internal successfully logged in with scopes: ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:public-authz-search ovirt-ext=token-info:validate ovirt-ext=token:password-access 2018-08-15 06:42:44,349+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-95) [5d4a34fa] Lock freed to object 'EngineLock:{exclusiveLocks='[182dd9de-fbd0-432a-992f-ea3cf8fcb365=PROVIDER]', sharedLocks=''}' 2018-08-15 06:47:04,205+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2018-08-15 06:47:04,205+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 8 threads waiting for tasks and 0 tasks in queue. 2018-08-15 06:47:04,205+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks. 2018-08-15 06:47:04,205+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2018-08-15 06:47:04,205+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads waiting for tasks. 2018-08-15 06:47:44,361+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [17bafa6] Lock Acquired to object 'EngineLock:{exclusiveLocks='[182dd9de-fbd0-432a-992f-ea3cf8fcb365=PROVIDER]', sharedLocks=''}' 2018-08-15 06:47:44,370+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [17bafa6] Running command: SyncNetworkProviderCommand internal: true. 2018-08-15 06:47:44,474+08 INFO [org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default task-78) [] User admin@internal successfully logged in with scopes: ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:public-authz-search ovirt-ext=token-info:validate ovirt-ext=token:password-access 2018-08-15 06:47:44,614+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-83) [17bafa6] Lock freed to object 'EngineLock:{exclusiveLocks='[182dd9de-fbd0-432a-992f-ea3cf8fcb365=PROVIDER]', sharedLocks=''}' 2018-08-15 06:52:44,625+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-78) [7b835e89] Lock Acquired to object 'EngineLock:{exclusiveLocks='[182dd9de-fbd0-432a-992f-ea3cf8fcb365=PROVIDER]', sharedLocks=''}' 2018-08-15 06:52:44,635+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-78) [7b835e89] Running command: SyncNetworkProviderCommand internal: true. 2018-08-15 06:52:44,736+08 INFO [org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default task-78) [] User admin@internal successfully logged in with scopes: ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:public-authz-search ovirt-ext=token-info:validate ovirt-ext=token:password-access 2018-08-15 06:52:44,871+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-78) [7b835e89] Lock freed to object 'EngineLock:{exclusiveLocks='[182dd9de-fbd0-432a-992f-ea3cf8fcb365=PROVIDER]', sharedLocks=''}' 2018-08-15 06:55:34,112+08 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [] VM '3157ba6d-2758-4052-8d29-c3e0d2cb53eb'(win10_admin2) moved from 'RestoringState' --> 'Up' 2018-08-15 06:55:34,152+08 INFO [org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [76df397b] Lock Acquired to object 'EngineLock:{exclusiveLocks='[17ebb2d8-41d5-4a64-a5ea-5bf590cfd6a0=DISK]', sharedLocks=''}' 2018-08-15 06:55:34,158+08 INFO [org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [76df397b] Running command: RemoveDiskCommand internal: true. Entities affected : ID: 17ebb2d8-41d5-4a64-a5ea-5bf590cfd6a0 Type: DiskAction group DELETE_DISK with role type USER 2018-08-15 06:55:34,167+08 INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [76df397b] Running command: RemoveImageCommand internal: true. Entities affected : ID: de72f436-2d2f-4478-b962-fcae0070d400 Type: Storage 2018-08-15 06:55:34,229+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [76df397b] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{storagePoolId='4e05a820-9faf-11e8-ad4e-00163e6e2f69', ignoreFailoverLimit='false', storageDomainId='de72f436-2d2f-4478-b962-fcae0070d400', imageGroupId='17ebb2d8-41d5-4a64-a5ea-5bf590cfd6a0', postZeros='false', discard='true', forceDelete='false'}), log id: 28ff18fa 2018-08-15 06:55:34,638+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [76df397b] FINISH, DeleteImageGroupVDSCommand, log id: 28ff18fa 2018-08-15 06:55:34,643+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [76df397b] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 'ce446e26-f697-4790-b687-c7d982e6dfac' 2018-08-15 06:55:34,643+08 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [76df397b] CommandMultiAsyncTasks::attachTask: Attaching task 'e974dc8e-1886-4775-bcc9-eebb13f96e06' to command 'ce446e26-f697-4790-b687-c7d982e6dfac'. 2018-08-15 06:55:34,652+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [76df397b] Adding task 'e974dc8e-1886-4775-bcc9-eebb13f96e06' (Parent Command 'RemoveDisk', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet.. 2018-08-15 06:55:34,909+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [76df397b] BaseAsyncTask::startPollingTask: Starting to poll task 'e974dc8e-1886-4775-bcc9-eebb13f96e06'. 2018-08-15 06:55:34,909+08 INFO [org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [76df397b] Lock freed to object 'EngineLock:{exclusiveLocks='[17ebb2d8-41d5-4a64-a5ea-5bf590cfd6a0=DISK]', sharedLocks=''}' 2018-08-15 06:55:34,936+08 INFO [org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [458258e0] Lock Acquired to object 'EngineLock:{exclusiveLocks='[7e9152b6-3780-4ad9-bb79-1f8bb8df304e=DISK]', sharedLocks=''}' 2018-08-15 06:55:34,968+08 INFO [org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [458258e0] Running command: RemoveDiskCommand internal: true. Entities affected : ID: 7e9152b6-3780-4ad9-bb79-1f8bb8df304e Type: DiskAction group DELETE_DISK with role type USER 2018-08-15 06:55:34,978+08 INFO [org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [458258e0] Running command: RemoveImageCommand internal: true. Entities affected : ID: de72f436-2d2f-4478-b962-fcae0070d400 Type: Storage 2018-08-15 06:55:35,042+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [458258e0] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{storagePoolId='4e05a820-9faf-11e8-ad4e-00163e6e2f69', ignoreFailoverLimit='false', storageDomainId='de72f436-2d2f-4478-b962-fcae0070d400', imageGroupId='7e9152b6-3780-4ad9-bb79-1f8bb8df304e', postZeros='false', discard='true', forceDelete='false'}), log id: 688109a6 2018-08-15 06:55:38,714+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [458258e0] FINISH, DeleteImageGroupVDSCommand, log id: 688109a6 2018-08-15 06:55:38,720+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [458258e0] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 'fc92f2a7-b204-4360-be81-38b135ecaf3b' 2018-08-15 06:55:38,720+08 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [458258e0] CommandMultiAsyncTasks::attachTask: Attaching task '14346b3c-641e-4b49-99e7-bb47311c3e18' to command 'fc92f2a7-b204-4360-be81-38b135ecaf3b'. 2018-08-15 06:55:38,728+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [458258e0] Adding task '14346b3c-641e-4b49-99e7-bb47311c3e18' (Parent Command 'RemoveDisk', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet.. 2018-08-15 06:55:38,864+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [458258e0] BaseAsyncTask::startPollingTask: Starting to poll task '14346b3c-641e-4b49-99e7-bb47311c3e18'. 2018-08-15 06:55:38,865+08 INFO [org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [458258e0] Lock freed to object 'EngineLock:{exclusiveLocks='[7e9152b6-3780-4ad9-bb79-1f8bb8df304e=DISK]', sharedLocks=''}' 2018-08-15 06:55:38,902+08 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [458258e0] EVENT_ID: USER_RUN_VM(32), VM win10_admin2 started on Host h4 2018-08-15 06:55:38,906+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DumpXmlsVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [458258e0] START, DumpXmlsVDSCommand(HostName = h4, Params:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', vmIds='[3157ba6d-2758-4052-8d29-c3e0d2cb53eb]'}), log id: 5adda8f0 2018-08-15 06:55:38,934+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DumpXmlsVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-77) [458258e0] FINISH, DumpXmlsVDSCommand, return: [{vmId=3157ba6d-2758-4052-8d29-c3e0d2cb53eb, devices=[Ljava.util.Map;@69175c3f, guestDiskMapping={4ee5bb0d-6b51-43d0-a398-665ec9d0abdf={name=\\.\PHYSICALDRIVE0}}}], log id: 5adda8f0 2018-08-15 06:55:41,200+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-49) [] Polling and updating Async Tasks: 2 tasks, 2 tasks to poll now 2018-08-15 06:55:41,207+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-49) [] SPMAsyncTask::PollTask: Polling task 'e974dc8e-1886-4775-bcc9-eebb13f96e06' (Parent Command 'RemoveDisk', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'. 2018-08-15 06:55:41,209+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-49) [] BaseAsyncTask::onTaskEndSuccess: Task 'e974dc8e-1886-4775-bcc9-eebb13f96e06' (Parent Command 'RemoveDisk', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully. 2018-08-15 06:55:41,212+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-49) [] CommandAsyncTask::endActionIfNecessary: All tasks of command 'ce446e26-f697-4790-b687-c7d982e6dfac' has ended -> executing 'endAction' 2018-08-15 06:55:41,212+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-49) [] CommandAsyncTask::endAction: Ending action for '1' tasks (command ID: 'ce446e26-f697-4790-b687-c7d982e6dfac'): calling endAction '. 2018-08-15 06:55:41,212+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-49) [] SPMAsyncTask::PollTask: Polling task '14346b3c-641e-4b49-99e7-bb47311c3e18' (Parent Command 'RemoveDisk', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'. 2018-08-15 06:55:41,212+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-6079) [] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'RemoveDisk', 2018-08-15 06:55:41,214+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-49) [] BaseAsyncTask::onTaskEndSuccess: Task '14346b3c-641e-4b49-99e7-bb47311c3e18' (Parent Command 'RemoveDisk', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully. 2018-08-15 06:55:41,216+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-49) [] CommandAsyncTask::endActionIfNecessary: All tasks of command 'fc92f2a7-b204-4360-be81-38b135ecaf3b' has ended -> executing 'endAction' 2018-08-15 06:55:41,216+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engineScheduled-Thread-49) [] CommandAsyncTask::endAction: Ending action for '1' tasks (command ID: 'fc92f2a7-b204-4360-be81-38b135ecaf3b'): calling endAction '. 2018-08-15 06:55:41,216+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-6080) [] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'RemoveDisk', 2018-08-15 06:55:41,219+08 INFO [org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand] (EE-ManagedThreadFactory-engine-Thread-6079) [76df397b] Ending command 'org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand' successfully. 2018-08-15 06:55:41,221+08 INFO [org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand] (EE-ManagedThreadFactory-engine-Thread-6080) [458258e0] Ending command 'org.ovirt.engine.core.bll.storage.disk.RemoveDiskCommand' successfully. 2018-08-15 06:55:41,222+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-6079) [76df397b] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'RemoveDisk' completed, handling the result. 2018-08-15 06:55:41,222+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-6079) [76df397b] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'RemoveDisk' succeeded, clearing tasks. 2018-08-15 06:55:41,222+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-6079) [76df397b] SPMAsyncTask::ClearAsyncTask: Attempting to clear task 'e974dc8e-1886-4775-bcc9-eebb13f96e06' 2018-08-15 06:55:41,223+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-6079) [76df397b] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{storagePoolId='4e05a820-9faf-11e8-ad4e-00163e6e2f69', ignoreFailoverLimit='false', taskId='e974dc8e-1886-4775-bcc9-eebb13f96e06'}), log id: 1b657619 2018-08-15 06:55:41,223+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-6080) [458258e0] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'RemoveDisk' completed, handling the result. 2018-08-15 06:55:41,223+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-6080) [458258e0] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'RemoveDisk' succeeded, clearing tasks. 2018-08-15 06:55:41,224+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-6080) [458258e0] SPMAsyncTask::ClearAsyncTask: Attempting to clear task '14346b3c-641e-4b49-99e7-bb47311c3e18' 2018-08-15 06:55:41,224+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-6079) [76df397b] START, HSMClearTaskVDSCommand(HostName = h4, HSMTaskGuidBaseVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', taskId='e974dc8e-1886-4775-bcc9-eebb13f96e06'}), log id: 51e0254e 2018-08-15 06:55:41,224+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-6080) [458258e0] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{storagePoolId='4e05a820-9faf-11e8-ad4e-00163e6e2f69', ignoreFailoverLimit='false', taskId='14346b3c-641e-4b49-99e7-bb47311c3e18'}), log id: 43b9a09b 2018-08-15 06:55:41,230+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-6079) [76df397b] FINISH, HSMClearTaskVDSCommand, log id: 51e0254e 2018-08-15 06:55:41,230+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-6079) [76df397b] FINISH, SPMClearTaskVDSCommand, log id: 1b657619 2018-08-15 06:55:41,231+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-6080) [458258e0] START, HSMClearTaskVDSCommand(HostName = h4, HSMTaskGuidBaseVDSCommandParameters:{hostId='a8f6210a-fce4-4fec-bb87-4ccddb82a232', taskId='14346b3c-641e-4b49-99e7-bb47311c3e18'}), log id: d0e78fd 2018-08-15 06:55:41,233+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-6079) [76df397b] BaseAsyncTask::removeTaskFromDB: Removed task 'e974dc8e-1886-4775-bcc9-eebb13f96e06' from DataBase 2018-08-15 06:55:41,233+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-6079) [76df397b] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 'ce446e26-f697-4790-b687-c7d982e6dfac' 2018-08-15 06:55:41,236+08 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-6080) [458258e0] FINISH, HSMClearTaskVDSCommand, log id: d0e78fd 2018-08-15 06:55:41,236+08 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (EE-ManagedThreadFactory-engine-Thread-6080) [458258e0] FINISH, SPMClearTaskVDSCommand, log id: 43b9a09b 2018-08-15 06:55:41,239+08 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedThreadFactory-engine-Thread-6080) [458258e0] BaseAsyncTask::removeTaskFromDB: Removed task '14346b3c-641e-4b49-99e7-bb47311c3e18' from DataBase 2018-08-15 06:55:41,239+08 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (EE-ManagedThreadFactory-engine-Thread-6080) [458258e0] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 'fc92f2a7-b204-4360-be81-38b135ecaf3b' 2018-08-15 06:56:41,612+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-5) [] Setting new tasks map. The map contains now 0 tasks 2018-08-15 06:56:41,612+08 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (EE-ManagedThreadFactory-engineScheduled-Thread-5) [] Cleared all tasks of pool '4e05a820-9faf-11e8-ad4e-00163e6e2f69'. 2018-08-15 06:57:04,207+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'default' is using 0 threads out of 1, 5 threads waiting for tasks. 2018-08-15 06:57:04,207+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engine' is using 0 threads out of 500, 8 threads waiting for tasks and 0 tasks in queue. 2018-08-15 06:57:04,207+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineScheduled' is using 0 threads out of 100, 100 threads waiting for tasks. 2018-08-15 06:57:04,207+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'engineThreadMonitoring' is using 1 threads out of 1, 0 threads waiting for tasks. 2018-08-15 06:57:04,207+08 INFO [org.ovirt.engine.core.bll.utils.ThreadPoolMonitoringService] (EE-ManagedThreadFactory-engineThreadMonitoring-Thread-1) [] Thread pool 'hostUpdatesChecker' is using 0 threads out of 5, 1 threads waiting for tasks. 2018-08-15 06:57:44,883+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-44) [7fe2887a] Lock Acquired to object 'EngineLock:{exclusiveLocks='[182dd9de-fbd0-432a-992f-ea3cf8fcb365=PROVIDER]', sharedLocks=''}' 2018-08-15 06:57:44,892+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-44) [7fe2887a] Running command: SyncNetworkProviderCommand internal: true. 2018-08-15 06:57:44,996+08 INFO [org.ovirt.engine.core.sso.utils.AuthenticationUtils] (default task-78) [] User admin@internal successfully logged in with scopes: ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:public-authz-search ovirt-ext=token-info:validate ovirt-ext=token:password-access 2018-08-15 06:57:45,199+08 INFO [org.ovirt.engine.core.bll.provider.network.SyncNetworkProviderCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-44) [7fe2887a] Lock freed to object 'EngineLock:{exclusiveLocks='[182dd9de-fbd0-432a-992f-ea3cf8fcb365=PROVIDER]', sharedLocks=''}' _______________________________________________ Users mailing list -- users@ovirt.org To unsubscribe send an email to users-le...@ovirt.org Privacy Statement: https://www.ovirt.org/site/privacy-policy/ oVirt Code of Conduct: https://www.ovirt.org/community/about/community-guidelines/ List Archives: https://lists.ovirt.org/archives/list/users@ovirt.org/message/6U6O44URNJCXMIMFNZBWP7K4UQF34RG7/