Snapshot delete (live merge) completed on the host, but fails on the engine with Null Exception Pointer.

Solution In Progress - Updated -

Environment

  • Red Hat Virtualization (RHV) 4.4.2

Issue

  • A snapshot deletion (Live Merge) failed with the following error
Failed to delete snapshot 'test' for VM 'AAAA'.

  • RHV-M UI/Webadmin reports VM has snapshot(s) with disk(s) in illegal status.

  • Cluster setting has Chipset/Firmware Type as "Cluster default"

alt text

  • VM Chipset/Firmware Type setting is set to "Cluster default"

alt text

Resolution

  • Bugzilla 1899768 was added with Engineering group addressed in RHV-M version 4.4.3.

Root Cause

  • The Live Merge completed on the host, but ovirt-engine fails with Null Exception Pointer. This is due to the OVF of the VM snapshots doesn't contain "< BiosType> < /BiosType>" parameter in the snapshot OVF configuration

  • In the 4.4.2 version, fails due to line 330

OvfVmWriter.java

328 protected void writeBiosType() {
329 BiosType effectiveBiosType = getEffectiveBiosType();
330 if (effectiveBiosType != BiosType.CLUSTER_DEFAULT) {
331 // For compatibility with oVirt 4.3, use values of BiosType constants that existed before
332 // introduction of CLUSTER_DEFAULT: 0 == I440FX_SEA_BIOS and so on
333 _writer.writeStartElement(BIOS_TYPE);
334 if (isCustomBiosType()) {
335 _writer.writeAttributeString(OVF_PREFIX, getOvfUri(), "custom", "true");
336 }
337 _writer.writeRaw(String.valueOf(effectiveBiosType.getValue() - 1));
338 _writer.writeEndElement();
339 }
340 }

  • The snapshot delete fails on the ovirt-engine side which results disk volumes being marked as illegal.

  • It is highly recommended not to restart the VM, as it may fail to start.

  • Please contact Red Hat Technical Support for assistance with resetting the illegal status. This will require modifications to the RHV database.

Diagnostic Steps

  • Per ovirt-engine RHV-M database, the VM has two disks with a snapshot image.
images:                                                                                                                                (1 = ok, 2 = locked, 4 = illegal)      (1/2 = preall/thin ; 4/5= qcow2/raw)

              image_guid              |            image_group_id            |            vm_snapshot_id            |               parentid               | imagestatus | volume_type | volume_format | active 
--------------------------------------+--------------------------------------+--------------------------------------+--------------------------------------+-------------+-------------+---------------+--------
 358fd2cf-5446-4bd6-884d-c79d925e9b4d | a9a5ceb7-82bf-4761-bc9e-0e09d3108b7d | bace2646-10f8-4217-8526-4140a150dce2 | 00000000-0000-0000-0000-000000000000 |           1 |           1 |             5 | f
 244defbb-1c46-4ac0-819a-3b461be077d8 | a9a5ceb7-82bf-4761-bc9e-0e09d3108b7d | 2838cbe1-b551-4d16-891d-c8d7f00f7610 | 358fd2cf-5446-4bd6-884d-c79d925e9b4d |           1 |           2 |             4 | t
(2 rows)

              image_guid              |            image_group_id            |            vm_snapshot_id            |               parentid               | imagestatus | volume_type | volume_format | active 
--------------------------------------+--------------------------------------+--------------------------------------+--------------------------------------+-------------+-------------+---------------+--------
 5455538c-1480-4b54-94e5-daf18dbb4a5a | 7a7e9d35-6492-4c8f-9642-344ba4696064 | bace2646-10f8-4217-8526-4140a150dce2 | 00000000-0000-0000-0000-000000000000 |           1 |           1 |             5 | f
 0d97ea6a-d500-446e-bf29-9f8dbe6afb3a | 7a7e9d35-6492-4c8f-9642-344ba4696064 | 2838cbe1-b551-4d16-891d-c8d7f00f7610 | 5455538c-1480-4b54-94e5-daf18dbb4a5a |           1 |           2 |             4 | t
(2 rows)

snapshots:
             snapshot_id              |                vm_id                 | snapshot_type | status | description |       creation_date        | memory_metadata_disk_id | memory_dump_disk_id 
