2018-06-27 16:19:18,550+02 INFO  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand] (default task-3) [73adb039-22cc-47b5-9d0f-3620a12df43f] Lock Acquired to object 'EngineLock:{exclusiveLocks='[4a8c9902-f9ab-490f-b1dd-82d9aee63b5f=VM]', sharedLocks=''}'
2018-06-27 16:19:19,186+02 INFO  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand] (EE-ManagedThreadFactory-engine-Thread-22973) [73adb039-22cc-47b5-9d0f-3620a12df43f] Running command: CreateSnapshotForVmCommand internal: false. Entities affected :  ID: 4a8c9902-f9ab-490f-b1dd-82d9aee63b5f Type: VMAction group MANIPULATE_VM_SNAPSHOTS with role type USER
2018-06-27 16:19:19,208+02 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-22973) [73adb039-22cc-47b5-9d0f-3620a12df43f] EVENT_ID: FREEZE_VM_INITIATED(10,766), Freeze of guest filesystems on VM ovirt-test01.srv was initiated.
2018-06-27 16:19:19,209+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FreezeVDSCommand] (EE-ManagedThreadFactory-engine-Thread-22973) [73adb039-22cc-47b5-9d0f-3620a12df43f] START, FreezeVDSCommand(HostName = ov-test-04-01, VdsAndVmIDVDSParametersBase:{hostId='d8794e95-3f89-4b1a-9bec-12ccf6db0cb1', vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f'}), log id: 2d55f627
2018-06-27 16:19:19,259+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FreezeVDSCommand] (EE-ManagedThreadFactory-engine-Thread-22973) [73adb039-22cc-47b5-9d0f-3620a12df43f] FINISH, FreezeVDSCommand, log id: 2d55f627
2018-06-27 16:19:19,262+02 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-22973) [73adb039-22cc-47b5-9d0f-3620a12df43f] EVENT_ID: FREEZE_VM_SUCCESS(10,767), Guest filesystems on VM ovirt-test01.srv have been frozen successfully.
2018-06-27 16:19:19,292+02 INFO  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotDiskCommand] (EE-ManagedThreadFactory-engine-Thread-22973) [73adb039-22cc-47b5-9d0f-3620a12df43f] Running command: CreateSnapshotDiskCommand internal: true. Entities affected :  ID: 4a8c9902-f9ab-490f-b1dd-82d9aee63b5f Type: VMAction group MANIPULATE_VM_SNAPSHOTS with role type USER
2018-06-27 16:19:19,359+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.CreateCinderSnapshotCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-10) [73adb039-22cc-47b5-9d0f-3620a12df43f] Running command: CreateCinderSnapshotCommand internal: true. Entities affected :  ID: e97009e5-c712-4199-9664-572eaba268dc Type: StorageAction group CONFIGURE_VM_STORAGE with role type USER
2018-06-27 16:19:20,228+02 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-22973) [] EVENT_ID: USER_CREATE_SNAPSHOT(45), Snapshot 'disk1_snap' creation for VM 'ovirt-test01.srv' was initiated by admin@internal-authz.
2018-06-27 16:19:22,322+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.CreateCinderSnapshotCommandCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-96) [73adb039-22cc-47b5-9d0f-3620a12df43f] Command 'CreateCinderSnapshot' id: 'e4561612-d000-47f3-980e-1c05ed813f88' child commands '[]' executions were completed, status 'SUCCEEDED'
2018-06-27 16:19:22,322+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.CreateCinderSnapshotCommandCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-96) [73adb039-22cc-47b5-9d0f-3620a12df43f] Command 'CreateCinderSnapshot' id: 'e4561612-d000-47f3-980e-1c05ed813f88' Updating status to 'SUCCEEDED', The command end method logic will be executed by one of its parent commands.
2018-06-27 16:19:22,332+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-96) [73adb039-22cc-47b5-9d0f-3620a12df43f] Command 'CreateSnapshotDisk' id: '378e2ffc-352b-4318-b34b-6c46a7fc15d8' child commands '[e4561612-d000-47f3-980e-1c05ed813f88]' executions were completed, status 'SUCCEEDED'
2018-06-27 16:19:22,332+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-96) [73adb039-22cc-47b5-9d0f-3620a12df43f] Command 'CreateSnapshotDisk' id: '378e2ffc-352b-4318-b34b-6c46a7fc15d8' Updating status to 'SUCCEEDED', The command end method logic will be executed by one of its parent commands.
2018-06-27 16:19:22,475+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-96) [73adb039-22cc-47b5-9d0f-3620a12df43f] START, SnapshotVDSCommand(HostName = ov-test-04-01, SnapshotVDSCommandParameters:{hostId='d8794e95-3f89-4b1a-9bec-12ccf6db0cb1', vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f'}), log id: 156534fb
2018-06-27 16:19:22,486+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-96) [73adb039-22cc-47b5-9d0f-3620a12df43f] Failed in 'SnapshotVDS' method
2018-06-27 16:19:22,489+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-96) [73adb039-22cc-47b5-9d0f-3620a12df43f] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM ov-test-04-01 command SnapshotVDS failed: Snapshot failed
2018-06-27 16:19:22,489+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-96) [73adb039-22cc-47b5-9d0f-3620a12df43f] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand' return value 'StatusOnlyReturn [status=Status [code=48, message=Snapshot failed]]'
2018-06-27 16:19:22,489+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-96) [73adb039-22cc-47b5-9d0f-3620a12df43f] HostName = ov-test-04-01
2018-06-27 16:19:22,489+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-96) [73adb039-22cc-47b5-9d0f-3620a12df43f] Command 'SnapshotVDSCommand(HostName = ov-test-04-01, SnapshotVDSCommandParameters:{hostId='d8794e95-3f89-4b1a-9bec-12ccf6db0cb1', vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f'})' execution failed: VDSGenericException: VDSErrorException: Failed to SnapshotVDS, error = Snapshot failed, code = 48
2018-06-27 16:19:22,489+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-96) [73adb039-22cc-47b5-9d0f-3620a12df43f] FINISH, SnapshotVDSCommand, log id: 156534fb
2018-06-27 16:19:22,501+02 WARN  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-96) [73adb039-22cc-47b5-9d0f-3620a12df43f] Could not perform live snapshot due to error, VM will still be configured to the new created snapshot: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to SnapshotVDS, error = Snapshot failed, code = 48 (Failed with error SNAPSHOT_FAILED and code 48)
2018-06-27 16:19:22,518+02 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-96) [73adb039-22cc-47b5-9d0f-3620a12df43f] EVENT_ID: USER_CREATE_LIVE_SNAPSHOT_FINISHED_FAILURE(170), Failed to create live snapshot 'disk1_snap' for VM 'ovirt-test01.srv'. VM restart is recommended. Note that using the created snapshot might cause data inconsistency.
2018-06-27 16:19:23,713+02 ERROR [org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-55) [73adb039-22cc-47b5-9d0f-3620a12df43f] Ending command 'org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand' with failure.
2018-06-27 16:19:23,722+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ThawVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-55) [73adb039-22cc-47b5-9d0f-3620a12df43f] START, ThawVDSCommand(HostName = ov-test-04-01, VdsAndVmIDVDSParametersBase:{hostId='d8794e95-3f89-4b1a-9bec-12ccf6db0cb1', vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f'}), log id: 7ffc6ee7
2018-06-27 16:19:23,732+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ThawVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-55) [73adb039-22cc-47b5-9d0f-3620a12df43f] FINISH, ThawVDSCommand, log id: 7ffc6ee7
2018-06-27 16:19:23,741+02 ERROR [org.ovirt.engine.core.bll.snapshots.CreateSnapshotDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-55) [73adb039-22cc-47b5-9d0f-3620a12df43f] Ending command 'org.ovirt.engine.core.bll.snapshots.CreateSnapshotDiskCommand' with failure.
2018-06-27 16:19:23,747+02 ERROR [org.ovirt.engine.core.bll.storage.disk.cinder.CreateCinderSnapshotCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-55) [73adb039-22cc-47b5-9d0f-3620a12df43f] Ending command 'org.ovirt.engine.core.bll.storage.disk.cinder.CreateCinderSnapshotCommand' with failure.
2018-06-27 16:19:23,834+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.RemoveCinderDiskVolumeCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [278e24e2-a9b1-4d46-aec7-415459b702ab] Running command: RemoveCinderDiskVolumeCommand internal: true. Entities affected :  ID: 00000000-0000-0000-0000-000000000000 Type: Storage
2018-06-27 16:19:24,461+02 INFO  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-55) [] Lock freed to object 'EngineLock:{exclusiveLocks='[4a8c9902-f9ab-490f-b1dd-82d9aee63b5f=VM]', sharedLocks=''}'
2018-06-27 16:19:24,467+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-55) [] EVENT_ID: USER_CREATE_SNAPSHOT_FINISHED_FAILURE(69), Failed to complete snapshot 'disk1_snap' creation for VM 'ovirt-test01.srv'.
2018-06-27 16:19:24,468+02 WARN  [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-55) [] Command 'CreateSnapshotForVm' id: 'b32848a3-f850-4862-bd18-d9f4da21453f' end method execution failed, as the command isn't marked for endAction() retries silently ignoring
2018-06-27 16:19:25,989+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.CinderBroker] (EE-ManagedThreadFactory-engineScheduled-Thread-61) [278e24e2-a9b1-4d46-aec7-415459b702ab] Snapshot does not exists
2018-06-27 16:19:25,989+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.RemoveCinderDiskVolumeCommandCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-61) [278e24e2-a9b1-4d46-aec7-415459b702ab] Command 'RemoveCinderDiskVolume' id: '36d96456-ba8d-41d2-a333-eb1e1522a920' child commands '[]' executions were completed, status 'SUCCEEDED'
2018-06-27 16:19:26,019+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.RemoveCinderDiskVolumeCommandCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-61) [278e24e2-a9b1-4d46-aec7-415459b702ab] Image status could not be provided since the cinder image might have already been removed from Cinder.
2018-06-27 16:19:27,036+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.RemoveCinderDiskVolumeCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-18) [278e24e2-a9b1-4d46-aec7-415459b702ab] Ending command 'org.ovirt.engine.core.bll.storage.disk.cinder.RemoveCinderDiskVolumeCommand' successfully.