Bug 1549117

Summary: Refresh failed after performing vm_reconfiguration_task
Product: Red Hat CloudForms Management Engine Reporter: Neha Chugh <nchugh>
Component: ProvidersAssignee: Sam Lucidi <slucidi>
Status: CLOSED CURRENTRELEASE QA Contact: Jad Haj Yahya <jhajyahy>
Severity: high Docs Contact:
Priority: high    
Version: 5.9.0CC: ademicev, cpelland, gblomqui, jfrey, jhajyahy, jhardy, jocarter, maufart, mkanoor, nchugh, niroy, obarenbo, simaishi, tfitzger
Target Milestone: GAKeywords: TestOnly, ZStream
Target Release: 5.10.0   
Hardware: All   
OS: All   
Whiteboard:
Fixed In Version: 5.10.0.0 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1562785 (view as bug list) Environment:
Last Closed: 2019-02-11 14:08:50 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: Openstack Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1562785    

Description Neha Chugh 2018-02-26 12:44:13 UTC
Description of problem:
Refresh failed after performing vm_reconfiguration_task

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

Steps to Reproduce:
After performing vm_reconfiguration_task, below exception observed:


[----] I, [2018-02-21T04:50:45.230840 #16150:113f140]  INFO -- : Q-task_id([vm_cloud_reconfigure_task_81000000000006]) MIQ(ManagerRefresh::SaveInventory.save_inventory) EMS: [osp_mes], id: [81000000000003] Saving EMS Inventory...
[----] I, [2018-02-21T04:50:45.249938 #26135:113f140]  INFO -- : MIQ(MiqServer#populate_queue_messages) Fetched 1 miq_queue rows for queue_name=ems, wcount=1, priority=200
[----] E, [2018-02-21T04:50:45.405843 #16150:113f140] ERROR -- : Q-task_id([vm_cloud_reconfigure_task_81000000000006]) MIQ(ManagerRefresh::SaveCollection::Saver::Default#save!) Error when saving InventoryCollection:<ManageIQ::Providers::Openstack::NetworkManager::CloudSubnet>, whitelist: [parent_cloud_subnet, ems_ref, __feedback_edge_set_parent, __parent_inventory_collections], strategy: local_db_find_missing_references with strategy: local_db_find_missing_references, saver_strategy: default, targeted: false. Message: undefined method `split' for true:TrueClass
[----] I, [2018-02-21T04:50:45.406115 #16150:113f140]  INFO -- : Q-task_id([vm_cloud_reconfigure_task_81000000000006]) Exception in realtime_block :ems_refresh - Timings: {:collect_inventory_for_targets=>3.0143344402313232, :parse_inventory=>2.890652894973755, :parse_targeted_inventory=>2.890794038772583, :save_inventory=>0.17719125747680664, :ems_refresh=>6.082733869552612}
[----] E, [2018-02-21T04:50:45.406282 #16150:113f140] ERROR -- : Q-task_id([vm_cloud_reconfigure_task_81000000000006]) MIQ(ManageIQ::Providers::Openstack::CloudManager::Refresher#refresh) EMS: [osp_mes], id: [81000000000003] Refresh failed
[----] E, [2018-02-21T04:50:45.406594 #16150:113f140] ERROR -- : Q-task_id([vm_cloud_reconfigure_task_81000000000006]) [NoMethodError]: undefined method `split' for true:TrueClass  Method:[block in method_missing]
[----] E, [2018-02-21T04:50:45.406731 #16150:113f140] ERROR -- : Q-task_id([vm_cloud_reconfigure_task_81000000000006]) /var/www/miq/vmdb/app/models/manager_refresh/inventory_collection.rb:1085:in `block in extract_references'
/opt/rh/rh-ruby23/root/usr/share/ruby/set.rb:306:in `each_key'
/opt/rh/rh-ruby23/root/usr/share/ruby/set.rb:306:in `each'
Actual results:

Refresh failed afte performing vm_reconfiguration task
Expected results:
VM recofiguration should be done successfully.

Additional info:

 [yank] complete - access files in /cases/02039549
 [browse] the files here: http://collab-shell.usersys.redhat.com/02039549/

Comment 9 Jad Haj Yahya 2018-06-13 09:29:29 UTC
Hi,

Could you provide steps to reproduce

Thanks

Comment 10 Neha Chugh 2018-06-13 10:36:01 UTC
Jadh,

The steps to reproduce the issue is :

1. Add a openstack as cloud provider
2. Reconfigure Openstack VM by navigating to Configuration -> Reconfigure this VM and then resize the flavor of openstack instance.

vm_cloud_reconfigure_task_81000000000006 : This id generated after he trying to resize the flavor of an Openstack Instance but before confirming the resized flavor and it reaches till "raw_resize_finish" method and it keeps on retrying this method.

Also in the database record that customer have shared, the expire_on time is 2 hours ahead of created_on time but the deliver_on time is much later than its expired time:

deliver_on :  2018-02-21 09:42:58.000317
created_on:   2018-02-20 08:55:07.759269
expires_on :  2018-02-20 10:55:07.757529

Due to which ems refresh failed to perform inventory collection:

[----] E, [2018-02-21T03:29:38.187242 #6663:113f140] ERROR -- : Q-task_id([vm_cloud_reconfigure_task_81000000000006]) [NoMethodError]: undefined method `split' for true:TrueClass  Method:[block in method_missing]
[----] E, [2018-02-21T03:29:38.187355 #6663:113f140] ERROR -- : Q-task_id([vm_cloud_reconfigure_task_81000000000006]) /var/www/miq/vmdb/app/models/manager_refresh/inventory_collection.rb:1085:in `block in extract_references'


Can you please check why such behavior has been noticed? Also, there is no database dump so to provide you issue reproducer environment as customer has deleted the environment due to infrastructure space problem.

As the issue is not reproducible in the test environment, so it would be bit difficult to investigate this issue. So all we have are the logs that are shared by the customer and are accessible via collab-shell:

[yank] complete - access files in /cases/02039549
 [browse] the files here: http://collab-shell.usersys.redhat.com/02039549/

Customer is looking for the root cause behind this behavior. Any inputs would be appreciable.

Thanks and Regards,
Neha Chugh

Comment 11 Jad Haj Yahya 2018-07-02 13:45:09 UTC
Verified on 5.10.0.2