Bug 1574631

Summary: Problem to create snapshot
Product: [oVirt] vdsm Reporter: Marcelo Leandro <marceloltmm>
Component: SuperVDSMAssignee: Ala Hino <ahino>
Status: CLOSED CURRENTRELEASE QA Contact: Avihai <aefrat>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 4.20.23CC: ahino, bugs, gveitmic, izuckerm, marceloltmm, tnisan
Target Milestone: ovirt-4.2.5Flags: rule-engine: ovirt-4.2+
rule-engine: exception+
Target Release: ---   
Hardware: Unspecified   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-07-31 15:29:04 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Storage RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
Logs(vdsm(spm), engine )
none
SPM vsm.log + engine.log
none
dumpxml vm.
none
engine,spm and host none

Description Marcelo Leandro 2018-05-03 17:41:29 UTC
Description of problem:
I had problem when try create a snapshot.

Version-Release number of selected component (if applicable):
4.20.23

How reproducible:
Create snapshot the vm.


Actual results:
Failed to complete snapshot 'teste' creation for VM 'VPS-CRIA'.

Expected results:
Create Snapshot

Additional info:

Error msg in SPM log.

2018-05-02 17:46:11,235-0300 WARN  (tasks/2) [storage.ResourceManager] Resource factory failed to create resource '01_img_6e5cce71-3438-4045-9d54-607123e0557e.ed7f1c0f-5986-4979-b783-5c465b0854c6'. Canceling request. (resourceManager:543)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/storage/resourceManager.py", line 539, in registerResource
    obj = namespaceObj.factory.createResource(name, lockType)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/resourceFactories.py", line 193, in createResource
    lockType)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/resourceFactories.py", line 122, in __getResourceCandidatesList
    imgUUID=resourceName)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/image.py", line 213, in getChain
    if srcVol.isLeaf():
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volume.py", line 1430, in isLeaf
    return self._manifest.isLeaf()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volume.py", line 138, in isLeaf
    return self.getVolType() == sc.type2name(sc.LEAF_VOL)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volume.py", line 134, in getVolType
    self.voltype = self.getMetaParam(sc.VOLTYPE)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volume.py", line 118, in getMetaParam
    meta = self.getMetadata()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/blockVolume.py", line 112, in getMetadata
    md = VolumeMetadata.from_lines(lines)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volumemetadata.py", line 103, in from_lines
    "Missing metadata key: %s: found: %s" % (e, md))
