Some VMs on VMware stuck in powered off state even after actual deletion

Hello,

I’ve noticed that ManageIQ jansa-2 fails to refresh power states on some vms on VMware. Those vms remain in retiring, powered off state even after they have been deleted from vcenter. I cant found specific error messages related to the issue. Could you please suggest how to debug this issue?

Here is a evm.log with messages on provider refresh.
(Referential integrity checks violated message are related for another infrastructure provider, not one containing stuck vms).

[----] I, [2021-03-15T19:09:33.580497 #2511:2afe8ae35964] INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::RefreshWorker::Runner#restart_inventory_collector) Restarting inventory collector...

[----] I, [2021-03-15T19:10:17.192072 #2511:2afe925dfa14] INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Collector#vim_collector) EMS: [dc01], id: [1000000000006] Monitor updates thread exited

[----] I, [2021-03-15T19:10:17.208641 #2511:2afe8ae35964] INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::RefreshWorker::Runner#restart_inventory_collector) Restarting inventory collector...Complete

[----] I, [2021-03-15T19:10:17.208757 #2511:2afe92c6977c] INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Collector#vim_collector) EMS: [dc01], id: [1000000000006] Monitor updates thread started

[----] I, [2021-03-15T19:10:17.212423 #2511:2afe92c6977c] INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Collector#connect) EMS: [dc01], id: [1000000000006] Connecting to [trbs-miqvcuser@trosbank.trus.tsocgen@rsbt-istmosvc01.trosbank.trus.tsocgen](mailto:trbs-miqvcuser@trosbank.trus.tsocgen@rsbt-istmosvc01.trosbank.trus.tsocgen)...

[----] I, [2021-03-15T19:10:17.332414 #2511:2afe92c6977c] INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Collector#connect) EMS: [dc01], id: [1000000000006] Connected

[----] I, [2021-03-15T19:10:17.352271 #2511:2afe92c6977c] INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Collector#vim_collector) EMS: [dc01], id: [1000000000006] Refreshing initial inventory

[----] I, [2021-03-15T19:10:17.712563 #2511:2afe92c6977c] INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Collector#process_update_set) EMS: [dc01], id: [1000000000006] Processing 56 updates...

[----] I, [2021-03-15T19:10:17.734319 #2511:2afe92c6977c] INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Collector#process_update_set) EMS: [dc01], id: [1000000000006] Processing 56 updates...Complete

[----] I, [2021-03-15T19:10:21.316959 #2511:2afe92c6977c] INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Collector#vim_collector) EMS: [dc01], id: [1000000000006] Refreshing initial inventory...Complete

[----] I, [2021-03-15T19:10:21.995651 #2511:2afe8da77298] INFO -- : EMS: [dc01], id: [1000000000006] Saving EMS Inventory...

[----] I, [2021-03-15T19:10:22.012421 #2511:2afe8da77298] INFO -- : EMS: [dc01], id: [1000000000006] Saving EMS Inventory...Complete

[----] I, [2021-03-15T19:10:22.019125 #2511:2afe8da77298] INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Saver#post_refresh) EMS: [dc01], id: [1000000000006] Performing post-refresh operations for VmOrTemplate instances...

[----] I, [2021-03-15T19:10:22.042024 #2511:2afe8da77298] INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Saver#post_refresh) EMS: [dc01], id: [1000000000006] Performing post-refresh operations for VmOrTemplate instances...Complete

[----] I, [2021-03-15T19:10:22.056649 #2511:2afe8da77298] INFO -- : EMS: [dc01], id: [1000000000006] Saving EMS Inventory...

[----] W, [2021-03-15T19:10:22.495655 #2511:2afe8da77298] WARN -- : Referential integrity check violated, ignoring {:storage_profile_id=>1000000000008, :storage_id=>nil} of InventoryCollection:<StorageProfileStorage> because of missing foreign key storage_id for ManageIQ::Providers::Vmware::InfraManager:1000000000006

[----] W, [2021-03-15T19:10:22.495792 #2511:2afe8da77298] WARN -- : Referential integrity check violated, ignoring {:storage_profile_id=>1000000000009, :storage_id=>nil} of InventoryCollection:<StorageProfileStorage> because of missing foreign key storage_id for ManageIQ::Providers::Vmware::InfraManager:1000000000006

[----] W, [2021-03-15T19:10:22.495850 #2511:2afe8da77298] WARN -- : Referential integrity check violated, ignoring {:storage_profile_id=>1000000000010, :storage_id=>nil} of InventoryCollection:<StorageProfileStorage> because of missing foreign key storage_id for ManageIQ::Providers::Vmware::InfraManager:1000000000006

[----] W, [2021-03-15T19:10:22.495900 #2511:2afe8da77298] WARN -- : Referential integrity check violated, ignoring {:storage_profile_id=>1000000000012, :storage_id=>nil} of InventoryCollection:<StorageProfileStorage> because of missing foreign key storage_id for ManageIQ::Providers::Vmware::InfraManager:1000000000006

[----] W, [2021-03-15T19:10:22.495953 #2511:2afe8da77298] WARN -- : Referential integrity check violated, ignoring {:storage_profile_id=>1000000000014, :storage_id=>nil} of InventoryCollection:<StorageProfileStorage> because of missing foreign key storage_id for ManageIQ::Providers::Vmware::InfraManager:1000000000006

[----] I, [2021-03-15T19:10:23.008700 #2511:2afe8da77298] INFO -- : EMS: [dc01], id: [1000000000006] Saving EMS Inventory...Complete

[----] I, [2021-03-15T19:10:23.019146 #2511:2afe8da77298] INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Saver#post_refresh) EMS: [dc01], id: [1000000000006] Performing post-refresh operations for VmOrTemplate instances...

[----] I, [2021-03-15T19:10:23.046106 #2511:2afe8da77298] INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Saver#post_refresh) EMS: [dc01], id: [1000000000006] Performing post-refresh operations for VmOrTemplate instances...Complete

Here’s how it looks. This VM is deleted from vCenter, but MIQ show it as existant and switched off. I’ve switched on debug logging for vim (:level_vim: debug) but no errors there. When I refresh selected VM (Configuration → Refresh relationships and power states), I get “Dropping refresh targets because streaming refresh is enabled” in evm.log. Please help how to debug this issue.

@agrare could this be a timing issue with streaming refresh? It’s interesting (to me) that the inventory sees ‘Number of Disks’ as 0 so the VM seems to show as partly removed from the EMS, but not marked as archived.

pemcg

This actually sounds more like https://github.com/ManageIQ/manageiq-providers-vmware/pull/683 which prevented refresh from marking VMs as archived if there was an ems_event linked to it from the DestroyVM_Task. All related records (e.g. the hardware and disks) could be deleted but nothing in the vm record could be updated (e.g. clearing the ems_id or changing the power state).

As a test you could try deleting any EmsEvents with event_type = "DestroyVM_Task_Complete" associated with that VM then kick a full refresh, or upgrade to jansa-3

1 Like

After deleting those events VM became archived. Thank you very much!

1 Like