Attachment 1455487 Details for Bug 1596619 – engine log

engine log

cinder_snapshot_bug.txt (text/plain), 12.08 KB, created by matthias.leopold on 2018-06-29 09:58:55 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: matthias.leopold

Created: 2018-06-29 09:58:55 UTC

Size: 12.08 KB

patch

obsolete

>2018-06-29 11:01:52,565+02 INFO  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand] (default task-4) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] Lock Acquired to object 'EngineLock:{exclusiveLocks='[da77bcdd-f2ea-40f6-af00-8245ac477b08=VM]', sharedLocks=''}'
>2018-06-29 11:01:53,537+02 INFO  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand] (EE-ManagedThreadFactory-engine-Thread-37811) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] Running command: CreateSnapshotForVmCommand internal: false. Entities affected :  ID: da77bcdd-f2ea-40f6-af00-8245ac477b08 Type: VMAction group MANIPULATE_VM_SNAPSHOTS with role type USER
>2018-06-29 11:01:53,563+02 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-37811) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] EVENT_ID: FREEZE_VM_INITIATED(10,766), Freeze of guest filesystems on VM ovirt-test01.srv-ubuntu was initiated.
>2018-06-29 11:01:53,565+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FreezeVDSCommand] (EE-ManagedThreadFactory-engine-Thread-37811) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] START, FreezeVDSCommand(HostName = ov-test-04-01, VdsAndVmIDVDSParametersBase:{hostId='d8794e95-3f89-4b1a-9bec-12ccf6db0cb1', vmId='da77bcdd-f2ea-40f6-af00-8245ac477b08'}), log id: 46e034f3
>2018-06-29 11:01:54,083+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FreezeVDSCommand] (EE-ManagedThreadFactory-engine-Thread-37811) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] FINISH, FreezeVDSCommand, log id: 46e034f3
>2018-06-29 11:01:54,087+02 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-37811) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] EVENT_ID: FREEZE_VM_SUCCESS(10,767), Guest filesystems on VM ovirt-test01.srv-ubuntu have been frozen successfully.
>2018-06-29 11:01:54,110+02 INFO  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotDiskCommand] (EE-ManagedThreadFactory-engine-Thread-37811) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] Running command: CreateSnapshotDiskCommand internal: true. Entities affected :  ID: da77bcdd-f2ea-40f6-af00-8245ac477b08 Type: VMAction group MANIPULATE_VM_SNAPSHOTS with role type USER
>2018-06-29 11:01:54,237+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.CreateCinderSnapshotCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-3) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] 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-29 11:01:54,995+02 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-37811) [] EVENT_ID: USER_CREATE_SNAPSHOT(45), Snapshot 'hallo' creation for VM 'ovirt-test01.srv-ubuntu' was initiated by admin@internal-authz.
>2018-06-29 11:01:55,786+02 INFO  [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-40) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] Command 'CreateSnapshotForVm' (id: '1f134545-6615-4c7e-a539-8a5a88afae35') waiting on child command id: '1ce5b467-b4b5-44cb-8b58-1479c58a5fc1' type:'CreateSnapshotDisk' to complete
>2018-06-29 11:01:56,808+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-73) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] Command 'CreateSnapshotDisk' (id: '1ce5b467-b4b5-44cb-8b58-1479c58a5fc1') waiting on child command id: 'c0ee4d61-8f8d-48b3-8ed8-7648562a4993' type:'CreateCinderSnapshot' to complete
>2018-06-29 11:01:57,484+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.CreateCinderSnapshotCommandCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-73) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] Command 'CreateCinderSnapshot' id: 'c0ee4d61-8f8d-48b3-8ed8-7648562a4993' child commands '[]' executions were completed, status 'SUCCEEDED'
>2018-06-29 11:01:57,484+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.CreateCinderSnapshotCommandCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-73) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] Command 'CreateCinderSnapshot' id: 'c0ee4d61-8f8d-48b3-8ed8-7648562a4993' Updating status to 'SUCCEEDED', The command end method logic will be executed by one of its parent commands.
>2018-06-29 11:01:59,558+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-92) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] Command 'CreateSnapshotDisk' id: '1ce5b467-b4b5-44cb-8b58-1479c58a5fc1' child commands '[c0ee4d61-8f8d-48b3-8ed8-7648562a4993]' executions were completed, status 'SUCCEEDED'
>2018-06-29 11:01:59,559+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-92) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] Command 'CreateSnapshotDisk' id: '1ce5b467-b4b5-44cb-8b58-1479c58a5fc1' Updating status to 'SUCCEEDED', The command end method logic will be executed by one of its parent commands.
>2018-06-29 11:02:00,659+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] START, SnapshotVDSCommand(HostName = ov-test-04-01, SnapshotVDSCommandParameters:{hostId='d8794e95-3f89-4b1a-9bec-12ccf6db0cb1', vmId='da77bcdd-f2ea-40f6-af00-8245ac477b08'}), log id: 40f0d3a3
>2018-06-29 11:02:00,671+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] Failed in 'SnapshotVDS' method
>2018-06-29 11:02:00,677+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM ov-test-04-01 command SnapshotVDS failed: Snapshot failed
>2018-06-29 11:02:00,677+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand' return value 'StatusOnlyReturn [status=Status [code=48, message=Snapshot failed]]'
>2018-06-29 11:02:00,677+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] HostName = ov-test-04-01
>2018-06-29 11:02:00,677+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] Command 'SnapshotVDSCommand(HostName = ov-test-04-01, SnapshotVDSCommandParameters:{hostId='d8794e95-3f89-4b1a-9bec-12ccf6db0cb1', vmId='da77bcdd-f2ea-40f6-af00-8245ac477b08'})' execution failed: VDSGenericException: VDSErrorException: Failed to SnapshotVDS, error = Snapshot failed, code = 48
>2018-06-29 11:02:00,677+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] FINISH, SnapshotVDSCommand, log id: 40f0d3a3
>2018-06-29 11:02:00,689+02 WARN  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] 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-29 11:02:00,706+02 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-27) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] EVENT_ID: USER_CREATE_LIVE_SNAPSHOT_FINISHED_FAILURE(170), Failed to create live snapshot 'hallo' for VM 'ovirt-test01.srv-ubuntu'. VM restart is recommended. Note that using the created snapshot might cause data inconsistency.
>2018-06-29 11:02:01,733+02 ERROR [org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-94) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] Ending command 'org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand' with failure.
>2018-06-29 11:02:01,741+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ThawVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-94) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] START, ThawVDSCommand(HostName = ov-test-04-01, VdsAndVmIDVDSParametersBase:{hostId='d8794e95-3f89-4b1a-9bec-12ccf6db0cb1', vmId='da77bcdd-f2ea-40f6-af00-8245ac477b08'}), log id: 36dac9fd
>2018-06-29 11:02:01,910+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ThawVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-94) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] FINISH, ThawVDSCommand, log id: 36dac9fd
>2018-06-29 11:02:01,919+02 ERROR [org.ovirt.engine.core.bll.snapshots.CreateSnapshotDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-94) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] Ending command 'org.ovirt.engine.core.bll.snapshots.CreateSnapshotDiskCommand' with failure.
>2018-06-29 11:02:01,925+02 ERROR [org.ovirt.engine.core.bll.storage.disk.cinder.CreateCinderSnapshotCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-94) [5fc77d3f-6262-441b-ad01-4b2d5faf5cc4] Ending command 'org.ovirt.engine.core.bll.storage.disk.cinder.CreateCinderSnapshotCommand' with failure.
>2018-06-29 11:02:01,983+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.RemoveCinderDiskVolumeCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-5) [431ed2dc] Running command: RemoveCinderDiskVolumeCommand internal: true. Entities affected :  ID: 00000000-0000-0000-0000-000000000000 Type: Storage
>2018-06-29 11:02:02,877+02 WARN  [org.ovirt.engine.core.bll.GetVmConfigurationBySnapshotQuery] (default task-9) [fa321351-41ce-4fe8-add9-a615ddd6cb3b] Snapshot 'ffe4dd3a-3802-49f9-821e-d732e1f9f212' does not exist
>2018-06-29 11:02:02,880+02 INFO  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-94) [] Lock freed to object 'EngineLock:{exclusiveLocks='[da77bcdd-f2ea-40f6-af00-8245ac477b08=VM]', sharedLocks=''}'
>2018-06-29 11:02:02,901+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-94) [] EVENT_ID: USER_CREATE_SNAPSHOT_FINISHED_FAILURE(69), Failed to complete snapshot 'hallo' creation for VM 'ovirt-test01.srv-ubuntu'.
>2018-06-29 11:02:02,902+02 WARN  [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-94) [] Command 'CreateSnapshotForVm' id: '1f134545-6615-4c7e-a539-8a5a88afae35' end method execution failed, as the command isn't marked for endAction() retries silently ignoring
>2018-06-29 11:02:02,911+02 WARN  [org.ovirt.engine.core.bll.GetVmConfigurationBySnapshotQuery] (default task-9) [fa321351-41ce-4fe8-add9-a615ddd6cb3b] Snapshot 'ffe4dd3a-3802-49f9-821e-d732e1f9f212' does not exist
>2018-06-29 11:02:06,856+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.CinderBroker] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [431ed2dc] Snapshot does not exists
>2018-06-29 11:02:06,856+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.RemoveCinderDiskVolumeCommandCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [431ed2dc] Command 'RemoveCinderDiskVolume' id: 'f047509d-c429-4190-9f3e-2031fdee3ab0' child commands '[]' executions were completed, status 'SUCCEEDED'
>2018-06-29 11:02:06,881+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.RemoveCinderDiskVolumeCommandCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-36) [431ed2dc] Image status could not be provided since the cinder image might have already been removed from Cinder.
>2018-06-29 11:02:07,891+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.RemoveCinderDiskVolumeCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-12) [431ed2dc] Ending command 'org.ovirt.engine.core.bll.storage.disk.cinder.RemoveCinderDiskVolumeCommand' successfully.

Actions: View

Attachments on bug 1596619: 1455487 | 1456264 | 1456266 | 1456267 | 1456268 | 1456461 | 1456462 | 1456600 | 1456601 | 1456602 | 1456603