On Wed, 2020-07-15 at 22:54 +0300, Nir Soffer wrote:
On Wed, Jul 15, 2020 at 7:54 PM Arsène Gschwind
<
arsene.gschwind@unibas.ch
> wrote:

On Wed, 2020-07-15 at 17:46 +0300, Nir Soffer wrote:

What we see in the data you sent:


Qemu chain:


$ qemu-img info --backing-chain

/dev/33777993-a3a5-4aad-a24c-dfe5e473faca/6197b30d-0732-4cc7-aef0-12f9f6e9565b

image: /dev/33777993-a3a5-4aad-a24c-dfe5e473faca/6197b30d-0732-4cc7-aef0-12f9f6e9565b

file format: qcow2

virtual size: 150G (161061273600 bytes)

disk size: 0

cluster_size: 65536

backing file: 8e412b5a-85ec-4c53-a5b8-dfb4d6d987b8 (actual path:

/dev/33777993-a3a5-4aad-a24c-dfe5e473faca/8e412b5a-85ec-4c53-a5b8-dfb4d6d987b8)

backing file format: qcow2

Format specific information:

    compat: 1.1

    lazy refcounts: false

    refcount bits: 16

    corrupt: false


image: /dev/33777993-a3a5-4aad-a24c-dfe5e473faca/8e412b5a-85ec-4c53-a5b8-dfb4d6d987b8

file format: qcow2

virtual size: 150G (161061273600 bytes)

disk size: 0

cluster_size: 65536

Format specific information:

    compat: 1.1

    lazy refcounts: false

    refcount bits: 16

    corrupt: false


Vdsm chain:


$ cat 6197b30d-0732-4cc7-aef0-12f9f6e9565b.meta

CAP=161061273600

CTIME=1594060718

DESCRIPTION=

DISKTYPE=DATA

DOMAIN=33777993-a3a5-4aad-a24c-dfe5e473faca

FORMAT=COW

GEN=0

IMAGE=d7bd480d-2c51-4141-a386-113abf75219e

LEGALITY=ILLEGAL


^^^^^^

This is the issue, the top volume is illegal.


PUUID=8e412b5a-85ec-4c53-a5b8-dfb4d6d987b8

TYPE=SPARSE

VOLTYPE=LEAF


$ cat 8e412b5a-85ec-4c53-a5b8-dfb4d6d987b8.meta

CAP=161061273600

CTIME=1587646763