--------------------------------------+--------------------------------------+---------------+--------+-------------+----------------------------+-------------------------+---------------------
 2838cbe1-b551-4d16-891d-c8d7f00f7610 | ad42acec-5d09-470e-a305-6acf234619af | ACTIVE        | OK     | Active VM   | 2020-11-19 21:33:30.528+00 |                         | 
 bace2646-10f8-4217-8526-4140a150dce2 | ad42acec-5d09-470e-a305-6acf234619af | REGULAR       | OK     | test        | 2020-11-19 21:51:23.709+00 |                         | 
(2 rows)
  • Both disk images are open and use by the VM.
  244defbb-1c46-4ac0-819a-3b461be077d8 1810c39d-bd04-4ca9-867d-c0a31a0cda26 -wi-ao----    1.00g IU_a9a5ceb7-82bf-4761-bc9e-0e09d3108b7d,MD_20,PU_358fd2cf-5446-4bd6-884d-c79d925e9b4d           
  358fd2cf-5446-4bd6-884d-c79d925e9b4d 1810c39d-bd04-4ca9-867d-c0a31a0cda26 -wi-ao----    1.00g IU_a9a5ceb7-82bf-4761-bc9e-0e09d3108b7d,MD_6,PU_00000000-0000-0000-0000-000000000000            

  0d97ea6a-d500-446e-bf29-9f8dbe6afb3a 1810c39d-bd04-4ca9-867d-c0a31a0cda26 -wi-ao----    1.00g IU_7a7e9d35-6492-4c8f-9642-344ba4696064,MD_23,PU_5455538c-1480-4b54-94e5-daf18dbb4a5a           
  5455538c-1480-4b54-94e5-daf18dbb4a5a 1810c39d-bd04-4ca9-867d-c0a31a0cda26 -wi-ao----    1.00g IU_7a7e9d35-6492-4c8f-9642-344ba4696064,MD_16,PU_00000000-0000-0000-0000-000000000000
  • Snapshot delete fails on the ovirt-engine side with the following Null Exception Pointer.
2020-11-19 21:54:43,110Z ERROR [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-90) [addad639-cb2e-49b8-9ffe-b34ad2139ab0] Failed invoking callback end method 'onSucceeded' for command '910303a8-5eda-49b4-b99e-b36a32c52afa' with exception 'null', the callback is marked for end method retries but max number of retries have been attempted. The command will be marked as Failed.
2020-11-19 21:54:43,110Z INFO  [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-90) [addad639-cb2e-49b8-9ffe-b34ad2139ab0] Exception in invoking callback of command RemoveSnapshotSingleDiskLive (910303a8-5eda-49b4-b99e-b36a32c52afa): NullPointerException: 
2020-11-19 21:54:43,110Z ERROR [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-90) [addad639-cb2e-49b8-9ffe-b34ad2139ab0] Error invoking callback method 'onSucceeded' for 'SUCCEEDED' command '910303a8-5eda-49b4-b99e-b36a32c52afa'
2020-11-19 21:54:43,110Z ERROR [org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-90) [addad639-cb2e-49b8-9ffe-b34ad2139ab0] Exception: java.lang.NullPointerException
        at org.ovirt.engine.core.utils//org.ovirt.engine.core.utils.ovf.OvfWriter.writeBiosType(OvfWriter.java:337)
        at org.ovirt.engine.core.utils//org.ovirt.engine.core.utils.ovf.OvfWriter.writeGeneralData(OvfWriter.java:309)
        at org.ovirt.engine.core.utils//org.ovirt.engine.core.utils.ovf.OvfOvirtWriter.writeGeneralData(OvfOvirtWriter.java:188)
        at org.ovirt.engine.core.utils//org.ovirt.engine.core.utils.ovf.OvfVmWriter.writeGeneralData(OvfVmWriter.java:40)
        at org.ovirt.engine.core.utils//org.ovirt.engine.core.utils.ovf.OvfWriter.buildVirtualSystem(OvfWriter.java:192)
        at org.ovirt.engine.core.utils//org.ovirt.engine.core.utils.ovf.IOvfBuilder.build(IOvfBuilder.java:34)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.utils.ovf.OvfManager.exportVm(OvfManager.java:77)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.storage.disk.image.ImagesHandler.prepareSnapshotConfigWithAlternateImage(ImagesHandler.java:803)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.storage.disk.image.ImagesHandler.prepareSnapshotConfigWithoutImageSingleImage(ImagesHandler.java:759)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskCommandBase.lambda$updateVmConfigurationForImageRemoval$2(RemoveSnapshotSingleDiskCommandBase.java:318)
        at org.ovirt.engine.core.utils//org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInNewTransaction(TransactionSupport.java:181)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskCommandBase.updateVmConfigurationForImageRemoval(RemoveSnapshotSingleDiskCommandBase.java:316)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskCommandBase.handleBackwardMerge(RemoveSnapshotSingleDiskCommandBase.java:253)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskCommandBase.lambda$syncDbRecords$0(RemoveSnapshotSingleDiskCommandBase.java:173)
        at org.ovirt.engine.core.utils//org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInNewTransaction(TransactionSupport.java:181)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskCommandBase.syncDbRecords(RemoveSnapshotSingleDiskCommandBase.java:163)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommand.onSucceeded(RemoveSnapshotSingleDiskLiveCommand.java:232)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.snapshots.RemoveSnapshotSingleDiskLiveCommandCallback.onSucceeded(RemoveSnapshotSingleDiskLiveCommandCallback.java:27)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.endCallback(CommandCallbacksPoller.java:69)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.invokeCallbackMethodsImpl(CommandCallbacksPoller.java:166)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.invokeCallbackMethods(CommandCallbacksPoller.java:109)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
        at org.glassfish.javax.enterprise.concurrent@1.0.0.redhat-1//org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.access$201(ManagedScheduledThreadPoolExecutor.java:383)
        at org.glassfish.javax.enterprise.concurrent@1.0.0.redhat-1//org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.run(ManagedScheduledThreadPoolExecutor.java:534)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:834)
        at org.glassfish.javax.enterprise.concurrent@1.0.0.redhat-1//org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread.run(ManagedThreadFactoryImpl.java:250)

