7:48 a.m.
Hello
I have a situation with a vm in which I cannot delete the snapshot.
The whole thing is quite strange because I can delete the snapshot when I create and
delete it from the web interface but when I do it with a python script through the API it
failes.
The script does create snapshot-> download snapshot-> delete snapshot and I used the
examples from ovirt python sdk on githab to create it ,in general it works prety well.
But on a specific machine (so far) it cannot delete the live snapshot
Ovirt is 4.3.10 and the guest is a windows 10 pc. Windows 10 guest has 2 disks attached
both on different fc domains one on an ssd emc and the other on an hdd emc. Both disks
are prealocated.
I cannot figure out what the problem is so far
the related engine log:
2021-08-03 15:51:00,385+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-61) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Comma
nd 'RemoveSnapshotSingleDiskLive' (id:
'80dc4609-b91f-4e93-bc12-7b2083933e5a') waiting on child command id:
'74c83880-581b-4774-ae51-8c4af0c92c53' type:'Merge' to complete
2021-08-03 15:51:00,385+03 INFO [org.ovirt.engine.core.bll.MergeCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-61) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Waiting on merge command to complete (
jobId = 62bf8c83-cd78-42a5-b57d-d67ddfdee8ee)
2021-08-03 15:51:00,387+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-61) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' (id:
'87bc90c7-2aa5-4a1b-b58c-54296518658a') waiting on child command id:
'ec806ac6-929f-42d9-a86e-98d6a39a4718' type:'Merge' to complete
2021-08-03 15:51:01,388+03 INFO [org.ovirt.engine.core.bll.MergeCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-30) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Waiting on merge command to complete (jobId = c57fb3e5-da20-4838-8db3-31655ba76c1f)
2021-08-03 15:51:07,491+03 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-38) [b929fd4a-8ce7-408f-927d-ab0169879c4e]
Command 'MoveImageGroup' (id: '1de1b800-873f-405f-805b-f44397740909')
waiting on child command id: 'd1136344-2888-4d63-8fe1-b506426bc8aa'
type:'CopyImageGroupWithData' to complete
2021-08-03 15:51:11,513+03 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-41) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshot' (id: '04e9d61e-28a2-4ab0-9bb7-5c805ee871e9')
waiting on child command id: '87bc90c7-2aa5-4a1b-b58c-54296518658a'
type:'RemoveSnapshotSingleDiskLive' to complete
2021-08-03 15:51:12,522+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-76) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' (id:
'80dc4609-b91f-4e93-bc12-7b2083933e5a') waiting on child command id:
'74c83880-581b-4774-ae51-8c4af0c92c53' type:'Merge' to complete
2021-08-03 15:51:12,523+03 INFO [org.ovirt.engine.core.bll.MergeCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-76) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Waiting on merge command to complete (jobId = 62bf8c83-cd78-42a5-b57d-d67ddfdee8ee)
2021-08-03 15:51:12,527+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-76) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' (id:
'87bc90c7-2aa5-4a1b-b58c-54296518658a') waiting on child command id:
'ec806ac6-929f-42d9-a86e-98d6a39a4718' type:'Merge' to complete
2021-08-03 15:51:13,528+03 INFO [org.ovirt.engine.core.bll.MergeCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-37) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Waiting on merge command to complete (jobId = c57fb3e5-da20-4838-8db3-31655ba76c1f)
2021-08-03 15:51:21,635+03 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-58) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshot' (id: '04e9d61e-28a2-4ab0-9bb7-5c805ee871e9')
waiting on child command id: '87bc90c7-2aa5-4a1b-b58c-54296518658a'
type:'RemoveSnapshotSingleDiskLive' to complete
2021-08-03 15:51:22,655+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-31) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' (id:
'80dc4609-b91f-4e93-bc12-7b2083933e5a') waiting on child command id:
'74c83880-581b-4774-ae51-8c4af0c92c53' type:'Merge' to complete
2021-08-03 15:51:22,661+03 INFO [org.ovirt.engine.core.bll.MergeCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-31) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Merge command (jobId = 62bf8c83-cd78-42a5-b57d-d67ddfdee8ee) has completed for images
'7611ebcf-5323-45ca-b16c-9302d0bdedc6'..'17618ba1-4ab8-49eb-a991-fc3d602ced14'
2021-08-03 15:51:22,664+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-31) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' (id:
'87bc90c7-2aa5-4a1b-b58c-54296518658a') waiting on child command id:
'ec806ac6-929f-42d9-a86e-98d6a39a4718' type:'Merge' to complete
2021-08-03 15:51:23,664+03 INFO [org.ovirt.engine.core.bll.MergeCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-41) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Waiting on merge command to complete (jobId = c57fb3e5-da20-4838-8db3-31655ba76c1f)
2021-08-03 15:51:24,672+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-6) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Executing Live Merge command step 'MERGE_STATUS'
2021-08-03 15:51:24,699+03 INFO [org.ovirt.engine.core.bll.MergeStatusCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-1)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] Running command: MergeStatusCommand internal: true.
Entities affected : ID: 96000ec9-e181-44eb-893f-e0a36e3a6775 Type: Storage
8-03 15:51:24,749+03 INFO [org.ovirt.engine.core.bll.MergeStatusCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-1)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] Successfully removed volume 17618ba1-4
ab8-49eb-a991-fc3d602ced14 from the chain
2021-08-03 15:51:24,749+03 INFO [org.ovirt.engine.core.bll.MergeStatusCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-1)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] Volume merge type 'COMMIT'
2021-08-03 15:51:25,691+03 INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-5) [b929fd4a-8ce7-408f-927d-ab0169879c4e]
Command 'CopyImageGroup
WithData' (id: 'd1136344-2888-4d63-8fe1-b506426bc8aa') waiting on child
command id: 'b40aeec9-b7cf-4ee5-9683-54d98f4307d5'
type:'CopyImageGroupVolumesData' to complete
2021-08-03 15:51:26,692+03 INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-35) [b929fd4a-8ce7-408f-927d-ab0169879c4e]
Command 'CopyImageGrou
pVolumesData' (id: 'b40aeec9-b7cf-4ee5-9683-54d98f4307d5') waiting on child
command id: 'f46d65cb-32d9-4269-982e-6e19331b8a27' type:'CopyData' to
complete
2021-08-03 15:51:26,711+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-35) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Executing Liv
e Merge command step 'DESTROY_IMAGE'
2021-08-03 15:51:26,726+03 INFO
[org.ovirt.engine.core.bll.storage.disk.image.DestroyImageCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] Running command:
DestroyImageCommand internal: true. Entities affected : ID:
96000ec9-e181-44eb-893f-e0a36e3a6775 Type: Storage
2021-08-03 15:51:26,747+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.DestroyImageVDSCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] START, DestroyIma
geVDSCommand(
DestroyImageVDSCommandParameters:{storagePoolId='5da76866-7b7d-11eb-9913-00163e1f2643',
ignoreFailoverLimit='false',
storageDomainId='96000ec9-e181-44eb-893f-e0a36e3a6775',
imageGroupId='205a30a3-f
c06-4ceb-8ef2-018f16d4ccbb', imageId='00000000-0000-0000-0000-000000000000',
imageList='[17618ba1-4ab8-49eb-a991-fc3d602ced14]', postZero='false',
force='false'}), log id: 307a3fb1
2021-08-03 15:51:26,834+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.DestroyImageVDSCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] FINISH, DestroyIm
ageVDSCommand, return: , log id: 307a3fb1
2021-08-03 15:51:26,846+03 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] CommandAsyncTask::Adding CommandM
ultiAsyncTasks object for command 'baaa5254-261c-452a-84b4-0a8b397cdb62'
2021-08-03 15:51:26,847+03 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] CommandMultiAsyncTasks::attachTas
k: Attaching task 'ae2e80a4-d224-4fc3-a84b-859042811525' to command
'baaa5254-261c-452a-84b4-0a8b397cdb62'.
2021-08-03 15:51:26,857+03 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] Adding task 'ae2e80a4-d224-4fc3-a
84b-859042811525' (Parent Command 'DestroyImage', Parameters Type
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't
started yet..
2021-08-03 15:51:26,858+03 INFO
[org.ovirt.engine.core.bll.storage.disk.image.DestroyImageCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] Successfully star
ted task to remove orphaned volumes
2021-08-03 15:51:26,863+03 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] BaseAsyncTask::startPollingTask: Star
ting to poll task 'ae2e80a4-d224-4fc3-a84b-859042811525'.
2021-08-03 15:51:26,863+03 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] BaseAsyncTask::startPollingTask: Star
ting to poll task 'ae2e80a4-d224-4fc3-a84b-859042811525'.
2021-08-03 15:51:28,799+03 INFO
[org.ovirt.engine.core.bll.storage.disk.image.DestroyImageCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-88) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Waiting on destroy image command to complete the task (taskId =
ae2e80a4-d224-4fc3-a84b-859042811525)
2021-08-03 15:51:30,805+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-48) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' (id:
'80dc4609-b91f-4e93-bc12-7b2083933e5a') waiting on child command id:
'baaa5254-261c-452a-84b4-0a8b397cdb62' type:'DestroyImage' to complete
2021-08-03 15:51:31,824+03 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-97) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshot' (id: '04e9d61e-28a2-4ab0-9bb7-5c805ee871e9')
waiting on child command id: '87bc90c7-2aa5-4a1b-b58c-54296518658a'
type:'RemoveSnapshotSingleDiskLive' to complete
2021-08-03 15:51:32,825+03 INFO
[org.ovirt.engine.core.bll.storage.disk.image.DestroyImageCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-33) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Waiting on destroy image command to complete the task (taskId =
ae2e80a4-d224-4fc3-a84b-859042811525)
2021-08-03 15:51:32,831+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-33) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' (id:
'87bc90c7-2aa5-4a1b-b58c-54296518658a') waiting on child command id:
'ec806ac6-929f-42d9-a86e-98d6a39a4718' type:'Merge' to complete
2021-08-03 15:51:33,594+03 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type
'DestroyImage' completed, handling the result.
2021-08-03 15:51:33,594+03 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type
'DestroyImage' succeeded, clearing tasks.
2021-08-03 15:51:33,594+03 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
SPMAsyncTask::ClearAsyncTask: Attempting to clear task
'ae2e80a4-d224-4fc3-a84b-859042811525'
2021-08-03 15:51:33,595+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
START, SPMClearTaskVDSCommand(
SPMTaskGuidBaseVDSCommandParameters:{storagePoolId='5da76866-7b7d-11eb-9913-00163e1f2643',
ignoreFailoverLimit='false',
taskId='ae2e80a4-d224-4fc3-a84b-859042811525'}), log id: 6225ae22
2021-08-03 15:51:33,596+03 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
START, HSMClearTaskVDSCommand(HostName = ovirt2-7.vmmgmt-int.uoc.gr,
HSMTaskGuidBaseVDSCommandParameters:{hostId='10599b78-5f45-48d2-bfe0-028f3dae69eb',
taskId='ae2e80a4-d224-4fc3-a84b-859042811525'}), log id: 45b18a8a
2021-08-03 15:51:33,611+03 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
FINISH, HSMClearTaskVDSCommand, return: , log id: 45b18a8a
2021-08-03 15:51:33,611+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
FINISH, SPMClearTaskVDSCommand, return: , log id: 6225ae22
2021-08-03 15:51:33,614+03 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
BaseAsyncTask::removeTaskFromDB: Removed task
'ae2e80a4-d224-4fc3-a84b-859042811525' from DataBase
2021-08-03 15:51:33,614+03 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks
object for entity 'baaa5254-261c-452a-84b4-0a8b397cdb62'
2021-08-03 15:51:33,839+03 INFO [org.ovirt.engine.core.bll.MergeCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-95) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Merge command (jobId = c57fb3e5-da20-4838-8db3-31655ba76c1f) has completed for images
'84c005da-cbec-4ace-8619-5a8e2ae5ea75'..'b43b7c33-5b53-4332-a2e0-f950debb919b'
2021-08-03 15:51:34,847+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-31) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Executing Live Merge command step 'MERGE_STATUS'
2021-08-03 15:51:34,917+03 ERROR [org.ovirt.engine.core.bll.MergeStatusCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-2)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] Failed to live merge. Top volume
b43b7c33-5b53-4332-a2e0-f950debb919b is still in qemu chain
[b43b7c33-5b53-4332-a2e0-f950debb919b, 84c005da-cbec-4ace-8619-5a8e2ae5ea75]
2021-08-03 15:51:35,866+03 INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-41) [b929fd4a-8ce7-408f-927d-ab0169879c4e]
Command 'CopyImageGroupWithData' (id:
'd1136344-2888-4d63-8fe1-b506426bc8aa') waiting on child command id:
'b40aeec9-b7cf-4ee5-9683-54d98f4307d5' type:'CopyImageGroupVolumesData' to
complete
2021-08-03 15:51:36,867+03 INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-50) [b929fd4a-8ce7-408f-927d-ab0169879c4e]
Command 'CopyImageGroupVolumesData' (id:
'b40aeec9-b7cf-4ee5-9683-54d98f4307d5') waiting on child command id:
'f46d65cb-32d9-4269-982e-6e19331b8a27' type:'CopyData' to complete
2021-08-03 15:51:36,873+03 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-50) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command id: '87bc90c7-2aa5-4a1b-b58c-54296518658a failed child command status for step
'MERGE_STATUS'
2021-08-03 15:51:36,873+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-50) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' id:
'87bc90c7-2aa5-4a1b-b58c-54296518658a' child commands
'[a7de75fe-e94c-4795-9310-2c8fc3d6d3fc, ec806ac6-929f-42d9-a86e-98d6a39a4718,
6443529c-d753-48f6-8a9e-af1f9f09dfb5]' executions were completed, status
'FAILED'
2021-08-03 15:51:37,982+03 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-22) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Merging of snapshot '1cd4985b-b0c0-40d6-bbde-54451e43bef6' images
'84c005da-cbec-4ace-8619-5a8e2ae5ea75'..'b43b7c33-5b53-4332-a2e0-f950debb919b'
failed. Images have been marked illegal and can no longer be previewed or reverted to.
Please retry Live Merge on the snapshot to complete the operation.
2021-08-03 15:51:37,985+03 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-22) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Ending command
'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand' with
failure.
2021-08-03 15:51:39,014+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-23) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Executing Live Merge command step 'REDUCE_IMAGE'
2021-08-03 15:51:39,029+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-23) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
No need to execute reduce image command, skipping its execution. Storage Type:
'FCP', Disk: 'anova.admin.uoc.gr_Disk2' Snapshot:
'anova.admin.uoc.gr-2021-08-03'
2021-08-03 15:51:39,034+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-23) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' id:
'80dc4609-b91f-4e93-bc12-7b2083933e5a' child commands
'[18653ea6-166c-41a3-b335-84525871b9e6, 74c83880-581b-4774-ae51-8c4af0c92c53,
92e92d8e-b099-47dd-ba8c-e3db907f9a62, baaa5254-261c-452a-84b4-0a8b397cdb62]'
executions were completed, status 'SUCCEEDED'
2021-08-03 15:51:39,040+03 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-23) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshot' (id: '04e9d61e-28a2-4ab0-9bb7-5c805ee871e9')
waiting on child command id: '80dc4609-b91f-4e93-bc12-7b2083933e5a'
type:'RemoveSnapshotSingleDiskLive' to complete
2021-08-03 15:51:40,046+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-96) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
START, GetImageInfoVDSCommand(
GetImageInfoVDSCommandParameters:{storagePoolId='5da76866-7b7d-11eb-9913-00163e1f2643',
ignoreFailoverLimit='false',
storageDomainId='96000ec9-e181-44eb-893f-e0a36e3a6775',
imageGroupId='205a30a3-fc06-4ceb-8ef2-018f16d4ccbb',
imageId='7611ebcf-5323-45ca-b16c-9302d0bdedc6'}), log id: 4c98e4db
2021-08-03 15:51:40,047+03 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-96) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
START, GetVolumeInfoVDSCommand(HostName = ovirt2-7.vmmgmt-int.uoc.gr,
GetVolumeInfoVDSCommandParameters:{hostId='10599b78-5f45-48d2-bfe0-028f3dae69eb',
storagePoolId='5da76866-7b7d-11eb-9913-00163e1f2643',
storageDomainId='96000ec9-e181-44eb-893f-e0a36e3a6775',
imageGroupId='205a30a3-fc06-4ceb-8ef2-018f16d4ccbb',
imageId='7611ebcf-5323-45ca-b16c-9302d0bdedc6'}), log id: 4aca5f83
2021-08-03 15:51:40,084+03 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-96) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
FINISH, GetVolumeInfoVDSCommand, return:
org.ovirt.engine.core.common.businessentities.storage.DiskImage@70097e6, log id: 4aca5f83
2021-08-03 15:51:40,084+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-96) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
FINISH, GetImageInfoVDSCommand, return:
org.ovirt.engine.core.common.businessentities.storage.DiskImage@70097e6, log id: 4c98e4db
2021-08-03 15:51:40,283+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-96) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Successfully merged snapshot '1cd4985b-b0c0-40d6-bbde-54451e43bef6' images
'17618ba1-4ab8-49eb-a991-fc3d602ced14'..'7611ebcf-5323-45ca-b16c-9302d0bdedc6'
2021-08-03 15:51:40,287+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-96) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Ending command
'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand'
successfully.
2021-08-03 15:51:40,296+03 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-96) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshot' id: '04e9d61e-28a2-4ab0-9bb7-5c805ee871e9' child
commands '[87bc90c7-2aa5-4a1b-b58c-54296518658a,
80dc4609-b91f-4e93-bc12-7b2083933e5a]' executions were completed, status
'FAILED'
2021-08-03 15:51:41,322+03 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-65) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Ending command 'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand' with
failure.
2021-08-03 15:51:41,353+03 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(EE-ManagedThreadFactory-engineScheduled-Thread-65) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
EVENT_ID: USER_REMOVE_SNAPSHOT_FINISHED_FAILURE(357), Failed to delete snapshot
'anova.admin.uoc.gr-2021-08-03' for VM 'anova.admin.uoc.gr'.
Any help would be highly appreciated
8:10 a.m.
2021-08-03 15:51:34,917+03 ERROR
[org.ovirt.engine.core.bll.MergeStatusCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-2)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] Failed to live merge. Top
volume b43b7c33-5b53-4332-a2e0-f950debb919b is still in qemu chain
[b43b7c33-5b53-4332-a2e0-f950debb919b,
84c005da-cbec-4ace-8619-5a8e2ae5ea75]
Can you attach vdsm logs (from SPM and the host running the VM) so we
can understand why it failed?
On Tue, Aug 3, 2021 at 6:07 PM <g.vasilopoulos(a)uoc.gr> wrote:
Hello
I have a situation with a vm in which I cannot delete the snapshot.
The whole thing is quite strange because I can delete the snapshot when I create and
delete it from the web interface but when I do it with a python script through the API it
failes.
The script does create snapshot-> download snapshot-> delete snapshot and I used
the examples from ovirt python sdk on githab to create it ,in general it works prety
well.
But on a specific machine (so far) it cannot delete the live snapshot
Ovirt is 4.3.10 and the guest is a windows 10 pc. Windows 10 guest has 2 disks attached
both on different fc domains one on an ssd emc and the other on an hdd emc. Both disks
are prealocated.
I cannot figure out what the problem is so far
the related engine log:
2021-08-03 15:51:00,385+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-61) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Comma
nd 'RemoveSnapshotSingleDiskLive' (id:
'80dc4609-b91f-4e93-bc12-7b2083933e5a') waiting on child command id:
'74c83880-581b-4774-ae51-8c4af0c92c53' type:'Merge' to complete
2021-08-03 15:51:00,385+03 INFO [org.ovirt.engine.core.bll.MergeCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-61) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Waiting on merge command to complete (
jobId = 62bf8c83-cd78-42a5-b57d-d67ddfdee8ee)
2021-08-03 15:51:00,387+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-61) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' (id:
'87bc90c7-2aa5-4a1b-b58c-54296518658a') waiting on child command id:
'ec806ac6-929f-42d9-a86e-98d6a39a4718' type:'Merge' to complete
2021-08-03 15:51:01,388+03 INFO [org.ovirt.engine.core.bll.MergeCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-30) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Waiting on merge command to complete (jobId = c57fb3e5-da20-4838-8db3-31655ba76c1f)
2021-08-03 15:51:07,491+03 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-38) [b929fd4a-8ce7-408f-927d-ab0169879c4e]
Command 'MoveImageGroup' (id: '1de1b800-873f-405f-805b-f44397740909')
waiting on child command id: 'd1136344-2888-4d63-8fe1-b506426bc8aa'
type:'CopyImageGroupWithData' to complete
2021-08-03 15:51:11,513+03 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-41) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshot' (id: '04e9d61e-28a2-4ab0-9bb7-5c805ee871e9')
waiting on child command id: '87bc90c7-2aa5-4a1b-b58c-54296518658a'
type:'RemoveSnapshotSingleDiskLive' to complete
2021-08-03 15:51:12,522+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-76) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' (id:
'80dc4609-b91f-4e93-bc12-7b2083933e5a') waiting on child command id:
'74c83880-581b-4774-ae51-8c4af0c92c53' type:'Merge' to complete
2021-08-03 15:51:12,523+03 INFO [org.ovirt.engine.core.bll.MergeCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-76) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Waiting on merge command to complete (jobId = 62bf8c83-cd78-42a5-b57d-d67ddfdee8ee)
2021-08-03 15:51:12,527+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-76) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' (id:
'87bc90c7-2aa5-4a1b-b58c-54296518658a') waiting on child command id:
'ec806ac6-929f-42d9-a86e-98d6a39a4718' type:'Merge' to complete
2021-08-03 15:51:13,528+03 INFO [org.ovirt.engine.core.bll.MergeCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-37) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Waiting on merge command to complete (jobId = c57fb3e5-da20-4838-8db3-31655ba76c1f)
2021-08-03 15:51:21,635+03 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-58) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshot' (id: '04e9d61e-28a2-4ab0-9bb7-5c805ee871e9')
waiting on child command id: '87bc90c7-2aa5-4a1b-b58c-54296518658a'
type:'RemoveSnapshotSingleDiskLive' to complete
2021-08-03 15:51:22,655+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-31) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' (id:
'80dc4609-b91f-4e93-bc12-7b2083933e5a') waiting on child command id:
'74c83880-581b-4774-ae51-8c4af0c92c53' type:'Merge' to complete
2021-08-03 15:51:22,661+03 INFO [org.ovirt.engine.core.bll.MergeCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-31) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Merge command (jobId = 62bf8c83-cd78-42a5-b57d-d67ddfdee8ee) has completed for images
'7611ebcf-5323-45ca-b16c-9302d0bdedc6'..'17618ba1-4ab8-49eb-a991-fc3d602ced14'
2021-08-03 15:51:22,664+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-31) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' (id:
'87bc90c7-2aa5-4a1b-b58c-54296518658a') waiting on child command id:
'ec806ac6-929f-42d9-a86e-98d6a39a4718' type:'Merge' to complete
2021-08-03 15:51:23,664+03 INFO [org.ovirt.engine.core.bll.MergeCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-41) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Waiting on merge command to complete (jobId = c57fb3e5-da20-4838-8db3-31655ba76c1f)
2021-08-03 15:51:24,672+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-6) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Executing Live Merge command step 'MERGE_STATUS'
2021-08-03 15:51:24,699+03 INFO [org.ovirt.engine.core.bll.MergeStatusCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-1)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] Running command: MergeStatusCommand internal: true.
Entities affected : ID: 96000ec9-e181-44eb-893f-e0a36e3a6775 Type: Storage
8-03 15:51:24,749+03 INFO [org.ovirt.engine.core.bll.MergeStatusCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-1)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] Successfully removed volume 17618ba1-4
ab8-49eb-a991-fc3d602ced14 from the chain
2021-08-03 15:51:24,749+03 INFO [org.ovirt.engine.core.bll.MergeStatusCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-1)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] Volume merge type 'COMMIT'
2021-08-03 15:51:25,691+03 INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-5) [b929fd4a-8ce7-408f-927d-ab0169879c4e]
Command 'CopyImageGroup
WithData' (id: 'd1136344-2888-4d63-8fe1-b506426bc8aa') waiting on child
command id: 'b40aeec9-b7cf-4ee5-9683-54d98f4307d5'
type:'CopyImageGroupVolumesData' to complete
2021-08-03 15:51:26,692+03 INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-35) [b929fd4a-8ce7-408f-927d-ab0169879c4e]
Command 'CopyImageGrou
pVolumesData' (id: 'b40aeec9-b7cf-4ee5-9683-54d98f4307d5') waiting on child
command id: 'f46d65cb-32d9-4269-982e-6e19331b8a27' type:'CopyData' to
complete
2021-08-03 15:51:26,711+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-35) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Executing Liv
e Merge command step 'DESTROY_IMAGE'
2021-08-03 15:51:26,726+03 INFO
[org.ovirt.engine.core.bll.storage.disk.image.DestroyImageCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] Running command:
DestroyImageCommand internal: true. Entities affected : ID:
96000ec9-e181-44eb-893f-e0a36e3a6775 Type: Storage
2021-08-03 15:51:26,747+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.DestroyImageVDSCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] START, DestroyIma
geVDSCommand(
DestroyImageVDSCommandParameters:{storagePoolId='5da76866-7b7d-11eb-9913-00163e1f2643',
ignoreFailoverLimit='false',
storageDomainId='96000ec9-e181-44eb-893f-e0a36e3a6775',
imageGroupId='205a30a3-f
c06-4ceb-8ef2-018f16d4ccbb', imageId='00000000-0000-0000-0000-000000000000',
imageList='[17618ba1-4ab8-49eb-a991-fc3d602ced14]', postZero='false',
force='false'}), log id: 307a3fb1
2021-08-03 15:51:26,834+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.DestroyImageVDSCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] FINISH, DestroyIm
ageVDSCommand, return: , log id: 307a3fb1
2021-08-03 15:51:26,846+03 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] CommandAsyncTask::Adding CommandM
ultiAsyncTasks object for command 'baaa5254-261c-452a-84b4-0a8b397cdb62'
2021-08-03 15:51:26,847+03 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] CommandMultiAsyncTasks::attachTas
k: Attaching task 'ae2e80a4-d224-4fc3-a84b-859042811525' to command
'baaa5254-261c-452a-84b4-0a8b397cdb62'.
2021-08-03 15:51:26,857+03 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] Adding task 'ae2e80a4-d224-4fc3-a
84b-859042811525' (Parent Command 'DestroyImage', Parameters Type
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't
started yet..
2021-08-03 15:51:26,858+03 INFO
[org.ovirt.engine.core.bll.storage.disk.image.DestroyImageCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] Successfully star
ted task to remove orphaned volumes
2021-08-03 15:51:26,863+03 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] BaseAsyncTask::startPollingTask: Star
ting to poll task 'ae2e80a4-d224-4fc3-a84b-859042811525'.
2021-08-03 15:51:26,863+03 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedThreadFactory-commandCoordinator-Thread-10)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] BaseAsyncTask::startPollingTask: Star
ting to poll task 'ae2e80a4-d224-4fc3-a84b-859042811525'.
2021-08-03 15:51:28,799+03 INFO
[org.ovirt.engine.core.bll.storage.disk.image.DestroyImageCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-88) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Waiting on destroy image command to complete the task (taskId =
ae2e80a4-d224-4fc3-a84b-859042811525)
2021-08-03 15:51:30,805+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-48) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' (id:
'80dc4609-b91f-4e93-bc12-7b2083933e5a') waiting on child command id:
'baaa5254-261c-452a-84b4-0a8b397cdb62' type:'DestroyImage' to complete
2021-08-03 15:51:31,824+03 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-97) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshot' (id: '04e9d61e-28a2-4ab0-9bb7-5c805ee871e9')
waiting on child command id: '87bc90c7-2aa5-4a1b-b58c-54296518658a'
type:'RemoveSnapshotSingleDiskLive' to complete
2021-08-03 15:51:32,825+03 INFO
[org.ovirt.engine.core.bll.storage.disk.image.DestroyImageCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-33) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Waiting on destroy image command to complete the task (taskId =
ae2e80a4-d224-4fc3-a84b-859042811525)
2021-08-03 15:51:32,831+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-33) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' (id:
'87bc90c7-2aa5-4a1b-b58c-54296518658a') waiting on child command id:
'ec806ac6-929f-42d9-a86e-98d6a39a4718' type:'Merge' to complete
2021-08-03 15:51:33,594+03 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type
'DestroyImage' completed, handling the result.
2021-08-03 15:51:33,594+03 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type
'DestroyImage' succeeded, clearing tasks.
2021-08-03 15:51:33,594+03 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
SPMAsyncTask::ClearAsyncTask: Attempting to clear task
'ae2e80a4-d224-4fc3-a84b-859042811525'
2021-08-03 15:51:33,595+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
START, SPMClearTaskVDSCommand(
SPMTaskGuidBaseVDSCommandParameters:{storagePoolId='5da76866-7b7d-11eb-9913-00163e1f2643',
ignoreFailoverLimit='false',
taskId='ae2e80a4-d224-4fc3-a84b-859042811525'}), log id: 6225ae22
2021-08-03 15:51:33,596+03 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
START, HSMClearTaskVDSCommand(HostName = ovirt2-7.vmmgmt-int.uoc.gr,
HSMTaskGuidBaseVDSCommandParameters:{hostId='10599b78-5f45-48d2-bfe0-028f3dae69eb',
taskId='ae2e80a4-d224-4fc3-a84b-859042811525'}), log id: 45b18a8a
2021-08-03 15:51:33,611+03 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
FINISH, HSMClearTaskVDSCommand, return: , log id: 45b18a8a
2021-08-03 15:51:33,611+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
FINISH, SPMClearTaskVDSCommand, return: , log id: 6225ae22
2021-08-03 15:51:33,614+03 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
BaseAsyncTask::removeTaskFromDB: Removed task
'ae2e80a4-d224-4fc3-a84b-859042811525' from DataBase
2021-08-03 15:51:33,614+03 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
(EE-ManagedThreadFactory-engine-Thread-1481337) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks
object for entity 'baaa5254-261c-452a-84b4-0a8b397cdb62'
2021-08-03 15:51:33,839+03 INFO [org.ovirt.engine.core.bll.MergeCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-95) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Merge command (jobId = c57fb3e5-da20-4838-8db3-31655ba76c1f) has completed for images
'84c005da-cbec-4ace-8619-5a8e2ae5ea75'..'b43b7c33-5b53-4332-a2e0-f950debb919b'
2021-08-03 15:51:34,847+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-31) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Executing Live Merge command step 'MERGE_STATUS'
2021-08-03 15:51:34,917+03 ERROR [org.ovirt.engine.core.bll.MergeStatusCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-2)
[3bf9345d-fab2-490f-ba44-6aa014bbb743] Failed to live merge. Top volume
b43b7c33-5b53-4332-a2e0-f950debb919b is still in qemu chain
[b43b7c33-5b53-4332-a2e0-f950debb919b, 84c005da-cbec-4ace-8619-5a8e2ae5ea75]
2021-08-03 15:51:35,866+03 INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-41) [b929fd4a-8ce7-408f-927d-ab0169879c4e]
Command 'CopyImageGroupWithData' (id:
'd1136344-2888-4d63-8fe1-b506426bc8aa') waiting on child command id:
'b40aeec9-b7cf-4ee5-9683-54d98f4307d5' type:'CopyImageGroupVolumesData' to
complete
2021-08-03 15:51:36,867+03 INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-50) [b929fd4a-8ce7-408f-927d-ab0169879c4e]
Command 'CopyImageGroupVolumesData' (id:
'b40aeec9-b7cf-4ee5-9683-54d98f4307d5') waiting on child command id:
'f46d65cb-32d9-4269-982e-6e19331b8a27' type:'CopyData' to complete
2021-08-03 15:51:36,873+03 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-50) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command id: '87bc90c7-2aa5-4a1b-b58c-54296518658a failed child command status for step
'MERGE_STATUS'
2021-08-03 15:51:36,873+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-50) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' id:
'87bc90c7-2aa5-4a1b-b58c-54296518658a' child commands
'[a7de75fe-e94c-4795-9310-2c8fc3d6d3fc, ec806ac6-929f-42d9-a86e-98d6a39a4718,
6443529c-d753-48f6-8a9e-af1f9f09dfb5]' executions were completed, status
'FAILED'
2021-08-03 15:51:37,982+03 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-22) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Merging of snapshot '1cd4985b-b0c0-40d6-bbde-54451e43bef6' images
'84c005da-cbec-4ace-8619-5a8e2ae5ea75'..'b43b7c33-5b53-4332-a2e0-f950debb919b'
failed. Images have been marked illegal and can no longer be previewed or reverted to.
Please retry Live Merge on the snapshot to complete the operation.
2021-08-03 15:51:37,985+03 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-22) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Ending command
'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand' with
failure.
2021-08-03 15:51:39,014+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-23) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Executing Live Merge command step 'REDUCE_IMAGE'
2021-08-03 15:51:39,029+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-23) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
No need to execute reduce image command, skipping its execution. Storage Type:
'FCP', Disk: 'anova.admin.uoc.gr_Disk2' Snapshot:
'anova.admin.uoc.gr-2021-08-03'
2021-08-03 15:51:39,034+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-23) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshotSingleDiskLive' id:
'80dc4609-b91f-4e93-bc12-7b2083933e5a' child commands
'[18653ea6-166c-41a3-b335-84525871b9e6, 74c83880-581b-4774-ae51-8c4af0c92c53,
92e92d8e-b099-47dd-ba8c-e3db907f9a62, baaa5254-261c-452a-84b4-0a8b397cdb62]'
executions were completed, status 'SUCCEEDED'
2021-08-03 15:51:39,040+03 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-23) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshot' (id: '04e9d61e-28a2-4ab0-9bb7-5c805ee871e9')
waiting on child command id: '80dc4609-b91f-4e93-bc12-7b2083933e5a'
type:'RemoveSnapshotSingleDiskLive' to complete
2021-08-03 15:51:40,046+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-96) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
START, GetImageInfoVDSCommand(
GetImageInfoVDSCommandParameters:{storagePoolId='5da76866-7b7d-11eb-9913-00163e1f2643',
ignoreFailoverLimit='false',
storageDomainId='96000ec9-e181-44eb-893f-e0a36e3a6775',
imageGroupId='205a30a3-fc06-4ceb-8ef2-018f16d4ccbb',
imageId='7611ebcf-5323-45ca-b16c-9302d0bdedc6'}), log id: 4c98e4db
2021-08-03 15:51:40,047+03 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-96) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
START, GetVolumeInfoVDSCommand(HostName = ovirt2-7.vmmgmt-int.uoc.gr,
GetVolumeInfoVDSCommandParameters:{hostId='10599b78-5f45-48d2-bfe0-028f3dae69eb',
storagePoolId='5da76866-7b7d-11eb-9913-00163e1f2643',
storageDomainId='96000ec9-e181-44eb-893f-e0a36e3a6775',
imageGroupId='205a30a3-fc06-4ceb-8ef2-018f16d4ccbb',
imageId='7611ebcf-5323-45ca-b16c-9302d0bdedc6'}), log id: 4aca5f83
2021-08-03 15:51:40,084+03 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-96) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
FINISH, GetVolumeInfoVDSCommand, return:
org.ovirt.engine.core.common.businessentities.storage.DiskImage@70097e6, log id: 4aca5f83
2021-08-03 15:51:40,084+03 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-96) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
FINISH, GetImageInfoVDSCommand, return:
org.ovirt.engine.core.common.businessentities.storage.DiskImage@70097e6, log id: 4c98e4db
2021-08-03 15:51:40,283+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-96) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Successfully merged snapshot '1cd4985b-b0c0-40d6-bbde-54451e43bef6' images
'17618ba1-4ab8-49eb-a991-fc3d602ced14'..'7611ebcf-5323-45ca-b16c-9302d0bdedc6'
2021-08-03 15:51:40,287+03 INFO
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-96) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Ending command
'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand'
successfully.
2021-08-03 15:51:40,296+03 INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(EE-ManagedThreadFactory-engineScheduled-Thread-96) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Command 'RemoveSnapshot' id: '04e9d61e-28a2-4ab0-9bb7-5c805ee871e9' child
commands '[87bc90c7-2aa5-4a1b-b58c-54296518658a,
80dc4609-b91f-4e93-bc12-7b2083933e5a]' executions were completed, status
'FAILED'
2021-08-03 15:51:41,322+03 ERROR
[org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-65) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
Ending command 'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand' with
failure.
2021-08-03 15:51:41,353+03 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(EE-ManagedThreadFactory-engineScheduled-Thread-65) [3bf9345d-fab2-490f-ba44-6aa014bbb743]
EVENT_ID: USER_REMOVE_SNAPSHOT_FINISHED_FAILURE(357), Failed to delete snapshot
'anova.admin.uoc.gr-2021-08-03' for VM 'anova.admin.uoc.gr'.
Any help would be highly appreciated
_______________________________________________
Users mailing list -- users(a)ovirt.org
To unsubscribe send an email to users-leave(a)ovirt.org
Privacy Statement: https://www.ovirt.org/privacy-policy.html
oVirt Code of Conduct: https://www.ovirt.org/community/about/community-guidelines/
List Archives:
https://lists.ovirt.org/archives/list/users@ovirt.org/message/LCNMR3L4LX5...
12:04 a.m.
hello Benny and thank you for the quick response:
this is the vdsm log:
2021-08-03 15:50:58,655+0300 INFO (jsonrpc/3) [storage.VolumeManifest]
96000ec9-e181-44eb-893f-e0a36e3a6775/205a30a3-fc06-4ceb-8ef2-018f16d4ccbb/7611ebcf-5323-45ca-b16c-9302d0bdedc6
info is {'status': 'OK', 'domain':
'96000ec9-e181-44eb-893f-e0a36e3a6775', 'voltype': 'INTERNAL',
'description':
'{"DiskAlias":"anova.admin.uoc.gr_Disk2","DiskDescription":""}',
'parent': '00000000-0000-0000-0000-000000000000', 'format':
'RAW', 'generation': 0, 'image':
'205a30a3-fc06-4ceb-8ef2-018f16d4ccbb', 'disktype': 'DATA',
'legality': 'LEGAL', 'mtime': '0', 'apparentsize':
'42949672960', 'children': [], 'pool': '',
'ctime': '1625846644', 'capacity': '42949672960',
'uuid': u'7611ebcf-5323-45ca-b16c-9302d0bdedc6', 'truesize':
'42949672960', 'type': 'PREALLOCATED', 'lease':
{'path': '/dev/96000ec9-e181-44eb-893f-e0a36e3a6775/leases',
'owners': [], 'version': None, 'offset': 105906176}} (volume:279)
2021-08-03 15:50:58,655+0300 INFO (jsonrpc/3) [vdsm.api] FINISH getVolumeInfo
return={'info': {'status': 'OK', 'domain':
'96000ec9-e181-44eb-893f-e0a36e3a6775', 'voltype': 'INTERNAL',
'description':
'{"DiskAlias":"anova.admin.uoc.gr_Disk2","DiskDescription":""}',
'parent': '00000000-0000-0000-0000-000000000000', 'format':
'RAW', 'generation': 0, 'image':
'205a30a3-fc06-4ceb-8ef2-018f16d4ccbb', 'disktype': 'DATA',
'legality': 'LEGAL', 'mtime': '0', 'apparentsize':
'42949672960', 'children': [], 'pool': '',
'ctime': '1625846644', 'capacity': '42949672960',
'uuid': u'7611ebcf-5323-45ca-b16c-9302d0bdedc6', 'truesize':
'42949672960', 'type': 'PREALLOCATED', 'lease':
{'path': '/dev/96000ec9-e181-44eb-893f-e0a36e3a6775/leases',
'owners': [], 'version': None, 'offset': 105906176}}}
from=::ffff:10.252.80.201,41898, flow_id=3bf9345d-fab2-490f-ba44-6aa014bbb743,
task_id=0b4e6fe7-4345-40b1-9e86-86ec2f662d3f (api:54)
2021-08-03 15:50:58,656+0300 INFO (jsonrpc/3) [vdsm.api] START
getVolumeInfo(sdUUID=u'96000ec9-e181-44eb-893f-e0a36e3a6775',
spUUID='5da76866-7b7d-11eb-9913-00163e1f2643',
imgUUID=u'205a30a3-fc06-4ceb-8ef2-018f16d4ccbb',
volUUID=u'17618ba1-4ab8-49eb-a991-fc3d602ced14', options=None)
from=::ffff:10.252.80.201,41898, flow_id=3bf9345d-fab2-490f-ba44-6aa014bbb743,
task_id=0c307c2c-9bd3-4d1a-9db8-ec45d822bc71 (api:48)
2021-08-03 15:50:58,657+0300 INFO (jsonrpc/3) [storage.VolumeManifest] Info request:
sdUUID=96000ec9-e181-44eb-893f-e0a36e3a6775 imgUUID=205a30a3-fc06-4ceb-8ef2-018f16d4ccbb
volUUID = 17618ba1-4ab8-49eb-a991-fc3d602ced14 (volume:240)
2021-08-03 15:50:58,681+0300 INFO (jsonrpc/3) [storage.VolumeManifest]
96000ec9-e181-44eb-893f-e0a36e3a6775/205a30a3-fc06-4ceb-8ef2-018f16d4ccbb/17618ba1-4ab8-49eb-a991-fc3d602ced14
info is {'status': 'OK', 'domain':
'96000ec9-e181-44eb-893f-e0a36e3a6775', 'voltype': 'LEAF',
'description': '', 'parent':
'7611ebcf-5323-45ca-b16c-9302d0bdedc6', 'format': 'COW',
'generation': 0, 'image': '205a30a3-fc06-4ceb-8ef2-018f16d4ccbb',
'disktype': 'DATA', 'legality': 'LEGAL', 'mtime':
'0', 'apparentsize': '1073741824', 'children': [],
'pool': '', 'ctime': '1627991040', 'capacity':
'42949672960', 'uuid': u'17618ba1-4ab8-49eb-a991-fc3d602ced14',
'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'path':
'/dev/96000ec9-e181-44eb-893f-e0a36e3a6775/leases', 'owners': [],
'version': None, 'offset': 111149056}} (volume:279)
2021-08-03 15:50:58,681+0300 INFO (jsonrpc/3) [vdsm.api] FINISH getVolumeInfo
return={'info': {'status': 'OK', 'domain':
'96000ec9-e181-44eb-893f-e0a36e3a6775', 'voltype': 'LEAF',
'description': '', 'parent':
'7611ebcf-5323-45ca-b16c-9302d0bdedc6', 'format': 'COW',
'generation': 0, 'image': '205a30a3-fc06-4ceb-8ef2-018f16d4ccbb',
'disktype': 'DATA', 'legality': 'LEGAL', 'mtime':
'0', 'apparentsize': '1073741824', 'children': [],
'pool': '', 'ctime': '1627991040', 'capacity':
'42949672960', 'uuid': u'17618ba1-4ab8-49eb-a991-fc3d602ced14',
'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'path':
'/dev/96000ec9-e181-44eb-893f-e0a36e3a6775/leases', 'owners': [],
'version': None, 'offset': 111149056}}} from=::ffff:10.252.80.201,41898,
flow_id=3bf9345d-fab2-490f-ba44-6aa014bbb743, task_id=0c307c2c-9bd3-4d1a-9db8-ec45d822bc71
(api:54)
2021-08-03 15:50:58,711+0300 INFO (jsonrpc/3) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Starting merge with
jobUUID=u'62bf8c83-cd78-42a5-b57d-d67ddfdee8ee', original
chain=7611ebcf-5323-45ca-b16c-9302d0bdedc6 < 17618ba1-4ab8-49eb-a991-fc3d602ced14
(top), disk='sdb', base='sdb[1]', top=None, bandwidth=0, flags=12
(vm:5951)
2021-08-03 15:50:58,735+0300 INFO (jsonrpc/3) [api.virt] FINISH merge
return={'status': {'message': 'Done', 'code': 0}}
from=::ffff:10.252.80.201,41898, flow_id=3bf9345d-fab2-490f-ba44-6aa014bbb743,
vmId=1c1d20ed-3167-4be7-bff3-29845142fc57 (api:54)
2021-08-03 15:50:58,735+0300 INFO (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC call VM.merge
succeeded in 0.37 seconds (__init__:312)
2021-08-03 15:50:58,736+0300 INFO (libvirt/events) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Block job ACTIVE_COMMIT for drive
/rhev/data-center/mnt/blockSD/96000ec9-e181-44eb-893f-e0a36e3a6775/images/205a30a3-fc06-4ceb-8ef2-018f16d4ccbb/17618ba1-4ab8-49eb-a991-fc3d602ced14
is ready (vm:5853)
2021-08-03 15:50:58,751+0300 INFO (jsonrpc/2) [storage.VolumeManifest] Info request:
sdUUID=a5a492a7-f770-4472-baa3-ac7297a581a9 imgUUID=2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5
volUUID = 84c005da-cbec-4ace-8619-5a8e2ae5ea75 (volume:240)
2021-08-03 15:50:58,801+0300 INFO (jsonrpc/2) [storage.VolumeManifest]
a5a492a7-f770-4472-baa3-ac7297a581a9/2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5/84c005da-cbec-4ace-8619-5a8e2ae5ea75
info is {'status': 'OK', 'domain':
'a5a492a7-f770-4472-baa3-ac7297a581a9', 'voltype': 'INTERNAL',
'description':
'{"DiskAlias":"anova_Disk1","DiskDescription":""}',
'parent': '00000000-0000-0000-0000-000000000000', 'format':
'RAW', 'generation': 0, 'image':
'2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5', 'disktype': 'DATA',
'legality': 'LEGAL', 'mtime': '0', 'apparentsize':
'150323855360', 'children': [], 'pool': '',
'ctime': '1627983559', 'capacity': '150323855360',
'uuid': u'84c005da-cbec-4ace-8619-5a8e2ae5ea75', 'truesize':
'150323855360', 'type': 'PREALLOCATED', 'lease':
{'path': '/dev/a5a492a7-f770-4472-baa3-ac7297a581a9/leases',
'owners': [], 'version': None, 'offset': 114294784}} (volume:279)
2021-08-03 15:50:58,801+0300 INFO (jsonrpc/2) [vdsm.api] FINISH getVolumeInfo
return={'info': {'status': 'OK', 'domain':
'a5a492a7-f770-4472-baa3-ac7297a581a9', 'voltype': 'INTERNAL',
'description':
'{"DiskAlias":"anova_Disk1","DiskDescription":""}',
'parent': '00000000-0000-0000-0000-000000000000', 'format':
'RAW', 'generation': 0, 'image':
'2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5', 'disktype': 'DATA',
'legality': 'LEGAL', 'mtime': '0', 'apparentsize':
'150323855360', 'children': [], 'pool': '',
'ctime': '1627983559', 'capacity': '150323855360',
'uuid': u'84c005da-cbec-4ace-8619-5a8e2ae5ea75', 'truesize':
'150323855360', 'type': 'PREALLOCATED', 'lease':
{'path': '/dev/a5a492a7-f770-4472-baa3-ac7297a581a9/leases',
'owners': [], 'version': None, 'offset': 114294784}}}
from=::ffff:10.252.80.201,41898, flow_id=3bf9345d-fab2-490f-ba44-6aa014bbb743,
task_id=2b773146-1823-4799-b5c1-64b25f2f6510 (api:54)
2021-08-03 15:50:58,802+0300 INFO (jsonrpc/2) [vdsm.api] START
getVolumeInfo(sdUUID=u'a5a492a7-f770-4472-baa3-ac7297a581a9',
spUUID='5da76866-7b7d-11eb-9913-00163e1f2643',
imgUUID=u'2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5',
volUUID=u'b43b7c33-5b53-4332-a2e0-f950debb919b', options=None)
from=::ffff:10.252.80.201,41898, flow_id=3bf9345d-fab2-490f-ba44-6aa014bbb743,
task_id=c55c0206-6e3a-4748-8bba-b8e759fa270b (api:48)
2021-08-03 15:50:58,803+0300 INFO (jsonrpc/2) [storage.VolumeManifest] Info request:
sdUUID=a5a492a7-f770-4472-baa3-ac7297a581a9 imgUUID=2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5
volUUID = b43b7c33-5b53-4332-a2e0-f950debb919b (volume:240)
2021-08-03 15:50:58,826+0300 INFO (jsonrpc/2) [storage.VolumeManifest]
a5a492a7-f770-4472-baa3-ac7297a581a9/2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5/b43b7c33-5b53-4332-a2e0-f950debb919b
info is {'status': 'OK', 'domain':
'a5a492a7-f770-4472-baa3-ac7297a581a9', 'voltype': 'LEAF',
'description': '', 'parent':
'84c005da-cbec-4ace-8619-5a8e2ae5ea75', 'format': 'COW',
'generation': 0, 'image': '2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5',
'disktype': 'DATA', 'legality': 'LEGAL', 'mtime':
'0', 'apparentsize': '1073741824', 'children': [],
'pool': '', 'ctime': '1627991039', 'capacity':
'150323855360', 'uuid': u'b43b7c33-5b53-4332-a2e0-f950debb919b',
'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'path':
'/dev/a5a492a7-f770-4472-baa3-ac7297a581a9/leases', 'owners': [],
'version': None, 'offset': 115343360}} (volume:279)
2021-08-03 15:50:58,826+0300 INFO (jsonrpc/2) [vdsm.api] FINISH getVolumeInfo
return={'info': {'status': 'OK', 'domain':
'a5a492a7-f770-4472-baa3-ac7297a581a9', 'voltype': 'LEAF',
'description': '', 'parent':
'84c005da-cbec-4ace-8619-5a8e2ae5ea75', 'format': 'COW',
'generation': 0, 'image': '2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5',
'disktype': 'DATA', 'legality': 'LEGAL', 'mtime':
'0', 'apparentsize': '1073741824', 'children': [],
'pool': '', 'ctime': '1627991039', 'capacity':
'150323855360', 'uuid': u'b43b7c33-5b53-4332-a2e0-f950debb919b',
'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'path':
'/dev/a5a492a7-f770-4472-baa3-ac7297a581a9/leases', 'owners': [],
'version': None, 'offset': 115343360}}} from=::ffff:10.252.80.201,41898,
flow_id=3bf9345d-fab2-490f-ba44-6aa014bbb743, task_id=c55c0206-6e3a-4748-8bba-b8e759fa270b
(api:54)
2021-08-03 15:50:58,845+0300 INFO (jsonrpc/2) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Starting merge with
jobUUID=u'c57fb3e5-da20-4838-8db3-31655ba76c1f', original
chain=84c005da-cbec-4ace-8619-5a8e2ae5ea75 < b43b7c33-5b53-4332-a2e0-f950debb919b
(top), disk='sda', base='sda[1]', top=None, bandwidth=0, flags=12
(vm:5951)
2021-08-03 15:50:58,911+0300 INFO (jsonrpc/2) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Starting cleanup thread for job:
62bf8c83-cd78-42a5-b57d-d67ddfdee8ee (vm:5815)
2021-08-03 15:50:58,912+0300 INFO (merge/62bf8c83) [vdsm.api] START
getVolumeInfo(sdUUID=u'96000ec9-e181-44eb-893f-e0a36e3a6775',
spUUID='5da76866-7b7d-11eb-9913-00163e1f2643',
imgUUID=u'205a30a3-fc06-4ceb-8ef2-018f16d4ccbb',
volUUID=u'17618ba1-4ab8-49eb-a991-fc3d602ced14', options=None) from=internal,
task_id=e8583530-0849-4e67-9a3b-fc7c85a8bd80 (api:48)
2021-08-03 15:50:58,913+0300 INFO (jsonrpc/2) [api.virt] FINISH merge
return={'status': {'message': 'Done', 'code': 0}}
from=::ffff:10.252.80.201,41898, flow_id=3bf9345d-fab2-490f-ba44-6aa014bbb743,
vmId=1c1d20ed-3167-4be7-bff3-29845142fc57 (api:54)
2021-08-03 15:50:58,913+0300 INFO (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call VM.merge
succeeded in 0.53 seconds (__init__:312)
2021-08-03 15:50:58,915+0300 INFO (merge/62bf8c83) [storage.VolumeManifest] Info request:
sdUUID=96000ec9-e181-44eb-893f-e0a36e3a6775 imgUUID=205a30a3-fc06-4ceb-8ef2-018f16d4ccbb
volUUID = 17618ba1-4ab8-49eb-a991-fc3d602ced14 (volume:240)
2021-08-03 15:50:58,932+0300 INFO (merge/62bf8c83) [storage.VolumeManifest]
96000ec9-e181-44eb-893f-e0a36e3a6775/205a30a3-fc06-4ceb-8ef2-018f16d4ccbb/17618ba1-4ab8-49eb-a991-fc3d602ced14
info is {'status': 'OK', 'domain':
'96000ec9-e181-44eb-893f-e0a36e3a6775', 'voltype': 'LEAF',
'description': '', 'parent':
'7611ebcf-5323-45ca-b16c-9302d0bdedc6', 'format': 'COW',
'generation': 0, 'image': '205a30a3-fc06-4ceb-8ef2-018f16d4ccbb',
'disktype': 'DATA', 'legality': 'LEGAL', 'mtime':
'0', 'apparentsize': '1073741824', 'children': [],
'pool': '', 'ctime': '1627991040', 'capacity':
'42949672960', 'uuid': u'17618ba1-4ab8-49eb-a991-fc3d602ced14',
'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'path':
'/dev/96000ec9-e181-44eb-893f-e0a36e3a6775/leases', 'owners': [],
'version': None, 'offset': 111149056}} (volume:279)
2021-08-03 15:50:58,932+0300 INFO (merge/62bf8c83) [vdsm.api] FINISH getVolumeInfo
return={'info': {'status': 'OK', 'domain':
'96000ec9-e181-44eb-893f-e0a36e3a6775', 'voltype': 'LEAF',
'description': '', 'parent':
'7611ebcf-5323-45ca-b16c-9302d0bdedc6', 'format': 'COW',
'generation': 0, 'image': '205a30a3-fc06-4ceb-8ef2-018f16d4ccbb',
'disktype': 'DATA', 'legality': 'LEGAL', 'mtime':
'0', 'apparentsize': '1073741824', 'children': [],
'pool': '', 'ctime': '1627991040', 'capacity':
'42949672960', 'uuid': u'17618ba1-4ab8-49eb-a991-fc3d602ced14',
'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'path':
'/dev/96000ec9-e181-44eb-893f-e0a36e3a6775/leases', 'owners': [],
'version': None, 'offset': 111149056}}} from=internal,
task_id=e8583530-0849-4e67-9a3b-fc7c85a8bd80 (api:54)
2021-08-03 15:50:58,933+0300 INFO (merge/62bf8c83) [vdsm.api] START
setVolumeSize(sdUUID=u'96000ec9-e181-44eb-893f-e0a36e3a6775',
spUUID='5da76866-7b7d-11eb-9913-00163e1f2643',
imgUUID=u'205a30a3-fc06-4ceb-8ef2-018f16d4ccbb',
volUUID=u'7611ebcf-5323-45ca-b16c-9302d0bdedc6', capacity='42949672960')
from=internal, task_id=7445bf99-892b-465e-92f5-9488a17dd7a9 (api:48)
2021-08-03 15:50:58,946+0300 INFO (merge/62bf8c83) [vdsm.api] FINISH setVolumeSize
return=None from=internal, task_id=7445bf99-892b-465e-92f5-9488a17dd7a9 (api:54)
2021-08-03 15:50:58,947+0300 INFO (merge/62bf8c83) [vdsm.api] START
imageSyncVolumeChain(sdUUID=u'96000ec9-e181-44eb-893f-e0a36e3a6775',
imgUUID=u'205a30a3-fc06-4ceb-8ef2-018f16d4ccbb',
volUUID=u'17618ba1-4ab8-49eb-a991-fc3d602ced14',
newChain=['7611ebcf-5323-45ca-b16c-9302d0bdedc6']) from=internal,
task_id=b05ae0b2-a5e9-47e6-b324-d35516fd6746 (api:48)
2021-08-03 15:50:59,040+0300 ERROR (libvirt/events) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Block job ACTIVE_COMMIT for drive
/rhev/data-center/mnt/blockSD/a5a492a7-f770-4472-baa3-ac7297a581a9/images/2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5/b43b7c33-5b53-4332-a2e0-f950debb919b
has failed (vm:5847)
2021-08-03 15:50:59,176+0300 INFO (merge/62bf8c83) [storage.Image] Current
chain=7611ebcf-5323-45ca-b16c-9302d0bdedc6 < 17618ba1-4ab8-49eb-a991-fc3d602ced14 (top)
(image:1221)
2021-08-03 15:50:59,177+0300 INFO (merge/62bf8c83) [storage.Image] Unlinking subchain:
[u'17618ba1-4ab8-49eb-a991-fc3d602ced14'] (image:1231)
2021-08-03 15:50:59,188+0300 INFO (merge/62bf8c83) [storage.Image] Leaf volume
17618ba1-4ab8-49eb-a991-fc3d602ced14 is being removed from the chain. Marking it ILLEGAL
to prevent data corruption (image:1239)
2021-08-03 15:50:59,189+0300 INFO (merge/62bf8c83) [storage.VolumeManifest]
sdUUID=96000ec9-e181-44eb-893f-e0a36e3a6775 imgUUID=205a30a3-fc06-4ceb-8ef2-018f16d4ccbb
volUUID = 17618ba1-4ab8-49eb-a991-fc3d602ced14 legality = ILLEGAL (volume:387)
2021-08-03 15:50:59,202+0300 INFO (merge/62bf8c83) [vdsm.api] FINISH imageSyncVolumeChain
return=None from=internal, task_id=b05ae0b2-a5e9-47e6-b324-d35516fd6746 (api:54)
2021-08-03 15:50:59,203+0300 INFO (merge/62bf8c83) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Disabling drive monitoring
(drivemonitor:60)
2021-08-03 15:50:59,203+0300 INFO (merge/62bf8c83) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Requesting pivot to complete active
layer commit (job 62bf8c83-cd78-42a5-b57d-d67ddfdee8ee) (vm:6211)
2021-08-03 15:50:59,215+0300 INFO (libvirt/events) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Block job ACTIVE_COMMIT for drive
/rhev/data-center/mnt/blockSD/96000ec9-e181-44eb-893f-e0a36e3a6775/images/205a30a3-fc06-4ceb-8ef2-018f16d4ccbb/17618ba1-4ab8-49eb-a991-fc3d602ced14
has completed (vm:5844)
2021-08-03 15:50:59,216+0300 INFO (merge/62bf8c83) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Waiting for libvirt to update the
XML after pivot of drive ua-205a30a3-fc06-4ceb-8ef2-018f16d4ccbb completed (vm:6294)
2021-08-03 15:50:59,237+0300 INFO (merge/62bf8c83) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') The XML update has been completed
(vm:6311)
2021-08-03 15:50:59,237+0300 INFO (merge/62bf8c83) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Pivot completed (job
62bf8c83-cd78-42a5-b57d-d67ddfdee8ee) (vm:6225)
2021-08-03 15:50:59,238+0300 INFO (merge/62bf8c83) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Synchronizing volume chain after
live merge (job 62bf8c83-cd78-42a5-b57d-d67ddfdee8ee) (vm:6259)
2021-08-03 15:50:59,259+0300 INFO (merge/62bf8c83) [vdsm.api] START
imageSyncVolumeChain(sdUUID=u'96000ec9-e181-44eb-893f-e0a36e3a6775',
imgUUID=u'205a30a3-fc06-4ceb-8ef2-018f16d4ccbb',
volUUID=u'17618ba1-4ab8-49eb-a991-fc3d602ced14',
newChain=['7611ebcf-5323-45ca-b16c-9302d0bdedc6']) from=internal,
task_id=fcf6601a-c432-4b80-821a-14954493b7f4 (api:48)
2021-08-03 15:50:59,485+0300 INFO (merge/62bf8c83) [storage.Image] Current
chain=7611ebcf-5323-45ca-b16c-9302d0bdedc6 < 17618ba1-4ab8-49eb-a991-fc3d602ced14 (top)
(image:1221)
2021-08-03 15:50:59,486+0300 INFO (merge/62bf8c83) [storage.Image] Unlinking subchain:
[u'17618ba1-4ab8-49eb-a991-fc3d602ced14'] (image:1231)
2021-08-03 15:50:59,497+0300 INFO (merge/62bf8c83) [storage.Image] Leaf volume
17618ba1-4ab8-49eb-a991-fc3d602ced14 is being removed from the chain. Marking it ILLEGAL
to prevent data corruption (image:1239)
2021-08-03 15:50:59,498+0300 INFO (merge/62bf8c83) [storage.VolumeManifest]
sdUUID=96000ec9-e181-44eb-893f-e0a36e3a6775 imgUUID=205a30a3-fc06-4ceb-8ef2-018f16d4ccbb
volUUID = 17618ba1-4ab8-49eb-a991-fc3d602ced14 legality = ILLEGAL (volume:387)
2021-08-03 15:50:59,510+0300 INFO (merge/62bf8c83) [vdsm.api] FINISH imageSyncVolumeChain
return=None from=internal, task_id=fcf6601a-c432-4b80-821a-14954493b7f4 (api:54)
2021-08-03 15:50:59,511+0300 INFO (merge/62bf8c83) [vdsm.api] START
getVolumeInfo(sdUUID=u'96000ec9-e181-44eb-893f-e0a36e3a6775',
spUUID='5da76866-7b7d-11eb-9913-00163e1f2643',
imgUUID=u'205a30a3-fc06-4ceb-8ef2-018f16d4ccbb',
volUUID='7611ebcf-5323-45ca-b16c-9302d0bdedc6', options=None) from=internal,
task_id=52f21e75-0ea6-461a-a580-673263a3dbbd (api:48)
2021-08-03 15:50:59,512+0300 INFO (merge/62bf8c83) [storage.VolumeManifest] Info request:
sdUUID=96000ec9-e181-44eb-893f-e0a36e3a6775 imgUUID=205a30a3-fc06-4ceb-8ef2-018f16d4ccbb
volUUID = 7611ebcf-5323-45ca-b16c-9302d0bdedc6 (volume:240)
2021-08-03 15:50:59,529+0300 INFO (merge/62bf8c83) [storage.VolumeManifest]
96000ec9-e181-44eb-893f-e0a36e3a6775/205a30a3-fc06-4ceb-8ef2-018f16d4ccbb/7611ebcf-5323-45ca-b16c-9302d0bdedc6
info is {'status': 'OK', 'domain':
'96000ec9-e181-44eb-893f-e0a36e3a6775', 'voltype': 'INTERNAL',
'description':
'{"DiskAlias":"anova.admin.uoc.gr_Disk2","DiskDescription":""}',
'parent': '00000000-0000-0000-0000-000000000000', 'format':
'RAW', 'generation': 0, 'image':
'205a30a3-fc06-4ceb-8ef2-018f16d4ccbb', 'disktype': 'DATA',
'legality': 'LEGAL', 'mtime': '0', 'apparentsize':
'42949672960', 'children': [], 'pool': '',
'ctime': '1625846644', 'capacity': '42949672960',
'uuid': '7611ebcf-5323-45ca-b16c-9302d0bdedc6', 'truesize':
'42949672960', 'type': 'PREALLOCATED', 'lease':
{'path': '/dev/96000ec9-e181-44eb-893f-e0a36e3a6775/leases',
'owners': [], 'version': None, 'offset': 105906176}} (volume:279)
2021-08-03 15:50:59,529+0300 INFO (merge/62bf8c83) [vdsm.api] FINISH getVolumeInfo
return={'info': {'status': 'OK', 'domain':
'96000ec9-e181-44eb-893f-e0a36e3a6775', 'voltype': 'INTERNAL',
'description':
'{"DiskAlias":"anova.admin.uoc.gr_Disk2","DiskDescription":""}',
'parent': '00000000-0000-0000-0000-000000000000', 'format':
'RAW', 'generation': 0, 'image':
'205a30a3-fc06-4ceb-8ef2-018f16d4ccbb', 'disktype': 'DATA',
'legality': 'LEGAL', 'mtime': '0', 'apparentsize':
'42949672960', 'children': [], 'pool': '',
'ctime': '1625846644', 'capacity': '42949672960',
'uuid': '7611ebcf-5323-45ca-b16c-9302d0bdedc6', 'truesize':
'42949672960', 'type': 'PREALLOCATED', 'lease':
{'path': '/dev/96000ec9-e181-44eb-893f-e0a36e3a6775/leases',
'owners': [], 'version': None, 'offset': 105906176}}}
from=internal, task_id=52f21e75-0ea6-461a-a580-673263a3dbbd (api:54)
2021-08-03 15:50:59,530+0300 INFO (merge/62bf8c83) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Enabling drive monitoring
(drivemonitor:56)
2021-08-03 15:50:59,531+0300 INFO (merge/62bf8c83) [storage.LVM] Deactivating lvs:
vg=96000ec9-e181-44eb-893f-e0a36e3a6775
lvs=[u'17618ba1-4ab8-49eb-a991-fc3d602ced14'] (lvm:1616)
2021-08-03 15:50:59,715+0300 INFO (merge/62bf8c83) [storage.StorageDomainManifest]
Unlinking volume runtime link:
u'/var/run/vdsm/storage/96000ec9-e181-44eb-893f-e0a36e3a6775/205a30a3-fc06-4ceb-8ef2-018f16d4ccbb/17618ba1-4ab8-49eb-a991-fc3d602ced14'
(blockSD:962)
2021-08-03 15:50:59,715+0300 INFO (merge/62bf8c83) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Synchronization completed (job
62bf8c83-cd78-42a5-b57d-d67ddfdee8ee) (vm:6268)
2021-08-03 15:50:59,896+0300 INFO (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC call Host.ping2
succeeded in 0.00 seconds (__init__:312)
2021-08-03 15:50:59,898+0300 INFO (jsonrpc/5) [api.virt] START getStats() from=::1,57084,
vmId=1b11dd30-028d-4938-a59c-6ae10c2089b3 (api:48)
2021-08-03 15:50:59,899+0300 INFO (jsonrpc/5) [api] FINISH getStats error=Virtual machine
does not exist: {'vmId': u'1b11dd30-028d-4938-a59c-6ae10c2089b3'}
(api:129)
2021-08-03 15:50:59,899+0300 INFO (jsonrpc/5) [api.virt] FINISH getStats
return={'status': {'message': "Virtual machine does not exist:
{'vmId': u'1b11dd30-028d-4938-a59c-6ae10c2089b3'}", 'code':
1}} from=::1,57084, vmId=1b11dd30-028d-4938-a59c-6ae10c2089b3 (api:54)
2021-08-03 15:50:59,899+0300 INFO (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call
VM.getStats failed (error 1) in 0.00 seconds (__init__:312)
2021-08-03 15:50:59,912+0300 INFO (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call Host.ping2
succeeded in 0.00 seconds (__init__:312)
2021-08-03 15:51:00,250+0300 INFO (jsonrpc/7) [api.host] START getAllVmStats()
from=::ffff:10.252.80.201,41898 (api:48)
2021-08-03 15:51:00,258+0300 INFO (jsonrpc/7) [api.host] FINISH getAllVmStats
return={'status': {'message': 'Done', 'code': 0},
'statsList': (suppressed)} from=::ffff:10.252.80.201,41898 (api:54)
2021-08-03 15:51:00,263+0300 INFO (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call
Host.getAllVmStats succeeded in 0.01 seconds (__init__:312)
2021-08-03 15:51:00,287+0300 INFO (jsonrpc/6) [api.host] START
dumpxmls(vmList=[u'1c1d20ed-3167-4be7-bff3-29845142fc57'])
from=::ffff:10.252.80.201,41898 (api:48)
2021-08-03 15:51:00,287+0300 INFO (jsonrpc/6) [api.host] FINISH dumpxmls
return={'status': {'message': 'Done', 'code': 0},
'domxmls': {u'1c1d20ed-3167-4be7-bff3-29845142fc57': '<domain
type=\'kvm\' id=\'12\'>\n
<name>anova.admin.uoc.gr</name>\n
<uuid>1c1d20ed-3167-4be7-bff3-29845142fc57</uuid>\n <metadata
xmlns:ns0="http://ovirt.org/vm/tune/1.0"
xmlns:ns1="http://ovirt.org/vm/1.0">\n <ovirt-tune:qos
xmlns:ovirt-tune="http://ovirt.org/vm/tune/1.0">\n
<ovirt-tune:ioTune><ovirt-tune:device name="sda"
path="/rhev/data-center/mnt/blockSD/a5a492a7-f770-4472-baa3-ac7297a581a9/images/2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5/84c005da-cbec-4ace-8619-5a8e2ae5ea75"><ovirt-tune:maximum><ovirt-tune:total_bytes_sec>0</ovirt-tune:total_bytes_sec><ovirt-tune:total_iops_sec>0</ovirt-tune:total_iops_sec><ovirt-tune:read_bytes_sec>157286400</ovirt-tune:read_bytes_sec><ovirt-tune:read_iops_sec>1200</ovirt-tune:read_iops_sec><ovirt-tune:write_bytes_sec>73400320</ovirt-tune:write_bytes_sec><ovirt-tune:write_iops_sec>180</ovirt-tune:write_iops_sec></ovirt-tune:maximum><ovirt-tune:guaranteed><ovirt-tune:total_bytes_sec>0</ovirt-tune:total_bytes_sec><ovirt-tune:total_iops_sec>0</ovirt-tune:total_iops_sec><ovirt-
tune:read_bytes_sec>157286400</ovirt-tune:read_bytes_sec><ovirt-tune:read_iops_sec>1200</ovirt-tune:read_iops_sec><ovirt-tune:write_bytes_sec>73400320</ovirt-tune:write_bytes_sec><ovirt-tune:write_iops_sec>180</ovirt-tune:write_iops_sec></ovirt-tune:guaranteed></ovirt-tune:device></ovirt-tune:ioTune></ovirt-tune:qos>\n
<ovirt-vm:vm xmlns:ovirt-vm="http://ovirt.org/vm/1.0">\n
<ovirt-vm:block_jobs>{"62bf8c83-cd78-42a5-b57d-d67ddfdee8ee":
{"blockJobType": "commit", "topVolume":
"17618ba1-4ab8-49eb-a991-fc3d602ced14", "strategy":
"commit", "jobID": "62bf8c83-cd78-42a5-b57d-d67ddfdee8ee",
"disk": {"domainID": "96000ec9-e181-44eb-893f-e0a36e3a6775",
"imageID": "205a30a3-fc06-4ceb-8ef2-018f16d4ccbb",
"volumeID": "17618ba1-4ab8-49eb-a991-fc3d602ced14",
"poolID": "5da76866-7b7d-11eb-9913-00163e1f2643"},
"baseVolume": "7611ebcf-5323-45ca-b16c-9302d0bdedc6"},
"c57fb3e5-da20-4838-8db3-31655ba76c1f": {"blockJobType":
"commit", "topVolume":
"b43b7c33-5b53-4332-a2e0-f950debb919b", "strategy"
: "commit", "jobID":
"c57fb3e5-da20-4838-8db3-31655ba76c1f", "disk": {"domainID":
"a5a492a7-f770-4472-baa3-ac7297a581a9", "imageID":
"2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5", "volumeID":
"b43b7c33-5b53-4332-a2e0-f950debb919b", "poolID":
"5da76866-7b7d-11eb-9913-00163e1f2643"}, "baseVolume":
"84c005da-cbec-4ace-8619-5a8e2ae5ea75"}}</ovirt-vm:block_jobs>\n
<ovirt-vm:clusterVersion>4.3</ovirt-vm:clusterVersion>\n
<ovirt-vm:destroy_on_reboot
type="bool">False</ovirt-vm:destroy_on_reboot>\n
<ovirt-vm:guestAgentAPIVersion
type="int">0</ovirt-vm:guestAgentAPIVersion>\n
<ovirt-vm:launchPaused>false</ovirt-vm:launchPaused>\n
<ovirt-vm:memGuaranteedSize
type="int">8192</ovirt-vm:memGuaranteedSize>\n
<ovirt-vm:minGuaranteedMemoryMb
type="int">8192</ovirt-vm:minGuaranteedMemoryMb>\n
<ovirt-vm:resumeBehavior>auto_resume</ovirt-vm:resumeBehavior>\n
<ovirt-vm:startTime type="float">1627989778.6</ovirt-vm:startTime>\n
<ovirt-vm:device mac_address="56:6f:c2:77:00:2d">\n
<ovirt-vm:network>Admin-850</ovirt-vm:network>\n
</ovirt-vm:device>\n <ovirt-vm:device devtype="disk"
name="sdb">\n
<ovirt-vm:domainID>96000ec9-e181-44eb-893f-e0a36e3a6775</ovirt-vm:domainID>\n
<ovirt-vm:guestName>\\\\.\\PhysicalDrive1</ovirt-vm:guestName>\n
<ovirt-vm:imageID>205a30a3-fc06-4ceb-8ef2-018f16d4ccbb</ovirt-vm:imageID>\n
<ovirt-vm:poolID>5da76866-7b7d-11eb-9913-00163e1f2643</ovirt-vm:poolID>\n
<ovirt-vm:volumeID>17618ba1-4ab8-49eb-a991-fc3d602ced14</ovirt-vm:volumeID>\n
<ovirt-vm:volumeChain>\n <ovirt-vm:volumeChainNode>\n
<ovirt-vm:domainID>96000ec9-e181-44eb-893f-e0a36e3a6775</ovirt-vm:domainID>\n
<ovirt-vm:imageID>205a30a3-fc06-4ceb-8ef2-018f16d4ccbb</ovirt-vm:imageID>\n
<ovirt-vm:leaseOffset
type="int">111149056</ovirt-vm:leaseOffset>\n
<ovirt-vm:leasePath>/dev/96000ec9-e181-44eb-893f-e0a36e3a6775/leases</ovirt-vm:leasePath>\n
<ovir
t-vm:path>/rhev/data-center/mnt/blockSD/96000ec9-e181-44eb-893f-e0a36e3a6775/images/205a30a3-fc06-4ceb-8ef2-018f16d4ccbb/17618ba1-4ab8-49eb-a991-fc3d602ced14</ovirt-vm:path>\n
<ovirt-vm:volumeID>17618ba1-4ab8-49eb-a991-fc3d602ced14</ovirt-vm:volumeID>\n
</ovirt-vm:volumeChainNode>\n
<ovirt-vm:volumeChainNode>\n
<ovirt-vm:domainID>96000ec9-e181-44eb-893f-e0a36e3a6775</ovirt-vm:domainID>\n
<ovirt-vm:imageID>205a30a3-fc06-4ceb-8ef2-018f16d4ccbb</ovirt-vm:imageID>\n
<ovirt-vm:leaseOffset
type="int">105906176</ovirt-vm:leaseOffset>\n
<ovirt-vm:leasePath>/dev/96000ec9-e181-44eb-893f-e0a36e3a6775/leases</ovirt-vm:leasePath>\n
<ovirt-vm:path>/rhev/data-center/mnt/blockSD/96000ec9-e181-44eb-893f-e0a36e3a6775/images/205a30a3-fc06-4ceb-8ef2-018f16d4ccbb/7611ebcf-5323-45ca-b16c-9302d0bdedc6</ovirt-vm:path>\n
<ovirt-vm:volumeID>7611ebcf-5323-45ca-b16c-9302d0bdedc6</ovirt
-vm:volumeID>\n </ovirt-vm:volumeChainNode>\n
</ovirt-vm:volumeChain>\n </ovirt-vm:device>\n <ovirt-vm:device
devtype="disk" name="sda">\n
<ovirt-vm:domainID>a5a492a7-f770-4472-baa3-ac7297a581a9</ovirt-vm:domainID>\n
<ovirt-vm:guestName>\\\\.\\PhysicalDrive0</ovirt-vm:guestName>\n
<ovirt-vm:imageID>2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5</ovirt-vm:imageID>\n
<ovirt-vm:poolID>5da76866-7b7d-11eb-9913-00163e1f2643</ovirt-vm:poolID>\n
<ovirt-vm:volumeID>b43b7c33-5b53-4332-a2e0-f950debb919b</ovirt-vm:volumeID>\n
<ovirt-vm:volumeChain>\n <ovirt-vm:volumeChainNode>\n
<ovirt-vm:domainID>a5a492a7-f770-4472-baa3-ac7297a581a9</ovirt-vm:domainID>\n
<ovirt-vm:imageID>2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5</ovirt-vm:imageID>\n
<ovirt-vm:leaseOffset
type="int">114294784</ovirt-vm:leaseOffset>\n
<ovirt-vm:leasePath>/dev/a5a492a7-f770-4472-baa3-ac7297a581a9/leases</ovir
t-vm:leasePath>\n
<ovirt-vm:path>/rhev/data-center/mnt/blockSD/a5a492a7-f770-4472-baa3-ac7297a581a9/images/2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5/84c005da-cbec-4ace-8619-5a8e2ae5ea75</ovirt-vm:path>\n
<ovirt-vm:volumeID>84c005da-cbec-4ace-8619-5a8e2ae5ea75</ovirt-vm:volumeID>\n
</ovirt-vm:volumeChainNode>\n
<ovirt-vm:volumeChainNode>\n
<ovirt-vm:domainID>a5a492a7-f770-4472-baa3-ac7297a581a9</ovirt-vm:domainID>\n
<ovirt-vm:imageID>2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5</ovirt-vm:imageID>\n
<ovirt-vm:leaseOffset
type="int">115343360</ovirt-vm:leaseOffset>\n
<ovirt-vm:leasePath>/dev/a5a492a7-f770-4472-baa3-ac7297a581a9/leases</ovirt-vm:leasePath>\n
<ovirt-vm:path>/rhev/data-center/mnt/blockSD/a5a492a7-f770-4472-baa3-ac7297a581a9/images/2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5/b43b7c33-5b53-4332-a2e0-f950debb919b</ovirt-vm:path>\n
<ovirt-vm:volumeID>b43b7
c33-5b53-4332-a2e0-f950debb919b</ovirt-vm:volumeID>\n
</ovirt-vm:volumeChainNode>\n </ovirt-vm:volumeChain>\n
</ovirt-vm:device>\n <ovirt-vm:device devtype="disk"
name="hdc"/>\n</ovirt-vm:vm>\n </metadata>\n <maxMemory
slots=\'16\' unit=\'KiB\'>33554432</maxMemory>\n <memory
unit=\'KiB\'>8388608</memory>\n <currentMemory
unit=\'KiB\'>8388608</currentMemory>\n <vcpu
placement=\'static\' current=\'2\'>16</vcpu>\n
<iothreads>1</iothreads>\n <resource>\n
<partition>/machine</partition>\n </resource>\n <sysinfo
type=\'smbios\'>\n <system>\n <entry
name=\'manufacturer\'>oVirt</entry>\n <entry
name=\'product\'>oVirt Node</entry>\n <entry
name=\'version\'>7-8.2003.0.el7.centos</entry>\n <entry
name=\'serial\'>4c4c4544-0053-4b10-8059-cac04f475832</entry>\n
<entry name=\'uuid\'>1c1d20ed-3167-4be7-bff3-29845142fc57</entry>\n
</system>\n </sysinfo>\n <os>\n <type arch=\'x86_64\'
machine=\'pc-i440fx-rhel7.6.0\'>hvm</type>\n
<smbios mode=\'sysinfo\'/>\n </os>\n <features>\n
<acpi/>\n <hyperv>\n <relaxed state=\'on\'/>\n
<vapic state=\'on\'/>\n <spinlocks state=\'on\'
retries=\'8191\'/>\n <synic state=\'on\'/>\n <stimer
state=\'on\'/>\n </hyperv>\n </features>\n <cpu
mode=\'custom\' match=\'exact\' check=\'full\'>\n <model
fallback=\'forbid\'>Westmere</model>\n <topology
sockets=\'16\' cores=\'1\' threads=\'1\'/>\n <feature
policy=\'require\' name=\'vme\'/>\n <feature
policy=\'require\' name=\'pclmuldq\'/>\n <feature
policy=\'require\' name=\'x2apic\'/>\n <feature
policy=\'require\' name=\'hypervisor\'/>\n <feature
policy=\'require\' name=\'arat\'/>\n <numa>\n <cell
id=\'0\' cpus=\'0-1\' memory=\'8388608\'
unit=\'KiB\'/>\n </numa>\n </cpu>\n <clock
offset=\'variable\' adjustment=\'10795\' basis=\'utc\'>\n
<timer name=\'hypervclock\' present=\'yes\'/>\n <timer
name=\'rtc\' tickpolicy=\'catchup\'/>\n <timer
name=\'pit\' tic
kpolicy=\'delay\'/>\n <timer name=\'hpet\'
present=\'no\'/>\n </clock>\n
<on_poweroff>destroy</on_poweroff>\n
<on_reboot>restart</on_reboot>\n <on_crash>destroy</on_crash>\n
<pm>\n <suspend-to-mem enabled=\'no\'/>\n <suspend-to-disk
enabled=\'no\'/>\n </pm>\n <devices>\n
<emulator>/usr/libexec/qemu-kvm</emulator>\n <disk type=\'file\'
device=\'cdrom\'>\n <driver name=\'qemu\' type=\'raw\'
error_policy=\'report\'/>\n <source
file=\'/rhev/data-center/mnt/10.252.80.208:_home_isos/5b1a0f29-8f97-42c3-bea2-39f83bbfbf24/images/11111111-1111-1111-1111-111111111111/virtio-win-0.1.185.iso\'>\n
<seclabel model=\'dac\' relabel=\'no\'/>\n
</source>\n <backingStore/>\n <target dev=\'hdc\'
bus=\'ide\'/>\n <readonly/>\n <boot
order=\'2\'/>\n <alias
name=\'ua-cfb42882-2eba-41b9-9999-43781eeff382\'/>\n <address
type=\'drive\' controller=\'0\' bus=\'1\' target=\'0\'
unit=\'0\'/>\n </disk>\n <disk type=\'block\'
device=\'di
sk\' snapshot=\'no\'>\n <driver name=\'qemu\'
type=\'qcow2\' cache=\'none\' error_policy=\'stop\'
io=\'native\'/>\n <source
dev=\'/rhev/data-center/mnt/blockSD/a5a492a7-f770-4472-baa3-ac7297a581a9/images/2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5/b43b7c33-5b53-4332-a2e0-f950debb919b\'>\n
<seclabel model=\'dac\' relabel=\'no\'/>\n
</source>\n <backingStore type=\'block\' index=\'1\'>\n
<format type=\'raw\'/>\n <source
dev=\'/rhev/data-center/mnt/blockSD/a5a492a7-f770-4472-baa3-ac7297a581a9/images/2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5/84c005da-cbec-4ace-8619-5a8e2ae5ea75\'/>\n
<backingStore/>\n </backingStore>\n <target
dev=\'sda\' bus=\'scsi\'/>\n <iotune>\n
<read_bytes_sec>157286400</read_bytes_sec>\n
<write_bytes_sec>73400320</write_bytes_sec>\n
<read_iops_sec>1200</read_iops_sec>\n
<write_iops_sec>180</write_iops_sec>\n </iotune>\n
<serial>2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5</serial>\n
<boot order=\'1\'/>\n <alias
name=\'ua-2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5\'/>\n <address
type=\'drive\' controller=\'0\' bus=\'0\' target=\'0\'
unit=\'0\'/>\n </disk>\n <disk type=\'block\'
device=\'disk\' snapshot=\'no\'>\n <driver
name=\'qemu\' type=\'raw\' cache=\'none\'
error_policy=\'stop\' io=\'native\'/>\n <source
dev=\'/rhev/data-center/mnt/blockSD/96000ec9-e181-44eb-893f-e0a36e3a6775/images/205a30a3-fc06-4ceb-8ef2-018f16d4ccbb/7611ebcf-5323-45ca-b16c-9302d0bdedc6\'>\n
<seclabel model=\'dac\' relabel=\'no\'/>\n
</source>\n <backingStore/>\n <target dev=\'sdb\'
bus=\'scsi\'/>\n
<serial>205a30a3-fc06-4ceb-8ef2-018f16d4ccbb</serial>\n <alias
name=\'ua-205a30a3-fc06-4ceb-8ef2-018f16d4ccbb\'/>\n <address
type=\'drive\' controller=\'0\' bus=\'0\' target=\'0\'
unit=\'1\'/>\n </disk>\n <controller type=\'ide\'
index=\'0\'>\n <alias name=\'ide\'/>\n <address
type=\'pci\' domain=\'0x0000\' bus=\'0x00\' slo
t=\'0x01\' function=\'0x1\'/>\n </controller>\n
<controller type=\'scsi\' index=\'0\'
model=\'virtio-scsi\'>\n <driver iothread=\'1\'/>\n
<alias name=\'ua-90ae154d-56b8-499a-9173-c4cd225ba0c6\'/>\n <address
type=\'pci\' domain=\'0x0000\' bus=\'0x00\' slot=\'0x07\'
function=\'0x0\'/>\n </controller>\n <controller
type=\'virtio-serial\' index=\'0\' ports=\'16\'>\n
<alias name=\'ua-a8dc285c-6fa9-45b2-a4f9-c8862be71342\'/>\n <address
type=\'pci\' domain=\'0x0000\' bus=\'0x00\' slot=\'0x04\'
function=\'0x0\'/>\n </controller>\n <controller
type=\'usb\' index=\'0\' model=\'piix3-uhci\'>\n <alias
name=\'usb\'/>\n <address type=\'pci\'
domain=\'0x0000\' bus=\'0x00\' slot=\'0x01\'
function=\'0x2\'/>\n </controller>\n <controller
type=\'pci\' index=\'0\' model=\'pci-root\'>\n <alias
name=\'pci.0\'/>\n </controller>\n <interface
type=\'bridge\'>\n <mac address=\'56:6f:c2:77:00:2d\'/>\n
<source bridge=\'Admin-850\'/
\n <target dev=\'vnet0\'/>\n <model
type=\'e1000\'/>\n <filterref
filter=\'vdsm-no-mac-spoofing\'/>\n <link state=\'up\'/>\n
<mtu size=\'1500\'/>\n <alias
name=\'ua-8cd33e8c-bfda-4474-9aa2-442f4547dddd\'/>\n <address
type=\'pci\' domain=\'0x0000\' bus=\'0x00\' slot=\'0x03\'
function=\'0x0\'/>\n </interface>\n <channel
type=\'unix\'>\n <source mode=\'bind\'
path=\'/var/lib/libvirt/qemu/channels/1c1d20ed-3167-4be7-bff3-29845142fc57.ovirt-guest-agent.0\'/>\n
<target type=\'virtio\' name=\'ovirt-guest-agent.0\'
state=\'disconnected\'/>\n <alias name=\'channel0\'/>\n
<address type=\'virtio-serial\' controller=\'0\' bus=\'0\'
port=\'1\'/>\n </channel>\n <channel type=\'unix\'>\n
<source mode=\'bind\'
path=\'/var/lib/libvirt/qemu/channels/1c1d20ed-3167-4be7-bff3-29845142fc57.org.qemu.guest_agent.0\'/>\n
<target type=\'virtio\' name=\'org.qemu.guest_agent.0\'
state=\'connected\'/>\n <alias name=\'channel1\'/>
\n
<address type=\'virtio-serial\' controller=\'0\' bus=\'0\'
port=\'2\'/>\n </channel>\n <channel
type=\'spicevmc\'>\n <target type=\'virtio\'
name=\'com.redhat.spice.0\' state=\'disconnected\'/>\n <alias
name=\'channel2\'/>\n <address type=\'virtio-serial\'
controller=\'0\' bus=\'0\' port=\'3\'/>\n </channel>\n
<input type=\'tablet\' bus=\'usb\'>\n <alias
name=\'input0\'/>\n <address type=\'usb\' bus=\'0\'
port=\'1\'/>\n </input>\n <input type=\'mouse\'
bus=\'ps2\'>\n <alias name=\'input1\'/>\n
</input>\n <input type=\'keyboard\' bus=\'ps2\'>\n
<alias name=\'input2\'/>\n </input>\n <graphics
type=\'spice\' port=\'5900\' tlsPort=\'5901\'
autoport=\'yes\' listen=\'10.252.83.35\'
passwdValidTo=\'2021-08-03T11:22:07\'>\n <listen
type=\'network\' address=\'10.252.83.35\'
network=\'vdsm-display\'/>\n <channel name=\'main\'
mode=\'secure\'/>\n <channel name=\'display\'
mode=\'secure\'/>\n <channel n
ame=\'inputs\' mode=\'secure\'/>\n <channel
name=\'cursor\' mode=\'secure\'/>\n <channel
name=\'playback\' mode=\'secure\'/>\n <channel
name=\'record\' mode=\'secure\'/>\n <channel
name=\'smartcard\' mode=\'secure\'/>\n <channel
name=\'usbredir\' mode=\'secure\'/>\n </graphics>\n
<graphics type=\'vnc\' port=\'5902\' autoport=\'yes\'
listen=\'10.252.83.35\' keymap=\'en-us\'
passwdValidTo=\'1970-01-01T00:00:01\'>\n <listen
type=\'network\' address=\'10.252.83.35\'
network=\'vdsm-display\'/>\n </graphics>\n <sound
model=\'ich6\'>\n <alias
name=\'ua-47623a12-6bfa-4bee-b219-ce75bef45f14\'/>\n <address
type=\'pci\' domain=\'0x0000\' bus=\'0x00\' slot=\'0x05\'
function=\'0x0\'/>\n </sound>\n <video>\n <model
type=\'qxl\' ram=\'65536\' vram=\'8192\' vgamem=\'16384\'
heads=\'1\' primary=\'yes\'/>\n <alias
name=\'ua-c7f4b218-ceee-44c7-9467-0619834d943f\'/>\n <address
type=\'pci\' domain=\'0x0000\' bus=\'0x00\' slot=\'0x0
2\' function=\'0x0\'/>\n </video>\n <memballoon
model=\'virtio\'>\n <stats period=\'5\'/>\n <alias
name=\'ua-77d77b58-d028-42af-9061-3011bd5e078d\'/>\n <address
type=\'pci\' domain=\'0x0000\' bus=\'0x00\' slot=\'0x06\'
function=\'0x0\'/>\n </memballoon>\n <rng
model=\'virtio\'>\n <backend
model=\'random\'>/dev/urandom</backend>\n <alias
name=\'ua-dac6fdf6-1164-4d64-8d98-a53b893a08c2\'/>\n <address
type=\'pci\' domain=\'0x0000\' bus=\'0x00\' slot=\'0x08\'
function=\'0x0\'/>\n </rng>\n </devices>\n <seclabel
type=\'dynamic\' model=\'selinux\' relabel=\'yes\'>\n
<label>system_u:system_r:svirt_t:s0:c257,c520</label>\n
<imagelabel>system_u:object_r:svirt_image_t:s0:c257,c520</imagelabel>\n
</seclabel>\n <seclabel type=\'dynamic\' model=\'dac\'
relabel=\'yes\'>\n <label>+107:+107</label>\n
<imagelabel>+107:+107</imagelabel>\n
</seclabel>\n</domain>\n'}} from=::ffff:10.252.80.201,41898 (api:54)
2021-08-03 15:51:00,287+0300 INFO (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call
Host.dumpxmls succeeded in 0.00 seconds (__init__:312)
2021-08-03 15:51:01,183+0300 INFO (periodic/4) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Cleanup thread
<vdsm.virt.vm.LiveMergeCleanupThread object at 0x7ff9987db690> successfully
completed, untracking job 62bf8c83-cd78-42a5-b57d-d67ddfdee8ee
(base=7611ebcf-5323-45ca-b16c-9302d0bdedc6, top=17618ba1-4ab8-49eb-a991-fc3d602ced14)
(vm:5758)
2021-08-03 15:51:01,208+0300 INFO (periodic/4) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Libvirt job
c57fb3e5-da20-4838-8db3-31655ba76c1f was terminated (vm:5807)
2021-08-03 15:51:01,208+0300 INFO (periodic/4) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Starting cleanup thread for job:
c57fb3e5-da20-4838-8db3-31655ba76c1f (vm:5815)
2021-08-03 15:51:01,209+0300 INFO (merge/c57fb3e5) [vdsm.api] START
getVolumeInfo(sdUUID=u'a5a492a7-f770-4472-baa3-ac7297a581a9',
spUUID='5da76866-7b7d-11eb-9913-00163e1f2643',
imgUUID=u'2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5',
volUUID=u'b43b7c33-5b53-4332-a2e0-f950debb919b', options=None) from=internal,
task_id=20f15173-bfe8-4df0-b879-87deea2569eb (api:48)
2021-08-03 15:51:01,210+0300 INFO (merge/c57fb3e5) [storage.VolumeManifest] Info request:
sdUUID=a5a492a7-f770-4472-baa3-ac7297a581a9 imgUUID=2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5
volUUID = b43b7c33-5b53-4332-a2e0-f950debb919b (volume:240)
2021-08-03 15:51:01,227+0300 INFO (merge/c57fb3e5) [storage.VolumeManifest]
a5a492a7-f770-4472-baa3-ac7297a581a9/2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5/b43b7c33-5b53-4332-a2e0-f950debb919b
info is {'status': 'OK', 'domain':
'a5a492a7-f770-4472-baa3-ac7297a581a9', 'voltype': 'LEAF',
'description': '', 'parent':
'84c005da-cbec-4ace-8619-5a8e2ae5ea75', 'format': 'COW',
'generation': 0, 'image': '2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5',
'disktype': 'DATA', 'legality': 'LEGAL', 'mtime':
'0', 'apparentsize': '1073741824', 'children': [],
'pool': '', 'ctime': '1627991039', 'capacity':
'150323855360', 'uuid': u'b43b7c33-5b53-4332-a2e0-f950debb919b',
'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'path':
'/dev/a5a492a7-f770-4472-baa3-ac7297a581a9/leases', 'owners': [],
'version': None, 'offset': 115343360}} (volume:279)
2021-08-03 15:51:01,228+0300 INFO (merge/c57fb3e5) [vdsm.api] FINISH getVolumeInfo
return={'info': {'status': 'OK', 'domain':
'a5a492a7-f770-4472-baa3-ac7297a581a9', 'voltype': 'LEAF',
'description': '', 'parent':
'84c005da-cbec-4ace-8619-5a8e2ae5ea75', 'format': 'COW',
'generation': 0, 'image': '2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5',
'disktype': 'DATA', 'legality': 'LEGAL', 'mtime':
'0', 'apparentsize': '1073741824', 'children': [],
'pool': '', 'ctime': '1627991039', 'capacity':
'150323855360', 'uuid': u'b43b7c33-5b53-4332-a2e0-f950debb919b',
'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'path':
'/dev/a5a492a7-f770-4472-baa3-ac7297a581a9/leases', 'owners': [],
'version': None, 'offset': 115343360}}} from=internal,
task_id=20f15173-bfe8-4df0-b879-87deea2569eb (api:54)
2021-08-03 15:51:01,229+0300 INFO (merge/c57fb3e5) [vdsm.api] START
setVolumeSize(sdUUID=u'a5a492a7-f770-4472-baa3-ac7297a581a9',
spUUID='5da76866-7b7d-11eb-9913-00163e1f2643',
imgUUID=u'2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5',
volUUID=u'84c005da-cbec-4ace-8619-5a8e2ae5ea75', capacity='150323855360')
from=internal, task_id=ada8862a-eebc-43a0-a4d3-29d3f63adc80 (api:48)
2021-08-03 15:51:01,241+0300 INFO (merge/c57fb3e5) [vdsm.api] FINISH setVolumeSize
return=None from=internal, task_id=ada8862a-eebc-43a0-a4d3-29d3f63adc80 (api:54)
2021-08-03 15:51:01,242+0300 INFO (merge/c57fb3e5) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Synchronizing volume chain after
live merge (job c57fb3e5-da20-4838-8db3-31655ba76c1f) (vm:6259)
2021-08-03 15:51:01,266+0300 INFO (merge/c57fb3e5) [vdsm.api] START
imageSyncVolumeChain(sdUUID=u'a5a492a7-f770-4472-baa3-ac7297a581a9',
imgUUID=u'2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5',
volUUID=u'b43b7c33-5b53-4332-a2e0-f950debb919b',
newChain=['84c005da-cbec-4ace-8619-5a8e2ae5ea75',
'b43b7c33-5b53-4332-a2e0-f950debb919b']) from=internal,
task_id=fbb973a1-25a6-49a2-900c-3ab182f8eb06 (api:48)
2021-08-03 15:51:01,497+0300 INFO (merge/c57fb3e5) [storage.Image] Current
chain=84c005da-cbec-4ace-8619-5a8e2ae5ea75 < b43b7c33-5b53-4332-a2e0-f950debb919b (top)
(image:1221)
2021-08-03 15:51:01,498+0300 INFO (merge/c57fb3e5) [vdsm.api] FINISH imageSyncVolumeChain
return=None from=internal, task_id=fbb973a1-25a6-49a2-900c-3ab182f8eb06 (api:54)
2021-08-03 15:51:01,499+0300 INFO (merge/c57fb3e5) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Synchronization completed (job
c57fb3e5-da20-4838-8db3-31655ba76c1f) (vm:6268)
12:29 a.m.
here os the vdsm.log from the SPM
there is a report for the second disk of the vm but the first (the one which failes to
merge does not seem to be anywhere)
2021-08-03 15:51:40,051+0300 INFO (jsonrpc/7) [vdsm.api] START
getVolumeInfo(sdUUID=u'96000ec9-e181-44eb-893f-e0a36e3a6775',
spUUID=u'5da76866-7b7d-11eb-9913-00163e1f2643',
imgUUID=u'205a30a3-fc06-4ceb-8ef2-018f16d4ccbb',
volUUID=u'7611ebcf-5323-45ca-b16c-9302d0bdedc6', options=None)
from=::ffff:10.252.80.201,58850, flow_id=3bf9345d-fab2-490f-ba44-6aa014bbb743,
task_id=be6c50d9-a8e4-4ef5-85cf-87a00d79d77e (api:48)
2021-08-03 15:51:40,052+0300 INFO (jsonrpc/7) [storage.VolumeManifest] Info request:
sdUUID=96000ec9-e181-44eb-893f-e0a36e3a6775 imgUUID=205a30a3-fc06-4ceb-8ef2-018f16d4ccbb
volUUID = 7611ebcf-5323-45ca-b16c-9302d0bdedc6 (volume:240)
2021-08-03 15:51:40,081+0300 INFO (jsonrpc/7) [storage.VolumeManifest]
96000ec9-e181-44eb-893f-e0a36e3a6775/205a30a3-fc06-4ceb-8ef2-018f16d4ccbb/7611ebcf-5323-45ca-b16c-9302d0bdedc6
info is {'status': 'OK', 'domain':
'96000ec9-e181-44eb-893f-e0a36e3a6775', 'voltype': 'LEAF',
'description':
'{"DiskAlias":"anova.admin.uoc.gr_Disk2","DiskDescription":""}',
'parent': '00000000-0000-0000-0000-000000000000', 'format':
'RAW', 'generation': 0, 'image':
'205a30a3-fc06-4ceb-8ef2-018f16d4ccbb', 'disktype': 'DATA',
'legality': 'LEGAL', 'mtime': '0', 'apparentsize':
'42949672960', 'children': [], 'pool': '',
'ctime': '1625846644', 'capacity': '42949672960',
'uuid': u'7611ebcf-5323-45ca-b16c-9302d0bdedc6', 'truesize':
'42949672960', 'type': 'PREALLOCATED', 'lease':
{'path': '/dev/96000ec9-e181-44eb-893f-e0a36e3a6775/leases',
'owners': [], 'version': None, 'offset': 105906176}} (volume:279)
2021-08-03 15:51:40,081+0300 INFO (jsonrpc/7) [vdsm.api] FINISH getVolumeInfo
return={'info': {'status': 'OK', 'domain':
'96000ec9-e181-44eb-893f-e0a36e3a6775', 'voltype': 'LEAF',
'description':
'{"DiskAlias":"anova.admin.uoc.gr_Disk2","DiskDescription":""}',
'parent': '00000000-0000-0000-0000-000000000000', 'format':
'RAW', 'generation': 0, 'image':
'205a30a3-fc06-4ceb-8ef2-018f16d4ccbb', 'disktype': 'DATA',
'legality': 'LEGAL', 'mtime': '0', 'apparentsize':
'42949672960', 'children': [], 'pool': '',
'ctime': '1625846644', 'capacity': '42949672960',
'uuid': u'7611ebcf-5323-45ca-b16c-9302d0bdedc6', 'truesize':
'42949672960', 'type': 'PREALLOCATED', 'lease':
{'path': '/dev/96000ec9-e181-44eb-893f-e0a36e3a6775/leases',
'owners': [], 'version': None, 'offset': 105906176}}}
from=::ffff:10.252.80.201,58850, flow_id=3bf9345d-fab2-490f-ba44-6aa014bbb743,
task_id=be6c50d9-a8e4-4ef5-85cf-87a00d79d77e (api:54)
2021-08-03 15:51:40,083+0300 INFO (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call
Volume.getInfo succeeded in 0.04 seconds (__init__:312)
last appearance of this drive on the spm vdsm.log is when the snapshot download finishes:
2021-08-03 15:34:18,619+0300 INFO (jsonrpc/6) [vdsm.api] FINISH get_image_ticket
return={'result': {u'timeout': 300, u'idle_time': 0,
u'uuid': u'5c1943a9-cac4-4398-9ec1-46ab82cacd04', u'ops':
[u'read'], u'url':
u'file:///rhev/data-center/mnt/blockSD/a5a492a7-f770-4472-baa3-ac7297a581a9/images/2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5/84c005da-cbec-4ace-8619-5a8e2ae5ea75',
u'expires': 6191177, u'transferred': 150256746496, u'transfer_id':
u'7dcb75c0-4373-4986-b25f-5629b1b68f5d', u'sparse': False,
u'active': True, u'size': 150323855360}} from=::ffff:10.252.80.201,58850,
flow_id=3035db30-8a8c-48a5-b0c6-0781fda6ac2e, task_id=674028a2-e37c-46e4-a463-eeae1b09aef0
(api:54)
2021-08-03 15:34:18,620+0300 INFO (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call
Host.get_image_ticket succeeded in 0.00 seconds (__init__:312)
If I can send any more information or test something please let me know.
3:03 a.m.
2021-08-03 15:50:59,040+0300 ERROR (libvirt/events) [virt.vm]
(vmId='1c1d20ed-3167-4be7-bff3-29845142fc57') Block job ACTIVE_COMMIT
for drive
/rhev/data-center/mnt/blockSD/a5a492a7-f770-4472-baa3-ac7297a581a9/images/2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5/b43b7c33-5b53-4332-a2e0-f950debb919b
has failed (vm:5847)
Do you have access to libvirtd logs?
Since you're using an outdated version it's possible you've hit an old
bug that's been fixed
On Wed, Aug 4, 2021 at 10:30 AM <g.vasilopoulos(a)uoc.gr> wrote:
here os the vdsm.log from the SPM
there is a report for the second disk of the vm but the first (the one which failes to
merge does not seem to be anywhere)
2021-08-03 15:51:40,051+0300 INFO (jsonrpc/7) [vdsm.api] START
getVolumeInfo(sdUUID=u'96000ec9-e181-44eb-893f-e0a36e3a6775',
spUUID=u'5da76866-7b7d-11eb-9913-00163e1f2643',
imgUUID=u'205a30a3-fc06-4ceb-8ef2-018f16d4ccbb',
volUUID=u'7611ebcf-5323-45ca-b16c-9302d0bdedc6', options=None)
from=::ffff:10.252.80.201,58850, flow_id=3bf9345d-fab2-490f-ba44-6aa014bbb743,
task_id=be6c50d9-a8e4-4ef5-85cf-87a00d79d77e (api:48)
2021-08-03 15:51:40,052+0300 INFO (jsonrpc/7) [storage.VolumeManifest] Info request:
sdUUID=96000ec9-e181-44eb-893f-e0a36e3a6775 imgUUID=205a30a3-fc06-4ceb-8ef2-018f16d4ccbb
volUUID = 7611ebcf-5323-45ca-b16c-9302d0bdedc6 (volume:240)
2021-08-03 15:51:40,081+0300 INFO (jsonrpc/7) [storage.VolumeManifest]
96000ec9-e181-44eb-893f-e0a36e3a6775/205a30a3-fc06-4ceb-8ef2-018f16d4ccbb/7611ebcf-5323-45ca-b16c-9302d0bdedc6
info is {'status': 'OK', 'domain':
'96000ec9-e181-44eb-893f-e0a36e3a6775', 'voltype': 'LEAF',
'description':
'{"DiskAlias":"anova.admin.uoc.gr_Disk2","DiskDescription":""}',
'parent': '00000000-0000-0000-0000-000000000000', 'format':
'RAW', 'generation': 0, 'image':
'205a30a3-fc06-4ceb-8ef2-018f16d4ccbb', 'disktype': 'DATA',
'legality': 'LEGAL', 'mtime': '0', 'apparentsize':
'42949672960', 'children': [], 'pool': '',
'ctime': '1625846644', 'capacity': '42949672960',
'uuid': u'7611ebcf-5323-45ca-b16c-9302d0bdedc6', 'truesize':
'42949672960', 'type': 'PREALLOCATED', 'lease':
{'path': '/dev/96000ec9-e181-44eb-893f-e0a36e3a6775/leases',
'owners': [], 'version': None, 'offset': 105906176}} (volume:279)
2021-08-03 15:51:40,081+0300 INFO (jsonrpc/7) [vdsm.api] FINISH getVolumeInfo
return={'info': {'status': 'OK', 'domain':
'96000ec9-e181-44eb-893f-e0a36e3a6775', 'voltype': 'LEAF',
'description':
'{"DiskAlias":"anova.admin.uoc.gr_Disk2","DiskDescription":""}',
'parent': '00000000-0000-0000-0000-000000000000', 'format':
'RAW', 'generation': 0, 'image':
'205a30a3-fc06-4ceb-8ef2-018f16d4ccbb', 'disktype': 'DATA',
'legality': 'LEGAL', 'mtime': '0', 'apparentsize':
'42949672960', 'children': [], 'pool': '',
'ctime': '1625846644', 'capacity': '42949672960',
'uuid': u'7611ebcf-5323-45ca-b16c-9302d0bdedc6', 'truesize':
'42949672960', 'type': 'PREALLOCATED', 'lease':
{'path': '/dev/96000ec9-e181-44eb-893f-e0a36e3a6775/leases',
'owners': [], 'version': None, 'offset': 105906176}}}
from=::ffff:10.252.80.201,58850, flow_id=3bf9345d-fab2-490f-ba44-6aa014bbb743,
task_id=be6c50d9-a8e4-4ef5-85cf-87a00d79d77e (api:54)
2021-08-03 15:51:40,083+0300 INFO (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call
Volume.getInfo succeeded in 0.04 seconds (__init__:312)
last appearance of this drive on the spm vdsm.log is when the snapshot download
finishes:
2021-08-03 15:34:18,619+0300 INFO (jsonrpc/6) [vdsm.api] FINISH get_image_ticket
return={'result': {u'timeout': 300, u'idle_time': 0,
u'uuid': u'5c1943a9-cac4-4398-9ec1-46ab82cacd04', u'ops':
[u'read'], u'url':
u'file:///rhev/data-center/mnt/blockSD/a5a492a7-f770-4472-baa3-ac7297a581a9/images/2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5/84c005da-cbec-4ace-8619-5a8e2ae5ea75',
u'expires': 6191177, u'transferred': 150256746496, u'transfer_id':
u'7dcb75c0-4373-4986-b25f-5629b1b68f5d', u'sparse': False,
u'active': True, u'size': 150323855360}} from=::ffff:10.252.80.201,58850,
flow_id=3035db30-8a8c-48a5-b0c6-0781fda6ac2e, task_id=674028a2-e37c-46e4-a463-eeae1b09aef0
(api:54)
2021-08-03 15:34:18,620+0300 INFO (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call
Host.get_image_ticket succeeded in 0.00 seconds (__init__:312)
If I can send any more information or test something please let me know.
_______________________________________________
Users mailing list -- users(a)ovirt.org
To unsubscribe send an email to users-leave(a)ovirt.org
Privacy Statement: https://www.ovirt.org/privacy-policy.html
oVirt Code of Conduct: https://www.ovirt.org/community/about/community-guidelines/
List Archives:
https://lists.ovirt.org/archives/list/users@ovirt.org/message/KEJ24BI6PLX...
3:09 a.m.
I think these are the corresponding logs
qcow2: Marking image as corrupt: Cluster allocation offset 0x7890c000 unaligned (L2
offset: 0x39e00000, L2 index: 0); further corruption events will be suppressed
main_channel_link: add main channel client
main_channel_client_handle_pong: net test: latency 12.959000 ms, bitrate 3117199391 bps
(2972.792998 Mbps)
inputs_connect: inputs channel client create
red_qxl_set_cursor_peer:
red_channel_client_disconnect: rcc=0x56405bdf69c0 (channel=0x56405ad7c940 type=3 id=0)
red_channel_client_disconnect: rcc=0x56405e78cdd0 (channel=0x56405bb96900 type=4 id=0)
red_channel_client_disconnect: rcc=0x56405e79c5b0 (channel=0x56405ad7c220 type=2 id=0)
red_channel_client_disconnect: rcc=0x56405bdea9f0 (channel=0x56405ad7c150 type=1 id=0)
main_channel_client_on_disconnect: rcc=0x56405bdea9f0
red_client_destroy: destroy client 0x56405c383110 with #channels=4
red_qxl_disconnect_cursor_peer:
red_qxl_disconnect_display_peer:
2021-08-03T08:10:50.516974Z qemu-kvm: terminating on signal 15 from pid 6847 (<unknown
process>)
2021-08-03 08:10:50.717+0000: shutting down, reason=destroyed
2021-08-03 11:02:57.502+0000: starting up libvirt version: 4.5.0, package: 33.el7_8.1
(CentOS BuildSystem <http://bugs.centos.org>;, 2020-05-12-16:25:35,
x86-01.bsys.centos.org), qemu version: 2.12.0qemu-kvm-ev-2.12.0-44.1.el7_8.1, kernel:
3.10.0-1127.8.2.el7.x86_64, hostname: ovirt3-5.vmmgmt-int.uoc.gr
LC_ALL=C \
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin \
QEMU_AUDIO_DRV=none \
/usr/libexec/qemu-kvm \
-name guest=anova.admin.uoc.gr,debug-threads=on \
-S \
-object
secret,id=masterKey0,format=raw,file=/var/lib/libvirt/qemu/domain-12-anova.admin.uoc.gr/master-key.aes
\
-machine pc-i440fx-rhel7.6.0,accel=kvm,usb=off,dump-guest-core=off \
-cpu
Westmere,vme=on,pclmuldq=on,x2apic=on,hypervisor=on,arat=on,hv_time,hv_relaxed,hv_vapic,hv_spinlocks=0x1fff,hv_synic,hv_stimer
\
-m size=8388608k,slots=16,maxmem=33554432k \
-realtime mlock=off \
-smp 2,maxcpus=16,sockets=16,cores=1,threads=1 \
-object iothread,id=iothread1 \
-numa node,nodeid=0,cpus=0-1,mem=8192 \
-uuid 1c1d20ed-3167-4be7-bff3-29845142fc57 \
-smbios 'type=1,manufacturer=oVirt,product=oVirt
Node,version=7-8.2003.0.el7.centos,serial=4c4c4544-0053-4b10-8059-cac04f475832,uuid=1c1d20ed-3167-4be7-bff3-29845142fc57'
\
-no-user-config \
-nodefaults \
-chardev socket,id=charmonitor,fd=33,server,nowait \
-mon chardev=charmonitor,id=monitor,mode=control \
-rtc base=2021-08-03T12:02:56,driftfix=slew \
-global kvm-pit.lost_tick_policy=delay \
-no-hpet \
-no-shutdown \
-global PIIX4_PM.disable_s3=1 \
-global PIIX4_PM.disable_s4=1 \
-boot strict=on \
-device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 \
-device
virtio-scsi-pci,iothread=iothread1,id=ua-90ae154d-56b8-499a-9173-c4cd225ba0c6,bus=pci.0,addr=0x7
\
-device
virtio-serial-pci,id=ua-a8dc285c-6fa9-45b2-a4f9-c8862be71342,max_ports=16,bus=pci.0,addr=0x4
\
-drive
file=/rhev/data-center/mnt/10.252.80.208:_home_isos/5b1a0f29-8f97-42c3-bea2-39f83bbfbf24/images/11111111-1111-1111-1111-111111111111/virtio-win-0.1.185.iso,format=raw,if=none,id=drive-ua-cfb42882-2eba-41b9-9999-43781eeff382,werror=report,rerror=report,readonly=on
\
-device
ide-cd,bus=ide.1,unit=0,drive=drive-ua-cfb42882-2eba-41b9-9999-43781eeff382,id=ua-cfb42882-2eba-41b9-9999-43781eeff382,bootindex=2
\
-drive
file=/rhev/data-center/mnt/blockSD/a5a492a7-f770-4472-baa3-ac7297a581a9/images/2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5/84c005da-cbec-4ace-8619-5a8e2ae5ea75,format=raw,if=none,id=drive-ua-2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5,serial=2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5,werror=stop,rerror=stop,cache=none,aio=native,throttling.bps-read=157286400,throttling.bps-write=73400320,throttling.iops-read=1200,throttling.iops-write=180
\
9:01 a.m.
On Fri, Aug 6, 2021 at 1:16 PM <g.vasilopoulos(a)uoc.gr> wrote:
I think these are the corresponding logs
qcow2: Marking image as corrupt: Cluster allocation offset 0x7890c000 unaligned (L2
offset: 0x39e00000, L2 index: 0); further corruption events will be suppressed
This disk was corrupted by a previous run of the vm.
main_channel_link: add main channel client
main_channel_client_handle_pong: net test: latency 12.959000 ms, bitrate 3117199391 bps
(2972.792998 Mbps)
inputs_connect: inputs channel client create
red_qxl_set_cursor_peer:
red_channel_client_disconnect: rcc=0x56405bdf69c0 (channel=0x56405ad7c940 type=3 id=0)
red_channel_client_disconnect: rcc=0x56405e78cdd0 (channel=0x56405bb96900 type=4 id=0)
red_channel_client_disconnect: rcc=0x56405e79c5b0 (channel=0x56405ad7c220 type=2 id=0)
red_channel_client_disconnect: rcc=0x56405bdea9f0 (channel=0x56405ad7c150 type=1 id=0)
main_channel_client_on_disconnect: rcc=0x56405bdea9f0
red_client_destroy: destroy client 0x56405c383110 with #channels=4
red_qxl_disconnect_cursor_peer:
red_qxl_disconnect_display_peer:
2021-08-03T08:10:50.516974Z qemu-kvm: terminating on signal 15 from pid 6847 (<unknown
process>)
2021-08-03 08:10:50.717+0000: shutting down, reason=destroyed
Did you replace the corrupted disk before starting the vm again 3 hours later?
2021-08-03 11:02:57.502+0000: starting up libvirt version: 4.5.0,
package: 33.el7_8.1 (CentOS BuildSystem <http://bugs.centos.org>;,
2020-05-12-16:25:35, x86-01.bsys.centos.org), qemu version:
2.12.0qemu-kvm-ev-2.12.0-44.1.el7_8.1, kernel: 3.10.0-1127.8.2.el7.x86_64, hostname:
ovirt3-5.vmmgmt-int.uoc.gr
LC_ALL=C \
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin \
QEMU_AUDIO_DRV=none \
/usr/libexec/qemu-kvm \
-name guest=anova.admin.uoc.gr,debug-threads=on \
-S \
-object
secret,id=masterKey0,format=raw,file=/var/lib/libvirt/qemu/domain-12-anova.admin.uoc.gr/master-key.aes
\
-machine pc-i440fx-rhel7.6.0,accel=kvm,usb=off,dump-guest-core=off \
-cpu
Westmere,vme=on,pclmuldq=on,x2apic=on,hypervisor=on,arat=on,hv_time,hv_relaxed,hv_vapic,hv_spinlocks=0x1fff,hv_synic,hv_stimer
\
-m size=8388608k,slots=16,maxmem=33554432k \
-realtime mlock=off \
-smp 2,maxcpus=16,sockets=16,cores=1,threads=1 \
-object iothread,id=iothread1 \
-numa node,nodeid=0,cpus=0-1,mem=8192 \
-uuid 1c1d20ed-3167-4be7-bff3-29845142fc57 \
-smbios 'type=1,manufacturer=oVirt,product=oVirt
Node,version=7-8.2003.0.el7.centos,serial=4c4c4544-0053-4b10-8059-cac04f475832,uuid=1c1d20ed-3167-4be7-bff3-29845142fc57'
\
-no-user-config \
-nodefaults \
-chardev socket,id=charmonitor,fd=33,server,nowait \
-mon chardev=charmonitor,id=monitor,mode=control \
-rtc base=2021-08-03T12:02:56,driftfix=slew \
-global kvm-pit.lost_tick_policy=delay \
-no-hpet \
-no-shutdown \
-global PIIX4_PM.disable_s3=1 \
-global PIIX4_PM.disable_s4=1 \
-boot strict=on \
-device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 \
-device
virtio-scsi-pci,iothread=iothread1,id=ua-90ae154d-56b8-499a-9173-c4cd225ba0c6,bus=pci.0,addr=0x7
\
-device
virtio-serial-pci,id=ua-a8dc285c-6fa9-45b2-a4f9-c8862be71342,max_ports=16,bus=pci.0,addr=0x4
\
-drive
file=/rhev/data-center/mnt/10.252.80.208:_home_isos/5b1a0f29-8f97-42c3-bea2-39f83bbfbf24/images/11111111-1111-1111-1111-111111111111/virtio-win-0.1.185.iso,format=raw,if=none,id=drive-ua-cfb42882-2eba-41b9-9999-43781eeff382,werror=report,rerror=report,readonly=on
\
-device
ide-cd,bus=ide.1,unit=0,drive=drive-ua-cfb42882-2eba-41b9-9999-43781eeff382,id=ua-cfb42882-2eba-41b9-9999-43781eeff382,bootindex=2
\
-drive
file=/rhev/data-center/mnt/blockSD/a5a492a7-f770-4472-baa3-ac7297a581a9/images/2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5/84c005da-cbec-4ace-8619-5a8e2ae5ea75,format=raw,if=none,id=drive-ua-2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5,serial=2e6e3cd3-f0cb-47a7-8bda-7738bd7c1fb5,werror=stop,rerror=stop,cache=none,aio=native,throttling.bps-read=157286400,throttling.bps-write=73400320,throttling.iops-read=1200,throttling.iops-write=180
\
This log does not show anything except the corruption in the previous run.
What we need is libvirtd.log from /var/log/libvirt/libvirtd.log.
The log usually does not exist since it is too verbose to enable by default.
You can try to enable libvirt logs temporarily, see:
https://libvirt.org/kbase/debuglogs.html
Nir
9:31 p.m.
Helo Nir,
No I do not have libvirt logs enabled.
I restored the vm from the snapshot and retried. It did boot but at the same time it did
not merge again when I tried it. On the other hand when I cloned it and tried to recreate
the situation the image did merge.
Is it possible that the image is corrupted for any reason beyond live merge failure,so the
merge fails regardles?
This is a production vm so I cannot play a lot with it :-(
I should probably clone it give the clone to production and see if this continues to
happen.
Thank you for your help. I ll let you know if I can find out anything new.
2:28 a.m.
On Tue, Aug 10, 2021 at 7:33 AM <g.vasilopoulos(a)uoc.gr> wrote:
Helo Nir,
No I do not have libvirt logs enabled.
I restored the vm from the snapshot and retried. It did boot but at the same time it did
not merge again when I tried it. On the other hand when I cloned it and tried to recreate
the situation the image did merge.
Is it possible that the image is corrupted for any reason beyond live merge failure,so
the merge fails regardles?
This is a production vm so I cannot play a lot with it :-(
I should probably clone it give the clone to production and see if this continues to
happen.
I see you are using ovirt 4.3.10 - we fixed some snapshot deletion
issues in 4.4.
For your case I would try to:
1. Clone the VM - can you delete the snapshot in the clone?
2. Shutdown the clone - can delete the snapshot when the clone is shutdown?
Please file a bug and attach vdsm and engine logs showing the
timeframe when you tried
to delete the snapshot.
Nir
991
days inactive
998
days old
8 comments
3 participants
participants (3)
-
Benny Zlotnik -
g.vasilopoulos＠uoc.gr -
Nir Soffer