DESCRIPTION={"DiskAlias":"cpslpd01_Disk1","DiskDescription":"SAP SLCM

H11 HDB D13"}

DISKTYPE=DATA

DOMAIN=33777993-a3a5-4aad-a24c-dfe5e473faca

FORMAT=COW

GEN=0

IMAGE=d7bd480d-2c51-4141-a386-113abf75219e

LEGALITY=LEGAL

PUUID=00000000-0000-0000-0000-000000000000

TYPE=SPARSE

VOLTYPE=INTERNAL


We set volume to ILLEGAL when we merge the top volume into the parent volume,

and both volumes contain the same data.


After we mark the volume as ILLEGAL, we pivot to the parent volume

(8e412b5a-85ec-4c53-a5b8-dfb4d6d987b8).


If the pivot was successful, the parent volume may have new data, and starting

the vm using the top volume may corrupt the vm filesystem. The ILLEGAL state

prevent this.


If the pivot was not successful, the vm must be started using the top

volume, but it

will always fail if the volume is ILLEGAL.


If the volume is ILLEGAL, trying to merge again when the VM is not running will

always fail, since vdsm does not if the pivot succeeded or not, and cannot merge

the volume in a safe way.


Do you have the vdsm from all merge attempts on this disk?

This is an extract of the vdsm logs, i may provide the complete log if it would help.

Yes, this is only the start of the merge. We see the success message
but this only means the merge
job was started.

Please share the complete log, and if needed the next log. The
important messages we look for are:

    Requesting pivot to complete active layer commit ...

Follow by:

    Pivot completed ...

If pivot failed, we expect to see this message:

    Pivot failed: ...

After these messages we may find very important logs that explain why
your disk was left
in an inconsistent state.
It looks like the Pivot completed successfully, see attached vdsm.log.
Is there a way to recover that VM?
Or would it be better to recover the VM from Backup?

Thanks a lot 
Arsene

Since this looks like a bug and may be useful to others, I think it is
time to file a vdsm bug,
and attach the logs to the bug.

2020-07-13 11:18:30,257+0200 INFO  (jsonrpc/5) [api.virt] START merge(drive={u'imageID': u'6c1445b3-33ac-4ec4-8e43-483d4a6da4e3', u'volumeID': u'6172a270-5f73-464d-bebd-8bf0658c1de0', u'domainID': u'a6f2625d-0f21-4d81-b98c-f545d5f86f8e', u'poolID': u'00000002-0002-0002-0002-000000000289'}, ba
seVolUUID=u'a9d5fe18-f1bd-462e-95f7-42a50e81eb11', topVolUUID=u'6172a270-5f73-464d-bebd-8bf0658c1de0', bandwidth=u'0', jobUUID=u'5059c2ce-e2a0-482d-be93-2b79e8536667') from=::ffff:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, vmId=b5534254-660f-44b1-bc83-d616c98ba0ba (api:4
8)
2020-07-13 11:18:30,271+0200 INFO  (jsonrpc/5) [vdsm.api] START getVolumeInfo(sdUUID='a6f2625d-0f21-4d81-b98c-f545d5f86f8e', spUUID='00000002-0002-0002-0002-000000000289', imgUUID='6c1445b3-33ac-4ec4-8e43-483d4a6da4e3', volUUID=u'a9d5fe18-f1bd-462e-95f7-42a50e81eb11', options=None) from=::fff
f:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, task_id=877c30b3-660c-4bfa-a215-75df8d03657e (api:48)
2020-07-13 11:18:30,281+0200 INFO  (jsonrpc/6) [api.virt] START merge(drive={u'imageID': u'b8e8b8b6-edd1-4d40-b80b-259268ff4878', u'volumeID': u'28ed1acb-9697-43bd-980b-fe4317a06f24', u'domainID': u'6b82f31b-fa2a-406b-832d-64d9666e1bcc', u'poolID': u'00000002-0002-0002-0002-000000000289'}, ba
seVolUUID=u'29f99f8d-d8a6-475a-928c-e2ffdba76d80', topVolUUID=u'28ed1acb-9697-43bd-980b-fe4317a06f24', bandwidth=u'0', jobUUID=u'241dfab0-2ef2-45a6-a22f-c7122e9fc193') from=::ffff:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, vmId=b5534254-660f-44b1-bc83-d616c98ba0ba (api:4
8)
2020-07-13 11:18:30,282+0200 INFO  (jsonrpc/7) [api.virt] START merge(drive={u'imageID': u'd7bd480d-2c51-4141-a386-113abf75219e', u'volumeID': u'6197b30d-0732-4cc7-aef0-12f9f6e9565b', u'domainID': u'33777993-a3a5-4aad-a24c-dfe5e473faca', u'poolID': u'00000002-0002-0002-0002-000000000289'}, ba
seVolUUID=u'8e412b5a-85ec-4c53-a5b8-dfb4d6d987b8', topVolUUID=u'6197b30d-0732-4cc7-aef0-12f9f6e9565b', bandwidth=u'0', jobUUID=u'720410c3-f1a0-4b25-bf26-cf40aa6b1f97') from=::ffff:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, vmId=b5534254-660f-44b1-bc83-d616c98ba0ba (api:4
8)
2020-07-13 11:18:30,299+0200 INFO  (jsonrpc/6) [vdsm.api] START getVolumeInfo(sdUUID='6b82f31b-fa2a-406b-832d-64d9666e1bcc', spUUID='00000002-0002-0002-0002-000000000289', imgUUID='b8e8b8b6-edd1-4d40-b80b-259268ff4878', volUUID=u'29f99f8d-d8a6-475a-928c-e2ffdba76d80', options=None) from=::fff
f:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, task_id=3163b275-71d5-4976-9046-c0b558a8437f (api:48)
2020-07-13 11:18:30,312+0200 INFO  (jsonrpc/7) [vdsm.api] START getVolumeInfo(sdUUID='33777993-a3a5-4aad-a24c-dfe5e473faca', spUUID='00000002-0002-0002-0002-000000000289', imgUUID='d7bd480d-2c51-4141-a386-113abf75219e', volUUID=u'8e412b5a-85ec-4c53-a5b8-dfb4d6d987b8', options=None) from=::fff
f:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, task_id=e4836371-e73a-4373-bd73-7754ecf1f3d1 (api:48)
2020-07-13 11:18:30,509+0200 INFO  (jsonrpc/6) [storage.VolumeManifest] Info request: sdUUID=6b82f31b-fa2a-406b-832d-64d9666e1bcc imgUUID=b8e8b8b6-edd1-4d40-b80b-259268ff4878 volUUID = 29f99f8d-d8a6-475a-928c-e2ffdba76d80  (volume:240)
2020-07-13 11:18:30,522+0200 INFO  (jsonrpc/5) [storage.VolumeManifest] Info request: sdUUID=a6f2625d-0f21-4d81-b98c-f545d5f86f8e imgUUID=6c1445b3-33ac-4ec4-8e43-483d4a6da4e3 volUUID = a9d5fe18-f1bd-462e-95f7-42a50e81eb11  (volume:240)
2020-07-13 11:18:30,545+0200 INFO  (jsonrpc/7) [storage.VolumeManifest] Info request: sdUUID=33777993-a3a5-4aad-a24c-dfe5e473faca imgUUID=d7bd480d-2c51-4141-a386-113abf75219e volUUID = 8e412b5a-85ec-4c53-a5b8-dfb4d6d987b8  (volume:240)
2020-07-13 11:18:30,569+0200 INFO  (jsonrpc/5) [storage.VolumeManifest] a6f2625d-0f21-4d81-b98c-f545d5f86f8e/6c1445b3-33ac-4ec4-8e43-483d4a6da4e3/a9d5fe18-f1bd-462e-95f7-42a50e81eb11 info is {'status': 'OK', 'domain': 'a6f2625d-0f21-4d81-b98c-f545d5f86f8e', 'voltype': 'INTERNAL', 'description
': '{"DiskAlias":"cpslpd01_HANADB_Disk1","DiskDescription":"SAP SLCM H11 HDB D13 data"}', 'parent': '00000000-0000-0000-0000-000000000000', 'format': 'RAW', 'generation': 0, 'image': '6c1445b3-33ac-4ec4-8e43-483d4a6da4e3', 'disktype': 'DATA', 'legality': 'LEGAL', 'mtime': '0', 'apparentsize':
 '354334801920', 'children': [], 'pool': '', 'ctime': '1587654444', 'capacity': '354334801920', 'uuid': u'a9d5fe18-f1bd-462e-95f7-42a50e81eb11', 'truesize': '354334801920', 'type': 'PREALLOCATED', 'lease': {'path': '/dev/a6f2625d-0f21-4d81-b98c-f545d5f86f8e/leases', 'owners': [], 'version': N
one, 'offset': 121634816}} (volume:279)
2020-07-13 11:18:30,569+0200 INFO  (jsonrpc/5) [vdsm.api] FINISH getVolumeInfo return={'info': {'status': 'OK', 'domain': 'a6f2625d-0f21-4d81-b98c-f545d5f86f8e', 'voltype': 'INTERNAL', 'description': '{"DiskAlias":"cpslpd01_HANADB_Disk1","DiskDescription":"SAP SLCM H11 HDB D13 data"}', 'paren
t': '00000000-0000-0000-0000-000000000000', 'format': 'RAW', 'generation': 0, 'image': '6c1445b3-33ac-4ec4-8e43-483d4a6da4e3', 'disktype': 'DATA', 'legality': 'LEGAL', 'mtime': '0', 'apparentsize': '354334801920', 'children': [], 'pool': '', 'ctime': '1587654444', 'capacity': '354334801920',
'uuid': u'a9d5fe18-f1bd-462e-95f7-42a50e81eb11', 'truesize': '354334801920', 'type': 'PREALLOCATED', 'lease': {'path': '/dev/a6f2625d-0f21-4d81-b98c-f545d5f86f8e/leases', 'owners': [], 'version': None, 'offset': 121634816}}} from=::ffff:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630
febc227, task_id=877c30b3-660c-4bfa-a215-75df8d03657e (api:54)
2020-07-13 11:18:30,571+0200 INFO  (jsonrpc/5) [vdsm.api] START getVolumeInfo(sdUUID='a6f2625d-0f21-4d81-b98c-f545d5f86f8e', spUUID='00000002-0002-0002-0002-000000000289', imgUUID='6c1445b3-33ac-4ec4-8e43-483d4a6da4e3', volUUID=u'6172a270-5f73-464d-bebd-8bf0658c1de0', options=None) from=::fff
f:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, task_id=548e96d6-e103-4344-991d-5e4f0f4cd703 (api:48)
2020-07-13 11:18:30,571+0200 INFO  (jsonrpc/5) [storage.VolumeManifest] Info request: sdUUID=a6f2625d-0f21-4d81-b98c-f545d5f86f8e imgUUID=6c1445b3-33ac-4ec4-8e43-483d4a6da4e3 volUUID = 6172a270-5f73-464d-bebd-8bf0658c1de0  (volume:240)
2020-07-13 11:18:30,585+0200 INFO  (jsonrpc/6) [storage.VolumeManifest] 6b82f31b-fa2a-406b-832d-64d9666e1bcc/b8e8b8b6-edd1-4d40-b80b-259268ff4878/29f99f8d-d8a6-475a-928c-e2ffdba76d80 info is {'status': 'OK', 'domain': '6b82f31b-fa2a-406b-832d-64d9666e1bcc', 'voltype': 'INTERNAL', 'description
': '{"DiskAlias":"cpslpd01_HANALogs_Disk1","DiskDescription":"SAP SLCM H11 HDB D13 logs"}', 'parent': '00000000-0000-0000-0000-000000000000', 'format': 'RAW', 'generation': 0, 'image': 'b8e8b8b6-edd1-4d40-b80b-259268ff4878', 'disktype': 'DATA', 'legality': 'LEGAL', 'mtime': '0', 'apparentsize
': '139586437120', 'children': [], 'pool': '', 'ctime': '1587654445', 'capacity': '139586437120', 'uuid': u'29f99f8d-d8a6-475a-928c-e2ffdba76d80', 'truesize': '139586437120', 'type': 'PREALLOCATED', 'lease': {'path': '/dev/6b82f31b-fa2a-406b-832d-64d9666e1bcc/leases', 'owners': [], 'version':
 None, 'offset': 121634816}} (volume:279)