2020-11-19 21:54:45,254Z ERROR [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-68) [addad639-cb2e-49b8-9ffe-b34ad2139ab0] Ending command 'org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand' with failure.
2020-11-19 21:54:45,346Z ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-68) [addad639-cb2e-49b8-9ffe-b34ad2139ab0] EVENT_ID: USER_REMOVE_SNAPSHOT_FINISHED_FAILURE(357), Failed to delete snapshot 'test' for VM 'AAAA'.
  • On the host where the VM is running, the vdsm logs show merge completed.
    The newChain only show base image for each of the disk.
2020-11-19 16:53:00,912-0500 INFO  (jsonrpc/0) [api.virt] START merge(drive={'poolID': 'adf361d4-eed4-11ea-85e4-00163e647ee7', 'volumeID': '244defbb-1c46-4ac0-819a-3b461be077d8', 'imageID': 'a9a5ceb7-82bf-4761-bc9e-0e09d3108b7d', 'domainID': '1810c39d-bd04-4ca9-867d-c0a31a0cda26'}, baseVolUUID='358fd2cf-5446-4bd6-884d-c79d925e9b4d', topVolUUID='244defbb-1c46-4ac0-819a-3b461be077d8', bandwidth='0', jobUUID='3bd7431b-d84b-41ae-981f-d938bcb8f00d') from=::ffff:10.10.182.204,36104, flow_id=addad639-cb2e-49b8-9ffe-b34ad2139ab0, vmId=ad42acec-5d09-470e-a305-6acf234619af (api:48)
2020-11-19 16:53:01,202-0500 INFO  (jsonrpc/0) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Starting merge with jobUUID='3bd7431b-d84b-41ae-981f-d938bcb8f00d', original chain=358fd2cf-5446-4bd6-884d-c79d925e9b4d < 244defbb-1c46-4ac0-819a-3b461be077d8 (top), disk='sda', base='sda[2]', top=None, bandwidth=0, flags=12 (vm:5432)
2020-11-19 16:53:01,238-0500 INFO  (libvirt/events) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Block job 3bd7431b-d84b-41ae-981f-d938bcb8f00d type ACTIVE_COMMIT for drive sda is ready (vm:5333)
2020-11-19 16:53:02,130-0500 INFO  (jsonrpc/2) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Starting cleanup thread for job: 3bd7431b-d84b-41ae-981f-d938bcb8f00d (vm:5284)
2020-11-19 16:53:02,491-0500 INFO  (merge/3bd7431b) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Requesting pivot to complete active layer commit (job 3bd7431b-d84b-41ae-981f-d938bcb8f00d) (vm:5779)
2020-11-19 16:53:02,534-0500 INFO  (libvirt/events) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Block job 3bd7431b-d84b-41ae-981f-d938bcb8f00d type ACTIVE_COMMIT for drive sda has completed (vm:5324)
2020-11-19 16:53:02,552-0500 INFO  (merge/3bd7431b) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Waiting for libvirt to update the XML after pivot of drive ua-a9a5ceb7-82bf-4761-bc9e-0e09d3108b7d completed (vm:5862)
2020-11-19 16:53:02,560-0500 INFO  (merge/3bd7431b) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') The XML update has been completed (vm:5879)
2020-11-19 16:53:02,560-0500 INFO  (merge/3bd7431b) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Pivot completed (job 3bd7431b-d84b-41ae-981f-d938bcb8f00d) (vm:5793)
2020-11-19 16:53:02,560-0500 INFO  (merge/3bd7431b) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Synchronizing volume chain after live merge (job 3bd7431b-d84b-41ae-981f-d938bcb8f00d) (vm:5827)
2020-11-19 16:53:02,568-0500 INFO  (merge/3bd7431b) [vdsm.api] START imageSyncVolumeChain(sdUUID='1810c39d-bd04-4ca9-867d-c0a31a0cda26', imgUUID='a9a5ceb7-82bf-4761-bc9e-0e09d3108b7d', volUUID='244defbb-1c46-4ac0-819a-3b461be077d8', newChain=['358fd2cf-5446-4bd6-884d-c79d925e9b4d']) from=internal, task_id=a81fa403-6a2e-4427-8d24-67269a641767 (api:48)
2020-11-19 16:53:02,786-0500 INFO  (merge/3bd7431b) [storage.Image] Current chain=358fd2cf-5446-4bd6-884d-c79d925e9b4d < 244defbb-1c46-4ac0-819a-3b461be077d8 (top)  (image:861)
2020-11-19 16:53:02,786-0500 INFO  (merge/3bd7431b) [storage.Image] Unlinking subchain: ['244defbb-1c46-4ac0-819a-3b461be077d8'] (image:871)
2020-11-19 16:53:02,807-0500 INFO  (merge/3bd7431b) [storage.Image] Leaf volume 244defbb-1c46-4ac0-819a-3b461be077d8 is being removed from the chain. Marking it ILLEGAL to prevent data corruption (image:879)
2020-11-19 16:53:02,808-0500 INFO  (merge/3bd7431b) [storage.VolumeManifest] sdUUID=1810c39d-bd04-4ca9-867d-c0a31a0cda26 imgUUID=a9a5ceb7-82bf-4761-bc9e-0e09d3108b7d volUUID = 244defbb-1c46-4ac0-819a-3b461be077d8 legality = ILLEGAL  (volume:385)
2020-11-19 16:53:02,881-0500 INFO  (merge/3bd7431b) [storage.LVM] Deactivating lvs: vg=1810c39d-bd04-4ca9-867d-c0a31a0cda26 lvs=['244defbb-1c46-4ac0-819a-3b461be077d8'] (lvm:1732)
2020-11-19 16:53:03,068-0500 INFO  (merge/3bd7431b) [storage.StorageDomainManifest] Unlinking volume runtime link: '/var/run/vdsm/storage/1810c39d-bd04-4ca9-867d-c0a31a0cda26/a9a5ceb7-82bf-4761-bc9e-0e09d3108b7d/244defbb-1c46-4ac0-819a-3b461be077d8' (blockSD:872)
2020-11-19 16:53:03,070-0500 INFO  (merge/3bd7431b) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Synchronization completed (job 3bd7431b-d84b-41ae-981f-d938bcb8f00d) (vm:5836)
2020-11-19 16:53:13,655-0500 INFO  (periodic/0) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Cleanup thread <vdsm.virt.vm.LiveMergeCleanupThread object at 0x7f73d052a5f8> successfully completed, untracking job 3bd7431b-d84b-41ae-981f-d938bcb8f00d (base=358fd2cf-5446-4bd6-884d-c79d925e9b4d, top=244defbb-1c46-4ac0-819a-3b461be077d8) (vm:5226)

