Bug 1302362
Summary: | IPv6 RabbitMQ connection shows periodic Exception in the reader loop: AMQ::Protocol::EmptyResponseError: Empty response received from the server | |||
---|---|---|---|---|
Product: | Red Hat CloudForms Management Engine | Reporter: | Marius Cornea <mcornea> | |
Component: | Providers | Assignee: | Ladislav Smola <lsmola> | |
Status: | CLOSED ERRATA | QA Contact: | Omri Hochman <ohochman> | |
Severity: | high | Docs Contact: | ||
Priority: | high | |||
Version: | 5.5.0 | CC: | cpelland, dajohnso, jfrey, jhardy, jprause, mfeifer, obarenbo | |
Target Milestone: | GA | Keywords: | ZStream | |
Target Release: | 5.6.0 | |||
Hardware: | Unspecified | |||
OS: | Unspecified | |||
Whiteboard: | openstack:event | |||
Fixed In Version: | 5.6.0.0 | Doc Type: | Bug Fix | |
Doc Text: | Story Points: | --- | ||
Clone Of: | ||||
: | 1302774 (view as bug list) | Environment: | ||
Last Closed: | 2016-06-29 15:34:04 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: | 1302774 |
Description
Marius Cornea
2016-01-27 15:42:01 UTC
This is the message seen in the rabbit log file: =WARNING REPORT==== 27-Jan-2016::12:17:44 === closing AMQP connection <0.1723.2> ([FD00:FD00:FD00:2000::15]:50374 -> [FD00:FD00:FD00:2000::15]:5672): connection_closed_abruptly Assigning to add test case After bunny update to 2.1.0 I am seeing: E, [2016-03-01T13:33:56.822777 #22647] ERROR -- #<Bunny::Session:0x1eae178 guest@2001:db8:fd00:1000::10:5672, vhost=/, hosts=[2001:db8:fd00:1000::10]>: Exception in the reader loop: AMQ::Protocol::EmptyResponseError: Empty response received from the server. E, [2016-03-01T13:33:56.822866 #22647] ERROR -- #<Bunny::Session:0x1eae178 guest@2001:db8:fd00:1000::10:5672, vhost=/, hosts=[2001:db8:fd00:1000::10]>: Backtrace: E, [2016-03-01T13:33:56.822905 #22647] ERROR -- #<Bunny::Session:0x1eae178 guest@2001:db8:fd00:1000::10:5672, vhost=/, hosts=[2001:db8:fd00:1000::10]>: /home/Ladas/.rvm/gems/ruby-2.2.3/gems/amq-protocol-2.0.1/lib/amq/protocol/frame.rb:60:in `decode_header' E, [2016-03-01T13:33:56.822943 #22647] ERROR -- #<Bunny::Session:0x1eae178 guest@2001:db8:fd00:1000::10:5672, vhost=/, hosts=[2001:db8:fd00:1000::10]>: /home/Ladas/.rvm/gems/ruby-2.2.3/gems/bunny-2.1.0/lib/bunny/transport.rb:245:in `read_next_frame' E, [2016-03-01T13:33:56.822966 #22647] ERROR -- #<Bunny::Session:0x1eae178 guest@2001:db8:fd00:1000::10:5672, vhost=/, hosts=[2001:db8:fd00:1000::10]>: /home/Ladas/.rvm/gems/ruby-2.2.3/gems/bunny-2.1.0/lib/bunny/reader_loop.rb:68:in `run_once' E, [2016-03-01T13:33:56.822988 #22647] ERROR -- #<Bunny::Session:0x1eae178 guest@2001:db8:fd00:1000::10:5672, vhost=/, hosts=[2001:db8:fd00:1000::10]>: /home/Ladas/.rvm/gems/ruby-2.2.3/gems/bunny-2.1.0/lib/bunny/reader_loop.rb:35:in `block in run_loop' E, [2016-03-01T13:33:56.823009 #22647] ERROR -- #<Bunny::Session:0x1eae178 guest@2001:db8:fd00:1000::10:5672, vhost=/, hosts=[2001:db8:fd00:1000::10]>: /home/Ladas/.rvm/gems/ruby-2.2.3/gems/bunny-2.1.0/lib/bunny/reader_loop.rb:32:in `loop' E, [2016-03-01T13:33:56.823030 #22647] ERROR -- #<Bunny::Session:0x1eae178 guest@2001:db8:fd00:1000::10:5672, vhost=/, hosts=[2001:db8:fd00:1000::10]>: /home/Ladas/.rvm/gems/ruby-2.2.3/gems/bunny-2.1.0/lib/bunny/reader_loop.rb:32:in `run_loop' W, [2016-03-01T13:33:56.823067 #22647] WARN -- #<Bunny::Session:0x1eae178 guest@2001:db8:fd00:1000::10:5672, vhost=/, hosts=[2001:db8:fd00:1000::10]>: Recovering from a network failure... W, [2016-03-01T13:34:06.824035 #22647] WARN -- #<Bunny::Session:0x1eae178 guest@2001:db8:fd00:1000::10:5672, vhost=/, hosts=[2001:db8:fd00:1000::10]>: Retrying connection on next host in line: 2001:db8:fd00:1000::10:5672 can't update to the newest bunny due to https://github.com/ruby-amqp/bunny/issues/383 New commit detected on ManageIQ/manageiq/master: https://github.com/ManageIQ/manageiq/commit/f2fb05d88ed67fe239780bb73a41b25a03597369 commit f2fb05d88ed67fe239780bb73a41b25a03597369 Author: Ladislav Smola <lsmola> AuthorDate: Tue Mar 1 15:39:28 2016 +0100 Commit: Ladislav Smola <lsmola> CommitDate: Tue Mar 1 15:39:28 2016 +0100 Make AMQP heartbeat configurable By default bunny takes the setting from the AMQP settings. If this setting is too low (like 1s) it might fail to give response in time, causing reconnect. Fixes BZ: https://bugzilla.redhat.com/show_bug.cgi?id=1302362 app/models/manageiq/providers/openstack/event_catcher_mixin.rb | 7 ++++--- config/vmdb.tmpl.yml | 2 ++ gems/pending/openstack/amqp/openstack_rabbit_event_monitor.rb | 3 ++- gems/pending/openstack/openstack_event_monitor.rb | 1 + 4 files changed, 9 insertions(+), 4 deletions(-) New commit detected on cfme/5.5.z: https://code.engineering.redhat.com/gerrit/gitweb?p=cfme.git;a=commitdiff;h=bffc540ffb6fdce4b19d42852e4dfdc09b4bdbff commit bffc540ffb6fdce4b19d42852e4dfdc09b4bdbff Author: Ladislav Smola <lsmola> AuthorDate: Tue Mar 1 15:39:28 2016 +0100 Commit: Ladislav Smola <lsmola> CommitDate: Mon Mar 7 10:53:27 2016 +0100 Make AMQP heartbeat configurable By default bunny takes the setting from the AMQP settings. If this setting is too low (like 1s) it might fail to give response in time, causing reconnect. Fixes BZ: https://bugzilla.redhat.com/show_bug.cgi?id=1302362 app/models/manageiq/providers/openstack/event_catcher_mixin.rb | 7 ++++--- config/vmdb.tmpl.yml | 2 ++ gems/pending/openstack/amqp/openstack_rabbit_event_monitor.rb | 3 ++- gems/pending/openstack/openstack_event_monitor.rb | 1 + 4 files changed, 9 insertions(+), 4 deletions(-) New commit detected on cfme/5.5.z: https://code.engineering.redhat.com/gerrit/gitweb?p=cfme.git;a=commitdiff;h=5bac7f3bb74c7fc6108fa2a5913ab67eae2b1ee4 commit 5bac7f3bb74c7fc6108fa2a5913ab67eae2b1ee4 Merge: 8171111 bffc540 Author: Greg Blomquist <gblomqui> AuthorDate: Fri Mar 11 09:40:14 2016 -0500 Commit: Greg Blomquist <gblomqui> CommitDate: Fri Mar 11 09:40:14 2016 -0500 Merge branch 'bz1302774' into '5.5.z' Make AMQP heartbeat configurable By default bunny takes the setting from the AMQP settings. If this setting is too low (like 1s) it might fail to give response in time, causing reconnect. Fixes BZ: https://bugzilla.redhat.com/show_bug.cgi?id=1302362 Clean cherry-pick of: https://github.com/ManageIQ/manageiq/pull/7027/ Fixes 5.5.z BZ https://bugzilla.redhat.com/show_bug.cgi?id=1302774 See merge request !837 app/models/manageiq/providers/openstack/event_catcher_mixin.rb | 7 ++++--- config/vmdb.tmpl.yml | 2 ++ gems/pending/openstack/amqp/openstack_rabbit_event_monitor.rb | 3 ++- gems/pending/openstack/openstack_event_monitor.rb | 1 + 4 files changed, 9 insertions(+), 4 deletions(-) The event monitor script output was clean during my testing on 5.6.0.10-rc2.1-nightly.20160613100711_27d575b [root@localhost vmdb]# rails r event_monitor_example.rb DEPRECATION WARNING: `config.serve_static_files` is deprecated and will be removed in Rails 5.1. Please use `config.public_file_server.enabled = false` instead. (called from serve_static_files= at /opt/rh/cfme-gemset/gems/railties-5.0.0.rc1/lib/rails/application/configuration.rb:80) Connected ... waiting for Openstack events saw event: #<OpenstackEvent:0x0000000387d9c8 @payload={"_context_domain"=>nil, "_context_roles"=>["admin"], "_context_quota_class"=>nil, "event_type"=>"keypair.import.start", "_context_request_id"=>"req-7aeb4053-cb1c-4535-908d-e3cc6c44efb6", "_context_service_catalog"=>[{"endpoints"=>[{"adminURL"=>"http://[fd00:fd00:fd00:2000::10]:8776/v1/652e1f2e92cd4f0483988d053c0557ff", "region"=>"regionOne", "internalURL"=>"http://[fd00:fd00:fd00:2000::10]:8776/v1/652e1f2e92cd4f0483988d053c0557ff", "publicURL"=>"http://[2001:db8:ca2:4::10]:8776/v1/652e1f2e92cd4f0483988d053c0557ff"}], "type"=>"volume", "name"=>"cinder"}, {"endpoints"=>[{"adminURL"=>"http://[fd00:fd00:fd00:2000::10]:8776/v2/652e1f2e92cd4f0483988d053c0557ff", "region"=>"regionOne", "internalURL"=>"http://[fd00:fd00:fd00:2000::10]:8776/v2/652e1f2e92cd4f0483988d053c0557ff", "publicURL"=>"http://[2001:db8:ca2:4::10]:8776/v2/652e1f2e92cd4f0483988d053c0557ff"}], "type"=>"volumev2", "name"=>"cinderv2"}], "timestamp"=>"2016-06-14 10:26:42.790442", "_context_user"=>"88c33af55c154b629bed681a72d3c26c", "_unique_id"=>"392e35ceb13246978b49339a041e5f5c", "_context_resource_uuid"=>nil, "_context_instance_lock_checked"=>false, "_context_user_id"=>"88c33af55c154b629bed681a72d3c26c", "payload"=>{"tenant_id"=>"652e1f2e92cd4f0483988d053c0557ff", "user_id"=>"88c33af55c154b629bed681a72d3c26c", "key_name"=>"userkey"}, "_context_project_name"=>"admin", "_context_read_deleted"=>"no", "_context_user_identity"=>"88c33af55c154b629bed681a72d3c26c 652e1f2e92cd4f0483988d053c0557ff - - -", "_context_auth_token"=>"206dc9b8a90d4ad294fe6ce41bd1ecb9", "_context_show_deleted"=>false, "_context_tenant"=>"652e1f2e92cd4f0483988d053c0557ff", "priority"=>"INFO", "_context_read_only"=>false, "_context_is_admin"=>true, "_context_project_id"=>"652e1f2e92cd4f0483988d053c0557ff", "_context_project_domain"=>nil, "_context_timestamp"=>"2016-06-14T10:26:42.553724", "_context_user_domain"=>nil, "_context_user_name"=>"admin", "publisher_id"=>"api.overcloud-controller-0.localdomain", "message_id"=>"e1b07c06-82a9-4eb1-92a4-f15007cac0d1", "_context_remote_address"=>"fd00:fd00:fd00:2000::13"}, @metadata={:user_id=>nil, :priority=>nil, :content_type=>nil}> saw event: #<OpenstackEvent:0x0000000386c088 @payload={"_context_domain"=>nil, "_context_roles"=>["admin"], "_context_quota_class"=>nil, "event_type"=>"keypair.import.end", "_context_request_id"=>"req-7aeb4053-cb1c-4535-908d-e3cc6c44efb6", "_context_service_catalog"=>[{"endpoints"=>[{"adminURL"=>"http://[fd00:fd00:fd00:2000::10]:8776/v1/652e1f2e92cd4f0483988d053c0557ff", "region"=>"regionOne", "internalURL"=>"http://[fd00:fd00:fd00:2000::10]:8776/v1/652e1f2e92cd4f0483988d053c0557ff", "publicURL"=>"http://[2001:db8:ca2:4::10]:8776/v1/652e1f2e92cd4f0483988d053c0557ff"}], "type"=>"volume", "name"=>"cinder"}, {"endpoints"=>[{"adminURL"=>"http://[fd00:fd00:fd00:2000::10]:8776/v2/652e1f2e92cd4f0483988d053c0557ff", "region"=>"regionOne", "internalURL"=>"http://[fd00:fd00:fd00:2000::10]:8776/v2/652e1f2e92cd4f0483988d053c0557ff", "publicURL"=>"http://[2001:db8:ca2:4::10]:8776/v2/652e1f2e92cd4f0483988d053c0557ff"}], "type"=>"volumev2", "name"=>"cinderv2"}], "timestamp"=>"2016-06-14 10:26:42.888869", "_context_user"=>"88c33af55c154b629bed681a72d3c26c", "_unique_id"=>"f271582dc6ba4dd4b9c04940a521dd3e", "_context_resource_uuid"=>nil, "_context_instance_lock_checked"=>false, "_context_user_id"=>"88c33af55c154b629bed681a72d3c26c", "payload"=>{"tenant_id"=>"652e1f2e92cd4f0483988d053c0557ff", "user_id"=>"88c33af55c154b629bed681a72d3c26c", "key_name"=>"userkey"}, "_context_project_name"=>"admin", "_context_read_deleted"=>"no", "_context_user_identity"=>"88c33af55c154b629bed681a72d3c26c 652e1f2e92cd4f0483988d053c0557ff - - -", "_context_auth_token"=>"206dc9b8a90d4ad294fe6ce41bd1ecb9", "_context_show_deleted"=>false, "_context_tenant"=>"652e1f2e92cd4f0483988d053c0557ff", "priority"=>"INFO", "_context_read_only"=>false, "_context_is_admin"=>true, "_context_project_id"=>"652e1f2e92cd4f0483988d053c0557ff", "_context_project_domain"=>nil, "_context_timestamp"=>"2016-06-14T10:26:42.553724", "_context_user_domain"=>nil, "_context_user_name"=>"admin", "publisher_id"=>"api.overcloud-controller-0.localdomain", "message_id"=>"fbe109f0-619a-48e6-81a1-1572dc9cbfd6", "_context_remote_address"=>"fd00:fd00:fd00:2000::13"}, @metadata={:user_id=>nil, :priority=>nil, :content_type=>nil}> saw event: #<OpenstackEvent:0x0000000383a290 @payload={"_context_domain"=>nil, "_context_roles"=>["admin"], "event_type"=>"network.create.start", "_context_request_id"=>"req-d866fccf-b632-479c-aef8-70b9537b8d65", "timestamp"=>"2016-06-14 10:27:27.860538", "_context_tenant_id"=>"652e1f2e92cd4f0483988d053c0557ff", "_context_user"=>"88c33af55c154b629bed681a72d3c26c", "_unique_id"=>"0ce8651aef0943b4985ea969f7462110", "_context_resource_uuid"=>nil, "_context_tenant_name"=>"admin", "_context_user_id"=>"88c33af55c154b629bed681a72d3c26c", "payload"=>{"network"=>{"router:external"=>true, "name"=>"external01", "provider:physical_network"=>"datacentre", "admin_state_up"=>true, "provider:network_type"=>"vlan", "provider:segmentation_id"=>"101"}}, "_context_project_name"=>"admin", "_context_user_identity"=>"88c33af55c154b629bed681a72d3c26c 652e1f2e92cd4f0483988d053c0557ff - - -", "_context_auth_token"=>"9a08f32b6edb4f17851b502ccc0d4715", "_context_show_deleted"=>false, "_context_tenant"=>"652e1f2e92cd4f0483988d053c0557ff", "priority"=>"INFO", "_context_read_only"=>false, "_context_is_admin"=>true, "_context_project_id"=>"652e1f2e92cd4f0483988d053c0557ff", "_context_project_domain"=>nil, "_context_timestamp"=>"2016-06-14 10:27:27.859198", "_context_user_domain"=>nil, "_context_user_name"=>"admin", "publisher_id"=>"network.overcloud-controller-0.localdomain", "message_id"=>"30528d36-6a62-44c3-9a96-f899cd350874"}, @metadata={:user_id=>nil, :priority=>nil, :content_type=>nil}> saw event: #<OpenstackEvent:0x0000000382b4c0 @payload={"_context_domain"=>nil, "_context_roles"=>["admin"], "event_type"=>"network.create.start", "_context_request_id"=>"req-d866fccf-b632-479c-aef8-70b9537b8d65", "timestamp"=>"2016-06-14 10:27:27.860538", "_context_tenant_id"=>"652e1f2e92cd4f0483988d053c0557ff", "_context_user"=>"88c33af55c154b629bed681a72d3c26c", "_unique_id"=>"606b8e8ff926479f83c9e889c7b1e5ba", "_context_resource_uuid"=>nil, "_context_tenant_name"=>"admin", "_context_user_id"=>"88c33af55c154b629bed681a72d3c26c", "payload"=>{"network"=>{"router:external"=>true, "name"=>"external01", "provider:physical_network"=>"datacentre", "admin_state_up"=>true, "provider:network_type"=>"vlan", "provider:segmentation_id"=>"101"}}, "_context_project_name"=>"admin", "_context_user_identity"=>"88c33af55c154b629bed681a72d3c26c 652e1f2e92cd4f0483988d053c0557ff - - -", "_context_auth_token"=>"9a08f32b6edb4f17851b502ccc0d4715", "_context_show_deleted"=>false, "_context_tenant"=>"652e1f2e92cd4f0483988d053c0557ff", "priority"=>"INFO", "_context_read_only"=>false, "_context_is_admin"=>true, "_context_project_id"=>"652e1f2e92cd4f0483988d053c0557ff", "_context_project_domain"=>nil, "_context_timestamp"=>"2016-06-14 10:27:27.859198", "_context_user_domain"=>nil, "_context_user_name"=>"admin", "publisher_id"=>"network.overcloud-controller-0.localdomain", "message_id"=>"30528d36-6a62-44c3-9a96-f899cd350874"}, @metadata={:user_id=>nil, :priority=>nil, :content_type=>nil}> saw event: #<OpenstackEvent:0x000000038060a8 @payload={"_context_domain"=>nil, "_context_roles"=>["admin"], "event_type"=>"network.create.end", "_context_request_id"=>"req-d866fccf-b632-479c-aef8-70b9537b8d65", "timestamp"=>"2016-06-14 10:27:27.996253", "_context_tenant_id"=>"652e1f2e92cd4f0483988d053c0557ff", "_context_user"=>"88c33af55c154b629bed681a72d3c26c", "_unique_id"=>"9dd7777884b742c5ba9a96e8e06505c6", "_context_resource_uuid"=>nil, "_context_tenant_name"=>"admin", "_context_user_id"=>"88c33af55c154b629bed681a72d3c26c", "payload"=>{"network"=>{"status"=>"ACTIVE", "subnets"=>[], "name"=>"external01", "provider:physical_network"=>"datacentre", "admin_state_up"=>true, "tenant_id"=>"652e1f2e92cd4f0483988d053c0557ff", "mtu"=>0, "router:external"=>true, "qos_policy_id"=>nil, "shared"=>false, "port_security_enabled"=>true, "provider:network_type"=>"vlan", "id"=>"8d617e0d-c0db-4383-870e-4352da8a5eb8", "provider:segmentation_id"=>101}}, "_context_project_name"=>"admin", "_context_user_identity"=>"88c33af55c154b629bed681a72d3c26c 652e1f2e92cd4f0483988d053c0557ff - - -", "_context_auth_token"=>"9a08f32b6edb4f17851b502ccc0d4715", "_context_show_deleted"=>false, "_context_tenant"=>"652e1f2e92cd4f0483988d053c0557ff", "priority"=>"INFO", "_context_read_only"=>false, "_context_is_admin"=>true, "_context_project_id"=>"652e1f2e92cd4f0483988d053c0557ff", "_context_project_domain"=>nil, "_context_timestamp"=>"2016-06-14 10:27:27.859198", "_context_user_domain"=>nil, "_context_user_name"=>"admin", "publisher_id"=>"network.overcloud-controller-0.localdomain", "message_id"=>"b66a1e7b-5a55-4090-89cb-24b4070af940"}, @metadata={:user_id=>nil, :priority=>nil, :content_type=>nil}> saw event: #<OpenstackEvent:0x000000037f6a40 @payload={"_context_domain"=>nil, "_context_roles"=>["admin"], "event_type"=>"network.create.end", "_context_request_id"=>"req-d866fccf-b632-479c-aef8-70b9537b8d65", "timestamp"=>"2016-06-14 10:27:27.996253", "_context_tenant_id"=>"652e1f2e92cd4f0483988d053c0557ff", "_context_user"=>"88c33af55c154b629bed681a72d3c26c", "_unique_id"=>"2edd7771dd684e26a80c15176759cbad", "_context_resource_uuid"=>nil, "_context_tenant_name"=>"admin", "_context_user_id"=>"88c33af55c154b629bed681a72d3c26c", "payload"=>{"network"=>{"status"=>"ACTIVE", "subnets"=>[], "name"=>"external01", "provider:physical_network"=>"datacentre", "admin_state_up"=>true, "tenant_id"=>"652e1f2e92cd4f0483988d053c0557ff", "mtu"=>0, "router:external"=>true, "qos_policy_id"=>nil, "shared"=>false, "port_security_enabled"=>true, "provider:network_type"=>"vlan", "id"=>"8d617e0d-c0db-4383-870e-4352da8a5eb8", "provider:segmentation_id"=>101}}, "_context_project_name"=>"admin", "_context_user_identity"=>"88c33af55c154b629bed681a72d3c26c 652e1f2e92cd4f0483988d053c0557ff - - -", "_context_auth_token"=>"9a08f32b6edb4f17851b502ccc0d4715", "_context_show_deleted"=>false, "_context_tenant"=>"652e1f2e92cd4f0483988d053c0557ff", "priority"=>"INFO", "_context_read_only"=>false, "_context_is_admin"=>true, "_context_project_id"=>"652e1f2e92cd4f0483988d053c0557ff", "_context_project_domain"=>nil, "_context_timestamp"=>"2016-06-14 10:27:27.859198", "_context_user_domain"=>nil, "_context_user_name"=>"admin", "publisher_id"=>"network.overcloud-controller-0.localdomain", "message_id"=>"b66a1e7b-5a55-4090-89cb-24b4070af940"}, @metadata={:user_id=>nil, :priority=>nil, :content_type=>nil}> Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHBA-2016:1348 |