2020-07-13 11:18:30,585+0200 INFO  (jsonrpc/6) [vdsm.api] FINISH getVolumeInfo return={'info': {'status': 'OK', 'domain': '6b82f31b-fa2a-406b-832d-64d9666e1bcc', 'voltype': 'INTERNAL', 'description': '{"DiskAlias":"cpslpd01_HANALogs_Disk1","DiskDescription":"SAP SLCM H11 HDB D13 logs"}', 'par
ent': '00000000-0000-0000-0000-000000000000', 'format': 'RAW', 'generation': 0, 'image': 'b8e8b8b6-edd1-4d40-b80b-259268ff4878', 'disktype': 'DATA', 'legality': 'LEGAL', 'mtime': '0', 'apparentsize': '139586437120', 'children': [], 'pool': '', 'ctime': '1587654445', 'capacity': '139586437120'
, 'uuid': u'29f99f8d-d8a6-475a-928c-e2ffdba76d80', 'truesize': '139586437120', 'type': 'PREALLOCATED', 'lease': {'path': '/dev/6b82f31b-fa2a-406b-832d-64d9666e1bcc/leases', 'owners': [], 'version': None, 'offset': 121634816}}} from=::ffff:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-886
30febc227, task_id=3163b275-71d5-4976-9046-c0b558a8437f (api:54)
2020-07-13 11:18:30,586+0200 INFO  (jsonrpc/6) [vdsm.api] START getVolumeInfo(sdUUID='6b82f31b-fa2a-406b-832d-64d9666e1bcc', spUUID='00000002-0002-0002-0002-000000000289', imgUUID='b8e8b8b6-edd1-4d40-b80b-259268ff4878', volUUID=u'28ed1acb-9697-43bd-980b-fe4317a06f24', options=None) from=::fff
f:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, task_id=3d7790d3-7b6d-49a0-8867-594b6c859894 (api:48)
2020-07-13 11:18:30,587+0200 INFO  (jsonrpc/6) [storage.VolumeManifest] Info request: sdUUID=6b82f31b-fa2a-406b-832d-64d9666e1bcc imgUUID=b8e8b8b6-edd1-4d40-b80b-259268ff4878 volUUID = 28ed1acb-9697-43bd-980b-fe4317a06f24  (volume:240)
2020-07-13 11:18:30,600+0200 INFO  (jsonrpc/7) [storage.VolumeManifest] 33777993-a3a5-4aad-a24c-dfe5e473faca/d7bd480d-2c51-4141-a386-113abf75219e/8e412b5a-85ec-4c53-a5b8-dfb4d6d987b8 info is {'status': 'OK', 'domain': '33777993-a3a5-4aad-a24c-dfe5e473faca', 'voltype': 'INTERNAL', 'description
': '{"DiskAlias":"cpslpd01_Disk1","DiskDescription":"SAP SLCM H11 HDB D13"}', 'parent': '00000000-0000-0000-0000-000000000000', 'format': 'COW', 'generation': 0, 'image': 'd7bd480d-2c51-4141-a386-113abf75219e', 'disktype': 'DATA', 'legality': 'LEGAL', 'mtime': '0', 'apparentsize': '4429185024
0', 'children': [], 'pool': '', 'ctime': '1587646763', 'capacity': '161061273600', 'uuid': u'8e412b5a-85ec-4c53-a5b8-dfb4d6d987b8', 'truesize': '44291850240', 'type': 'SPARSE', 'lease': {'path': '/dev/33777993-a3a5-4aad-a24c-dfe5e473faca/leases', 'owners': [], 'version': None, 'offset': 13421
7728}} (volume:279)
2020-07-13 11:18:30,600+0200 INFO  (jsonrpc/7) [vdsm.api] FINISH getVolumeInfo return={'info': {'status': 'OK', 'domain': '33777993-a3a5-4aad-a24c-dfe5e473faca', 'voltype': 'INTERNAL', 'description': '{"DiskAlias":"cpslpd01_Disk1","DiskDescription":"SAP SLCM H11 HDB D13"}', 'parent': '0000000
0-0000-0000-0000-000000000000', 'format': 'COW', 'generation': 0, 'image': 'd7bd480d-2c51-4141-a386-113abf75219e', 'disktype': 'DATA', 'legality': 'LEGAL', 'mtime': '0', 'apparentsize': '44291850240', 'children': [], 'pool': '', 'ctime': '1587646763', 'capacity': '161061273600', 'uuid': u'8e4
12b5a-85ec-4c53-a5b8-dfb4d6d987b8', 'truesize': '44291850240', 'type': 'SPARSE', 'lease': {'path': '/dev/33777993-a3a5-4aad-a24c-dfe5e473faca/leases', 'owners': [], 'version': None, 'offset': 134217728}}} from=::ffff:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, task_id=e48
36371-e73a-4373-bd73-7754ecf1f3d1 (api:54)
2020-07-13 11:18:30,601+0200 INFO  (jsonrpc/7) [vdsm.api] START getVolumeInfo(sdUUID='33777993-a3a5-4aad-a24c-dfe5e473faca', spUUID='00000002-0002-0002-0002-000000000289', imgUUID='d7bd480d-2c51-4141-a386-113abf75219e', volUUID=u'6197b30d-0732-4cc7-aef0-12f9f6e9565b', options=None) from=::fff
f:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, task_id=4fc04383-42da-4240-9783-395c1b610754 (api:48)
2020-07-13 11:18:30,602+0200 INFO  (jsonrpc/7) [storage.VolumeManifest] Info request: sdUUID=33777993-a3a5-4aad-a24c-dfe5e473faca imgUUID=d7bd480d-2c51-4141-a386-113abf75219e volUUID = 6197b30d-0732-4cc7-aef0-12f9f6e9565b  (volume:240)
2020-07-13 11:18:30,615+0200 INFO  (jsonrpc/5) [storage.VolumeManifest] a6f2625d-0f21-4d81-b98c-f545d5f86f8e/6c1445b3-33ac-4ec4-8e43-483d4a6da4e3/6172a270-5f73-464d-bebd-8bf0658c1de0 info is {'status': 'OK', 'domain': 'a6f2625d-0f21-4d81-b98c-f545d5f86f8e', 'voltype': 'LEAF', 'description': '
', 'parent': 'a9d5fe18-f1bd-462e-95f7-42a50e81eb11', 'format': 'COW', 'generation': 0, 'image': '6c1445b3-33ac-4ec4-8e43-483d4a6da4e3', 'disktype': 'DATA', 'legality': 'LEGAL', 'mtime': '0', 'apparentsize': '53687091200', 'children': [], 'pool': '', 'ctime': '1594060717', 'capacity': '3543348
01920', 'uuid': u'6172a270-5f73-464d-bebd-8bf0658c1de0', 'truesize': '53687091200', 'type': 'SPARSE', 'lease': {'path': '/dev/a6f2625d-0f21-4d81-b98c-f545d5f86f8e/leases', 'owners': [], 'version': None, 'offset': 125829120}} (volume:279)
2020-07-13 11:18:30,616+0200 INFO  (jsonrpc/5) [vdsm.api] FINISH getVolumeInfo return={'info': {'status': 'OK', 'domain': 'a6f2625d-0f21-4d81-b98c-f545d5f86f8e', 'voltype': 'LEAF', 'description': '', 'parent': 'a9d5fe18-f1bd-462e-95f7-42a50e81eb11', 'format': 'COW', 'generation': 0, 'image':
'6c1445b3-33ac-4ec4-8e43-483d4a6da4e3', 'disktype': 'DATA', 'legality': 'LEGAL', 'mtime': '0', 'apparentsize': '53687091200', 'children': [], 'pool': '', 'ctime': '1594060717', 'capacity': '354334801920', 'uuid': u'6172a270-5f73-464d-bebd-8bf0658c1de0', 'truesize': '53687091200', 'type': 'SPA
RSE', 'lease': {'path': '/dev/a6f2625d-0f21-4d81-b98c-f545d5f86f8e/leases', 'owners': [], 'version': None, 'offset': 125829120}}} from=::ffff:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, task_id=548e96d6-e103-4344-991d-5e4f0f4cd703 (api:54)
2020-07-13 11:18:30,630+0200 INFO  (jsonrpc/5) [virt.vm] (vmId='b5534254-660f-44b1-bc83-d616c98ba0ba') Starting merge with jobUUID=u'5059c2ce-e2a0-482d-be93-2b79e8536667', original chain=a9d5fe18-f1bd-462e-95f7-42a50e81eb11 < 6172a270-5f73-464d-bebd-8bf0658c1de0 (top), disk='sdb', base='sdb[1
]', top=None, bandwidth=0, flags=12 (vm:5945)
2020-07-13 11:18:30,640+0200 INFO  (jsonrpc/6) [storage.VolumeManifest] 6b82f31b-fa2a-406b-832d-64d9666e1bcc/b8e8b8b6-edd1-4d40-b80b-259268ff4878/28ed1acb-9697-43bd-980b-fe4317a06f24 info is {'status': 'OK', 'domain': '6b82f31b-fa2a-406b-832d-64d9666e1bcc', 'voltype': 'LEAF', 'description': '
', 'parent': '29f99f8d-d8a6-475a-928c-e2ffdba76d80', 'format': 'COW', 'generation': 0, 'image': 'b8e8b8b6-edd1-4d40-b80b-259268ff4878', 'disktype': 'DATA', 'legality': 'LEGAL', 'mtime': '0', 'apparentsize': '3221225472', 'children': [], 'pool': '', 'ctime': '1594060717', 'capacity': '13958643
7120', 'uuid': u'28ed1acb-9697-43bd-980b-fe4317a06f24', 'truesize': '3221225472', 'type': 'SPARSE', 'lease': {'path': '/dev/6b82f31b-fa2a-406b-832d-64d9666e1bcc/leases', 'owners': [], 'version': None, 'offset': 127926272}} (volume:279)
2020-07-13 11:18:30,640+0200 INFO  (jsonrpc/6) [vdsm.api] FINISH getVolumeInfo return={'info': {'status': 'OK', 'domain': '6b82f31b-fa2a-406b-832d-64d9666e1bcc', 'voltype': 'LEAF', 'description': '', 'parent': '29f99f8d-d8a6-475a-928c-e2ffdba76d80', 'format': 'COW', 'generation': 0, 'image':
'b8e8b8b6-edd1-4d40-b80b-259268ff4878', 'disktype': 'DATA', 'legality': 'LEGAL', 'mtime': '0', 'apparentsize': '3221225472', 'children': [], 'pool': '', 'ctime': '1594060717', 'capacity': '139586437120', 'uuid': u'28ed1acb-9697-43bd-980b-fe4317a06f24', 'truesize': '3221225472', 'type': 'SPARS
E', 'lease': {'path': '/dev/6b82f31b-fa2a-406b-832d-64d9666e1bcc/leases', 'owners': [], 'version': None, 'offset': 127926272}}} from=::ffff:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, task_id=3d7790d3-7b6d-49a0-8867-594b6c859894 (api:54)
2020-07-13 11:18:30,649+0200 INFO  (jsonrpc/7) [storage.VolumeManifest] 33777993-a3a5-4aad-a24c-dfe5e473faca/d7bd480d-2c51-4141-a386-113abf75219e/6197b30d-0732-4cc7-aef0-12f9f6e9565b info is {'status': 'OK', 'domain': '33777993-a3a5-4aad-a24c-dfe5e473faca', 'voltype': 'LEAF', 'description': '
', 'parent': '8e412b5a-85ec-4c53-a5b8-dfb4d6d987b8', 'format': 'COW', 'generation': 0, 'image': 'd7bd480d-2c51-4141-a386-113abf75219e', 'disktype': 'DATA', 'legality': 'LEGAL', 'mtime': '0', 'apparentsize': '5368709120', 'children': [], 'pool': '', 'ctime': '1594060718', 'capacity': '16106127
3600', 'uuid': u'6197b30d-0732-4cc7-aef0-12f9f6e9565b', 'truesize': '5368709120', 'type': 'SPARSE', 'lease': {'path': '/dev/33777993-a3a5-4aad-a24c-dfe5e473faca/leases', 'owners': [], 'version': None, 'offset': 165675008}} (volume:279)
2020-07-13 11:18:30,649+0200 INFO  (jsonrpc/7) [vdsm.api] FINISH getVolumeInfo return={'info': {'status': 'OK', 'domain': '33777993-a3a5-4aad-a24c-dfe5e473faca', 'voltype': 'LEAF', 'description': '', 'parent': '8e412b5a-85ec-4c53-a5b8-dfb4d6d987b8', 'format': 'COW', 'generation': 0, 'image':
'd7bd480d-2c51-4141-a386-113abf75219e', 'disktype': 'DATA', 'legality': 'LEGAL', 'mtime': '0', 'apparentsize': '5368709120', 'children': [], 'pool': '', 'ctime': '1594060718', 'capacity': '161061273600', 'uuid': u'6197b30d-0732-4cc7-aef0-12f9f6e9565b', 'truesize': '5368709120', 'type': 'SPARS
E', 'lease': {'path': '/dev/33777993-a3a5-4aad-a24c-dfe5e473faca/leases', 'owners': [], 'version': None, 'offset': 165675008}}} from=::ffff:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, task_id=4fc04383-42da-4240-9783-395c1b610754 (api:54)
2020-07-13 11:18:30,676+0200 INFO  (jsonrpc/5) [api.virt] FINISH merge return={'status': {'message': 'Done', 'code': 0}} from=::ffff:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, vmId=b5534254-660f-44b1-bc83-d616c98ba0ba (api:54)
2020-07-13 11:18:30,676+0200 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call VM.merge succeeded in 0.42 seconds (__init__:312)
2020-07-13 11:18:30,690+0200 INFO  (jsonrpc/7) [virt.vm] (vmId='b5534254-660f-44b1-bc83-d616c98ba0ba') Starting merge with jobUUID=u'720410c3-f1a0-4b25-bf26-cf40aa6b1f97', original chain=8e412b5a-85ec-4c53-a5b8-dfb4d6d987b8 < 6197b30d-0732-4cc7-aef0-12f9f6e9565b (top), disk='sda', base='sda[1]', top=None, bandwidth=0, flags=12 (vm:5945)
2020-07-13 11:18:30,716+0200 INFO  (jsonrpc/7) [vdsm.api] START sendExtendMsg(spUUID='00000002-0002-0002-0002-000000000289', volDict={'newSize': 50734301184, 'domainID': '33777993-a3a5-4aad-a24c-dfe5e473faca', 'name': 'sda', 'poolID': '00000002-0002-0002-0002-000000000289', 'clock': <Clock(total=0.00*, extend-volume=0.00*)>, 'internal': True, 'volumeID': u'8e412b5a-85ec-4c53-a5b8-dfb4d6d987b8', 'imageID': 'd7bd480d-2c51-4141-a386-113abf75219e'}, newSize=50734301184, callbackFunc=<bound method Vm.__afterVolumeExtension of <vdsm.virt.vm.Vm object at 0x7fa1e06cd890>>) from=::ffff:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, task_id=ca213f64-0223-4adb-bba9-8b704e477c40 (api:48)
2020-07-13 11:18:30,716+0200 INFO  (jsonrpc/7) [vdsm.api] FINISH sendExtendMsg return=None from=::ffff:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, task_id=ca213f64-0223-4adb-bba9-8b704e477c40 (api:54)
2020-07-13 11:18:30,740+0200 INFO  (jsonrpc/6) [virt.vm] (vmId='b5534254-660f-44b1-bc83-d616c98ba0ba') Starting merge with jobUUID=u'241dfab0-2ef2-45a6-a22f-c7122e9fc193', original chain=29f99f8d-d8a6-475a-928c-e2ffdba76d80 < 28ed1acb-9697-43bd-980b-fe4317a06f24 (top), disk='sdc', base='sdc[1]', top=None, bandwidth=0, flags=12 (vm:5945)
2020-07-13 11:18:30,752+0200 INFO  (mailbox-hsm) [storage.MailBox.HsmMailMonitor] HSM_MailMonitor sending mail to SPM - ['/usr/bin/dd', 'of=/rhev/data-center/00000002-0002-0002-0002-000000000289/mastersd/dom_md/inbox', 'iflag=fullblock', 'oflag=direct', 'conv=notrunc', 'bs=4096', 'count=1', 'seek=2'] (mailbox:380)
2020-07-13 11:18:30,808+0200 INFO  (jsonrpc/6) [api.virt] FINISH merge return={'status': {'message': 'Done', 'code': 0}} from=::ffff:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, vmId=b5534254-660f-44b1-bc83-d616c98ba0ba (api:54)
2020-07-13 11:18:30,809+0200 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call VM.merge succeeded in 0.53 seconds (__init__:312)
2020-07-13 11:18:30,817+0200 INFO  (jsonrpc/7) [api.virt] FINISH merge return={'status': {'message': 'Done', 'code': 0}} from=::ffff:10.34.38.31,39226, flow_id=4a8b9527-06a3-4be6-9bb9-88630febc227, vmId=b5534254-660f-44b1-bc83-d616c98ba0ba (api:54)


The most important log is the one showing the original merge. If the merge

succeeded, we should see a log showing the new libvirt chain, which

should contain

only the parent volume.


Nir


--

Arsène Gschwind <
arsene.gschwind@unibas.ch
>
Universitaet Basel

-- 
Arsène Gschwind
Fa. Sapify AG im Auftrag der universitaet Basel
IT Services
Klinelbergstr. 70 | CH-4056 Basel | Switzerland
Tel: +41 79 449 25 63 | http://its.unibas.ch
ITS-ServiceDesk: support-its@unibas.ch | +41 61 267 14 11