1:07 a.m.
We are running a fresh install of oVIRT 4.1.3, using ISCSI, the VM in
question has multiple Disks (4 to be exact). It snapshotted OK while on
iSCSI however when I went to delete the single snapshot that existed it
went into Locked state and never came back. The deletion has been going for
well over an hour, and I am not convinced since the snapshot is less than
12 hours old that it’s really doing anything.
I have seen that doing some Googling indicates there might be some known
issues with iSCSI/Block Storage/Multiple Disk Snapshot issues.
In the logs on the engine it shows:
2017-07-12 21:59:42,473Z INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(DefaultQuartzScheduler2) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 21:59:52,480Z INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(DefaultQuartzScheduler2) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'RemoveSnapshot' (id: '40482d09-8a7c-4dbd-8324-3e789296887a') waiting on
child command id: '75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk' to complete
2017-07-12 21:59:52,483Z INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(DefaultQuartzScheduler2) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 22:00:02,490Z INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(DefaultQuartzScheduler6) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'RemoveSnapshot' (id: '40482d09-8a7c-4dbd-8324-3e789296887a') waiting on
child command id: '75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk' to complete
2017-07-12 22:00:02,493Z INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(DefaultQuartzScheduler6) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 22:00:12,498Z INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(DefaultQuartzScheduler3) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'RemoveSnapshot' (id: '40482d09-8a7c-4dbd-8324-3e789296887a') waiting on
child command id: '75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk' to complete
2017-07-12 22:00:12,501Z INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(DefaultQuartzScheduler3) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 22:00:22,508Z INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(DefaultQuartzScheduler5) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'RemoveSnapshot' (id: '40482d09-8a7c-4dbd-8324-3e789296887a') waiting on
child command id: '75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk' to complete
2017-07-12 22:00:22,511Z INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(DefaultQuartzScheduler5) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
This is what I seen on the SPM when I grep’d the Snapshot ID.
2017-07-12 14:22:18,773-0700 INFO (jsonrpc/6) [vdsm.api] START
createVolume(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d', size=u'107374182400',
volFormat=4, preallocate=2, diskType=2,
volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845', desc=u'',
srcImgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
srcVolUUID=u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', initialSize=None)
from=::ffff:10.4.64.7,60016, flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e
(api:46)
2017-07-12 14:22:19,095-0700 WARN (tasks/6) [root] File:
/rhev/data-center/00000001-0001-0001-0001-000000000311/0c02a758-4295-4199-97de-b041744b3b15/images/6a887015-67cd-4f7b-b709-eef97142258d/5921ba71-0f00-46cd-b0be-3c2ac1396845
already removed (utils:120)
2017-07-12 14:22:19,096-0700 INFO (tasks/6) [storage.Volume] Request to
create snapshot
6a887015-67cd-4f7b-b709-eef97142258d/5921ba71-0f00-46cd-b0be-3c2ac1396845
of volume
6a887015-67cd-4f7b-b709-eef97142258d/0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae
(blockVolume:545)
2017-07-12 14:22:19,676-0700 INFO (tasks/6) [storage.LVM] Change LV tags
(vg=0c02a758-4295-4199-97de-b041744b3b15,
lv=5921ba71-0f00-46cd-b0be-3c2ac1396845,
delTags=['OVIRT_VOL_INITIALIZING'], addTags=['MD_10',
u'PU_0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
u'IU_6a887015-67cd-4f7b-b709-eef97142258d']) (lvm:1344)
2017-07-12 14:22:36,010-0700 INFO (jsonrpc/5) [vdsm.api] START
getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845', options=None)
from=::ffff:10.4.64.7,59664, flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e
(api:46)
2017-07-12 14:22:36,077-0700 INFO (jsonrpc/5) [storage.VolumeManifest]
Info request: sdUUID=0c02a758-4295-4199-97de-b041744b3b15
imgUUID=6a887015-67cd-4f7b-b709-eef97142258d volUUID =
5921ba71-0f00-46cd-b0be-3c2ac1396845 (volume:238)
2017-07-12 14:22:36,185-0700 INFO (jsonrpc/5) [storage.VolumeManifest]
0c02a758-4295-4199-97de-b041744b3b15/6a887015-67cd-4f7b-b709-eef97142258d/5921ba71-0f00-46cd-b0be-3c2ac1396845
info is {'status': 'OK', 'domain':
'0c02a758-4295-4199-97de-b041744b3b15',
'voltype': 'LEAF', 'description': '', 'parent':
'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', 'format': 'COW',
'generation': 0,
'image': '6a887015-67cd-4f7b-b709-eef97142258d', 'ctime':
'1499894539',
'disktype': '2', 'legality': 'LEGAL', 'mtime':
'0', 'apparentsize':
'1073741824', 'children': [], 'pool': '',
'capacity': '107374182400',
'uuid': u'5921ba71-0f00-46cd-b0be-3c2ac1396845', 'truesize':
'1073741824',
'type': 'SPARSE', 'lease': {'owners': [],
'version': None}} (volume:272)
2017-07-12 14:22:36,186-0700 INFO (jsonrpc/5) [vdsm.api] FINISH
getVolumeInfo return={'info': {'status': 'OK', 'domain':
'0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
'description':
'', 'parent': '0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
'format': 'COW',
'generation': 0, 'image': '6a887015-67cd-4f7b-b709-eef97142258d',
'ctime':
'1499894539', 'disktype': '2', 'legality':
'LEGAL', 'mtime': '0',
'apparentsize': '1073741824', 'children': [], 'pool':
'', 'capacity':
'107374182400', 'uuid': u'5921ba71-0f00-46cd-b0be-3c2ac1396845',
'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'owners': [],
'version': None}}} from=::ffff:10.4.64.7,59664,
flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e (api:52)
2017-07-12 14:24:24,854-0700 INFO (jsonrpc/1) [vdsm.api] START
deleteVolume(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volumes=[u'5921ba71-0f00-46cd-b0be-3c2ac1396845'], postZero=u'false',
force=u'false', discard=False) from=::ffff:10.4.64.7,60016,
flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e (api:46)
2017-07-12 14:24:25,010-0700 INFO (tasks/7) [storage.Volume] Request to
delete LV 5921ba71-0f00-46cd-b0be-3c2ac1396845 of image
6a887015-67cd-4f7b-b709-eef97142258d in VG
0c02a758-4295-4199-97de-b041744b3b15 (blockVolume:579)
2017-07-12 14:24:25,130-0700 INFO (tasks/7) [storage.VolumeManifest]
sdUUID=0c02a758-4295-4199-97de-b041744b3b15
imgUUID=6a887015-67cd-4f7b-b709-eef97142258d volUUID =
5921ba71-0f00-46cd-b0be-3c2ac1396845 legality = ILLEGAL (volume:398)
2017-07-12 14:24:38,881-0700 INFO (jsonrpc/2) [vdsm.api] START
getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845', options=None)
from=::ffff:10.4.64.7,59664, flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e
(api:46)
2017-07-12 14:24:49,911-0700 INFO (jsonrpc/1) [vdsm.api] START
getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volUUID=u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', options=None)
from=::ffff:10.4.64.7,59664, flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e
(api:46)
2017-07-12 14:24:49,912-0700 INFO (jsonrpc/1) [storage.VolumeManifest]
Info request: sdUUID=0c02a758-4295-4199-97de-b041744b3b15
imgUUID=6a887015-67cd-4f7b-b709-eef97142258d volUUID =
0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae (volume:238)
2017-07-12 14:24:50,036-0700 INFO (jsonrpc/1) [storage.VolumeManifest]
0c02a758-4295-4199-97de-b041744b3b15/6a887015-67cd-4f7b-b709-eef97142258d/0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae
info is {'status': 'OK', 'domain':
'0c02a758-4295-4199-97de-b041744b3b15',
'voltype': 'LEAF', 'description': '', 'parent':
'00000000-0000-0000-0000-000000000000', 'format': 'COW',
'generation': 0,
'image': '6a887015-67cd-4f7b-b709-eef97142258d', 'ctime':
'1499885619',
'disktype': '2', 'legality': 'LEGAL', 'mtime':
'0', 'apparentsize':
'110729625600', 'children': [], 'pool': '',
'capacity': '107374182400',
'uuid': u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', 'truesize':
'110729625600', 'type': 'SPARSE', 'lease':
{'owners': [], 'version': None}}
(volume:272)
2017-07-12 14:24:50,037-0700 INFO (jsonrpc/1) [vdsm.api] FINISH
getVolumeInfo return={'info': {'status': 'OK', 'domain':
'0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
'description':
'', 'parent': '00000000-0000-0000-0000-000000000000',
'format': 'COW',
'generation': 0, 'image': '6a887015-67cd-4f7b-b709-eef97142258d',
'ctime':
'1499885619', 'disktype': '2', 'legality':
'LEGAL', 'mtime': '0',
'apparentsize': '110729625600', 'children': [], 'pool':
'', 'capacity':
'107374182400', 'uuid': u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
'truesize': '110729625600', 'type': 'SPARSE',
'lease': {'owners': [],
'version': None}}} from=::ffff:10.4.64.7,59664,
flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e (api:52)
HELP, Right now I am starting to think Block Storage and oVIRT = BAD!
--
Devin Acosta
Red Hat Certified Architect, LinuxStack
11:38 a.m.
Hi,
Can you please attach full engine and vdsm logs?
On Thu, Jul 13, 2017 at 1:07 AM, Devin Acosta <devin(a)pabstatencio.com> wrote:
We are running a fresh install of oVIRT 4.1.3, using ISCSI, the VM
in
question has multiple Disks (4 to be exact). It snapshotted OK while on
iSCSI however when I went to delete the single snapshot that existed it went
into Locked state and never came back. The deletion has been going for well
over an hour, and I am not convinced since the snapshot is less than 12
hours old that it’s really doing anything.
I have seen that doing some Googling indicates there might be some known
issues with iSCSI/Block Storage/Multiple Disk Snapshot issues.
In the logs on the engine it shows:
2017-07-12 21:59:42,473Z INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(DefaultQuartzScheduler2) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 21:59:52,480Z INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(DefaultQuartzScheduler2) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'RemoveSnapshot' (id: '40482d09-8a7c-4dbd-8324-3e789296887a') waiting on
child command id: '75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk' to complete
2017-07-12 21:59:52,483Z INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(DefaultQuartzScheduler2) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 22:00:02,490Z INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(DefaultQuartzScheduler6) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'RemoveSnapshot' (id: '40482d09-8a7c-4dbd-8324-3e789296887a') waiting on
child command id: '75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk' to complete
2017-07-12 22:00:02,493Z INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(DefaultQuartzScheduler6) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 22:00:12,498Z INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(DefaultQuartzScheduler3) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'RemoveSnapshot' (id: '40482d09-8a7c-4dbd-8324-3e789296887a') waiting on
child command id: '75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk' to complete
2017-07-12 22:00:12,501Z INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(DefaultQuartzScheduler3) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 22:00:22,508Z INFO
[org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback]
(DefaultQuartzScheduler5) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'RemoveSnapshot' (id: '40482d09-8a7c-4dbd-8324-3e789296887a') waiting on
child command id: '75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk' to complete
2017-07-12 22:00:22,511Z INFO
[org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback]
(DefaultQuartzScheduler5) [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
This is what I seen on the SPM when I grep’d the Snapshot ID.
2017-07-12 14:22:18,773-0700 INFO (jsonrpc/6) [vdsm.api] START
createVolume(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d', size=u'107374182400',
volFormat=4, preallocate=2, diskType=2,
volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845', desc=u'',
srcImgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
srcVolUUID=u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', initialSize=None)
from=::ffff:10.4.64.7,60016, flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e
(api:46)
2017-07-12 14:22:19,095-0700 WARN (tasks/6) [root] File:
/rhev/data-center/00000001-0001-0001-0001-000000000311/0c02a758-4295-4199-97de-b041744b3b15/images/6a887015-67cd-4f7b-b709-eef97142258d/5921ba71-0f00-46cd-b0be-3c2ac1396845
already removed (utils:120)
2017-07-12 14:22:19,096-0700 INFO (tasks/6) [storage.Volume] Request to
create snapshot
6a887015-67cd-4f7b-b709-eef97142258d/5921ba71-0f00-46cd-b0be-3c2ac1396845 of
volume
6a887015-67cd-4f7b-b709-eef97142258d/0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae
(blockVolume:545)
2017-07-12 14:22:19,676-0700 INFO (tasks/6) [storage.LVM] Change LV tags
(vg=0c02a758-4295-4199-97de-b041744b3b15,
lv=5921ba71-0f00-46cd-b0be-3c2ac1396845, delTags=['OVIRT_VOL_INITIALIZING'],
addTags=['MD_10', u'PU_0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
u'IU_6a887015-67cd-4f7b-b709-eef97142258d']) (lvm:1344)
2017-07-12 14:22:36,010-0700 INFO (jsonrpc/5) [vdsm.api] START
getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845', options=None)
from=::ffff:10.4.64.7,59664, flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e
(api:46)
2017-07-12 14:22:36,077-0700 INFO (jsonrpc/5) [storage.VolumeManifest] Info
request: sdUUID=0c02a758-4295-4199-97de-b041744b3b15
imgUUID=6a887015-67cd-4f7b-b709-eef97142258d volUUID =
5921ba71-0f00-46cd-b0be-3c2ac1396845 (volume:238)
2017-07-12 14:22:36,185-0700 INFO (jsonrpc/5) [storage.VolumeManifest]
0c02a758-4295-4199-97de-b041744b3b15/6a887015-67cd-4f7b-b709-eef97142258d/5921ba71-0f00-46cd-b0be-3c2ac1396845
info is {'status': 'OK', 'domain':
'0c02a758-4295-4199-97de-b041744b3b15',
'voltype': 'LEAF', 'description': '', 'parent':
'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', 'format': 'COW',
'generation': 0,
'image': '6a887015-67cd-4f7b-b709-eef97142258d', 'ctime':
'1499894539',
'disktype': '2', 'legality': 'LEGAL', 'mtime':
'0', 'apparentsize':
'1073741824', 'children': [], 'pool': '',
'capacity': '107374182400',
'uuid': u'5921ba71-0f00-46cd-b0be-3c2ac1396845', 'truesize':
'1073741824',
'type': 'SPARSE', 'lease': {'owners': [],
'version': None}} (volume:272)
2017-07-12 14:22:36,186-0700 INFO (jsonrpc/5) [vdsm.api] FINISH
getVolumeInfo return={'info': {'status': 'OK', 'domain':
'0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
'description':
'', 'parent': '0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
'format': 'COW',
'generation': 0, 'image': '6a887015-67cd-4f7b-b709-eef97142258d',
'ctime':
'1499894539', 'disktype': '2', 'legality':
'LEGAL', 'mtime': '0',
'apparentsize': '1073741824', 'children': [], 'pool':
'', 'capacity':
'107374182400', 'uuid': u'5921ba71-0f00-46cd-b0be-3c2ac1396845',
'truesize':
'1073741824', 'type': 'SPARSE', 'lease':
{'owners': [], 'version': None}}}
from=::ffff:10.4.64.7,59664, flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e
(api:52)
2017-07-12 14:24:24,854-0700 INFO (jsonrpc/1) [vdsm.api] START
deleteVolume(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volumes=[u'5921ba71-0f00-46cd-b0be-3c2ac1396845'], postZero=u'false',
force=u'false', discard=False) from=::ffff:10.4.64.7,60016,
flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e (api:46)
2017-07-12 14:24:25,010-0700 INFO (tasks/7) [storage.Volume] Request to
delete LV 5921ba71-0f00-46cd-b0be-3c2ac1396845 of image
6a887015-67cd-4f7b-b709-eef97142258d in VG
0c02a758-4295-4199-97de-b041744b3b15 (blockVolume:579)
2017-07-12 14:24:25,130-0700 INFO (tasks/7) [storage.VolumeManifest]
sdUUID=0c02a758-4295-4199-97de-b041744b3b15
imgUUID=6a887015-67cd-4f7b-b709-eef97142258d volUUID =
5921ba71-0f00-46cd-b0be-3c2ac1396845 legality = ILLEGAL (volume:398)
2017-07-12 14:24:38,881-0700 INFO (jsonrpc/2) [vdsm.api] START
getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845', options=None)
from=::ffff:10.4.64.7,59664, flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e
(api:46)
2017-07-12 14:24:49,911-0700 INFO (jsonrpc/1) [vdsm.api] START
getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volUUID=u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', options=None)
from=::ffff:10.4.64.7,59664, flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e
(api:46)
2017-07-12 14:24:49,912-0700 INFO (jsonrpc/1) [storage.VolumeManifest] Info
request: sdUUID=0c02a758-4295-4199-97de-b041744b3b15
imgUUID=6a887015-67cd-4f7b-b709-eef97142258d volUUID =
0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae (volume:238)
2017-07-12 14:24:50,036-0700 INFO (jsonrpc/1) [storage.VolumeManifest]
0c02a758-4295-4199-97de-b041744b3b15/6a887015-67cd-4f7b-b709-eef97142258d/0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae
info is {'status': 'OK', 'domain':
'0c02a758-4295-4199-97de-b041744b3b15',
'voltype': 'LEAF', 'description': '', 'parent':
'00000000-0000-0000-0000-000000000000', 'format': 'COW',
'generation': 0,
'image': '6a887015-67cd-4f7b-b709-eef97142258d', 'ctime':
'1499885619',
'disktype': '2', 'legality': 'LEGAL', 'mtime':
'0', 'apparentsize':
'110729625600', 'children': [], 'pool': '',
'capacity': '107374182400',
'uuid': u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', 'truesize':
'110729625600',
'type': 'SPARSE', 'lease': {'owners': [],
'version': None}} (volume:272)
2017-07-12 14:24:50,037-0700 INFO (jsonrpc/1) [vdsm.api] FINISH
getVolumeInfo return={'info': {'status': 'OK', 'domain':
'0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
'description':
'', 'parent': '00000000-0000-0000-0000-000000000000',
'format': 'COW',
'generation': 0, 'image': '6a887015-67cd-4f7b-b709-eef97142258d',
'ctime':
'1499885619', 'disktype': '2', 'legality':
'LEGAL', 'mtime': '0',
'apparentsize': '110729625600', 'children': [], 'pool':
'', 'capacity':
'107374182400', 'uuid': u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
'truesize':
'110729625600', 'type': 'SPARSE', 'lease':
{'owners': [], 'version': None}}}
from=::ffff:10.4.64.7,59664, flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e
(api:52)
HELP, Right now I am starting to think Block Storage and oVIRT = BAD!
--
Devin Acosta
Red Hat Certified Architect, LinuxStack
_______________________________________________
Users mailing list
Users(a)ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
7:22 p.m.
Hi,
i have the same problem with gluster.
this is a bug that i opened
https://bugzilla.redhat.com/show_bug.cgi?id=1461029 .
In the bug i used single disk vm but i start to notice the problem with
multiple disk vm.
2017-07-13 0:07 GMT+02:00 Devin Acosta <devin(a)pabstatencio.com>:
We are running a fresh install of oVIRT 4.1.3, using ISCSI, the VM
in
question has multiple Disks (4 to be exact). It snapshotted OK while on
iSCSI however when I went to delete the single snapshot that existed it
went into Locked state and never came back. The deletion has been going for
well over an hour, and I am not convinced since the snapshot is less than
12 hours old that it’s really doing anything.
I have seen that doing some Googling indicates there might be some known
issues with iSCSI/Block Storage/Multiple Disk Snapshot issues.
In the logs on the engine it shows:
2017-07-12 21:59:42,473Z INFO [org.ovirt.engine.core.bll.
SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler2)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 21:59:52,480Z INFO [org.ovirt.engine.core.bll.
ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler2)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command 'RemoveSnapshot' (id:
'40482d09-8a7c-4dbd-8324-3e789296887a') waiting on child command id:
'75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk'
to complete
2017-07-12 21:59:52,483Z INFO [org.ovirt.engine.core.bll.
SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler2)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 22:00:02,490Z INFO [org.ovirt.engine.core.bll.
ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler6)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command 'RemoveSnapshot' (id:
'40482d09-8a7c-4dbd-8324-3e789296887a') waiting on child command id:
'75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk'
to complete
2017-07-12 22:00:02,493Z INFO [org.ovirt.engine.core.bll.
SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler6)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 22:00:12,498Z INFO [org.ovirt.engine.core.bll.
ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler3)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command 'RemoveSnapshot' (id:
'40482d09-8a7c-4dbd-8324-3e789296887a') waiting on child command id:
'75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk'
to complete
2017-07-12 22:00:12,501Z INFO [org.ovirt.engine.core.bll.
SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler3)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 22:00:22,508Z INFO [org.ovirt.engine.core.bll.
ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler5)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command 'RemoveSnapshot' (id:
'40482d09-8a7c-4dbd-8324-3e789296887a') waiting on child command id:
'75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk'
to complete
2017-07-12 22:00:22,511Z INFO [org.ovirt.engine.core.bll.
SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler5)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
This is what I seen on the SPM when I grep’d the Snapshot ID.
2017-07-12 14:22:18,773-0700 INFO (jsonrpc/6) [vdsm.api] START
createVolume(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d', size=u'107374182400',
volFormat=4, preallocate=2, diskType=2,
volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845',
desc=u'', srcImgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
srcVolUUID=u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', initialSize=None)
from=::ffff:10.4.64.7,60016, flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e
(api:46)
2017-07-12 14:22:19,095-0700 WARN (tasks/6) [root] File:
/rhev/data-center/00000001-0001-0001-0001-000000000311/
0c02a758-4295-4199-97de-b041744b3b15/images/6a887015-
67cd-4f7b-b709-eef97142258d/5921ba71-0f00-46cd-b0be-3c2ac1396845 already
removed (utils:120)
2017-07-12 14:22:19,096-0700 INFO (tasks/6) [storage.Volume] Request to
create snapshot
6a887015-67cd-4f7b-b709-eef97142258d/5921ba71-0f00-46cd-b0be-3c2ac1396845
of volume 6a887015-67cd-4f7b-b709-eef97142258d/0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae
(blockVolume:545)
2017-07-12 14:22:19,676-0700 INFO (tasks/6) [storage.LVM] Change LV tags
(vg=0c02a758-4295-4199-97de-b041744b3b15, lv=5921ba71-0f00-46cd-b0be-3c2ac1396845,
delTags=['OVIRT_VOL_INITIALIZING'], addTags=['MD_10',
u'PU_0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
u'IU_6a887015-67cd-4f7b-b709-eef97142258d'])
(lvm:1344)
2017-07-12 14:22:36,010-0700 INFO (jsonrpc/5) [vdsm.api] START
getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845', options=None)
from=::ffff:10.4.64.7,59664, flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e
(api:46)
2017-07-12 14:22:36,077-0700 INFO (jsonrpc/5) [storage.VolumeManifest]
Info request: sdUUID=0c02a758-4295-4199-97de-b041744b3b15
imgUUID=6a887015-67cd-4f7b-b709-eef97142258d volUUID =
5921ba71-0f00-46cd-b0be-3c2ac1396845 (volume:238)
2017-07-12 14:22:36,185-0700 INFO (jsonrpc/5) [storage.VolumeManifest]
0c02a758-4295-4199-97de-b041744b3b15/6a887015-67cd-4f7b-b709-eef97142258d/
5921ba71-0f00-46cd-b0be-3c2ac1396845 info is {'status': 'OK',
'domain':
'0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
'description':
'', 'parent': '0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
'format': 'COW',
'generation': 0, 'image':
'6a887015-67cd-4f7b-b709-eef97142258d',
'ctime': '1499894539', 'disktype': '2',
'legality': 'LEGAL', 'mtime': '0',
'apparentsize': '1073741824', 'children': [], 'pool':
'', 'capacity':
'107374182400', 'uuid': u'5921ba71-0f00-46cd-b0be-3c2ac1396845',
'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'owners': [],
'version': None}} (volume:272)
2017-07-12 14:22:36,186-0700 INFO (jsonrpc/5) [vdsm.api] FINISH
getVolumeInfo return={'info': {'status': 'OK', 'domain':
'0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
'description':
'', 'parent': '0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
'format': 'COW',
'generation': 0, 'image':
'6a887015-67cd-4f7b-b709-eef97142258d',
'ctime': '1499894539', 'disktype': '2',
'legality': 'LEGAL', 'mtime': '0',
'apparentsize': '1073741824', 'children': [], 'pool':
'', 'capacity':
'107374182400', 'uuid': u'5921ba71-0f00-46cd-b0be-3c2ac1396845',
'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'owners': [],
'version': None}}} from=::ffff:10.4.64.7,59664,
flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e
(api:52)
2017-07-12 14:24:24,854-0700 INFO (jsonrpc/1) [vdsm.api] START
deleteVolume(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volumes=[u'5921ba71-0f00-46cd-b0be-3c2ac1396845'], postZero=u'false',
force=u'false', discard=False) from=::ffff:10.4.64.7,60016,
flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e (api:46)
2017-07-12 14:24:25,010-0700 INFO (tasks/7) [storage.Volume] Request to
delete LV 5921ba71-0f00-46cd-b0be-3c2ac1396845 of image
6a887015-67cd-4f7b-b709-eef97142258d in VG 0c02a758-4295-4199-97de-b041744b3b15
(blockVolume:579)
2017-07-12 14:24:25,130-0700 INFO (tasks/7) [storage.VolumeManifest]
sdUUID=0c02a758-4295-4199-97de-b041744b3b15 imgUUID=6a887015-67cd-4f7b-b709-eef97142258d
volUUID = 5921ba71-0f00-46cd-b0be-3c2ac1396845 legality = ILLEGAL
(volume:398)
2017-07-12 14:24:38,881-0700 INFO (jsonrpc/2) [vdsm.api] START
getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845', options=None)
from=::ffff:10.4.64.7,59664, flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e
(api:46)
2017-07-12 14:24:49,911-0700 INFO (jsonrpc/1) [vdsm.api] START
getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volUUID=u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', options=None)
from=::ffff:10.4.64.7,59664, flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e
(api:46)
2017-07-12 14:24:49,912-0700 INFO (jsonrpc/1) [storage.VolumeManifest]
Info request: sdUUID=0c02a758-4295-4199-97de-b041744b3b15
imgUUID=6a887015-67cd-4f7b-b709-eef97142258d volUUID =
0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae (volume:238)
2017-07-12 14:24:50,036-0700 INFO (jsonrpc/1) [storage.VolumeManifest]
0c02a758-4295-4199-97de-b041744b3b15/6a887015-67cd-4f7b-b709-eef97142258d/
0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae info is {'status': 'OK',
'domain':
'0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
'description':
'', 'parent': '00000000-0000-0000-0000-000000000000',
'format': 'COW',
'generation': 0, 'image':
'6a887015-67cd-4f7b-b709-eef97142258d',
'ctime': '1499885619', 'disktype': '2',
'legality': 'LEGAL', 'mtime': '0',
'apparentsize': '110729625600', 'children': [], 'pool':
'', 'capacity':
'107374182400', 'uuid': u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
'truesize': '110729625600', 'type': 'SPARSE',
'lease': {'owners': [],
'version': None}} (volume:272)
2017-07-12 14:24:50,037-0700 INFO (jsonrpc/1) [vdsm.api] FINISH
getVolumeInfo return={'info': {'status': 'OK', 'domain':
'0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
'description':
'', 'parent': '00000000-0000-0000-0000-000000000000',
'format': 'COW',
'generation': 0, 'image':
'6a887015-67cd-4f7b-b709-eef97142258d',
'ctime': '1499885619', 'disktype': '2',
'legality': 'LEGAL', 'mtime': '0',
'apparentsize': '110729625600', 'children': [], 'pool':
'', 'capacity':
'107374182400', 'uuid': u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
'truesize': '110729625600', 'type': 'SPARSE',
'lease': {'owners': [],
'version': None}}} from=::ffff:10.4.64.7,59664,
flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e
(api:52)
HELP, Right now I am starting to think Block Storage and oVIRT = BAD!
--
Devin Acosta
Red Hat Certified Architect, LinuxStack
_______________________________________________
Users mailing list
Users(a)ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
7:18 p.m.
I have attached the logs.
--
Devin Acosta
Red Hat Certified Architect, LinuxStack
602-354-1220 <//602-354-1220> || devin(a)linuxguru.co
On July 13, 2017 at 9:22:03 AM, richard anthony falzini (
richardfalzini(a)gmail.com) wrote:
Hi,
i have the same problem with gluster.
this is a bug that i opened
https://bugzilla.redhat.com/show_bug.cgi?id=1461029 .
In the bug i used single disk vm but i start to notice the problem with
multiple disk vm.
2017-07-13 0:07 GMT+02:00 Devin Acosta <devin(a)pabstatencio.com>:
We are running a fresh install of oVIRT 4.1.3, using ISCSI, the VM
in
question has multiple Disks (4 to be exact). It snapshotted OK while on
iSCSI however when I went to delete the single snapshot that existed it
went into Locked state and never came back. The deletion has been going for
well over an hour, and I am not convinced since the snapshot is less than
12 hours old that it’s really doing anything.
I have seen that doing some Googling indicates there might be some known
issues with iSCSI/Block Storage/Multiple Disk Snapshot issues.
In the logs on the engine it shows:
2017-07-12 21:59:42,473Z INFO [org.ovirt.engine.core.bll.
SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler2)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 21:59:52,480Z INFO [org.ovirt.engine.core.bll.
ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler2)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command 'RemoveSnapshot' (id:
'40482d09-8a7c-4dbd-8324-3e789296887a') waiting on child command id:
'75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk'
to complete
2017-07-12 21:59:52,483Z INFO [org.ovirt.engine.core.bll.
SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler2)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 22:00:02,490Z INFO [org.ovirt.engine.core.bll.
ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler6)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command 'RemoveSnapshot' (id:
'40482d09-8a7c-4dbd-8324-3e789296887a') waiting on child command id:
'75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk'
to complete
2017-07-12 22:00:02,493Z INFO [org.ovirt.engine.core.bll.
SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler6)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 22:00:12,498Z INFO [org.ovirt.engine.core.bll.
ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler3)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command 'RemoveSnapshot' (id:
'40482d09-8a7c-4dbd-8324-3e789296887a') waiting on child command id:
'75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk'
to complete
2017-07-12 22:00:12,501Z INFO [org.ovirt.engine.core.bll.
SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler3)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 22:00:22,508Z INFO [org.ovirt.engine.core.bll.
ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler5)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command 'RemoveSnapshot' (id:
'40482d09-8a7c-4dbd-8324-3e789296887a') waiting on child command id:
'75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk'
to complete
2017-07-12 22:00:22,511Z INFO [org.ovirt.engine.core.bll.
SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler5)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
This is what I seen on the SPM when I grep’d the Snapshot ID.
2017-07-12 14:22:18,773-0700 INFO (jsonrpc/6) [vdsm.api] START
createVolume(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d', size=u'107374182400',
volFormat=4, preallocate=2, diskType=2,
volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845',
desc=u'', srcImgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
srcVolUUID=u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', initialSize=None)
from=::ffff:10.4.64.7,60016, flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e
(api:46)
2017-07-12 14:22:19,095-0700 WARN (tasks/6) [root] File:
/rhev/data-center/00000001-0001-0001-0001-000000000311/
0c02a758-4295-4199-97de-b041744b3b15/images/6a887015-
67cd-4f7b-b709-eef97142258d/5921ba71-0f00-46cd-b0be-3c2ac1396845 already
removed (utils:120)
2017-07-12 14:22:19,096-0700 INFO (tasks/6) [storage.Volume] Request to
create snapshot
6a887015-67cd-4f7b-b709-eef97142258d/5921ba71-0f00-46cd-b0be-3c2ac1396845
of volume 6a887015-67cd-4f7b-b709-eef97142258d/0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae
(blockVolume:545)
2017-07-12 14:22:19,676-0700 INFO (tasks/6) [storage.LVM] Change LV tags
(vg=0c02a758-4295-4199-97de-b041744b3b15, lv=5921ba71-0f00-46cd-b0be-3c2ac1396845,
delTags=['OVIRT_VOL_INITIALIZING'], addTags=['MD_10',
u'PU_0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
u'IU_6a887015-67cd-4f7b-b709-eef97142258d'])
(lvm:1344)
2017-07-12 14:22:36,010-0700 INFO (jsonrpc/5) [vdsm.api] START
getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845', options=None)
from=::ffff:10.4.64.7,59664, flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e
(api:46)
2017-07-12 14:22:36,077-0700 INFO (jsonrpc/5) [storage.VolumeManifest]
Info request: sdUUID=0c02a758-4295-4199-97de-b041744b3b15
imgUUID=6a887015-67cd-4f7b-b709-eef97142258d volUUID =
5921ba71-0f00-46cd-b0be-3c2ac1396845 (volume:238)
2017-07-12 14:22:36,185-0700 INFO (jsonrpc/5) [storage.VolumeManifest]
0c02a758-4295-4199-97de-b041744b3b15/6a887015-67cd-4f7b-b709-eef97142258d/
5921ba71-0f00-46cd-b0be-3c2ac1396845 info is {'status': 'OK',
'domain':
'0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
'description':
'', 'parent': '0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
'format': 'COW',
'generation': 0, 'image':
'6a887015-67cd-4f7b-b709-eef97142258d',
'ctime': '1499894539', 'disktype': '2',
'legality': 'LEGAL', 'mtime': '0',
'apparentsize': '1073741824', 'children': [], 'pool':
'', 'capacity':
'107374182400', 'uuid': u'5921ba71-0f00-46cd-b0be-3c2ac1396845',
'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'owners': [],
'version': None}} (volume:272)
2017-07-12 14:22:36,186-0700 INFO (jsonrpc/5) [vdsm.api] FINISH
getVolumeInfo return={'info': {'status': 'OK', 'domain':
'0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
'description':
'', 'parent': '0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
'format': 'COW',
'generation': 0, 'image':
'6a887015-67cd-4f7b-b709-eef97142258d',
'ctime': '1499894539', 'disktype': '2',
'legality': 'LEGAL', 'mtime': '0',
'apparentsize': '1073741824', 'children': [], 'pool':
'', 'capacity':
'107374182400', 'uuid': u'5921ba71-0f00-46cd-b0be-3c2ac1396845',
'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'owners': [],
'version': None}}} from=::ffff:10.4.64.7,59664,
flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e
(api:52)
2017-07-12 14:24:24,854-0700 INFO (jsonrpc/1) [vdsm.api] START
deleteVolume(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volumes=[u'5921ba71-0f00-46cd-b0be-3c2ac1396845'], postZero=u'false',
force=u'false', discard=False) from=::ffff:10.4.64.7,60016,
flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e (api:46)
2017-07-12 14:24:25,010-0700 INFO (tasks/7) [storage.Volume] Request to
delete LV 5921ba71-0f00-46cd-b0be-3c2ac1396845 of image
6a887015-67cd-4f7b-b709-eef97142258d in VG 0c02a758-4295-4199-97de-b041744b3b15
(blockVolume:579)
2017-07-12 14:24:25,130-0700 INFO (tasks/7) [storage.VolumeManifest]
sdUUID=0c02a758-4295-4199-97de-b041744b3b15 imgUUID=6a887015-67cd-4f7b-b709-eef97142258d
volUUID = 5921ba71-0f00-46cd-b0be-3c2ac1396845 legality = ILLEGAL
(volume:398)
2017-07-12 14:24:38,881-0700 INFO (jsonrpc/2) [vdsm.api] START
getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845', options=None)
from=::ffff:10.4.64.7,59664, flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e
(api:46)
2017-07-12 14:24:49,911-0700 INFO (jsonrpc/1) [vdsm.api] START
getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volUUID=u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', options=None)
from=::ffff:10.4.64.7,59664, flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e
(api:46)
2017-07-12 14:24:49,912-0700 INFO (jsonrpc/1) [storage.VolumeManifest]
Info request: sdUUID=0c02a758-4295-4199-97de-b041744b3b15
imgUUID=6a887015-67cd-4f7b-b709-eef97142258d volUUID =
0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae (volume:238)
2017-07-12 14:24:50,036-0700 INFO (jsonrpc/1) [storage.VolumeManifest]
0c02a758-4295-4199-97de-b041744b3b15/6a887015-67cd-4f7b-b709-eef97142258d/
0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae info is {'status': 'OK',
'domain':
'0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
'description':
'', 'parent': '00000000-0000-0000-0000-000000000000',
'format': 'COW',
'generation': 0, 'image':
'6a887015-67cd-4f7b-b709-eef97142258d',
'ctime': '1499885619', 'disktype': '2',
'legality': 'LEGAL', 'mtime': '0',
'apparentsize': '110729625600', 'children': [], 'pool':
'', 'capacity':
'107374182400', 'uuid': u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
'truesize': '110729625600', 'type': 'SPARSE',
'lease': {'owners': [],
'version': None}} (volume:272)
2017-07-12 14:24:50,037-0700 INFO (jsonrpc/1) [vdsm.api] FINISH
getVolumeInfo return={'info': {'status': 'OK', 'domain':
'0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
'description':
'', 'parent': '00000000-0000-0000-0000-000000000000',
'format': 'COW',
'generation': 0, 'image':
'6a887015-67cd-4f7b-b709-eef97142258d',
'ctime': '1499885619', 'disktype': '2',
'legality': 'LEGAL', 'mtime': '0',
'apparentsize': '110729625600', 'children': [], 'pool':
'', 'capacity':
'107374182400', 'uuid': u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
'truesize': '110729625600', 'type': 'SPARSE',
'lease': {'owners': [],
'version': None}}} from=::ffff:10.4.64.7,59664,
flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e
(api:52)
HELP, Right now I am starting to think Block Storage and oVIRT = BAD!
--
Devin Acosta
Red Hat Certified Architect, LinuxStack
_______________________________________________
Users mailing list
Users(a)ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
7:32 p.m.
You can get my logs from:
https://files.linuxstack.cloud/s/NjoyMF11I38rJpH
They were a little to big to attach to this e-mail. Would like to know if
this is the similar bug that Richard indicated is a possibility.
--
Devin Acosta
Red Hat Certified Architect, LinuxStack
602-354-1220 <//602-354-1220> || devin(a)linuxguru.co
On July 14, 2017 at 9:18:08 AM, Devin Acosta (devin(a)pabstatencio.com) wrote:
I have attached the logs.
--
Devin Acosta
Red Hat Certified Architect, LinuxStack
602-354-1220 <//602-354-1220> || devin(a)linuxguru.co
On July 13, 2017 at 9:22:03 AM, richard anthony falzini (
richardfalzini(a)gmail.com) wrote:
Hi,
i have the same problem with gluster.
this is a bug that i opened
https://bugzilla.redhat.com/show_bug.cgi?id=1461029 .
In the bug i used single disk vm but i start to notice the problem with
multiple disk vm.
2017-07-13 0:07 GMT+02:00 Devin Acosta <devin(a)pabstatencio.com>:
We are running a fresh install of oVIRT 4.1.3, using ISCSI, the VM
in
question has multiple Disks (4 to be exact). It snapshotted OK while on
iSCSI however when I went to delete the single snapshot that existed it
went into Locked state and never came back. The deletion has been going for
well over an hour, and I am not convinced since the snapshot is less than
12 hours old that it’s really doing anything.
I have seen that doing some Googling indicates there might be some known
issues with iSCSI/Block Storage/Multiple Disk Snapshot issues.
In the logs on the engine it shows:
2017-07-12 21:59:42,473Z INFO [org.ovirt.engine.core.bll.
SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler2)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 21:59:52,480Z INFO [org.ovirt.engine.core.bll.
ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler2)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command 'RemoveSnapshot' (id:
'40482d09-8a7c-4dbd-8324-3e789296887a') waiting on child command id:
'75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk'
to complete
2017-07-12 21:59:52,483Z INFO [org.ovirt.engine.core.bll.
SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler2)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 22:00:02,490Z INFO [org.ovirt.engine.core.bll.
ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler6)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command 'RemoveSnapshot' (id:
'40482d09-8a7c-4dbd-8324-3e789296887a') waiting on child command id:
'75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk'
to complete
2017-07-12 22:00:02,493Z INFO [org.ovirt.engine.core.bll.
SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler6)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 22:00:12,498Z INFO [org.ovirt.engine.core.bll.
ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler3)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command 'RemoveSnapshot' (id:
'40482d09-8a7c-4dbd-8324-3e789296887a') waiting on child command id:
'75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk'
to complete
2017-07-12 22:00:12,501Z INFO [org.ovirt.engine.core.bll.
SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler3)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
2017-07-12 22:00:22,508Z INFO [org.ovirt.engine.core.bll.
ConcurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler5)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command 'RemoveSnapshot' (id:
'40482d09-8a7c-4dbd-8324-3e789296887a') waiting on child command id:
'75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk'
to complete
2017-07-12 22:00:22,511Z INFO [org.ovirt.engine.core.bll.
SerialChildCommandsExecutionCallback] (DefaultQuartzScheduler5)
[a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
type:'PrepareMerge' to complete
This is what I seen on the SPM when I grep’d the Snapshot ID.
2017-07-12 14:22:18,773-0700 INFO (jsonrpc/6) [vdsm.api] START
createVolume(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d', size=u'107374182400',
volFormat=4, preallocate=2, diskType=2,
volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845',
desc=u'', srcImgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
srcVolUUID=u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', initialSize=None)
from=::ffff:10.4.64.7,60016, flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e
(api:46)
2017-07-12 14:22:19,095-0700 WARN (tasks/6) [root] File:
/rhev/data-center/00000001-0001-0001-0001-000000000311/
0c02a758-4295-4199-97de-b041744b3b15/images/6a887015-
67cd-4f7b-b709-eef97142258d/5921ba71-0f00-46cd-b0be-3c2ac1396845 already
removed (utils:120)
2017-07-12 14:22:19,096-0700 INFO (tasks/6) [storage.Volume] Request to
create snapshot
6a887015-67cd-4f7b-b709-eef97142258d/5921ba71-0f00-46cd-b0be-3c2ac1396845
of volume 6a887015-67cd-4f7b-b709-eef97142258d/0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae
(blockVolume:545)
2017-07-12 14:22:19,676-0700 INFO (tasks/6) [storage.LVM] Change LV tags
(vg=0c02a758-4295-4199-97de-b041744b3b15, lv=5921ba71-0f00-46cd-b0be-3c2ac1396845,
delTags=['OVIRT_VOL_INITIALIZING'], addTags=['MD_10',
u'PU_0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
u'IU_6a887015-67cd-4f7b-b709-eef97142258d'])
(lvm:1344)
2017-07-12 14:22:36,010-0700 INFO (jsonrpc/5) [vdsm.api] START
getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845', options=None)
from=::ffff:10.4.64.7,59664, flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e
(api:46)
2017-07-12 14:22:36,077-0700 INFO (jsonrpc/5) [storage.VolumeManifest]
Info request: sdUUID=0c02a758-4295-4199-97de-b041744b3b15
imgUUID=6a887015-67cd-4f7b-b709-eef97142258d volUUID =
5921ba71-0f00-46cd-b0be-3c2ac1396845 (volume:238)
2017-07-12 14:22:36,185-0700 INFO (jsonrpc/5) [storage.VolumeManifest]
0c02a758-4295-4199-97de-b041744b3b15/6a887015-67cd-4f7b-b709-eef97142258d/
5921ba71-0f00-46cd-b0be-3c2ac1396845 info is {'status': 'OK',
'domain':
'0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
'description':
'', 'parent': '0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
'format': 'COW',
'generation': 0, 'image':
'6a887015-67cd-4f7b-b709-eef97142258d',
'ctime': '1499894539', 'disktype': '2',
'legality': 'LEGAL', 'mtime': '0',
'apparentsize': '1073741824', 'children': [], 'pool':
'', 'capacity':
'107374182400', 'uuid': u'5921ba71-0f00-46cd-b0be-3c2ac1396845',
'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'owners': [],
'version': None}} (volume:272)
2017-07-12 14:22:36,186-0700 INFO (jsonrpc/5) [vdsm.api] FINISH
getVolumeInfo return={'info': {'status': 'OK', 'domain':
'0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
'description':
'', 'parent': '0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
'format': 'COW',
'generation': 0, 'image':
'6a887015-67cd-4f7b-b709-eef97142258d',
'ctime': '1499894539', 'disktype': '2',
'legality': 'LEGAL', 'mtime': '0',
'apparentsize': '1073741824', 'children': [], 'pool':
'', 'capacity':
'107374182400', 'uuid': u'5921ba71-0f00-46cd-b0be-3c2ac1396845',
'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'owners': [],
'version': None}}} from=::ffff:10.4.64.7,59664,
flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e
(api:52)
2017-07-12 14:24:24,854-0700 INFO (jsonrpc/1) [vdsm.api] START
deleteVolume(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volumes=[u'5921ba71-0f00-46cd-b0be-3c2ac1396845'], postZero=u'false',
force=u'false', discard=False) from=::ffff:10.4.64.7,60016,
flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e (api:46)
2017-07-12 14:24:25,010-0700 INFO (tasks/7) [storage.Volume] Request to
delete LV 5921ba71-0f00-46cd-b0be-3c2ac1396845 of image
6a887015-67cd-4f7b-b709-eef97142258d in VG 0c02a758-4295-4199-97de-b041744b3b15
(blockVolume:579)
2017-07-12 14:24:25,130-0700 INFO (tasks/7) [storage.VolumeManifest]
sdUUID=0c02a758-4295-4199-97de-b041744b3b15 imgUUID=6a887015-67cd-4f7b-b709-eef97142258d
volUUID = 5921ba71-0f00-46cd-b0be-3c2ac1396845 legality = ILLEGAL
(volume:398)
2017-07-12 14:24:38,881-0700 INFO (jsonrpc/2) [vdsm.api] START
getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845', options=None)
from=::ffff:10.4.64.7,59664, flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e
(api:46)
2017-07-12 14:24:49,911-0700 INFO (jsonrpc/1) [vdsm.api] START
getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
spUUID=u'00000001-0001-0001-0001-000000000311',
imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
volUUID=u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', options=None)
from=::ffff:10.4.64.7,59664, flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e
(api:46)
2017-07-12 14:24:49,912-0700 INFO (jsonrpc/1) [storage.VolumeManifest]
Info request: sdUUID=0c02a758-4295-4199-97de-b041744b3b15
imgUUID=6a887015-67cd-4f7b-b709-eef97142258d volUUID =
0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae (volume:238)
2017-07-12 14:24:50,036-0700 INFO (jsonrpc/1) [storage.VolumeManifest]
0c02a758-4295-4199-97de-b041744b3b15/6a887015-67cd-4f7b-b709-eef97142258d/
0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae info is {'status': 'OK',
'domain':
'0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
'description':
'', 'parent': '00000000-0000-0000-0000-000000000000',
'format': 'COW',
'generation': 0, 'image':
'6a887015-67cd-4f7b-b709-eef97142258d',
'ctime': '1499885619', 'disktype': '2',
'legality': 'LEGAL', 'mtime': '0',
'apparentsize': '110729625600', 'children': [], 'pool':
'', 'capacity':
'107374182400', 'uuid': u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
'truesize': '110729625600', 'type': 'SPARSE',
'lease': {'owners': [],
'version': None}} (volume:272)
2017-07-12 14:24:50,037-0700 INFO (jsonrpc/1) [vdsm.api] FINISH
getVolumeInfo return={'info': {'status': 'OK', 'domain':
'0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
'description':
'', 'parent': '00000000-0000-0000-0000-000000000000',
'format': 'COW',
'generation': 0, 'image':
'6a887015-67cd-4f7b-b709-eef97142258d',
'ctime': '1499885619', 'disktype': '2',
'legality': 'LEGAL', 'mtime': '0',
'apparentsize': '110729625600', 'children': [], 'pool':
'', 'capacity':
'107374182400', 'uuid': u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
'truesize': '110729625600', 'type': 'SPARSE',
'lease': {'owners': [],
'version': None}}} from=::ffff:10.4.64.7,59664,
flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e
(api:52)
HELP, Right now I am starting to think Block Storage and oVIRT = BAD!
--
Devin Acosta
Red Hat Certified Architect, LinuxStack
_______________________________________________
Users mailing list
Users(a)ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
12:37 p.m.
Please note that bug 1461029
<https://bugzilla.redhat.com/show_bug.cgi?id=1461029> is about live merge
(the VM is up) while, at least according to the logs, the issue described
here is related to cold merge (the VM is down).
On Thu, Jul 13, 2017 at 7:22 PM, richard anthony falzini <
richardfalzini(a)gmail.com> wrote:
Hi,
i have the same problem with gluster.
this is a bug that i opened https://bugzilla.redhat.com/
show_bug.cgi?id=1461029 .
In the bug i used single disk vm but i start to notice the problem with
multiple disk vm.
2017-07-13 0:07 GMT+02:00 Devin Acosta <devin(a)pabstatencio.com>:
> We are running a fresh install of oVIRT 4.1.3, using ISCSI, the VM in
> question has multiple Disks (4 to be exact). It snapshotted OK while on
> iSCSI however when I went to delete the single snapshot that existed it
> went into Locked state and never came back. The deletion has been going for
> well over an hour, and I am not convinced since the snapshot is less than
> 12 hours old that it’s really doing anything.
>
> I have seen that doing some Googling indicates there might be some known
> issues with iSCSI/Block Storage/Multiple Disk Snapshot issues.
>
> In the logs on the engine it shows:
>
> 2017-07-12 21:59:42,473Z INFO [org.ovirt.engine.core.bll.Se
> rialChildCommandsExecutionCallback] (DefaultQuartzScheduler2)
> [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
> 'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
> waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
> type:'PrepareMerge' to complete
> 2017-07-12 21:59:52,480Z INFO [org.ovirt.engine.core.bll.Co
> ncurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler2)
> [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command 'RemoveSnapshot' (id:
> '40482d09-8a7c-4dbd-8324-3e789296887a') waiting on child command id:
> '75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk'
> to complete
> 2017-07-12 21:59:52,483Z INFO [org.ovirt.engine.core.bll.Se
> rialChildCommandsExecutionCallback] (DefaultQuartzScheduler2)
> [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
> 'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
> waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
> type:'PrepareMerge' to complete
> 2017-07-12 22:00:02,490Z INFO [org.ovirt.engine.core.bll.Co
> ncurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler6)
> [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command 'RemoveSnapshot' (id:
> '40482d09-8a7c-4dbd-8324-3e789296887a') waiting on child command id:
> '75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk'
> to complete
> 2017-07-12 22:00:02,493Z INFO [org.ovirt.engine.core.bll.Se
> rialChildCommandsExecutionCallback] (DefaultQuartzScheduler6)
> [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
> 'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
> waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
> type:'PrepareMerge' to complete
> 2017-07-12 22:00:12,498Z INFO [org.ovirt.engine.core.bll.Co
> ncurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler3)
> [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command 'RemoveSnapshot' (id:
> '40482d09-8a7c-4dbd-8324-3e789296887a') waiting on child command id:
> '75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk'
> to complete
> 2017-07-12 22:00:12,501Z INFO [org.ovirt.engine.core.bll.Se
> rialChildCommandsExecutionCallback] (DefaultQuartzScheduler3)
> [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
> 'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
> waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
> type:'PrepareMerge' to complete
> 2017-07-12 22:00:22,508Z INFO [org.ovirt.engine.core.bll.Co
> ncurrentChildCommandsExecutionCallback] (DefaultQuartzScheduler5)
> [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command 'RemoveSnapshot' (id:
> '40482d09-8a7c-4dbd-8324-3e789296887a') waiting on child command id:
> '75c535fd-4558-459a-9992-875c48578a97'
type:'ColdMergeSnapshotSingleDisk'
> to complete
> 2017-07-12 22:00:22,511Z INFO [org.ovirt.engine.core.bll.Se
> rialChildCommandsExecutionCallback] (DefaultQuartzScheduler5)
> [a5f6eaf2-7996-4d51-ba62-050272d1f097] Command
> 'ColdMergeSnapshotSingleDisk' (id:
'75c535fd-4558-459a-9992-875c48578a97')
> waiting on child command id: 'd92e9a22-5f0f-4b61-aac6-5601f8ac2cda'
> type:'PrepareMerge' to complete
>
> This is what I seen on the SPM when I grep’d the Snapshot ID.
>
> 2017-07-12 14:22:18,773-0700 INFO (jsonrpc/6) [vdsm.api] START
> createVolume(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
> spUUID=u'00000001-0001-0001-0001-000000000311',
> imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
size=u'107374182400',
> volFormat=4, preallocate=2, diskType=2,
volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845',
> desc=u'', srcImgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
> srcVolUUID=u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', initialSize=None)
> from=::ffff:10.4.64.7,60016, flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e
> (api:46)
> 2017-07-12 14:22:19,095-0700 WARN (tasks/6) [root] File:
> /rhev/data-center/00000001-0001-0001-0001-000000000311/0c02a
> 758-4295-4199-97de-b041744b3b15/images/6a887015-67cd-4f7b-
> b709-eef97142258d/5921ba71-0f00-46cd-b0be-3c2ac1396845 already removed
> (utils:120)
> 2017-07-12 14:22:19,096-0700 INFO (tasks/6) [storage.Volume] Request to
> create snapshot
6a887015-67cd-4f7b-b709-eef97142258d/5921ba71-0f00-46cd-b0be-3c2ac1396845
> of volume 6a887015-67cd-4f7b-b709-eef97142258d/0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae
> (blockVolume:545)
> 2017-07-12 14:22:19,676-0700 INFO (tasks/6) [storage.LVM] Change LV tags
> (vg=0c02a758-4295-4199-97de-b041744b3b15, lv=5921ba71-0f00-46cd-b0be-3c2ac1396845,
> delTags=['OVIRT_VOL_INITIALIZING'], addTags=['MD_10',
> u'PU_0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
> u'IU_6a887015-67cd-4f7b-b709-eef97142258d']) (lvm:1344)
> 2017-07-12 14:22:36,010-0700 INFO (jsonrpc/5) [vdsm.api] START
> getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
> spUUID=u'00000001-0001-0001-0001-000000000311',
> imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
> volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845', options=None)
> from=::ffff:10.4.64.7,59664, flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e
> (api:46)
> 2017-07-12 14:22:36,077-0700 INFO (jsonrpc/5) [storage.VolumeManifest]
> Info request: sdUUID=0c02a758-4295-4199-97de-b041744b3b15
> imgUUID=6a887015-67cd-4f7b-b709-eef97142258d volUUID =
> 5921ba71-0f00-46cd-b0be-3c2ac1396845 (volume:238)
> 2017-07-12 14:22:36,185-0700 INFO (jsonrpc/5) [storage.VolumeManifest]
> 0c02a758-4295-4199-97de-b041744b3b15/6a887015-67cd-4f7b-
> b709-eef97142258d/5921ba71-0f00-46cd-b0be-3c2ac1396845 info is
> {'status': 'OK', 'domain':
'0c02a758-4295-4199-97de-b041744b3b15',
> 'voltype': 'LEAF', 'description': '',
'parent':
> '0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', 'format': 'COW',
'generation':
> 0, 'image': '6a887015-67cd-4f7b-b709-eef97142258d', 'ctime':
> '1499894539', 'disktype': '2', 'legality':
'LEGAL', 'mtime': '0',
> 'apparentsize': '1073741824', 'children': [], 'pool':
'', 'capacity':
> '107374182400', 'uuid':
u'5921ba71-0f00-46cd-b0be-3c2ac1396845',
> 'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'owners': [],
> 'version': None}} (volume:272)
> 2017-07-12 14:22:36,186-0700 INFO (jsonrpc/5) [vdsm.api] FINISH
> getVolumeInfo return={'info': {'status': 'OK',
'domain':
> '0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
> 'description': '', 'parent':
'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
> 'format': 'COW', 'generation': 0, 'image':
'6a887015-67cd-4f7b-b709-eef97142258d',
> 'ctime': '1499894539', 'disktype': '2',
'legality': 'LEGAL', 'mtime': '0',
> 'apparentsize': '1073741824', 'children': [], 'pool':
'', 'capacity':
> '107374182400', 'uuid':
u'5921ba71-0f00-46cd-b0be-3c2ac1396845',
> 'truesize': '1073741824', 'type': 'SPARSE',
'lease': {'owners': [],
> 'version': None}}} from=::ffff:10.4.64.7,59664,
> flow_id=e94eebf8-75dc-407a-8916-f4ff632f843e (api:52)
> 2017-07-12 14:24:24,854-0700 INFO (jsonrpc/1) [vdsm.api] START
> deleteVolume(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
> spUUID=u'00000001-0001-0001-0001-000000000311',
> imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
> volumes=[u'5921ba71-0f00-46cd-b0be-3c2ac1396845'],
postZero=u'false',
> force=u'false', discard=False) from=::ffff:10.4.64.7,60016,
> flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e (api:46)
> 2017-07-12 14:24:25,010-0700 INFO (tasks/7) [storage.Volume] Request to
> delete LV 5921ba71-0f00-46cd-b0be-3c2ac1396845 of image
> 6a887015-67cd-4f7b-b709-eef97142258d in VG 0c02a758-4295-4199-97de-b041744b3b15
> (blockVolume:579)
> 2017-07-12 14:24:25,130-0700 INFO (tasks/7) [storage.VolumeManifest]
> sdUUID=0c02a758-4295-4199-97de-b041744b3b15
> imgUUID=6a887015-67cd-4f7b-b709-eef97142258d volUUID =
> 5921ba71-0f00-46cd-b0be-3c2ac1396845 legality = ILLEGAL (volume:398)
> 2017-07-12 14:24:38,881-0700 INFO (jsonrpc/2) [vdsm.api] START
> getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
> spUUID=u'00000001-0001-0001-0001-000000000311',
> imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
> volUUID=u'5921ba71-0f00-46cd-b0be-3c2ac1396845', options=None)
> from=::ffff:10.4.64.7,59664, flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e
> (api:46)
> 2017-07-12 14:24:49,911-0700 INFO (jsonrpc/1) [vdsm.api] START
> getVolumeInfo(sdUUID=u'0c02a758-4295-4199-97de-b041744b3b15',
> spUUID=u'00000001-0001-0001-0001-000000000311',
> imgUUID=u'6a887015-67cd-4f7b-b709-eef97142258d',
> volUUID=u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae', options=None)
> from=::ffff:10.4.64.7,59664, flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e
> (api:46)
> 2017-07-12 14:24:49,912-0700 INFO (jsonrpc/1) [storage.VolumeManifest]
> Info request: sdUUID=0c02a758-4295-4199-97de-b041744b3b15
> imgUUID=6a887015-67cd-4f7b-b709-eef97142258d volUUID =
> 0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae (volume:238)
> 2017-07-12 14:24:50,036-0700 INFO (jsonrpc/1) [storage.VolumeManifest]
> 0c02a758-4295-4199-97de-b041744b3b15/6a887015-67cd-4f7b-
> b709-eef97142258d/0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae info is
> {'status': 'OK', 'domain':
'0c02a758-4295-4199-97de-b041744b3b15',
> 'voltype': 'LEAF', 'description': '',
'parent':
> '00000000-0000-0000-0000-000000000000', 'format': 'COW',
'generation':
> 0, 'image': '6a887015-67cd-4f7b-b709-eef97142258d', 'ctime':
> '1499885619', 'disktype': '2', 'legality':
'LEGAL', 'mtime': '0',
> 'apparentsize': '110729625600', 'children': [],
'pool': '', 'capacity':
> '107374182400', 'uuid':
u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
> 'truesize': '110729625600', 'type': 'SPARSE',
'lease': {'owners': [],
> 'version': None}} (volume:272)
> 2017-07-12 14:24:50,037-0700 INFO (jsonrpc/1) [vdsm.api] FINISH
> getVolumeInfo return={'info': {'status': 'OK',
'domain':
> '0c02a758-4295-4199-97de-b041744b3b15', 'voltype': 'LEAF',
> 'description': '', 'parent':
'00000000-0000-0000-0000-000000000000',
> 'format': 'COW', 'generation': 0, 'image':
'6a887015-67cd-4f7b-b709-eef97142258d',
> 'ctime': '1499885619', 'disktype': '2',
'legality': 'LEGAL', 'mtime': '0',
> 'apparentsize': '110729625600', 'children': [],
'pool': '', 'capacity':
> '107374182400', 'uuid':
u'0c3de1a8-ac18-4d7b-b348-3b097bf0a0ae',
> 'truesize': '110729625600', 'type': 'SPARSE',
'lease': {'owners': [],
> 'version': None}}} from=::ffff:10.4.64.7,59664,
> flow_id=c5e4bda4-9cd3-461d-8164-51d5614b995e (api:52)
>
> HELP, Right now I am starting to think Block Storage and oVIRT = BAD!
>
>
>
>
> --
>
> Devin Acosta
> Red Hat Certified Architect, LinuxStack
>
>
>
> _______________________________________________
> Users mailing list
> Users(a)ovirt.org
> http://lists.ovirt.org/mailman/listinfo/users
>
>
_______________________________________________
Users mailing list
Users(a)ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
2493
days inactive
2495
days old
5 comments
4 participants
participants (4)
-
Ala Hino -
Benny Zlotnik -
Devin Acosta -
richard anthony falzini