2020-11-19 16:53:01,972-0500 INFO  (jsonrpc/2) [api.virt] START merge(drive={'poolID': 'adf361d4-eed4-11ea-85e4-00163e647ee7', 'volumeID': '0d97ea6a-d500-446e-bf29-9f8dbe6afb3a', 'imageID': '7a7e9d35-6492-4c8f-9642-344ba4696064', 'domainID': '1810c39d-bd04-4ca9-867d-c0a31a0cda26'}, baseVolUUID='5455538c-1480-4b54-94e5-daf18dbb4a5a', topVolUUID='0d97ea6a-d500-446e-bf29-9f8dbe6afb3a', bandwidth='0', jobUUID='462d3f6f-cc7d-4622-b770-2d2f82324ad5') from=::ffff:10.10.182.204,36104, flow_id=addad639-cb2e-49b8-9ffe-b34ad2139ab0, vmId=ad42acec-5d09-470e-a305-6acf234619af (api:48)
2020-11-19 16:53:02,100-0500 INFO  (jsonrpc/2) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Starting merge with jobUUID='462d3f6f-cc7d-4622-b770-2d2f82324ad5', original chain=5455538c-1480-4b54-94e5-daf18dbb4a5a < 0d97ea6a-d500-446e-bf29-9f8dbe6afb3a (top), disk='sdb', base='sdb[1]', top=None, bandwidth=0, flags=12 (vm:5432)
2020-11-19 16:53:02,135-0500 INFO  (libvirt/events) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Block job 462d3f6f-cc7d-4622-b770-2d2f82324ad5 type ACTIVE_COMMIT for drive sdb is ready (vm:5333)
2020-11-19 16:53:13,690-0500 INFO  (periodic/0) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Starting cleanup thread for job: 462d3f6f-cc7d-4622-b770-2d2f82324ad5 (vm:5284)
2020-11-19 16:53:14,131-0500 INFO  (merge/462d3f6f) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Requesting pivot to complete active layer commit (job 462d3f6f-cc7d-4622-b770-2d2f82324ad5) (vm:5779)
2020-11-19 16:53:14,172-0500 INFO  (libvirt/events) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Block job 462d3f6f-cc7d-4622-b770-2d2f82324ad5 type ACTIVE_COMMIT for drive sdb has completed (vm:5324)
2020-11-19 16:53:14,185-0500 INFO  (merge/462d3f6f) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Waiting for libvirt to update the XML after pivot of drive ua-7a7e9d35-6492-4c8f-9642-344ba4696064 completed (vm:5862)
2020-11-19 16:53:14,192-0500 INFO  (merge/462d3f6f) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') The XML update has been completed (vm:5879)
2020-11-19 16:53:14,192-0500 INFO  (merge/462d3f6f) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Pivot completed (job 462d3f6f-cc7d-4622-b770-2d2f82324ad5) (vm:5793)
2020-11-19 16:53:14,192-0500 INFO  (merge/462d3f6f) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Synchronizing volume chain after live merge (job 462d3f6f-cc7d-4622-b770-2d2f82324ad5) (vm:5827)
2020-11-19 16:53:14,199-0500 INFO  (merge/462d3f6f) [vdsm.api] START imageSyncVolumeChain(sdUUID='1810c39d-bd04-4ca9-867d-c0a31a0cda26', imgUUID='7a7e9d35-6492-4c8f-9642-344ba4696064', volUUID='0d97ea6a-d500-446e-bf29-9f8dbe6afb3a', newChain=['5455538c-1480-4b54-94e5-daf18dbb4a5a']) from=internal, task_id=1885b82e-f5a4-4ef8-b9bd-59ff416f4fc5 (api:48)
2020-11-19 16:53:14,420-0500 INFO  (merge/462d3f6f) [storage.Image] Current chain=5455538c-1480-4b54-94e5-daf18dbb4a5a < 0d97ea6a-d500-446e-bf29-9f8dbe6afb3a (top)  (image:861)
2020-11-19 16:53:14,420-0500 INFO  (merge/462d3f6f) [storage.Image] Unlinking subchain: ['0d97ea6a-d500-446e-bf29-9f8dbe6afb3a'] (image:871)
2020-11-19 16:53:14,441-0500 INFO  (merge/462d3f6f) [storage.Image] Leaf volume 0d97ea6a-d500-446e-bf29-9f8dbe6afb3a is being removed from the chain. Marking it ILLEGAL to prevent data corruption (image:879)
2020-11-19 16:53:14,442-0500 INFO  (merge/462d3f6f) [storage.VolumeManifest] sdUUID=1810c39d-bd04-4ca9-867d-c0a31a0cda26 imgUUID=7a7e9d35-6492-4c8f-9642-344ba4696064 volUUID = 0d97ea6a-d500-446e-bf29-9f8dbe6afb3a legality = ILLEGAL  (volume:385)
2020-11-19 16:53:14,516-0500 INFO  (merge/462d3f6f) [storage.LVM] Deactivating lvs: vg=1810c39d-bd04-4ca9-867d-c0a31a0cda26 lvs=['0d97ea6a-d500-446e-bf29-9f8dbe6afb3a'] (lvm:1732)
2020-11-19 16:53:14,676-0500 INFO  (merge/462d3f6f) [storage.StorageDomainManifest] Unlinking volume runtime link: '/var/run/vdsm/storage/1810c39d-bd04-4ca9-867d-c0a31a0cda26/7a7e9d35-6492-4c8f-9642-344ba4696064/0d97ea6a-d500-446e-bf29-9f8dbe6afb3a' (blockSD:872)
2020-11-19 16:53:14,678-0500 INFO  (merge/462d3f6f) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Synchronization completed (job 462d3f6f-cc7d-4622-b770-2d2f82324ad5) (vm:5836)
2020-11-19 16:53:28,655-0500 INFO  (periodic/2) [virt.vm] (vmId='ad42acec-5d09-470e-a305-6acf234619af') Cleanup thread <vdsm.virt.vm.LiveMergeCleanupThread object at 0x7f73d05b0710> successfully completed, untracking job 462d3f6f-cc7d-4622-b770-2d2f82324ad5 (base=5455538c-1480-4b54-94e5-daf18dbb4a5a, top=0d97ea6a-d500-446e-bf29-9f8dbe6afb3a) (vm:5226)
  • After the failure, ovirt-engine RHV-M DB shows VM disk images status with illegal status
