Bug 1704693

Summary: evm.log is full of error messages "cannot obtain exclusive access to locked queue"
Product: Red Hat CloudForms Management Engine Reporter: Ievgen Zapolskyi <izapolsk>
Component: ProvidersAssignee: Marek Aufart <maufart>
Status: CLOSED EOL QA Contact: Sudhir Mallamprabhakara <smallamp>
Severity: low Docs Contact: Red Hat CloudForms Documentation <cloudforms-docs>
Priority: medium    
Version: 5.10.4CC: abellott, dmetzger, jfrey, jhardy, jocarter, kborole, maufart, mnadeem, mshriver, obarenbo, rspagnol, smallamp
Target Milestone: GAKeywords: Reopened, TestOnly, ZStream
Target Release: 5.12.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1765582 1767880 (view as bug list) Environment:
Last Closed: 2020-03-25 18:02:57 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: 1765582, 1767880    

Description Ievgen Zapolskyi 2019-04-30 11:13:12 UTC
Description of problem:
It happens when I add RHOS13 provider.
It seems to me that there is either issue with redundant logging or issue with lock.
 
evm.log:[----] E, [2019-04-30T06:24:33.938554 #18265:19d46fc] ERROR -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::EventCatcher::Runner#start_event_monitor) EMS [env-rhos13.cfme2.lab.eng.rdu2.redhat.com] as [admin] Event Monitor Thread aborted because [RESOURCE_LOCKED - cannot obtain exclusive access to locked queue 'miq-10.8.198.66-nova' in vhost '/']
evm.log:[----] E, [2019-04-30T06:24:33.938630 #18265:19d46fc] ERROR -- : [Bunny::ResourceLocked]: RESOURCE_LOCKED - cannot obtain exclusive access to locked queue 'miq-10.8.198.66-nova' in vhost '/'  Method:[block (2 levels) in <class:LogProxy>]
evm.log:[----] E, [2019-04-30T06:24:33.938704 #18265:19d46fc] ERROR -- : /opt/rh/cfme-gemset/gems/bunny-2.1.0/lib/bunny/channel.rb:1946:in `raise_if_continuation_resulted_in_a_channel_error!'


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

How reproducible:
100%

Steps to Reproduce:
1. Add RHOS 13 provider 
2. check evm.log for messages like above
3.

Actual results:
evm.log is full of such messages

Expected results:
no such messages or limited number of them if it is expected

Comment 2 Ievgen Zapolskyi 2019-04-30 11:29:56 UTC
according to full log, it looks like that queue is just absent.

full log:
[----] E, [2019-04-30T07:27:05.192945 #18265:5391660] ERROR -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::EventCatcher::Runner#start_event_monitor) EMS [env-rhos13.cfme2.lab.eng.rdu2.redhat.com] as [admin] Event Monitor Thread aborted because [RESOURCE_LOCKED - cannot obtain exclusive access to locked queue 'miq-10.8.198.66-nova' in vhost '/']
[----] E, [2019-04-30T07:27:05.193084 #18265:5391660] ERROR -- : [Bunny::ResourceLocked]: RESOURCE_LOCKED - cannot obtain exclusive access to locked queue 'miq-10.8.198.66-nova' in vhost '/'  Method:[block (2 levels) in <class:LogProxy>]
[----] E, [2019-04-30T07:27:05.193162 #18265:5391660] ERROR -- : /opt/rh/cfme-gemset/gems/bunny-2.1.0/lib/bunny/channel.rb:1946:in `raise_if_continuation_resulted_in_a_channel_error!'
/opt/rh/cfme-gemset/gems/bunny-2.1.0/lib/bunny/channel.rb:1020:in `queue_declare'
/opt/rh/cfme-gemset/gems/bunny-2.1.0/lib/bunny/queue.rb:371:in `declare!'
/opt/rh/cfme-gemset/gems/bunny-2.1.0/lib/bunny/queue.rb:52:in `initialize'
/opt/rh/cfme-gemset/gems/bunny-2.1.0/lib/bunny/channel.rb:410:in `new'
/opt/rh/cfme-gemset/gems/bunny-2.1.0/lib/bunny/channel.rb:410:in `queue'
/opt/rh/cfme-gemset/gems/bunny-2.1.0/lib/bunny/session.rb:439:in `queue_exists?'
/opt/rh/cfme-gemset/bundler/gems/cfme-providers-openstack-89747aa4890f/lib/manageiq/providers/openstack/legacy/events/openstack_rabbit_event_monitor.rb:148:in `block in remove_legacy_queues'
/opt/rh/cfme-gemset/bundler/gems/cfme-providers-openstack-89747aa4890f/lib/manageiq/providers/openstack/legacy/events/openstack_rabbit_event_monitor.rb:146:in `each'
/opt/rh/cfme-gemset/bundler/gems/cfme-providers-openstack-89747aa4890f/lib/manageiq/providers/openstack/legacy/events/openstack_rabbit_event_monitor.rb:146:in `remove_legacy_queues'
/opt/rh/cfme-gemset/bundler/gems/cfme-providers-openstack-89747aa4890f/lib/manageiq/providers/openstack/legacy/events/openstack_rabbit_event_monitor.rb:108:in `initialize_queues'
/opt/rh/cfme-gemset/bundler/gems/cfme-providers-openstack-89747aa4890f/lib/manageiq/providers/openstack/legacy/events/openstack_rabbit_event_monitor.rb:78:in `start'
/opt/rh/cfme-gemset/bundler/gems/cfme-providers-openstack-89747aa4890f/app/models/manageiq/providers/openstack/event_catcher_mixin.rb:38:in `monitor_events'
/var/www/miq/vmdb/app/models/manageiq/providers/base_manager/event_catcher/runner.rb:161:in `block in start_event_monitor'
[----] I, [2019-04-30T07:27:05.193324 #18265:1074f58]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager::EventCatcher::Runner#start_event_monitor) EMS [env-rhos13.cfme2.lab.eng.rdu2.redhat.com] as [admin] Started Event Monitor Thread

Comment 4 Marek Aufart 2019-05-09 07:12:17 UTC
I'm not sure if this is a bug, let me explain.

Event monitor can be Ceilomter/Panko or AMQP. AMQP is deprecated for some time, but it haven't been removed due to users who use use it. With recommended Panko, this issue should not appear. Event monitor tries to reconnect after 20s if it has failed which is correct. The error message logged just reports that failure from OSP side. So reporting looks correct to me.

If AMQP is required in this case, I'd suggest check OpenStack deployment if AMQP works as expected. Not working vhost can be changed in CF settings https://github.com/ManageIQ/manageiq-providers-openstack/blob/master/config/settings.yml#L144

Comment 16 CFME Bot 2019-10-24 14:47:35 UTC
New commit detected on ManageIQ/manageiq-providers-openstack/master:

https://github.com/ManageIQ/manageiq-providers-openstack/commit/b8d21fc1528fa35c98e3942430488d3536cf7442
commit b8d21fc1528fa35c98e3942430488d3536cf7442
Author:     Marek Aufart <maufart>
AuthorDate: Thu Oct 24 03:35:01 2019 -0400
Commit:     Marek Aufart <maufart>
CommitDate: Thu Oct 24 03:35:01 2019 -0400

    Fix unique client IDs for AMQP event monitor

    AMQP event monitor is deprecated, but there was issue with client unique
    identification when multiple EMS are used (cloud/netowrk/storage). Fixing
    client uniqueness by adding ems_id.

    Fixes: https://bugzilla.redhat.com/show_bug.cgi?id=1704693

 lib/manageiq/providers/openstack/legacy/events/openstack_rabbit_event_monitor.rb | 5 +-
 1 file changed, 3 insertions(+), 2 deletions(-)

Comment 19 Sudhir Mallamprabhakara 2019-11-12 03:49:19 UTC
Changing the test coverage to + as we have the test coverage covered in the cloned BZ 1765582