Note: This is a beta release of Red Hat Bugzilla 5.0. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Also email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback here.
Bug 1519635 - Refresh failed for OpenStack 10
Summary: Refresh failed for OpenStack 10
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: Red Hat CloudForms Management Engine
Classification: Red Hat
Component: Appliance
Version: 5.8.0
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: GA
: 5.9.0
Assignee: Marek Aufart
QA Contact: Ola Pavlenko
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-12-01 04:58 UTC by Chen
Modified: 2017-12-05 15:17 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-12-05 12:23:57 UTC
Category: ---
Cloudforms Team: Openstack


Attachments (Terms of Use)

Description Chen 2017-12-01 04:58:44 UTC
Description of problem:

Swift and Cinder providers failed to refresh

<Snip of the trace>

[----] I, [2017-11-30T05:01:00.329287 #17252:ef1140]  INFO -- : MIQ(ManageIQ::Providers::StorageManager::SwiftManager::Refresher#refresh) Refreshing all targets...
[----] I, [2017-11-30T05:01:00.329412 #17252:ef1140]  INFO -- : MIQ(ManageIQ::Providers::StorageManager::SwiftManager::Refresher#refresh) EMS: [PIC-OSP Swift Manager], id: [246000000000007] Refreshing targets for EMS...
[----] I, [2017-11-30T05:01:00.329486 #17252:ef1140]  INFO -- : MIQ(ManageIQ::Providers::StorageManager::SwiftManager::Refresher#refresh) EMS: [PIC-OSP Swift Manager], id: [246000000000007]   ManageIQ::Providers::StorageManager::SwiftManager [PIC-OSP Swift Manager] id [246000000000007]
[----] I, [2017-11-30T05:01:00.332140 #17252:ef1140]  INFO -- : MIQ(ManageIQ::Providers::StorageManager::SwiftManager::Refresher#refresh_targets_for_ems) EMS: [PIC-OSP Swift Manager], id: [246000000000007] Refreshing target ManageIQ::Providers::StorageManager::SwiftManager [PIC-OSP Swift Manager] id [246000000000007]...
/opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/dependencies.rb:512:in `load_missing_constant': Unable to autoload constant ManageIQ::Providers::CloudManager::RefreshParser, expected /var/www/miq/vmdb/app/models/manageiq/providers/cloud_manager/refresh_parser.rb to define it (LoadError)
        from /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/dependencies.rb:203:in `const_missing'
        from /var/www/miq/vmdb/app/models/manageiq/providers/cloud_manager/refresh_parser.rb:4:in `<module:Providers>'
        from /var/www/miq/vmdb/app/models/manageiq/providers/cloud_manager/refresh_parser.rb:3:in `<top (required)>'
        from /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/dependencies.rb:293:in `require'
        from /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/dependencies.rb:293:in `block in require'
        from /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/dependencies.rb:259:in `load_dependency'
        from /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/dependencies.rb:293:in `require'
        from /var/www/miq/vmdb/app/models/manageiq/providers/storage_manager/swift_manager/refresh_parser.rb:2:in `<module:Providers>'
        from /var/www/miq/vmdb/app/models/manageiq/providers/storage_manager/swift_manager/refresh_parser.rb:1:in `<top (required)>'



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

5.8.2.3
multiple appliances with 1 UI 1 worker and 1 DB

How reproducible:

100% at customer's environment

Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:

Logs can be found in collab-shell.usersys.redhat.com:/cases/01981964/20171130_pic.log.tar

Comment 2 Chen 2017-12-01 09:02:44 UTC
Hi,

We removed the Cinder and Swift storage provider from the UI but the refresh still failed. I found this time CloudManager also encountered this trace.

[----] I, [2017-12-01T15:44:57.896597 #18426:ef1140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::Refresher#refresh) Refreshing all targets...
[----] I, [2017-12-01T15:44:57.896740 #18426:ef1140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::Refresher#refresh) EMS: [PIC-OSP], id: [246000000000008] Refreshing targets for EMS...
[----] I, [2017-12-01T15:44:57.896837 #18426:ef1140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::Refresher#refresh) EMS: [PIC-OSP], id: [246000000000008]   ManageIQ::Providers::Openstack::CloudManager [PIC-OSP] id [246000000000008]
[----] I, [2017-12-01T15:44:57.899679 #18426:ef1140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::Refresher#refresh_targets_for_ems) EMS: [PIC-OSP], id: [246000000000008] Refreshing target ManageIQ::Providers::Openstack::CloudManager [PIC-OSP] id [246000000000008]...
/opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/dependencies.rb:512:in `load_missing_constant': Unable to autoload constant ManageIQ::Providers::CloudManager::RefreshParser, expected /var/www/miq/vmdb/app/models/manageiq/providers/cloud_manager/refresh_parser.rb to define it (LoadError)
        from /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/dependencies.rb:203:in `const_missing'
        from /var/www/miq/vmdb/app/models/manageiq/providers/cloud_manager/refresh_parser.rb:4:in `<module:Providers>'
        from /var/www/miq/vmdb/app/models/manageiq/providers/cloud_manager/refresh_parser.rb:3:in `<top (required)>'
        from /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/dependencies.rb:293:in `require'
        from /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/dependencies.rb:293:in `block in require'
        from /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/dependencies.rb:259:in `load_dependency'
        from /opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/dependencies.rb:293:in `require'
        from /var/www/miq/vmdb/app/models/manageiq/providers/openstack/cloud_manager/refresh_parser.rb:4:in `<module:Providers>'

The CloudManager is in a loop to refresh but never succeeded.

[----] I, [2017-12-01T16:22:39.765918 #22258:ef1140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::Refresher#refresh) Refreshing all targets...
[----] I, [2017-12-01T16:23:12.494608 #22321:ef1140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::Refresher#refresh) Refreshing all targets...
[----] I, [2017-12-01T16:23:45.232340 #22363:ef1140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::Refresher#refresh) Refreshing all targets...
[----] I, [2017-12-01T16:24:18.001816 #22437:ef1140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::Refresher#refresh) Refreshing all targets...
[----] I, [2017-12-01T16:24:51.032452 #22480:ef1140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::Refresher#refresh) Refreshing all targets...
[----] I, [2017-12-01T16:25:23.756653 #22542:ef1140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::Refresher#refresh) Refreshing all targets...
[----] I, [2017-12-01T16:25:56.467294 #22586:ef1140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::Refresher#refresh) Refreshing all targets...
[----] I, [2017-12-01T16:26:29.315344 #22675:ef1140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::Refresher#refresh) Refreshing all targets...
[----] I, [2017-12-01T16:27:01.896811 #22732:ef1140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::Refresher#refresh) Refreshing all targets...
[----] I, [2017-12-01T16:27:34.516875 #22791:ef1140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::Refresher#refresh) Refreshing all targets...

Apart from this, I can see Refresh worker was destroyed again and again.

[----] I, [2017-12-01T16:24:40.517221 #1596:ef1140]  INFO -- : MIQ(MiqServer#clean_worker_records) SQL Record for Worker [ManageIQ::Providers::Openstack::CloudManager::RefreshWorker] with ID: [246000000041717], PID: [22437], GUID: [ff1e3216-d670-11e7-90d8-fa163e9d4c05], Status: [aborted] is being deleted
[----] W, [2017-12-01T16:24:40.522482 #1596:ef1140]  WARN -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::RefreshWorker#log_destroy_of_worker_messages) Destroying: Message id: [246000000365436], MiqWorker id: [246000000041717], Zone: [PIC-OSP], Role: [ems_inventory], Server: [], Ident: [ems_246000000000008], Target id: [], Instance id: [], Task id: [], Command: [EmsRefresh.refresh], Timeout: [7200], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [[["ManageIQ::Providers::Openstack::CloudManager", 246000000000008]]]

Was that because the "kill algorithm" was called to kill Refresh worker ?

[----] D, [2017-12-01T16:25:13.387109 #1596:ef1140] DEBUG -- : MIQ(MiqServer#invoke_algorithm) Invoke algorithm started with options: [{:name=>:used_swap_percent_gt_value, :value=>80, :type=>:kill}]
[----] D, [2017-12-01T16:25:13.387212 #1596:ef1140] DEBUG -- : MIQ(MiqServer#invoke_algorithm) Executing [kill] algorithm: [used_swap_percent_gt_value]
[----] D, [2017-12-01T16:25:13.387603 #1596:ef1140] DEBUG -- : MIQ(MiqServer#invoke_algorithm) Executing [kill] algorithm: [used_swap_percent_gt_value] completed with result: [false]

Best Regards,
Chen

Comment 5 Gregg Tanzillo 2017-12-01 11:33:42 UTC
This issue is not related to the "kill algorithm" processing. If you look at that message it returns "false"

[----] D, [2017-12-01T16:25:13.387603 #1596:ef1140] DEBUG -- : MIQ(MiqServer#invoke_algorithm) Executing [kill] algorithm: [used_swap_percent_gt_value] completed with result: [false]

Meaning that swap percent was not exceeded and no action taken. I looked at the top_output and did not see any swap being used in any of the logs. Things look healthy from a resource perspective.

The issue is the "load_missing_constant" error as you pointed out -

[----] I, [2017-11-30T03:12:59.220948 #31134:ef1140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::Refresher#refresh_targets_for_ems) EMS: [PIC-OSP], id: [246000000000008] Refreshing target ManageIQ::Providers::Openstack::CloudManager [PIC-OSP] id [246000000000008]...
/opt/rh/cfme-gemset/gems/activesupport-5.0.3/lib/active_support/dependencies.rb:512:in `load_missing_constant': Unable to autoload constant ManageIQ::Providers::CloudManager::RefreshParser, expected /var/www/miq/vmdb/app/models/manageiq/providers/cloud_manager/refresh_parser.rb to define it (LoadError)

It seems that every time a refresh is started it hits that error. The error causes the worker process to exit which is detected by the server process -

[----] W, [2017-11-30T03:13:04.614587 #1596:ef1140]  WARN -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::RefreshWorker#status_update) No such process [Refresh Worker for Providers: PIC-OSP] with PID=[31134], aborting worker.
[----] I, [2017-11-30T03:13:22.212685 #1596:ef1140]  INFO -- : MIQ(MiqServer#clean_worker_records) SQL Record for Worker [ManageIQ::Providers::Openstack::CloudManager::RefreshWorker] with ID: [246000000025987], PID: [31134], GUID: [4904c19e-d539-11e7-90d8-fa163e9d4c05], Status: [aborted] is being deleted

The then server starts a new refresh worker and the cycle repeats.

I think we need to have someone on the providers team look at this issue further

Comment 8 Chen 2017-12-04 08:41:37 UTC
Hi Ladislav,

Thank you for your help.

>For the CLI, please test this with the failing project 'pj-p10180306', 
> as stated in the exception:
>Unable to obtain collection: 'stacks' in service: 'orchestration' using 
>project scope: 'pj-p10180306' in provider: '172.22.37.22'

I noticed that project as well. Could you please let me know how can I specify the project ID when "heat stack-list" ?

Best Regards,
Chen


Note You need to log in before you can comment on or make changes to this bug.