10:05 a.m.
Hello,
We are experiencing some problems with some snapshots in illegal status
generated with the python API. I think I'm not the only one, and that is
not a relief but I hope someone can help about it.
I'm a bit scared because, for what I see, the creation date in the engine
for every snapshot is way different from the date when it was really
created. The name of the snapshot is in the format
backup_snapshot_YYYYMMDD-HHMMSS, but as you can see in the following
examples, the stored date is totally random...
Size
Creation Date
Snapshot Description
Status
Disk Snapshot ID
33 GiB
Mar 2, 2018, 5:03:57 PM
backup_snapshot_20190217-011645
Illegal
5734df23-de67-41a8-88a1-423cecfe7260
33 GiB
May 8, 2018, 10:02:56 AM
backup_snapshot_20190216-013047
Illegal
f649d9c1-563e-49d4-9fad-6bc94abc279b
10 GiB
Feb 21, 2018, 11:10:17 AM
backup_snapshot_20190217-010004
Illegal
2929df28-eae8-4f27-afee-a984fe0b07e7
43 GiB
Feb 2, 2018, 12:55:51 PM
backup_snapshot_20190216-015544
Illegal
4bd4360e-e0f4-4629-ab38-2f0d80d3ae0f
11 GiB
Feb 13, 2018, 12:51:08 PM
backup_snapshot_20190217-010541
Illegal
fbaff53b-30ce-4b20-8f10-80e70becb48c
11 GiB
Feb 13, 2018, 4:05:39 PM
backup_snapshot_20190217-011207
Illegal
c628386a-da6c-4a0d-ae7d-3e6ecda27d6d
11 GiB
Feb 13, 2018, 4:38:25 PM
backup_snapshot_20190216-012058
Illegal
e9ddaa5c-007d-49e6-8384-efefebb00aa6
11 GiB
Feb 13, 2018, 10:52:09 AM
backup_snapshot_20190216-012550
Illegal
5b6db52a-bfe3-45f8-b7bb-d878c4e63cb4
55 GiB
Jan 22, 2018, 5:02:29 PM
backup_snapshot_20190217-012659
Illegal
7efe2e7e-ca24-4b27-b512-b42795c79ea4
When I'm getting the logs for the first one, to check what happened to it,
I get the following
2019-02-17 01:16:45,839+01 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.CreateVolumeVDSCommand] (default
task-100) [96944daa-c90a-4ad7-a556-c98e66550f87] START,
CreateVolumeVDSCommand(
CreateVolumeVDSCommandParameters:{storagePoolId='fa64792e-73b3-4da2-9d0b-f334422aaccf',
ignoreFailoverLimit='false',
storageDomainId='e655abce-c5e8-44f3-8d50-9fd76edf05cb',
imageGroupId='c5cc464e-eb71-4edf-a780-60180c592a6f',
imageSizeInBytes='32212254720', volumeFormat='COW',
newImageId='fa154782-0dbb-45b5-ba62-d6937259f097', imageType='Sparse',
newImageDescription='', imageInitialSizeInBytes='0',
imageId='5734df23-de67-41a8-88a1-423cecfe7260',
sourceImageGroupId='c5cc464e-eb71-4edf-a780-60180c592a6f'}), log id:
497c168a
2019-02-17 01:18:26,506+01 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand]
(default task-212) [19f00d3e-5159-48aa-b3a0-615a085b62d9] START,
GetVolumeInfoVDSCommand(HostName = hood13.pic.es,
GetVolumeInfoVDSCommandParameters:{hostId='0a774472-5737-4ea2-b49a-6f0ea4572199',
storagePoolId='fa64792e-73b3-4da2-9d0b-f334422aaccf',
storageDomainId='e655abce-c5e8-44f3-8d50-9fd76edf05cb',
imageGroupId='c5cc464e-eb71-4edf-a780-60180c592a6f',
imageId='5734df23-de67-41a8-88a1-423cecfe7260'}), log id: 111a34cf
2019-02-17 01:18:26,764+01 INFO
[org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand]
(default task-212) [19f00d3e-5159-48aa-b3a0-615a085b62d9] Successfully
added Download disk 'vm.example.com_Disk1' (id
'5734df23-de67-41a8-88a1-423cecfe7260') for image transfer command
'11104d8c-2a9b-4924-96ce-42ef66725616'
2019-02-17 01:18:27,310+01 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.AddImageTicketVDSCommand]
(default task-212) [19f00d3e-5159-48aa-b3a0-615a085b62d9] START,
AddImageTicketVDSCommand(HostName = hood11.pic.es,
AddImageTicketVDSCommandParameters:{hostId='79cbda85-35f4-44df-b309-01b57bc2477e',
ticketId='0d389c3e-5ea5-4886-8ea7-60a1560e3b2d', timeout='300',
operations='[read]', size='35433480192',
url='file:///rhev/data-center/mnt/blockSD/e655abce-c5e8-44f3-8d50-9fd76edf05cb/images/c5cc464e-eb71-4edf-a780-60180c592a6f/5734df23-de67-41a8-88a1-423cecfe7260',
filename='null'}), log id: f5de141
2019-02-17 01:22:28,898+01 INFO
[org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-100)
[19f00d3e-5159-48aa-b3a0-615a085b62d9] Renewing transfer ticket for
Download disk 'vm.example.com_Disk1' (id
'5734df23-de67-41a8-88a1-423cecfe7260')
2019-02-17 01:26:33,588+01 INFO
[org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-100)
[19f00d3e-5159-48aa-b3a0-615a085b62d9] Renewing transfer ticket for
Download disk 'vm.example.com_Disk1' (id
'5734df23-de67-41a8-88a1-423cecfe7260')
2019-02-17 01:26:49,319+01 INFO
[org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-6)
[19f00d3e-5159-48aa-b3a0-615a085b62d9] Finalizing successful transfer for
Download disk 'vm.example.com_Disk1' (id
'5734df23-de67-41a8-88a1-423cecfe7260')
2019-02-17 01:27:17,771+01 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(EE-ManagedThreadFactory-engineScheduled-Thread-6)
[19f00d3e-5159-48aa-b3a0-615a085b62d9] EVENT_ID:
VDS_BROKER_COMMAND_FAILURE(10,802), VDSM hood11.pic.es command
TeardownImageVDS failed: Cannot deactivate Logical Volume: ('General
Storage Exception: ("5 [] [\' Logical volume
e655abce-c5e8-44f3-8d50-9fd76edf05cb/5734df23-de67-41a8-88a1-423cecfe7260
in use.\', \' Logical volume
e655abce-c5e8-44f3-8d50-9fd76edf05cb/fa154782-0dbb-45b5-ba62-d6937259f097
in
use.\']\\ne655abce-c5e8-44f3-8d50-9fd76edf05cb/[\'5734df23-de67-41a8-88a1-423cecfe7260\',
\'fa154782-0dbb-45b5-ba62-d6937259f097\']",)',)
2019-02-17 01:27:17,772+01 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.TeardownImageVDSCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-6)
[19f00d3e-5159-48aa-b3a0-615a085b62d9] Command
'TeardownImageVDSCommand(HostName = hood11.pic.es,
ImageActionsVDSCommandParameters:{hostId='79cbda85-35f4-44df-b309-01b57bc2477e'})'
execution failed: VDSGenericException: VDSErrorException: Failed in
vdscommand to TeardownImageVDS, error = Cannot deactivate Logical Volume:
('General Storage Exception: ("5 [] [\' Logical volume
e655abce-c5e8-44f3-8d50-9fd76edf05cb/5734df23-de67-41a8-88a1-423cecfe7260
in use.\', \' Logical volume
e655abce-c5e8-44f3-8d50-9fd76edf05cb/fa154782-0dbb-45b5-ba62-d6937259f097
in
use.\']\\ne655abce-c5e8-44f3-8d50-9fd76edf05cb/[\'5734df23-de67-41a8-88a1-423cecfe7260\',
\'fa154782-0dbb-45b5-ba62-d6937259f097\']",)',)
2019-02-17 01:27:19,204+01 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand]
(EE-ManagedThreadFactory-commandCoordinator-Thread-6)
[e73bfbec-d6bd-40e5-8009-97e6005ad1d4] START, MergeVDSCommand(HostName =
hood11.pic.es,
MergeVDSCommandParameters:{hostId='79cbda85-35f4-44df-b309-01b57bc2477e',
vmId='addd5eba-9078-41aa-9244-fe485aded951',
storagePoolId='fa64792e-73b3-4da2-9d0b-f334422aaccf',
storageDomainId='e655abce-c5e8-44f3-8d50-9fd76edf05cb',
imageGroupId='c5cc464e-eb71-4edf-a780-60180c592a6f',
imageId='fa154782-0dbb-45b5-ba62-d6937259f097',
baseImageId='5734df23-de67-41a8-88a1-423cecfe7260',
topImageId='fa154782-0dbb-45b5-ba62-d6937259f097', bandwidth='0'}), log
id:
1d956d48
2019-02-17 01:27:29,923+01 INFO
[org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-49)
[19f00d3e-5159-48aa-b3a0-615a085b62d9] Transfer was
successful. Download disk 'vm.example.com_Disk1' (id
'5734df23-de67-41a8-88a1-423cecfe7260')
2019-02-17 01:27:30,997+01 INFO
[org.ovirt.engine.core.bll.storage.disk.image.TransferDiskImageCommand]
(EE-ManagedThreadFactory-engineScheduled-Thread-46)
[19f00d3e-5159-48aa-b3a0-615a085b62d9] Successfully
transferred disk '5734df23-de67-41a8-88a1-423cecfe7260' (command id
'11104d8c-2a9b-4924-96ce-42ef66725616')
For what I understand, there was a "Cannot deactivate logical volume"
problem that I would thank very much if someone can help me about how to
solve
Thanks again
--
Bruno Rodríguez Rodríguez
"Si algo me ha enseñado el tetris, es que los errores se acumulan y los
triunfos desaparecen"