MetaDataKeyNotFoundError: Meta Data key not found error: ("Missing metadata key: 'DOMAIN': found: {'NONE': '######################################################################################################################################################################################################################################################################################################################################################################################################################################################################################################################'}",)
2018-05-02 17:46:11,286-0300 WARN  (tasks/2) [storage.ResourceManager.Request] (ResName='01_img_6e5cce71-3438-4045-9d54-607123e0557e.ed7f1c0f-5986-4979-b783-5c465b0854c6', ReqID='a3cd9388-977b-45b9-9aa0-e431aeff8750') Tried to cancel a processed request (resourceManager:187)
2018-05-02 17:46:11,286-0300 ERROR (tasks/2) [storage.TaskManager.Task] (Task='ba0766ca-08a1-4d65-a4e9-1e0171939037') Unexpected error (task:875)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 882, in _run
    return fn(*args, **kargs)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 336, in run
    return self.cmd(*self.argslist, **self.argsdict)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/securable.py", line 79, in wrapper
    return method(self, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/sp.py", line 1938, in createVolume
    with rm.acquireResource(img_ns, imgUUID, rm.EXCLUSIVE):
  File "/usr/lib/python2.7/site-packages/vdsm/storage/resourceManager.py", line 1025, in acquireResource
    return _manager.acquireResource(namespace, name, lockType, timeout=timeout)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/resourceManager.py", line 475, in acquireResource
    raise se.ResourceAcqusitionFailed()
ResourceAcqusitionFailed: Could not acquire resource. Probably resource factory threw an exception.: ()

Comment 1 Marcelo Leandro 2018-05-03 20:29:26 UTC
Created attachment 1430882 [details]
Logs(vdsm(spm), engine )

Comment 2 Allon Mureinik 2018-05-07 11:45:25 UTC
Ala, can you take a look please?

Comment 3 Ala Hino 2018-05-07 19:27:05 UTC
Can you please run the following commands (on the host) send the output?

(1)
vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=c94783a0-907d-4a40-acad-b27b1f4d1118

(2)
vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=9ab418bf-dcfb-4acc-a067-a60ed5ec8b11

Comment 4 Marcelo Leandro 2018-05-07 19:38:46 UTC
Follow:

(1)
vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=c94783a0-907d-4a40-acad-b27b1f4d1118

vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=c94783a0-907d-4a40-acad-b27b1f4d1118
{
    "status": "OK",
    "lease": {
        "owners": [],
        "version": null
    },
    "domain": "6e5cce71-3438-4045-9d54-607123e0557e",
    "capacity": "53687091200",
    "voltype": "INTERNAL",
    "description": "{\"DiskAlias\":\"VPS-CRIA_Disk1\",\"DiskDescription\":\"\"}",
    "parent": "00000000-0000-0000-0000-000000000000",
    "format": "RAW",
    "generation": 0,
    "image": "ed7f1c0f-5986-4979-b783-5c465b0854c6",
    "uuid": "c94783a0-907d-4a40-acad-b27b1f4d1118",
    "disktype": "2",
    "legality": "LEGAL",
    "mtime": "0",
    "apparentsize": "53687091200",
    "truesize": "53687091200",
    "type": "PREALLOCATED",
    "children": [],
    "pool": "",
    "ctime": "1444743841"
}


(2)
vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=9ab418bf-dcfb-4acc-a067-a60ed5ec8b11


 vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=9ab418bf-dcfb-4acc-a067-a60ed5ec8b11
vdsm-client: Command Volume.getInfo with args {'storagepoolID': '77e24b20-9d21-4952-a089-3c5c592b4e6d', 'storagedomainID': '6e5cce71-3438-4045-9d54-607123e0557e', 'volumeID': '9ab418bf-dcfb-4acc-a067-a60ed5ec8b11', 'imageID': 'ed7f1c0f-5986-4979-b783-5c465b0854c6'} failed:
(code=201, message=Volume does not exist: (u'9ab418bf-dcfb-4acc-a067-a60ed5ec8b11',))



Thanks.

Comment 5 Marcelo Leandro 2018-05-07 19:39:23 UTC
Follow:

(1)
vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=c94783a0-907d-4a40-acad-b27b1f4d1118

vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=c94783a0-907d-4a40-acad-b27b1f4d1118
{
    "status": "OK",
    "lease": {
        "owners": [],
        "version": null
    },
    "domain": "6e5cce71-3438-4045-9d54-607123e0557e",
    "capacity": "53687091200",
    "voltype": "INTERNAL",
    "description": "{\"DiskAlias\":\"VPS-CRIA_Disk1\",\"DiskDescription\":\"\"}",
    "parent": "00000000-0000-0000-0000-000000000000",
    "format": "RAW",
    "generation": 0,
    "image": "ed7f1c0f-5986-4979-b783-5c465b0854c6",
    "uuid": "c94783a0-907d-4a40-acad-b27b1f4d1118",
    "disktype": "2",
    "legality": "LEGAL",
    "mtime": "0",
    "apparentsize": "53687091200",
    "truesize": "53687091200",
    "type": "PREALLOCATED",
    "children": [],
    "pool": "",
    "ctime": "1444743841"
}


(2)
vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=9ab418bf-dcfb-4acc-a067-a60ed5ec8b11


 vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=9ab418bf-dcfb-4acc-a067-a60ed5ec8b11
vdsm-client: Command Volume.getInfo with args {'storagepoolID': '77e24b20-9d21-4952-a089-3c5c592b4e6d', 'storagedomainID': '6e5cce71-3438-4045-9d54-607123e0557e', 'volumeID': '9ab418bf-dcfb-4acc-a067-a60ed5ec8b11', 'imageID': 'ed7f1c0f-5986-4979-b783-5c465b0854c6'} failed:
(code=201, message=Volume does not exist: (u'9ab418bf-dcfb-4acc-a067-a60ed5ec8b11',))



Thanks.

Comment 6 Ala Hino 2018-05-07 20:08:47 UTC
How many hosts do you have in the environment?
If there are multiple hosts, can you please run the commands on the SPM (if you didn't run that previously)?

Comment 7 Marcelo Leandro 2018-05-07 20:34:24 UTC
(In reply to Ala Hino from comment #6)
> How many hosts do you have in the environment?
> If there are multiple hosts, can you please run the commands on the SPM (if
> you didn't run that previously)?

I am have 12 hosts, I runed in the spm.

Comment 8 Ala Hino 2018-05-08 10:10:29 UTC
Based on the exception, it seems that the volume metadata is corrupted.

Can you please run the following commands on the host running the VM?

(1)
vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=c94783a0-907d-4a40-acad-b27b1f4d1118

(2)
vdsm-client StorageDomain getInfo storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e

Comment 9 Marcelo Leandro 2018-05-08 11:39:36 UTC
(In reply to Ala Hino from comment #8)
> Based on the exception, it seems that the volume metadata is corrupted.
> 
> Can you please run the following commands on the host running the VM?
> 
> (1)
> vdsm-client Volume getInfo
> storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d
> storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e
> imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6
> volumeID=c94783a0-907d-4a40-acad-b27b1f4d1118
> 
> (2)
> vdsm-client StorageDomain getInfo
> storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e

I think this too, but strange because it has 3 VMs run perfect.

Follow,


(1)
 vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=c94783a0-907d-4a40-acad-b27b1f4d1118
{
    "status": "OK",
    "lease": {
        "owners": [],
        "version": null
    },
    "domain": "6e5cce71-3438-4045-9d54-607123e0557e",
    "capacity": "53687091200",
    "voltype": "INTERNAL",
    "description": "{\"DiskAlias\":\"VPS-CRIA_Disk1\",\"DiskDescription\":\"\"}",
    "parent": "00000000-0000-0000-0000-000000000000",
    "format": "RAW",
    "generation": 0,
    "image": "ed7f1c0f-5986-4979-b783-5c465b0854c6",
    "uuid": "c94783a0-907d-4a40-acad-b27b1f4d1118",
    "disktype": "2",
    "legality": "LEGAL",
    "mtime": "0",
    "apparentsize": "53687091200",
    "truesize": "53687091200",
    "type": "PREALLOCATED",
    "children": [],
    "pool": "",
    "ctime": "1444743841"
}

(2)
{
    "uuid": "6e5cce71-3438-4045-9d54-607123e0557e",
    "type": "ISCSI",
    "vguuid": "7JOYDc-iQgm-11Pk-2czh-S8k0-Qc5U-f1npF1",
    "metadataDevice": "36005076300810a4db800000000000002",
    "state": "OK",
    "version": "4",
    "role": "Regular",
    "vgMetadataDevice": "36005076300810a4db800000000000002",
    "class": "Data",
    "pool": [
        "77e24b20-9d21-4952-a089-3c5c592b4e6d"
    ],
    "name": "IBM01"
}

Very thanks.

Comment 10 Ala Hino 2018-05-08 13:08:47 UTC
There might be a volume in the chain that supposed to be deleted from the storage but still there.

Could you please run the following command:

vdsm-client Image getVolumes storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6

This command returns a list as below:

[
    "760fbfba-0f60-475e-a918-6c8731ee0f4c"
]

Per returned UUID, please run the following:

vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=<UUID_FROM_THE_LIST>

Hopefully we now can find the volume that supposed to be deleted but still exists in the storage.

Comment 11 Marcelo Leandro 2018-05-08 13:22:50 UTC
(In reply to Ala Hino from comment #10)
> There might be a volume in the chain that supposed to be deleted from the
> storage but still there.
> 
> Could you please run the following command:
> 
> vdsm-client Image getVolumes
> storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d
> storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e
> imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6
> 
> This command returns a list as below:
> 
> [
>     "760fbfba-0f60-475e-a918-6c8731ee0f4c"
> ]
> 
> Per returned UUID, please run the following:
> 
> vdsm-client Volume getInfo
> storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d
> storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e
> imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=<UUID_FROM_THE_LIST>
> 
> Hopefully we now can find the volume that supposed to be deleted but still
> exists in the storage.

Follow:

 vdsm-client Image getVolumes storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6
[
    "5586b887-f486-4339-8811-dfe6630ee0b4",
    "6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a",
    "fe710931-3683-4dd5-a5dd-c169adc5c387",
    "6146f5ed-3974-4657-9077-5dfb17d8e8ad",
    "c94783a0-907d-4a40-acad-b27b1f4d1118"
]

first volumeid: 
vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=5586b887-f486-4339-8811-dfe6630ee0b4
{
    "status": "OK",
    "lease": {
        "owners": [],
        "version": null
    },
    "domain": "6e5cce71-3438-4045-9d54-607123e0557e",
    "capacity": "53687091200",
    "voltype": "INTERNAL",
    "description": "",
    "parent": "c94783a0-907d-4a40-acad-b27b1f4d1118",
    "format": "COW",
    "generation": 0,
    "image": "ed7f1c0f-5986-4979-b783-5c465b0854c6",
    "uuid": "5586b887-f486-4339-8811-dfe6630ee0b4",
    "disktype": "2",
    "legality": "LEGAL",
    "mtime": "0",
    "apparentsize": "1073741824",
    "truesize": "1073741824",
    "type": "SPARSE",
    "children": [],
    "pool": "",
    "ctime": "1492911421"
 
Second volumeid:
vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a
{
    "status": "INVALID",
    "truesize": "0",
    "apparentsize": "0",
    "children": []
}

third volumeid:

vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=fe710931-3683-4dd5-a5dd-c169adc5c387
{
    "status": "OK",
    "lease": {
        "owners": [],
        "version": null
    },
    "domain": "6e5cce71-3438-4045-9d54-607123e0557e",
    "capacity": "53687091200",
    "voltype": "INTERNAL",
    "description": "",
    "parent": "5586b887-f486-4339-8811-dfe6630ee0b4",
    "format": "COW",
    "generation": 0,
    "image": "ed7f1c0f-5986-4979-b783-5c465b0854c6",
    "uuid": "fe710931-3683-4dd5-a5dd-c169adc5c387",
    "disktype": "2",
    "legality": "LEGAL",
    "mtime": "0",
    "apparentsize": "1073741824",
    "truesize": "1073741824",
    "type": "SPARSE",
    "children": [],
    "pool": "",
    "ctime": "1492994911"
}

fourth volumeid:

vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=6146f5ed-3974-4657-9077-5dfb17d8e8ad
{
    "status": "OK",
    "lease": {
        "owners": [],
        "version": null
    },
    "domain": "6e5cce71-3438-4045-9d54-607123e0557e",
    "capacity": "53687091200",
    "voltype": "LEAF",
    "description": "",
    "parent": "fe710931-3683-4dd5-a5dd-c169adc5c387",
    "format": "COW",
    "generation": 0,
    "image": "ed7f1c0f-5986-4979-b783-5c465b0854c6",
    "uuid": "6146f5ed-3974-4657-9077-5dfb17d8e8ad",
    "disktype": "2",
    "legality": "LEGAL",
    "mtime": "0",
    "apparentsize": "1073741824",
    "truesize": "1073741824",
    "type": "SPARSE",
    "children": [],
    "pool": "",
    "ctime": "1493083035"
}


fifth volumeid:

vdsm-client Volume getInfo storagepoolID=77e24b20-9d21-4952-a089-3c5c592b4e6d storagedomainID=6e5cce71-3438-4045-9d54-607123e0557e imageID=ed7f1c0f-5986-4979-b783-5c465b0854c6 volumeID=c94783a0-907d-4a40-acad-b27b1f4d1118
{
    "status": "OK",
    "lease": {
        "owners": [],
        "version": null
    },
    "domain": "6e5cce71-3438-4045-9d54-607123e0557e",
    "capacity": "53687091200",
    "voltype": "INTERNAL",
    "description": "{\"DiskAlias\":\"VPS-CRIA_Disk1\",\"DiskDescription\":\"\"}",
    "parent": "00000000-0000-0000-0000-000000000000",
    "format": "RAW",
    "generation": 0,
    "image": "ed7f1c0f-5986-4979-b783-5c465b0854c6",
    "uuid": "c94783a0-907d-4a40-acad-b27b1f4d1118",
    "disktype": "2",
    "legality": "LEGAL",
    "mtime": "0",
    "apparentsize": "53687091200",
    "truesize": "53687091200",
    "type": "PREALLOCATED",
    "children": [],
    "pool": "",
    "ctime": "1444743841"
}

Thanks.

Comment 12 Ala Hino 2018-05-08 13:56:48 UTC
So, volume 6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a isn't valid.

Could you please run the following commands and share the output?

(1)
lvs -o attr,size,tags /dev/6e5cce71-3438-4045-9d54-607123e0557e/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a

(2)
qemu-img info --backing-chain /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/ed7f1c0f-5986-4979-b783-5c465b0854c6/6146f5ed-3974-4657-9077-5dfb17d8e8ad

Comment 13 Marcelo Leandro 2018-05-08 16:20:02 UTC
(In reply to Ala Hino from comment #12)
> So, volume 6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a isn't valid.
> 
> Could you please run the following commands and share the output?
> 
> (1)
> lvs -o attr,size,tags
> /dev/6e5cce71-3438-4045-9d54-607123e0557e/6ad106fe-b3a8-4fa0-8b66-
> d5caee66fa6a
> 
> (2)
> qemu-img info --backing-chain
> /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-
> 9d54-607123e0557e/images/ed7f1c0f-5986-4979-b783-5c465b0854c6/6146f5ed-3974-
> 4657-9077-5dfb17d8e8ad

Follow:

(1)
 lvs -o attr,size,tags /dev/6e5cce71-3438-4045-9d54-607123e0557e/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a
  Attr       LSize LV Tags
  -wi-a----- 2,00g IU_ed7f1c0f-5986-4979-b783-5c465b0854c6,MD_111,PU_c94783a0-907d-4a40-acad-b27b1f4d1118


(2)
 qemu-img info --backing-chain /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/ed7f1c0f-5986-4979-b783-5c465b0854c6/6146f5ed-3974-4657-9077-5dfb17d8e8ad
image: /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/ed7f1c0f-5986-4979-b783-5c465b0854c6/6146f5ed-3974-4657-9077-5dfb17d8e8ad
file format: qcow2
virtual size: 50G (53687091200 bytes)
disk size: 0
cluster_size: 65536
backing file: fe710931-3683-4dd5-a5dd-c169adc5c387 (actual path: /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/ed7f1c0f-5986-4979-b783-5c465b0854c6/fe710931-3683-4dd5-a5dd-c169adc5c387)
backing file format: qcow2
Format specific information:
    compat: 0.10
    refcount bits: 16

image: /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/ed7f1c0f-5986-4979-b783-5c465b0854c6/fe710931-3683-4dd5-a5dd-c169adc5c387
file format: qcow2
virtual size: 50G (53687091200 bytes)
disk size: 0
cluster_size: 65536
backing file: 5586b887-f486-4339-8811-dfe6630ee0b4 (actual path: /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/ed7f1c0f-5986-4979-b783-5c465b0854c6/5586b887-f486-4339-8811-dfe6630ee0b4)
backing file format: qcow2
Format specific information:
    compat: 0.10
    refcount bits: 16

image: /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/ed7f1c0f-5986-4979-b783-5c465b0854c6/5586b887-f486-4339-8811-dfe6630ee0b4
file format: qcow2
virtual size: 50G (53687091200 bytes)
disk size: 0
cluster_size: 65536
backing file: c94783a0-907d-4a40-acad-b27b1f4d1118 (actual path: /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/ed7f1c0f-5986-4979-b783-5c465b0854c6/c94783a0-907d-4a40-acad-b27b1f4d1118)
backing file format: raw
Format specific information:
    compat: 0.10
    refcount bits: 16

image: /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/ed7f1c0f-5986-4979-b783-5c465b0854c6/c94783a0-907d-4a40-acad-b27b1f4d1118
file format: raw
virtual size: 50G (53687091200 bytes)
disk size: 0

Thanks.

Comment 14 Ala Hino 2018-05-10 11:18:19 UTC
So, the volume isn't part of qemu which means that we have to manually remove it from the storage and from the database.

Could you please send a database dump?

And, run the following command:

qemu-img info --backing-chain /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a

Comment 15 Marcelo Leandro 2018-05-10 11:59:01 UTC
(In reply to Ala Hino from comment #14)
> So, the volume isn't part of qemu which means that we have to manually
> remove it from the storage and from the database.
> 
> Could you please send a database dump?
> 
> And, run the following command:
> 
> qemu-img info --backing-chain
> /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-
> 9d54-607123e0557e/images/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a

I run in the SPM and the host where the VM run, but had the same result:

qemu-img info --backing-chain /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a
qemu-img: Could not open '/rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a': Could not open '/rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a': No such file or directory


The database dump I sended to your email.

Very Thanks,

Marcelo Leandro

Comment 16 Ala Hino 2018-05-10 12:24:58 UTC
Ah, the volume must be active.
Can you please run the following:

(1) Activate the volume:
lvchange -a y /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a

(2) Get qeum-img info:
qemu-img info --backing-chain /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a

(3) Deactivate the volume:
lvchange -a n /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a

Please share the output of qemu-img command.

Comment 17 Marcelo Leandro 2018-05-10 12:43:43 UTC
(In reply to Ala Hino from comment #16)
> Ah, the volume must be active.
> Can you please run the following:
> 
> (1) Activate the volume:
> lvchange -a y
> /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-
> 9d54-607123e0557e/images/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a
> 
> (2) Get qeum-img info:
> qemu-img info --backing-chain
> /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-
> 9d54-607123e0557e/images/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a
> 
> (3) Deactivate the volume:
> lvchange -a n
> /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-
> 9d54-607123e0557e/images/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a
> 
> Please share the output of qemu-img command.

With this commands not works,  but works with follows.

(1) Activete the volume
lvchange -a y /dev/6e5cce71-3438-4045-9d54-607123e0557e/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a
  /dev/mapper/2307244693962414c: read failed after 0 of 4096 at 0: Erro de entrada/saída
  /dev/mapper/2307244693962414c: read failed after 0 of 4096 at 13087167938560: Erro de entrada/saída
  /dev/mapper/2307244693962414c: read failed after 0 of 4096 at 13087167995904: Erro de entrada/saída
  /dev/mapper/2307244693962414c: read failed after 0 of 4096 at 4096: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/metadata: read failed after 0 of 4096 at 0: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/metadata: read failed after 0 of 4096 at 536805376: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/metadata: read failed after 0 of 4096 at 536862720: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/metadata: read failed after 0 of 4096 at 4096: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/ids: read failed after 0 of 4096 at 0: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/ids: read failed after 0 of 4096 at 134152192: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/ids: read failed after 0 of 4096 at 134209536: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/ids: read failed after 0 of 4096 at 4096: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/leases: read failed after 0 of 4096 at 0: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/leases: read failed after 0 of 4096 at 2147418112: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/leases: read failed after 0 of 4096 at 2147475456: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/leases: read failed after 0 of 4096 at 4096: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/outbox: read failed after 0 of 4096 at 0: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/outbox: read failed after 0 of 4096 at 134152192: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/outbox: read failed after 0 of 4096 at 134209536: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/outbox: read failed after 0 of 4096 at 4096: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/inbox: read failed after 0 of 4096 at 0: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/inbox: read failed after 0 of 4096 at 134152192: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/inbox: read failed after 0 of 4096 at 134209536: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/inbox: read failed after 0 of 4096 at 4096: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/master: read failed after 0 of 4096 at 0: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/master: read failed after 0 of 4096 at 1073676288: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/master: read failed after 0 of 4096 at 1073733632: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/master: read failed after 0 of 4096 at 4096: Erro de entrada/saída

(2) Get qemu-img info:
 qemu-img info --backing-chain /dev/6e5cce71-3438-4045-9d54-607123e0557e/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a
qemu-img: Could not open '/dev/6e5cce71-3438-4045-9d54-607123e0557e/5054ec8e-16fa-4a70-a46b-3b83d9282cc1': Could not open '/dev/6e5cce71-3438-4045-9d54-607123e0557e/5054ec8e-16fa-4a70-a46b-3b83d9282cc1': No such file or directory

(3) Deactivate :

 lvchange -a n /dev/6e5cce71-3438-4045-9d54-607123e0557e/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a
  /dev/mapper/2307244693962414c: read failed after 0 of 4096 at 0: Erro de entrada/saída
  /dev/mapper/2307244693962414c: read failed after 0 of 4096 at 13087167938560: Erro de entrada/saída
  /dev/mapper/2307244693962414c: read failed after 0 of 4096 at 13087167995904: Erro de entrada/saída
  /dev/mapper/2307244693962414c: read failed after 0 of 4096 at 4096: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/metadata: read failed after 0 of 4096 at 0: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/metadata: read failed after 0 of 4096 at 536805376: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/metadata: read failed after 0 of 4096 at 536862720: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/metadata: read failed after 0 of 4096 at 4096: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/ids: read failed after 0 of 4096 at 0: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/ids: read failed after 0 of 4096 at 134152192: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/ids: read failed after 0 of 4096 at 134209536: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/ids: read failed after 0 of 4096 at 4096: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/leases: read failed after 0 of 4096 at 0: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/leases: read failed after 0 of 4096 at 2147418112: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/leases: read failed after 0 of 4096 at 2147475456: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/leases: read failed after 0 of 4096 at 4096: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/outbox: read failed after 0 of 4096 at 0: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/outbox: read failed after 0 of 4096 at 134152192: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/outbox: read failed after 0 of 4096 at 134209536: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/outbox: read failed after 0 of 4096 at 4096: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/inbox: read failed after 0 of 4096 at 0: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/inbox: read failed after 0 of 4096 at 134152192: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/inbox: read failed after 0 of 4096 at 134209536: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/inbox: read failed after 0 of 4096 at 4096: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/master: read failed after 0 of 4096 at 0: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/master: read failed after 0 of 4096 at 1073676288: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/master: read failed after 0 of 4096 at 1073733632: Erro de entrada/saída
  /dev/c2dc0101-748e-4a7b-9913-47993eaa52bd/master: read failed after 0 of 4096 at 4096: Erro de entrada/saída


I had many errors when active and deactive this volume.

Thanks,

Comment 18 Ala Hino 2018-05-10 13:02:55 UTC
My bad. Please try the following:

(1) Activate the volume:
lvchange -a y /dev/6e5cce71-3438-4045-9d54-607123e0557e/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a

(2) Get qeum-img info:
qemu-img info --backing-chain /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-9d54-607123e0557e/images/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a

(3) Deactivate the volume:
lvchange -a n /dev/6e5cce71-3438-4045-9d54-607123e0557e/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a

Comment 19 Marcelo Leandro 2018-05-10 13:06:12 UTC
(In reply to Ala Hino from comment #18)
> My bad. Please try the following:
> 
> (1) Activate the volume:
> lvchange -a y
> /dev/6e5cce71-3438-4045-9d54-607123e0557e/6ad106fe-b3a8-4fa0-8b66-
> d5caee66fa6a
> 
> (2) Get qeum-img info:
> qemu-img info --backing-chain
> /rhev/data-center/77e24b20-9d21-4952-a089-3c5c592b4e6d/6e5cce71-3438-4045-
> 9d54-607123e0557e/images/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a
> 
> (3) Deactivate the volume:
> lvchange -a n
> /dev/6e5cce71-3438-4045-9d54-607123e0557e/6ad106fe-b3a8-4fa0-8b66-
> d5caee66fa6a

I executed this command in last topic.

Thanks,

Marcelo Leandro

Comment 20 Ala Hino 2018-05-10 13:07:44 UTC
The path to volume in comment #16 was wrong.
The correct path is in comment #18.

Comment 21 Marcelo Leandro 2018-05-10 13:23:30 UTC
(In reply to Ala Hino from comment #20)
> The path to volume in comment #16 was wrong.
> The correct path is in comment #18.

Yes, but I already modify the path in my comment #17.

Comment 22 Ala Hino 2018-05-13 19:12:31 UTC
I looked into the database and it seems that the invalid volume isn't in the database:

$ select * from images where image_guid = '6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a'::uuid;

image_guid | creation_date | size | it_guid | parentid | imagestatus | lastmodified | vm_snapshot_id | volume_type | volume_format | image_group_id | _create_date | _update_date | active | volume_classification | qcow_compat 
------------+---------------+------+---------+----------+-------------+--------------+----------------+-------------+---------------+----------------+--------------+--------------+--------+-----------------------+-------------
(0 rows)

$ select * from images where parentid = '6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a'::uuid;

image_guid | creation_date | size | it_guid | parentid | imagestatus | lastmodified | vm_snapshot_id | volume_type | volume_format | image_group_id | _create_date | _update_date | active | volume_classification | qcow_compat 
------------+---------------+------+---------+----------+-------------+--------------+----------------+-------------+---------------+----------------+--------------+--------------+--------+-----------------------+-------------
(0 rows)

Can you please send the list, as seen in the GUI, of existing snapshots of 'VPS-CRIA' Vm?

Comment 23 Ala Hino 2018-05-14 08:26:26 UTC
Actually, looking deeper into the db, I see that there are no "real" snapshots but the Active one:

# select snapshot_id,description from snapshots where vm_id = 'd5527a7c-bd56-49dd-9659-05d2567f2c3b';
             snapshot_id              |           description           
--------------------------------------+---------------------------------
 7e4cfc3b-a6d6-4b90-b08c-884c9112db43 | Next Run configuration snapshot
 3bf4cbc4-aeed-4856-8c42-7b4c05c2c78a | Active VM
(2 rows)

And there is only one image:

The DB has just 1 image for that disk.

# select image_guid,parentid,imagestatus,vm_snapshot_id,active from images where image_group_id ='ed7f1c0f-5986-4979-b783-5c465b0854c6';
              image_guid              |               parentid               | imagestatus |            vm_snapshot_id            | active 
--------------------------------------+--------------------------------------+-------------+--------------------------------------+--------
 c94783a0-907d-4a40-acad-b27b1f4d1118 | 00000000-0000-0000-0000-000000000000 |           1 | 3bf4cbc4-aeed-4856-8c42-7b4c05c2c78a | t
(1 row)

Did you do any DB/LVM metadata restore?

Comment 24 Marcelo Leandro 2018-05-15 14:42:01 UTC
Reply Comment 22:

Can you please send the list, as seen in the GUI, of existing snapshots of 'VPS-CRIA' Vm?

Only this disk snapshot id:
c94783a0-907d-4a40-acad-b27b1f4d1118


Reply Comment 23:

Did you do any DB/LVM metadata restore?
No, but we had problem with storage connection, but now it's ok with the connection.

Comment 25 Ilan Zuckerman 2018-05-17 07:57:21 UTC
Hi all,
I am also having similar issue with snapshot creation on particular cluster we have in our scaled out environment.

SPM log:

2018-05-17 07:09:37,423+0000 WARN  (tasks/0) [storage.ResourceManager] Resource factory failed to create resource '01_img_6a96947d-4b1c-429d-81dc-1530dfb51eb5.313a14b9-faf5-430b-8122-7fd2921bfd5c'. Canceling request. (resourceManager:543)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/storage/resourceManager.py", line 539, in registerResource
    obj = namespaceObj.factory.createResource(name, lockType)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/resourceFactories.py", line 193, in createResource
    lockType)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/resourceFactories.py", line 122, in __getResourceCandidatesList
    imgUUID=resourceName)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/image.py", line 213, in getChain
    if srcVol.isLeaf():
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volume.py", line 1437, in isLeaf
    return self._manifest.isLeaf()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volume.py", line 138, in isLeaf
    return self.getVolType() == sc.type2name(sc.LEAF_VOL)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volume.py", line 134, in getVolType
    self.voltype = self.getMetaParam(sc.VOLTYPE)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volume.py", line 118, in getMetaParam
    meta = self.getMetadata()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/blockVolume.py", line 112, in getMetadata
    md = VolumeMetadata.from_lines(lines)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/volumemetadata.py", line 103, in from_lines
    "Missing metadata key: %s: found: %s" % (e, md))
MetaDataKeyNotFoundError: Meta Data key not found error: ("Missing metadata key: 'DOMAIN': found: {'NONE': '######################################################################################################################################################################################################################################################################################################################################################################################################################################################################################################################'}",)
2018-05-17 07:09:37,425+0000 WARN  (tasks/0) [storage.ResourceManager.Request] (ResName='01_img_6a96947d-4b1c-429d-81dc-1530dfb51eb5.313a14b9-faf5-430b-8122-7fd2921bfd5c', ReqID='447f09a5-31fb-4894-891f-ed7e8b61be33') Tried to cancel a processed request (resourceManager:187)
2018-05-17 07:09:37,426+0000 ERROR (tasks/0) [storage.TaskManager.Task] (Task='ff1aa784-d764-4849-bba5-68e07a114b01') Unexpected error (task:875)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 882, in _run
    return fn(*args, **kargs)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 336, in run
    return self.cmd(*self.argslist, **self.argsdict)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/securable.py", line 79, in wrapper
    return method(self, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/sp.py", line 1938, in createVolume
    with rm.acquireResource(img_ns, imgUUID, rm.EXCLUSIVE):
  File "/usr/lib/python2.7/site-packages/vdsm/storage/resourceManager.py", line 1025, in acquireResource
    return _manager.acquireResource(namespace, name, lockType, timeout=timeout)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/resourceManager.py", line 475, in acquireResource
    raise se.ResourceAcqusitionFailed()
ResourceAcqusitionFailed: Could not acquire resource. Probably resource factory threw an exception.: ()
2018-05-17 07:09:37,489+0000 INFO  (tasks/0) [storage.ThreadPool.WorkerThread] FINISH task ff1aa784-d764-4849-bba5-68e07a114b01 (threadPool:210)
2018-05-17 07:09:38,806+0000 INFO  (jsonrpc/5) [vdsm.api] START getSpmStatus(spUUID=u'd608083d-ff34-43b6-84c4-d7585d32c9af', options=None) from=::ffff:10.12.69.37,57386, task_id=aa22f10b-b97b-4ebf-8486-aa5ec4fd59cf (api:46)

------------------------------------------------------------------

Executed the same command from comment 3 (with appropriate values):

-=>>vdsm-client Volume getInfo storagepoolID=d608083d-ff34-43b6-84c4-d7585d32c9af storagedomainID=6a96947d-4b1c-429d-81dc-1530dfb51eb5 imageID=313a14b9-faf5-430b-8122-7fd2921bfd5c volumeID=56c664a2-09c7-4a13-b681-1f5ca0b7e5b8
{
    "status": "OK", 
    "lease": {
        "path": "/dev/6a96947d-4b1c-429d-81dc-1530dfb51eb5/leases", 
        "owners": [], 
        "version": null, 
        "offset": 1293942784
    }, 
    "domain": "6a96947d-4b1c-429d-81dc-1530dfb51eb5", 
    "capacity": "112742891520", 
    "voltype": "INTERNAL", 
    "description": "", 
    "parent": "ee875fcd-6c58-4a72-ab1f-918deaa3b56e", 
    "format": "COW", 
    "generation": 0, 
    "image": "313a14b9-faf5-430b-8122-7fd2921bfd5c", 
    "uuid": "56c664a2-09c7-4a13-b681-1f5ca0b7e5b8", 
    "disktype": "DATA", 
    "legality": "LEGAL", 
    "mtime": "0", 
    "apparentsize": "1073741824", 
    "truesize": "1073741824", 
    "type": "SPARSE", 
    "children": [], 
    "pool": "", 
    "ctime": "1520438506"
}

-------------------------------------------------------

Please let me know if additional info needed.
I will provide our environment details in private message.

#Topology
Engine / Engine DB (1 machine)
DWH DB (separate machine)
400 Hosts
RHEL 7.5 3.10.0-858.el7.x86_64
ovirt-engine-4.2.3.5-0.1.el7.noarch

Comment 27 Ilan Zuckerman 2018-05-17 08:17:26 UTC
Created attachment 1437779 [details]
SPM vsm.log + engine.log

Comment 28 Ala Hino 2018-05-21 19:43:39 UTC
Marcelo,

Can you please run the following command and upload the result?

$ virsh -r dumpxml d5527a7c-bd56-49dd-9659-05d2567f2c3b

Comment 29 Marcelo Leandro 2018-05-21 20:17:03 UTC
(In reply to Ala Hino from comment #28)
> Marcelo,
> 
> Can you please run the following command and upload the result?
> 
> $ virsh -r dumpxml d5527a7c-bd56-49dd-9659-05d2567f2c3b

The vm need is on?

I run whit down and this result:

virsh -r dumpxml d5527a7c-bd56-49dd-9659-05d2567f2c3b
Error: Failed to get domain "d5527a7c-bd56-49dd-9659-05d2567f2c3b"
Error: Domain not found: No domain with the name corresponding to 'd5527a7c-bd56-49dd-9659-05d2567f2c3b'

Comment 30 Ala Hino 2018-05-21 20:20:49 UTC
(In reply to Marcelo Leandro from comment #29)
> (In reply to Ala Hino from comment #28)
> > Marcelo,
> > 
> > Can you please run the following command and upload the result?
> > 
> > $ virsh -r dumpxml d5527a7c-bd56-49dd-9659-05d2567f2c3b
> 
> The vm need is on?
> 
> I run whit down and this result:
> 
> virsh -r dumpxml d5527a7c-bd56-49dd-9659-05d2567f2c3b
> Error: Failed to get domain "d5527a7c-bd56-49dd-9659-05d2567f2c3b"
> Error: Domain not found: No domain with the name corresponding to
> 'd5527a7c-bd56-49dd-9659-05d2567f2c3b'

Yeah, the VM must be running.

Comment 31 Marcelo Leandro 2018-05-21 20:21:02 UTC
Created attachment 1439765 [details]
dumpxml vm.

dumpxml the command :

virsh -r dumpxml d5527a7c-bd56-49dd-9659-05d2567f2c3b

Comment 32 Yaniv Kaul 2018-06-04 07:31:17 UTC
Is there a chance this is going into 4.2.4, or shall we move it to 4.2.5?

Comment 33 Tal Nisan 2018-06-04 07:42:08 UTC
It is currently under review, should be making it to 4.2.4

Comment 34 Sandro Bonazzola 2018-06-15 12:14:56 UTC
This bug is not marked as blocker and we entered blocker only phase for 4.2.4.
Please consider re-targeting to 4.2.5.

Comment 35 Avihai 2018-07-16 12:12:54 UTC
Hi Ala ,

Can you please provide a clear scenario for this bug verification effort?

Comment 36 Ala Hino 2018-07-16 14:41:08 UTC
Hi Avihai,

I had to change the code in order to verify this fix.
I can guide you to change the code in your environment if you wish.

Comment 43 Avihai 2018-07-18 12:17:05 UTC
Checked create/delete snapshots after doing live merge without issues.

Verified.

Engine : 4.2.5.2_SNAPSHOT-76.g2d45cde.0.scratch.master.el7ev
VDSM   : 4.20.34-1

Comment 44 Sandro Bonazzola 2018-07-31 15:29:04 UTC
This bugzilla is included in oVirt 4.2.5 release, published on July 30th 2018.

Since the problem described in this bug report should be
resolved in oVirt 4.2.5 release, it has been closed with a resolution of CURRENT RELEASE.

If the solution does not work for you, please open a new bug report.

Comment 45 Ala Hino 2018-08-28 09:00:30 UTC
Hi Marcelo,

The issue now is that you are not able to create new snapshots, right?

Please run the following command again and share the result:

lvs -o attr,size,tags /dev/6e5cce71-3438-4045-9d54-607123e0557e/6ad106fe-b3a8-4fa0-8b66-d5caee66fa6a

Comment 46 Marcelo Leandro 2018-08-30 18:52:41 UTC
(In reply to Ala Hino from comment #45)
> Hi Marcelo,
> 
> The issue now is that you are not able to create new snapshots, right?
> 
> Please run the following command again and share the result:
> 
> lvs -o attr,size,tags
> /dev/6e5cce71-3438-4045-9d54-607123e0557e/6ad106fe-b3a8-4fa0-8b66-
> d5caee66fa6a

Hello Ala,

I am no more with this problem, I am have only one problem with snapshot now.

When I try remove a snapshot, show this msg:

General command validation failure.

And now the vm status is  not responding but stay running.

Very thank.

Comment 47 Ala Hino 2018-08-30 19:15:34 UTC
Hello Marcelo,

Could you please share vdsm and engine logs?

Comment 48 Marcelo Leandro 2018-08-30 20:05:54 UTC
Created attachment 1479892 [details]
engine,spm and host