Attachment 1456600 Details for Bug 1596619 – engine log 20180704

engine log 20180704

1596619_engine_0704.log (text/plain), 11.68 KB, created by matthias.leopold on 2018-07-04 19:46:34 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: matthias.leopold

Created: 2018-07-04 19:46:34 UTC

Size: 11.68 KB

patch

obsolete

>2018-07-04 11:42:50,484+02 INFO  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand] (default task-4) [42083336-1598-48b2-b2d5-2385dec36540] Lock Acquired to object 'EngineLock:{exclusiveLocks='[4a8c9902-f9ab-490f-b1dd-82d9aee63b5f=VM]', sharedLocks=''}'
>2018-07-04 11:42:51,466+02 INFO  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand] (EE-ManagedThreadFactory-engine-Thread-153398) [42083336-1598-48b2-b2d5-2385dec36540] Running command: CreateSnapshotForVmCommand internal: false. Entities affected :  ID: 4a8c9902-f9ab-490f-b1dd-82d9aee63b5f Type: VMAction group MANIPULATE_VM_SNAPSHOTS with role type USER
>2018-07-04 11:42:51,482+02 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-153398) [42083336-1598-48b2-b2d5-2385dec36540] EVENT_ID: FREEZE_VM_INITIATED(10,766), Freeze of guest filesystems on VM ovirt-test01.srv was initiated.
>2018-07-04 11:42:51,483+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FreezeVDSCommand] (EE-ManagedThreadFactory-engine-Thread-153398) [42083336-1598-48b2-b2d5-2385dec36540] START, FreezeVDSCommand(HostName = ov-test-04-01, VdsAndVmIDVDSParametersBase:{hostId='d8794e95-3f89-4b1a-9bec-12ccf6db0cb1', vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f'}), log id: 36cfed54
>2018-07-04 11:42:51,536+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FreezeVDSCommand] (EE-ManagedThreadFactory-engine-Thread-153398) [42083336-1598-48b2-b2d5-2385dec36540] FINISH, FreezeVDSCommand, log id: 36cfed54
>2018-07-04 11:42:51,551+02 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-153398) [42083336-1598-48b2-b2d5-2385dec36540] EVENT_ID: FREEZE_VM_SUCCESS(10,767), Guest filesystems on VM ovirt-test01.srv have been frozen successfully.
>2018-07-04 11:42:51,577+02 INFO  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotDiskCommand] (EE-ManagedThreadFactory-engine-Thread-153398) [42083336-1598-48b2-b2d5-2385dec36540] Running command: CreateSnapshotDiskCommand internal: true. Entities affected :  ID: 4a8c9902-f9ab-490f-b1dd-82d9aee63b5f Type: VMAction group MANIPULATE_VM_SNAPSHOTS with role type USER
>2018-07-04 11:42:51,674+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.CreateCinderSnapshotCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-10) [42083336-1598-48b2-b2d5-2385dec36540] Running command: CreateCinderSnapshotCommand internal: true. Entities affected :  ID: e97009e5-c712-4199-9664-572eaba268dc Type: StorageAction group CONFIGURE_VM_STORAGE with role type USER
>2018-07-04 11:42:52,387+02 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-153398) [] EVENT_ID: USER_CREATE_SNAPSHOT(45), Snapshot 'test4bugzilla20180704' creation for VM 'ovirt-test01.srv' was initiated by admin@internal-authz.
>2018-07-04 11:42:53,115+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-43) [42083336-1598-48b2-b2d5-2385dec36540] Command 'CreateSnapshotDisk' (id: '1e5d190d-51a5-4f29-9492-a48288cf0625') waiting on child command id: '2ad8553f-0c12-41d3-bb62-5daff9d282d9' type:'CreateCinderSnapshot' to complete
>2018-07-04 11:42:54,190+02 INFO  [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-73) [42083336-1598-48b2-b2d5-2385dec36540] Command 'CreateSnapshotForVm' (id: '1d1aa238-49ee-4ccf-8994-6384354299e3') waiting on child command id: '1e5d190d-51a5-4f29-9492-a48288cf0625' type:'CreateSnapshotDisk' to complete
>2018-07-04 11:42:55,834+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.CreateCinderSnapshotCommandCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-65) [42083336-1598-48b2-b2d5-2385dec36540] Command 'CreateCinderSnapshot' id: '2ad8553f-0c12-41d3-bb62-5daff9d282d9' child commands '[]' executions were completed, status 'SUCCEEDED'
>2018-07-04 11:42:55,834+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.CreateCinderSnapshotCommandCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-65) [42083336-1598-48b2-b2d5-2385dec36540] Command 'CreateCinderSnapshot' id: '2ad8553f-0c12-41d3-bb62-5daff9d282d9' Updating status to 'SUCCEEDED', The command end method logic will be executed by one of its parent commands.
>2018-07-04 11:42:55,862+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-65) [42083336-1598-48b2-b2d5-2385dec36540] Command 'CreateSnapshotDisk' id: '1e5d190d-51a5-4f29-9492-a48288cf0625' child commands '[2ad8553f-0c12-41d3-bb62-5daff9d282d9]' executions were completed, status 'SUCCEEDED'
>2018-07-04 11:42:55,862+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-65) [42083336-1598-48b2-b2d5-2385dec36540] Command 'CreateSnapshotDisk' id: '1e5d190d-51a5-4f29-9492-a48288cf0625' Updating status to 'SUCCEEDED', The command end method logic will be executed by one of its parent commands.
>2018-07-04 11:42:58,024+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [42083336-1598-48b2-b2d5-2385dec36540] START, SnapshotVDSCommand(HostName = ov-test-04-01, SnapshotVDSCommandParameters:{hostId='d8794e95-3f89-4b1a-9bec-12ccf6db0cb1', vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f'}), log id: 3ed8aafb
>2018-07-04 11:42:58,040+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [42083336-1598-48b2-b2d5-2385dec36540] Failed in 'SnapshotVDS' method
>2018-07-04 11:42:58,043+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [42083336-1598-48b2-b2d5-2385dec36540] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM ov-test-04-01 command SnapshotVDS failed: Snapshot failed
>2018-07-04 11:42:58,043+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [42083336-1598-48b2-b2d5-2385dec36540] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand' return value 'StatusOnlyReturn [status=Status [code=48, message=Snapshot failed]]'
>2018-07-04 11:42:58,043+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [42083336-1598-48b2-b2d5-2385dec36540] HostName = ov-test-04-01
>2018-07-04 11:42:58,043+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [42083336-1598-48b2-b2d5-2385dec36540] 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-07-04 11:42:58,043+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [42083336-1598-48b2-b2d5-2385dec36540] FINISH, SnapshotVDSCommand, log id: 3ed8aafb
>2018-07-04 11:42:58,045+02 WARN  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [42083336-1598-48b2-b2d5-2385dec36540] 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-07-04 11:42:58,054+02 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-37) [42083336-1598-48b2-b2d5-2385dec36540] EVENT_ID: USER_CREATE_LIVE_SNAPSHOT_FINISHED_FAILURE(170), Failed to create live snapshot 'test4bugzilla20180704' for VM 'ovirt-test01.srv'. VM restart is recommended. Note that using the created snapshot might cause data inconsistency.
>2018-07-04 11:42:59,083+02 ERROR [org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [42083336-1598-48b2-b2d5-2385dec36540] Ending command 'org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand' with failure.
>2018-07-04 11:42:59,091+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ThawVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [42083336-1598-48b2-b2d5-2385dec36540] START, ThawVDSCommand(HostName = ov-test-04-01, VdsAndVmIDVDSParametersBase:{hostId='d8794e95-3f89-4b1a-9bec-12ccf6db0cb1', vmId='4a8c9902-f9ab-490f-b1dd-82d9aee63b5f'}), log id: 27654b6a
>2018-07-04 11:42:59,099+02 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ThawVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [42083336-1598-48b2-b2d5-2385dec36540] FINISH, ThawVDSCommand, log id: 27654b6a
>2018-07-04 11:42:59,107+02 ERROR [org.ovirt.engine.core.bll.snapshots.CreateSnapshotDiskCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [42083336-1598-48b2-b2d5-2385dec36540] Ending command 'org.ovirt.engine.core.bll.snapshots.CreateSnapshotDiskCommand' with failure.
>2018-07-04 11:42:59,113+02 ERROR [org.ovirt.engine.core.bll.storage.disk.cinder.CreateCinderSnapshotCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [42083336-1598-48b2-b2d5-2385dec36540] Ending command 'org.ovirt.engine.core.bll.storage.disk.cinder.CreateCinderSnapshotCommand' with failure.
>2018-07-04 11:42:59,152+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.RemoveCinderDiskVolumeCommand] (EE-ManagedThreadFactory-commandCoordinator-Thread-1) [150ec62e] Running command: RemoveCinderDiskVolumeCommand internal: true. Entities affected :  ID: 00000000-0000-0000-0000-000000000000 Type: Storage
>2018-07-04 11:42:59,757+02 INFO  [org.ovirt.engine.core.bll.snapshots.CreateSnapshotForVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [] Lock freed to object 'EngineLock:{exclusiveLocks='[4a8c9902-f9ab-490f-b1dd-82d9aee63b5f=VM]', sharedLocks=''}'
>2018-07-04 11:42:59,764+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [] EVENT_ID: USER_CREATE_SNAPSHOT_FINISHED_FAILURE(69), Failed to complete snapshot 'test4bugzilla20180704' creation for VM 'ovirt-test01.srv'.
>2018-07-04 11:42:59,764+02 WARN  [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-1) [] Command 'CreateSnapshotForVm' id: '1d1aa238-49ee-4ccf-8994-6384354299e3' end method execution failed, as the command isn't marked for endAction() retries silently ignoring
>2018-07-04 11:43:01,258+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.CinderBroker] (EE-ManagedThreadFactory-engineScheduled-Thread-62) [150ec62e] Snapshot does not exists
>2018-07-04 11:43:01,258+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.RemoveCinderDiskVolumeCommandCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-62) [150ec62e] Command 'RemoveCinderDiskVolume' id: '5df1a8ee-c353-4472-aca0-3edf37204880' child commands '[]' executions were completed, status 'SUCCEEDED'
>2018-07-04 11:43:01,283+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.RemoveCinderDiskVolumeCommandCallback] (EE-ManagedThreadFactory-engineScheduled-Thread-62) [150ec62e] Image status could not be provided since the cinder image might have already been removed from Cinder.
>2018-07-04 11:43:02,294+02 INFO  [org.ovirt.engine.core.bll.storage.disk.cinder.RemoveCinderDiskVolumeCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-26) [150ec62e] 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