images:                                                                                                                                                    (1 = ok, 2 = locked, 4 = illegal)      (1/2 = preall/thin ; 4/5= qcow2/raw)

              image_guid              |            image_group_id            |            vm_snapshot_id            |               parentid               | imagestatus | volume_type | volume_format | active 
--------------------------------------+--------------------------------------+--------------------------------------+--------------------------------------+-------------+-------------+---------------+--------
 358fd2cf-5446-4bd6-884d-c79d925e9b4d | a9a5ceb7-82bf-4761-bc9e-0e09d3108b7d | bace2646-10f8-4217-8526-4140a150dce2 | 00000000-0000-0000-0000-000000000000 |           4 |           1 |             5 | f
 244defbb-1c46-4ac0-819a-3b461be077d8 | a9a5ceb7-82bf-4761-bc9e-0e09d3108b7d | 2838cbe1-b551-4d16-891d-c8d7f00f7610 | 358fd2cf-5446-4bd6-884d-c79d925e9b4d |           1 |           2 |             4 | t
(2 rows)

              image_guid              |            image_group_id            |            vm_snapshot_id            |               parentid               | imagestatus | volume_type | volume_format | active 
--------------------------------------+--------------------------------------+--------------------------------------+--------------------------------------+-------------+-------------+---------------+--------
 5455538c-1480-4b54-94e5-daf18dbb4a5a | 7a7e9d35-6492-4c8f-9642-344ba4696064 | bace2646-10f8-4217-8526-4140a150dce2 | 00000000-0000-0000-0000-000000000000 |           4 |           1 |             5 | f
 0d97ea6a-d500-446e-bf29-9f8dbe6afb3a | 7a7e9d35-6492-4c8f-9642-344ba4696064 | 2838cbe1-b551-4d16-891d-c8d7f00f7610 | 5455538c-1480-4b54-94e5-daf18dbb4a5a |           1 |           2 |             4 | t
