yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1489921] [NEW] Nova connects to rabbitmq successfully but has invalid credentials

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Tyler Bishop <tyler.bishop@xxxxxxxxxxxxxxxxx>
Date: Fri, 28 Aug 2015 14:56:46 -0000
Reply-to: Bug 1489921 <1489921@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

>From rabbitmq log:

=INFO REPORT==== 28-Aug-2015::10:54:20 ===
accepting AMQP connection <0.15664.0> (10.0.2.26:55772 -> 10.0.2.8:5672)

=INFO REPORT==== 28-Aug-2015::10:54:20 ===
Mirrored queue 'q-agent-notifier-security_group-update_fanout_c8d714e02b944c7f91dad2530a34ff01' in vhost '/': Adding mirror on node 'rabbit@os-controller-1003': <7448.19519.0>

=INFO REPORT==== 28-Aug-2015::10:54:20 ===
Mirrored queue 'q-agent-notifier-dvr-update_fanout_87fb0fc8e8224ffb88ea91ee20ad8e29' in vhost '/': Adding mirror on node 'rabbit@os-controller-1002': <7447.3416.0>

=INFO REPORT==== 28-Aug-2015::10:54:20 ===
Mirrored queue 'q-agent-notifier-dvr-update_fanout_87fb0fc8e8224ffb88ea91ee20ad8e29' in vhost '/': Adding mirror on node 'rabbit@os-controller-1003': <7448.19521.0>

=ERROR REPORT==== 28-Aug-2015::10:54:20 ===
closing AMQP connection <0.15305.0> (10.0.2.26:55758 -> 10.0.2.8:5672):
{handshake_error,starting,0,
                 {amqp_error,access_refused,
                             "AMQPLAIN login refused: user 'openstack' - invalid credentials",
                             'connection.start_ok'}}

=INFO REPORT==== 28-Aug-2015::10:54:21 ===
accepting AMQP connection <0.15747.0> (10.0.2.26:55773 -> 10.0.2.8:5672)

>From Nova Log:

2015-08-28 10:54:19.524 14743 DEBUG oslo_concurrency.lockutils [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Lock "compute_resources" acquired by "_update_available_resource" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:444
2015-08-28 10:54:19.827 14743 INFO nova.compute.resource_tracker [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Total usable vcpus: 48, total allocated vcpus: 1
2015-08-28 10:54:19.827 14743 INFO nova.compute.resource_tracker [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Final resource view: name=osc-1001.prd.cin1.corp.hosting.net phys_ram=257524MB used_ram=2560MB phys_disk=5GB used_disk=20GB total_vcpus=48 used_vcpus=1 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x3f80250>
2015-08-28 10:54:19.886 14743 INFO nova.scheduler.client.report [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Compute_service record updated for ('osc-1001.prd.cin1.corp.hosting.net', 'osc-1001.prd.cin1.corp.hosting.net')
2015-08-28 10:54:19.886 14743 INFO nova.compute.resource_tracker [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Compute_service record updated for osc-1001.prd.cin1.corp.hosting.net:osc-1001.prd.cin1.corp.hosting.net
2015-08-28 10:54:19.887 14743 DEBUG oslo_concurrency.lockutils [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Lock "compute_resources" released by "_update_available_resource" :: held 0.363s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:456
2015-08-28 10:54:19.922 14743 DEBUG nova.service [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Creating RPC server for service compute start /usr/lib/python2.7/site-packages/nova/service.py:188
2015-08-28 10:54:19.925 14743 INFO oslo_messaging._drivers.impl_rabbit [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Connecting to AMQP server on 10.0.2.8:5672
2015-08-28 10:54:19.943 14743 INFO oslo_messaging._drivers.impl_rabbit [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Connected to AMQP server on 10.0.2.8:5672
2015-08-28 10:54:19.969 14743 DEBUG nova.service [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Join ServiceGroup membership for this service compute start /usr/lib/python2.7/site-packages/nova/service.py:206
2015-08-28 10:54:19.969 14743 DEBUG nova.servicegroup.drivers.db [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] DB_Driver: join new ServiceGroup member osc-1001.prd.cin1.corp.hosting.net to the compute group, service = <nova.service.Service object at 0x364f9d0> join /usr/lib/python2.7/site-packages/nova/servicegroup/drivers/db.py:59

Rabbit configuration in nova.conf
[oslo_messaging_rabbit]
rabbit_hosts=10.0.2.8:5672,10.0.2.7:5672,10.0.2.6:5672
rabbit_userid=openstack
rabbit_password=placeholderpassword

Functionality seems fine and nothing shows up in the nova log but
rabbitmq references this hypervisor and with only the nova openstack
service running i get the message.

** Affects: nova
     Importance: Undecided
         Status: New

** Description changed:

  From rabbitmq log:
- 
  
  =INFO REPORT==== 28-Aug-2015::10:54:20 ===
  accepting AMQP connection <0.15664.0> (10.0.2.26:55772 -> 10.0.2.8:5672)
  
  =INFO REPORT==== 28-Aug-2015::10:54:20 ===
  Mirrored queue 'q-agent-notifier-security_group-update_fanout_c8d714e02b944c7f91dad2530a34ff01' in vhost '/': Adding mirror on node 'rabbit@os-controller-1003': <7448.19519.0>
  
  =INFO REPORT==== 28-Aug-2015::10:54:20 ===
  Mirrored queue 'q-agent-notifier-dvr-update_fanout_87fb0fc8e8224ffb88ea91ee20ad8e29' in vhost '/': Adding mirror on node 'rabbit@os-controller-1002': <7447.3416.0>
  
  =INFO REPORT==== 28-Aug-2015::10:54:20 ===
  Mirrored queue 'q-agent-notifier-dvr-update_fanout_87fb0fc8e8224ffb88ea91ee20ad8e29' in vhost '/': Adding mirror on node 'rabbit@os-controller-1003': <7448.19521.0>
  
  =ERROR REPORT==== 28-Aug-2015::10:54:20 ===
  closing AMQP connection <0.15305.0> (10.0.2.26:55758 -> 10.0.2.8:5672):
  {handshake_error,starting,0,
-                  {amqp_error,access_refused,
-                              "AMQPLAIN login refused: user 'openstack' - invalid credentials",
-                              'connection.start_ok'}}
+                  {amqp_error,access_refused,
+                              "AMQPLAIN login refused: user 'openstack' - invalid credentials",
+                              'connection.start_ok'}}
  
  =INFO REPORT==== 28-Aug-2015::10:54:21 ===
  accepting AMQP connection <0.15747.0> (10.0.2.26:55773 -> 10.0.2.8:5672)
  
  From Nova Log:
  
  2015-08-28 10:54:19.524 14743 DEBUG oslo_concurrency.lockutils [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Lock "compute_resources" acquired by "_update_available_resource" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:444
  2015-08-28 10:54:19.827 14743 INFO nova.compute.resource_tracker [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Total usable vcpus: 48, total allocated vcpus: 1
- 2015-08-28 10:54:19.827 14743 INFO nova.compute.resource_tracker [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Final resource view: name=osc-1001.prd.cin1.corp.beyondhosting.net phys_ram=257524MB used_ram=2560MB phys_disk=5GB used_disk=20GB total_vcpus=48 used_vcpus=1 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x3f80250>
- 2015-08-28 10:54:19.886 14743 INFO nova.scheduler.client.report [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Compute_service record updated for ('osc-1001.prd.cin1.corp.beyondhosting.net', 'osc-1001.prd.cin1.corp.beyondhosting.net')
- 2015-08-28 10:54:19.886 14743 INFO nova.compute.resource_tracker [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Compute_service record updated for osc-1001.prd.cin1.corp.beyondhosting.net:osc-1001.prd.cin1.corp.beyondhosting.net
+ 2015-08-28 10:54:19.827 14743 INFO nova.compute.resource_tracker [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Final resource view: name=osc-1001.prd.cin1.corp.hosting.net phys_ram=257524MB used_ram=2560MB phys_disk=5GB used_disk=20GB total_vcpus=48 used_vcpus=1 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x3f80250>
+ 2015-08-28 10:54:19.886 14743 INFO nova.scheduler.client.report [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Compute_service record updated for ('osc-1001.prd.cin1.corp.hosting.net', 'osc-1001.prd.cin1.corp.hosting.net')
+ 2015-08-28 10:54:19.886 14743 INFO nova.compute.resource_tracker [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Compute_service record updated for osc-1001.prd.cin1.corp.hosting.net:osc-1001.prd.cin1.corp.hosting.net
  2015-08-28 10:54:19.887 14743 DEBUG oslo_concurrency.lockutils [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Lock "compute_resources" released by "_update_available_resource" :: held 0.363s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:456
  2015-08-28 10:54:19.922 14743 DEBUG nova.service [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Creating RPC server for service compute start /usr/lib/python2.7/site-packages/nova/service.py:188
  2015-08-28 10:54:19.925 14743 INFO oslo_messaging._drivers.impl_rabbit [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Connecting to AMQP server on 10.0.2.8:5672
  2015-08-28 10:54:19.943 14743 INFO oslo_messaging._drivers.impl_rabbit [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Connected to AMQP server on 10.0.2.8:5672
  2015-08-28 10:54:19.969 14743 DEBUG nova.service [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Join ServiceGroup membership for this service compute start /usr/lib/python2.7/site-packages/nova/service.py:206
- 2015-08-28 10:54:19.969 14743 DEBUG nova.servicegroup.drivers.db [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] DB_Driver: join new ServiceGroup member osc-1001.prd.cin1.corp.beyondhosting.net to the compute group, service = <nova.service.Service object at 0x364f9d0> join /usr/lib/python2.7/site-packages/nova/servicegroup/drivers/db.py:59
- 
+ 2015-08-28 10:54:19.969 14743 DEBUG nova.servicegroup.drivers.db [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] DB_Driver: join new ServiceGroup member osc-1001.prd.cin1.corp.hosting.net to the compute group, service = <nova.service.Service object at 0x364f9d0> join /usr/lib/python2.7/site-packages/nova/servicegroup/drivers/db.py:59
  
  Rabbit configuration in nova.conf
  [oslo_messaging_rabbit]
  rabbit_hosts=10.0.2.8:5672,10.0.2.7:5672,10.0.2.6:5672
  rabbit_userid=openstack
  rabbit_password=placeholderpassword
  
  Functionality seems fine and nothing shows up in the nova log but
  rabbitmq references this hypervisor and with only the nova openstack
  service running i get the message.

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1489921

Title:
  Nova connects to rabbitmq successfully but has invalid credentials

Status in OpenStack Compute (nova):
  New

Bug description:
  From rabbitmq log:

  =INFO REPORT==== 28-Aug-2015::10:54:20 ===
  accepting AMQP connection <0.15664.0> (10.0.2.26:55772 -> 10.0.2.8:5672)

  =INFO REPORT==== 28-Aug-2015::10:54:20 ===
  Mirrored queue 'q-agent-notifier-security_group-update_fanout_c8d714e02b944c7f91dad2530a34ff01' in vhost '/': Adding mirror on node 'rabbit@os-controller-1003': <7448.19519.0>

  =INFO REPORT==== 28-Aug-2015::10:54:20 ===
  Mirrored queue 'q-agent-notifier-dvr-update_fanout_87fb0fc8e8224ffb88ea91ee20ad8e29' in vhost '/': Adding mirror on node 'rabbit@os-controller-1002': <7447.3416.0>

  =INFO REPORT==== 28-Aug-2015::10:54:20 ===
  Mirrored queue 'q-agent-notifier-dvr-update_fanout_87fb0fc8e8224ffb88ea91ee20ad8e29' in vhost '/': Adding mirror on node 'rabbit@os-controller-1003': <7448.19521.0>

  =ERROR REPORT==== 28-Aug-2015::10:54:20 ===
  closing AMQP connection <0.15305.0> (10.0.2.26:55758 -> 10.0.2.8:5672):
  {handshake_error,starting,0,
                   {amqp_error,access_refused,
                               "AMQPLAIN login refused: user 'openstack' - invalid credentials",
                               'connection.start_ok'}}

  =INFO REPORT==== 28-Aug-2015::10:54:21 ===
  accepting AMQP connection <0.15747.0> (10.0.2.26:55773 -> 10.0.2.8:5672)

  From Nova Log:

  2015-08-28 10:54:19.524 14743 DEBUG oslo_concurrency.lockutils [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Lock "compute_resources" acquired by "_update_available_resource" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:444
  2015-08-28 10:54:19.827 14743 INFO nova.compute.resource_tracker [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Total usable vcpus: 48, total allocated vcpus: 1
  2015-08-28 10:54:19.827 14743 INFO nova.compute.resource_tracker [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Final resource view: name=osc-1001.prd.cin1.corp.hosting.net phys_ram=257524MB used_ram=2560MB phys_disk=5GB used_disk=20GB total_vcpus=48 used_vcpus=1 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x3f80250>
  2015-08-28 10:54:19.886 14743 INFO nova.scheduler.client.report [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Compute_service record updated for ('osc-1001.prd.cin1.corp.hosting.net', 'osc-1001.prd.cin1.corp.hosting.net')
  2015-08-28 10:54:19.886 14743 INFO nova.compute.resource_tracker [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Compute_service record updated for osc-1001.prd.cin1.corp.hosting.net:osc-1001.prd.cin1.corp.hosting.net
  2015-08-28 10:54:19.887 14743 DEBUG oslo_concurrency.lockutils [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Lock "compute_resources" released by "_update_available_resource" :: held 0.363s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:456
  2015-08-28 10:54:19.922 14743 DEBUG nova.service [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Creating RPC server for service compute start /usr/lib/python2.7/site-packages/nova/service.py:188
  2015-08-28 10:54:19.925 14743 INFO oslo_messaging._drivers.impl_rabbit [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Connecting to AMQP server on 10.0.2.8:5672
  2015-08-28 10:54:19.943 14743 INFO oslo_messaging._drivers.impl_rabbit [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Connected to AMQP server on 10.0.2.8:5672
  2015-08-28 10:54:19.969 14743 DEBUG nova.service [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] Join ServiceGroup membership for this service compute start /usr/lib/python2.7/site-packages/nova/service.py:206
  2015-08-28 10:54:19.969 14743 DEBUG nova.servicegroup.drivers.db [req-91919deb-c6be-42a8-91f6-557f078f7d19 - - - - -] DB_Driver: join new ServiceGroup member osc-1001.prd.cin1.corp.hosting.net to the compute group, service = <nova.service.Service object at 0x364f9d0> join /usr/lib/python2.7/site-packages/nova/servicegroup/drivers/db.py:59

  Rabbit configuration in nova.conf
  [oslo_messaging_rabbit]
  rabbit_hosts=10.0.2.8:5672,10.0.2.7:5672,10.0.2.6:5672
  rabbit_userid=openstack
  rabbit_password=placeholderpassword

  Functionality seems fine and nothing shows up in the nova log but
  rabbitmq references this hypervisor and with only the nova openstack
  service running i get the message.

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1489921/+subscriptions
Follow ups

[Bug 1489921] Re: Nova connects to rabbitmq successfully but has invalid credentials
From: Davanum Srinivas (DIMS), 2015-11-23
[Bug 1489921] Re: Nova connects to rabbitmq successfully but has invalid credentials
From: Sean Dague, 2015-09-23
[Bug 1489921] Re: Nova connects to rabbitmq successfully but has invalid credentials
From: Davanum Srinivas (DIMS), 2015-08-30