search

ManageIQ / manageiq-providers-vmware

ManageIQ plugin for the VMware vSphere and vCloud providers.
Apache License 2.0
22 stars 70 forks source link

VMware customization specifications not detected in Jansa-2 #674

Closed phospi closed 3 years ago

phospi commented 3 years ago

I tested jansa-2 release and found the same problem as described in #611 which should have been fixed with #614 - customization specifications are not detected in the vmware provider.

steps to reproduce:

add new vsphere provider with permission to read/modify customization specification run Refresh Relationships and Power States, wait until inventory completes try Provision VMs from Template and choose "Customize -> Specification" in dialog there is no any Custom Specifications in list reproducibility: always

Jansa-2 details:

vSphere details:

agrare commented 3 years ago

@phospi after refresh do you have any CustomizationSpecs in your database?

# cd /var/www/miq/vmdb
# rails c
>> CustomizationSpec.count
   (1.2ms)  SELECT COUNT(*) FROM "customization_specs"
=> 1
phospi commented 3 years ago

@agrare CustomizationSpec.count is 0.

However, there is a vmware provider configured and the configured user is able to read the existing customization specs in vmware.

svinopterix commented 3 years ago

@agrare Same issue on vCenter 6.5.0 build 15259038 ESXi 6.5.0 build 17167537

CustomizationSpec.count is 0

agrare commented 3 years ago

Very strange, I just deployed a jansa-2 appliance and it is successfully pulling CustomizationSpecs from 6.7 and 6.5 vCenters. Can you turn on debug logging and then run a full refresh then upload the evm.log for the refresh worker for that vCenter?

# ps aux | grep 'Vmware::InfraManager::RefreshWorker'
root      180083  8.1  6.0 576120 358092 ?       SNl  08:37   0:23 MIQ: Vmware::InfraManager::RefreshWorker id: 32, queue: ems_5
grep '#180083' log/evm.log > vmware_refresh.log

For example I see the customization spec manager in the collector:

[----] I, [2020-12-09T08:38:07.501260 #180083:2ad65ca62108]  INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Collector#vim_collector) EMS: [dev-vc65], id: [5] Refreshing initial inventory
[----] I, [2020-12-09T08:38:10.843071 #180083:2ad65ca62108]  INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Collector#process_update_set) EMS: [dev-vc65], id: [5] Processing 100 updates...
[----] D, [2020-12-09T08:38:10.843207 #180083:2ad65ca62108] DEBUG -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Collector#log_object_update) EMS: [dev-vc65], id: [5] Object: [CustomizationSpecManager:CustomizationSpecManager] Kind: [enter]

And later on saving the 2 customization specs from this vSphere:

[----] D, [2020-12-09T08:38:17.121792 #180083:2ad65ca68760] DEBUG -- : Saving manager dev-vc65 | Layer 0
[----] D, [2020-12-09T08:38:17.121845 #180083:2ad65ca68760] DEBUG -- : ----- BEGIN ----- Saving collection InventoryCollection:<CustomizationSpec> of size 2 to the database, for the manager: 'dev-vc65'...
[----] D, [2020-12-09T08:38:17.286333 #180083:2ad65ca68760] DEBUG -- : Processing InventoryCollection:<CustomizationSpec> of size 2...
[----] D, [2020-12-09T08:38:17.437604 #180083:2ad65ca68760] DEBUG -- : Processing InventoryCollection:<CustomizationSpec>, created=2, updated=0, deleted=0...Complete
[----] D, [2020-12-09T08:38:17.437693 #180083:2ad65ca68760] DEBUG -- : ----- END ----- Saving collection InventoryCollection:<CustomizationSpec>, for the manager: 'dev-vc65'...Complete

If you see the CustomizationSpecManager in the collector but still see 0 specs being saved I'm expecting to see a warning similar to this in the logs: "Failed to get customization spec for [name]: error"

If you don't see that we're going to have to start adding some additional debug logging to try to figure out what is happening.

phospi commented 3 years ago

Got this error, which seems to break the RefreshWorker:

[----] E, [2020-12-09T19:20:32.173557 #1004381:2af33772847c] ERROR -- : [RuntimeError]: Missing parser for OpaqueNetwork  Method:[block (2 levels) in <class:LogProxy>]
[----] E, [2020-12-09T19:20:32.173626 #1004381:2af33772847c] ERROR -- : /opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-70f087a9f7bf/app/models/manageiq/providers/vmware/infra_manager/inventory/parser.rb:25:in 'parse'
[----] E, [2020-12-09T19:20:32.173710 #1004381:2af33772847c] ERROR -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Collector#vim_collector) EMS: [TSTDEKARLSVC901_2], id: [21000000000407] Refresh failed
[----] E, [2020-12-09T19:20:32.173776 #1004381:2af33772847c] ERROR -- : [RuntimeError]: Missing parser for OpaqueNetwork  Method:[block (2 levels) in <class:LogProxy>]
[----] E, [2020-12-09T19:20:32.173823 #1004381:2af33772847c] ERROR -- : /opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-70f087a9f7bf/app/models/manageiq/providers/vmware/infra_manager/inventory/parser.rb:25:in 'parse'
[----] E, [2020-12-09T19:29:24.462082 #1004381:2af334ae63b4] ERROR -- : /opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-70f087a9f7bf/app/models/manageiq/providers/vmware/infra_manager/inventory/parser.rb:25:in `parse'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-70f087a9f7bf/app/models/manageiq/providers/vmware/infra_manager/inventory/collector.rb:197:in `block in parse_updates'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-70f087a9f7bf/app/models/manageiq/providers/vmware/infra_manager/inventory/collector.rb:189:in `each'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-70f087a9f7bf/app/models/manageiq/providers/vmware/infra_manager/inventory/collector.rb:189:in `parse_updates'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-70f087a9f7bf/app/models/manageiq/providers/vmware/infra_manager/inventory/collector.rb:87:in `full_refresh'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-70f087a9f7bf/app/models/manageiq/providers/vmware/infra_manager/inventory/collector.rb:63:in `vim_collector'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-70f087a9f7bf/app/models/manageiq/providers/vmware/infra_manager/inventory/collector.rb:53:in `block in vim_collector_thread'
[----] E, [2020-12-09T19:29:24.462163 #1004381:2af334ae63b4] ERROR -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Inventory::Collector#vim_collector) EMS: [TSTDEKARLSVC901_2], id: [21000000000407] Refresh failed
[----] E, [2020-12-09T19:29:24.462226 #1004381:2af334ae63b4] ERROR -- : [RuntimeError]: Missing parser for OpaqueNetwork  Method:[block (2 levels) in <class:LogProxy>]
[----] E, [2020-12-09T19:29:24.462268 #1004381:2af334ae63b4] ERROR -- : /opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-70f087a9f7bf/app/models/manageiq/providers/vmware/infra_manager/inventory/parser.rb:25:in `parse'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-70f087a9f7bf/app/models/manageiq/providers/vmware/infra_manager/inventory/collector.rb:197:in `block in parse_updates'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-70f087a9f7bf/app/models/manageiq/providers/vmware/infra_manager/inventory/collector.rb:189:in `each'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-70f087a9f7bf/app/models/manageiq/providers/vmware/infra_manager/inventory/collector.rb:189:in `parse_updates'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-70f087a9f7bf/app/models/manageiq/providers/vmware/infra_manager/inventory/collector.rb:87:in `full_refresh'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-70f087a9f7bf/app/models/manageiq/providers/vmware/infra_manager/inventory/collector.rb:63:in `vim_collector'
/opt/manageiq/manageiq-gemset/bundler/gems/manageiq-providers-vmware-70f087a9f7bf/app/models/manageiq/providers/vmware/infra_manager/inventory/collector.rb:53:in `block in vim_collector_thread'
agrare commented 3 years ago

That was fixed by https://github.com/ManageIQ/manageiq-providers-vmware/pull/578 it was backported to jansa but isn't in the jansa-2 tag

phospi commented 3 years ago

@agrare Now I find this message. And it's the only kind of message I get when grepping customi.

[root@server005 vmdb]# grep -i customi vmware_refresh_1.log
[----] D, [2020-12-10T03:39:08.299499 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:39:13.478148 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:39:33.853368 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:39:39.221726 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:39:39.410935 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:39:39.703207 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:39:44.937806 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:40:10.174416 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:40:10.280743 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:40:15.505410 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:40:15.658401 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:40:45.792520 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:40:45.916290 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:41:06.059084 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:41:11.418512 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:41:11.755904 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:41:12.017363 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:41:17.304614 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.
[----] D, [2020-12-10T03:41:37.441398 #1008510:2ac98b6c83cc] DEBUG -- : Skipping InventoryCollection:<CustomizationSpec>, strategy: local_db_find_missing_references processing because it will do no operation.

Nevermind CustomizationSpec.count is now 2, as expected.

svinopterix commented 3 years ago

@agrare could you please provide more detailed instructions for this: "Can you turn on debug logging and then run a full refresh then upload the evm.log for the refresh worker for that vCenter?"

Now I see that power state of on of the VMs isn't refreshed correctly (its still Powered Off in MIQ while an actual VM is already deleted). May it be related to RefreshWorker?

agrare commented 3 years ago

Hey @svinopterix sure which part do you need help with? You can set the log level in the general configuration UI https://www.manageiq.org/docs/reference/latest/general_configuration/ A full refresh can be initiated by restarting the server or initiating "Configuration -> Refresh relationships and power states" on your vsphere provider. The evm.log is located at /var/www/miq/vmdb/log/evm.log on the appliance

agrare commented 3 years ago

@phospi thanks for updating the issue! So it seems that your refreshes were failing due to that parser bug. Thanks for the bug report.