(2 rows)

snapshots:
             snapshot_id              |                vm_id                 | snapshot_type | status | description |       creation_date        | memory_metadata_disk_id | memory_dump_disk_id 
--------------------------------------+--------------------------------------+---------------+--------+-------------+----------------------------+-------------------------+---------------------
 2838cbe1-b551-4d16-891d-c8d7f00f7610 | ad42acec-5d09-470e-a305-6acf234619af | ACTIVE        | OK     | Active VM   | 2020-11-19 21:33:30.528+00 |                         | 
 bace2646-10f8-4217-8526-4140a150dce2 | ad42acec-5d09-470e-a305-6acf234619af | REGULAR       | OK     | test        | 2020-11-19 21:51:23.709+00 |                         |
  • Snapshot/leaf images are removed and only the base images exist on the storage domain.
  358fd2cf-5446-4bd6-884d-c79d925e9b4d 1810c39d-bd04-4ca9-867d-c0a31a0cda26 -wi-ao----    1.00g   IU_a9a5ceb7-82bf-4761-bc9e-0e09d3108b7d,MD_6,PU_00000000-0000-0000-0000-000000000000            
  5455538c-1480-4b54-94e5-daf18dbb4a5a 1810c39d-bd04-4ca9-867d-c0a31a0cda26 -wi-ao----    1.00g   IU_7a7e9d35-6492-4c8f-9642-344ba4696064,MD_16,PU_00000000-0000-0000-0000-000000000000

This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.

Comments