Revision history [back]

click to hide/show revision 1
initial version

Launch Instance, nova-conductor ACCESS_REFUSED

Hello everyone,

I am getting following error when I try to launch a instance:

# /var/log/nova/nova-conductor.log
ERROR oslo_messaging.rpc.server AccessRefused: (0, 0): (403) ACCESS_REFUSED - Login was refused using authentication mechanism AMQPLAIN. For details see the broker logfile.

I followed the Installation Guide and did the Minimal Deployment for Stein.

This is just a test-setup and nova, keystone, glance, neutron, placement are running on the same machine.

After finishing the Installation Guide I went on with Launch Instance Provider but the instance creation got stuck and I think it's related to the error above.

My System:

➜ root@horizon /root # cat /etc/centos-release
CentOS Linux release 7.6.1810 (Core)

➜ root@horizon /root # openstack --version
openstack 3.18.0

If I restart the openstack-nova-conductor service it connects to rabbit an the connection ist established.

➜ root@horizon /root # systemctl restart openstack-nova-conductor
➜ root@horizon /root # systemctl status openstack-nova-conductor
● openstack-nova-conductor.service - OpenStack Nova Conductor Server
   Loaded: loaded (/usr/lib/systemd/system/openstack-nova-conductor.service; enabled; vendor preset: disabled)
   Active: active (running) since Sun 2019-06-23 12:34:20 CEST; 46s ago
 Main PID: 28512 (nova-conductor)
    Tasks: 3
   CGroup: /system.slice/openstack-nova-conductor.service
           ├─28512 /usr/bin/python2 /usr/bin/nova-conductor
           ├─28525 /usr/bin/python2 /usr/bin/nova-conductor
           └─28526 /usr/bin/python2 /usr/bin/nova-conductor

Jun 23 12:34:08 horizon.aurora.local systemd[1]: Starting OpenStack Nova Conductor Server...
Jun 23 12:34:20 horizon.aurora.local systemd[1]: Started OpenStack Nova Conductor Server.

Output of the logfile:

# /var/log/rabbitmq/rabbit@horizon.log
=INFO REPORT==== 23-Jun-2019::12:34:21 ===
accepting AMQP connection <0.1031.0> (10.0.0.5:46342 -> 10.0.0.5:5672)

=INFO REPORT==== 23-Jun-2019::12:34:22 ===
Connection <0.1031.0> (10.0.0.5:46342 -> 10.0.0.5:5672) has a client-provided name: nova-conductor:28525:d9a97e37-ba7b-4eeb-b9d1-0a8a82cb1e48

=INFO REPORT==== 23-Jun-2019::12:34:22 ===
connection <0.1031.0> (10.0.0.5:46342 -> 10.0.0.5:5672 - nova-conductor:28525:d9a97e37-ba7b-4eeb-b9d1-0a8a82cb1e48): user 'openstack' authenticated and granted access to vhost '/'

=INFO REPORT==== 23-Jun-2019::12:34:22 ===
accepting AMQP connection <0.1049.0> (10.0.0.5:46344 -> 10.0.0.5:5672)

=INFO REPORT==== 23-Jun-2019::12:34:22 ===
Connection <0.1049.0> (10.0.0.5:46344 -> 10.0.0.5:5672) has a client-provided name: nova-conductor:28526:48c254f4-7aa5-4ac4-9a97-e3de5e854f70

=INFO REPORT==== 23-Jun-2019::12:34:22 ===
connection <0.1049.0> (10.0.0.5:46344 -> 10.0.0.5:5672 - nova-conductor:28526:48c254f4-7aa5-4ac4-9a97-e3de5e854f70): user 'openstack' authenticated and granted access to vhost '/'

=INFO REPORT==== 23-Jun-2019::12:34:22 ===
accepting AMQP connection <0.1067.0> (10.0.0.5:46346 -> 10.0.0.5:5672)

=INFO REPORT==== 23-Jun-2019::12:34:22 ===
Connection <0.1067.0> (10.0.0.5:46346 -> 10.0.0.5:5672) has a client-provided name: nova-conductor:28525:8767e474-d319-4acb-951c-612cc4b7148e

=INFO REPORT==== 23-Jun-2019::12:34:22 ===
connection <0.1067.0> (10.0.0.5:46346 -> 10.0.0.5:5672 - nova-conductor:28525:8767e474-d319-4acb-951c-612cc4b7148e): user 'openstack' authenticated and granted access to vhost '/'

=INFO REPORT==== 23-Jun-2019::12:34:32 ===
accepting AMQP connection <0.1078.0> (10.0.0.5:46348 -> 10.0.0.5:5672)

=INFO REPORT==== 23-Jun-2019::12:34:32 ===
Connection <0.1078.0> (10.0.0.5:46348 -> 10.0.0.5:5672) has a client-provided name: nova-conductor:28526:15b68eaf-a921-4a2e-95ca-849a5be3d558

=INFO REPORT==== 23-Jun-2019::12:34:32 ===
    connection <0.1078.0> (10.0.0.5:46348 -> 10.0.0.5:5672 - nova-conductor:28526:15b68eaf-a921-4a2e-95ca-849a5be3d558): user 'openstack' authenticated and granted access to vhost '/'

I also checked the output of lsof

➜ root@horizon /root # lsof -ni :5672 | grep cond
nova-cond 28525     nova    7u  IPv4 129366      0t0  TCP 10.0.0.5:46342->10.0.0.5:amqp (ESTABLISHED)
nova-cond 28525     nova    8u  IPv4 129368      0t0  TCP 10.0.0.5:46346->10.0.0.5:amqp (ESTABLISHED)
nova-cond 28526     nova    7u  IPv4 129367      0t0  TCP 10.0.0.5:46344->10.0.0.5:amqp (ESTABLISHED)
nova-cond 28526     nova    8u  IPv4 129396      0t0  TCP 10.0.0.5:46348->10.0.0.5:amqp (ESTABLISHED)

Now I want to launch a Instance. Doesn't matter if I use the CLI or via Dashboard.

➜ root@horizon /root # source adminrc
➜ root@horizon /root # openstack server create --flavor m1.nano --image cirros --nic net-id=6dda2525-282c-4075-8a22-d25151fc91d5 --security-group default --key-name admin_pubkey provider-instance

I don't see any errors in nova-api.log, nova-compute.log, nova-scheduler.log but I get a error in nova-conductor.log. The transport_url ist correct, since the other services are not complaining about a authentication error.

# /var/log/nova/nova-conductor.log
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server [req-a160bb04-1041-45ae-97e5-b66391d4968b b098d14e920c4a76aefc8e566928f4b9 44eea4c7fb1f402087aadc02afd5b8d4 - default default] Exception during message handling: AccessRefused
: (0, 0): (403) ACCESS_REFUSED - Login was refused using authentication mechanism AMQPLAIN. For details see the broker logfile.
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 166, in _process_incoming
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     res = self.dispatcher.dispatch(message)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 265, in dispatch
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     return self._do_dispatch(endpoint, method, ctxt, args)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 194, in _do_dispatch
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     result = func(ctxt, **new_args)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/conductor/manager.py", line 1518, in schedule_and_build_instances
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     limits=host.limits, host_list=host_list)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/compute/rpcapi.py", line 1082, in build_and_run_instance
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     cctxt.cast(ctxt, 'build_and_run_instance', **kwargs)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 153, in cast
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     self.transport._send(self.target, msg_ctxt, msg, retry=self.retry)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 128, in _send
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     retry=retry)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 645, in send
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     call_monitor_timeout, retry=retry)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 605, in _send
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     with self._get_connection(rpc_common.PURPOSE_SEND) as conn:
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 559, in _get_connection
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     purpose=purpose)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/common.py", line 404, in __init__
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     self.connection = connection_pool.get()
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/pool.py", line 107, in get
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     return self.create()
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/pool.py", line 144, in create
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     return self.connection_cls(self.conf, self.url, purpose)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/impl_rabbit.py", line 531, in __init__
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     self.ensure_connection()
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/impl_rabbit.py", line 646, in ensure_connection
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     self.connection.ensure_connection(errback=on_error)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/kombu/connection.py", line 405, in ensure_connection
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     callback)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/kombu/utils/functional.py", line 332, in retry_over_time
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     return fun(*args, **kwargs)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/kombu/connection.py", line 261, in connect
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     return self.connection
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/kombu/connection.py", line 802, in connection
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     self._connection = self._establish_connection()
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/kombu/connection.py", line 757, in _establish_connection
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     conn = self.transport.establish_connection()
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/kombu/transport/pyamqp.py", line 130, in establish_connection
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     conn.connect()
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/amqp/connection.py", line 313, in connect
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     self.drain_events(timeout=self.connect_timeout)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/amqp/connection.py", line 500, in drain_events
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     while not self.blocking_read(timeout):
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/amqp/connection.py", line 506, in blocking_read
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     return self.on_inbound_frame(frame)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/amqp/method_framing.py", line 55, in on_frame
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     callback(channel, method_sig, buf, None)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/amqp/connection.py", line 510, in on_inbound_method
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     method_sig, payload, content,
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/amqp/abstract_channel.py", line 126, in dispatch_method
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     method_sig, payload, content,
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/amqp/abstract_channel.py", line 126, in dispatch_method
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     listener(*args)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/amqp/connection.py", line 639, in _on_close
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     (class_id, method_id), ConnectionError)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server AccessRefused: (0, 0): (403) ACCESS_REFUSED - Login was refused using authentication mechanism AMQPLAIN. For details see the broker logfile.

The error says I should look into the broker logfiles:

=INFO REPORT==== 23-Jun-2019::12:30:17 ===
accepting AMQP connection <0.1011.0> (10.0.0.5:46320 -> 10.0.0.5:5672)

=INFO REPORT==== 23-Jun-2019::12:30:17 ===
Connection <0.1011.0> (10.0.0.5:46320 -> 10.0.0.5:5672) has a client-provided name: nova-conductor:24366:f052ecf8-342e-445a-bfaa-58d68c33d385

=ERROR REPORT==== 23-Jun-2019::12:30:17 ===
Error on AMQP connection <0.1011.0> (10.0.0.5:46320 -> 10.0.0.5:5672, state: starting):
AMQPLAIN login refused: user 'openstack' - invalid credentials

=INFO REPORT==== 23-Jun-2019::12:30:17 ===
closing AMQP connection <0.1011.0> (10.0.0.5:46320 -> 10.0.0.5:5672 - nova-conductor:24366:f052ecf8-342e-445a-bfaa-58d68c33d385)

I checked the transport_url again, and also checked the values in the database - they are correct:

➜ root@horizon /root # nova-manage cell_v2 list_cells
+-------+--------------------------------------+----------------------------------------------+-----------------------------------------------------------+----------+
|  Name |                 UUID                 |                Transport URL                 |                    Database Connection                    | Disabled |
+-------+--------------------------------------+----------------------------------------------+-----------------------------------------------------------+----------+
| cell0 | 00000000-0000-0000-0000-000000000000 |                    none:/                    | mysql+pymysql://nova:****@horizon.aurora.local/nova_cell0 |  False   |
| cell1 | 222cce20-8ff1-417c-abb0-305f7e3c9efd | rabbit://openstack:****@horizon.aurora.local |    mysql+pymysql://nova:****@horizon.aurora.local/nova    |  False   |
+-------+--------------------------------------+----------------------------------------------+-----------------------------------------------------------+----------+

This is mit nova.conf, I've removed the comments from the file for better readability and replaced the passwords:

[DEFAULT]
enabled_apis = osapi_compute,metadata
transport_url = rabbit://openstack:RABBIT_PASS@horizon.aurora.local
my_ip = 10.0.0.5
use_neutron = true
firewall_driver = nova.virt.firewall.NoopFirewallDriver

#debug=true

[api]
auth_strategy = keystone

[api_database]
connection = mysql+pymysql://nova:NOVA_DBPASS@horizon.aurora.local/nova_api

[barbican]
[cache]
[cells]
[cinder]
[compute]
[conductor]
[console]
[consoleauth]
[cors]

[database]
connection = mysql+pymysql://nova:NOVA_DBPASS@horizon.aurora.local/nova

[devices]
[ephemeral_storage_encryption]
[filter_scheduler]

[glance]
api_servers = http://horizon.aurora.local:9292

[guestfs]
[healthcheck]
[hyperv]
[ironic]
[key_manager]
[keystone]

[keystone_authtoken]
auth_url = http://horizon.aurora.local:5000/v3
memcached_servers = horizon.aurora.local:11211
auth_type = password
project_domain_name = Default
user_domain_name = Default
project_name = service
username = nova
password = NOVA_PASS

[libvirt]
[metrics]
[mks]

[neutron]
url = http://horizon.aurora.local:9696
auth_url = http://horizon.aurora.local:5000
auth_type = password
project_domain_name = default
user_domain_name = default
region_name = Aurora
project_name = service
username = neutron
password = NEUTRON_PASS
service_metadata_proxy = true
metadata_proxy_shared_secret = METADATA_SECRET

[notifications]
[osapi_v21]

[oslo_concurrency]
lock_path = /var/lib/nova/tmp

[oslo_messaging_amqp]
[oslo_messaging_kafka]
[oslo_messaging_notifications]
[oslo_messaging_rabbit]
[oslo_middleware]
[oslo_policy]
[pci]

[placement]
region_name = Aurora
project_domain_name = Default
project_name = service
auth_type = password
user_domain_name = Default
auth_url = http://horizon.aurora.local:5000/v3
username = placement
password = PLACEMENT_PASS

[placement_database]
connection = mysql+pymysql://placement:PLACEMENT_DBPASS@horizon.aurora.local/placement

[powervm]
[privsep]
[profiler]
[quota]
[rdp]
[remote_debug]
[scheduler]
[serial_console]
[service_user]
[spice]
[upgrade_levels]
[vault]
[vendordata_dynamic_auth]
[vmware]

[vnc]
enabled = true
server_listen = 0.0.0.0
server_proxyclient_address = $my_ip
novncproxy_base_url = http://horizon.aurora.local:6080/vnc_auto.html

[workarounds]
[wsgi]
[xenserver]
[xvp]

[zvm]

I don't really know how to fix this. Or am I on a wrong trail and the issue is somewhere else? If I need to provide more informations, please let me know.

Thank you for taking time and reading my post.

Launch Instance, nova-conductor ACCESS_REFUSED

Hello everyone,

I am getting following error when I try to launch a instance:

# /var/log/nova/nova-conductor.log
ERROR oslo_messaging.rpc.server AccessRefused: (0, 0): (403) ACCESS_REFUSED - Login was refused using authentication mechanism AMQPLAIN. For details see the broker logfile.

I followed the Installation Guide and did the Minimal Deployment for Stein.

This is just a test-setup and nova, keystone, glance, neutron, placement are running on the same machine.

After finishing the Installation Guide I went on with Launch Instance Provider but the instance creation got stuck and I think it's related to the error above.

My System:

➜ root@horizon /root # cat /etc/centos-release
CentOS Linux release 7.6.1810 (Core)

➜ root@horizon /root # openstack --version
openstack 3.18.0

If I restart the openstack-nova-conductor service it connects to rabbit an the connection ist established.

➜ root@horizon /root # systemctl restart openstack-nova-conductor
➜ root@horizon /root # systemctl status openstack-nova-conductor
● openstack-nova-conductor.service - OpenStack Nova Conductor Server
   Loaded: loaded (/usr/lib/systemd/system/openstack-nova-conductor.service; enabled; vendor preset: disabled)
   Active: active (running) since Sun 2019-06-23 12:34:20 CEST; 46s ago
 Main PID: 28512 (nova-conductor)
    Tasks: 3
   CGroup: /system.slice/openstack-nova-conductor.service
           ├─28512 /usr/bin/python2 /usr/bin/nova-conductor
           ├─28525 /usr/bin/python2 /usr/bin/nova-conductor
           └─28526 /usr/bin/python2 /usr/bin/nova-conductor

Jun 23 12:34:08 horizon.aurora.local systemd[1]: Starting OpenStack Nova Conductor Server...
Jun 23 12:34:20 horizon.aurora.local systemd[1]: Started OpenStack Nova Conductor Server.

Output of the logfile:

# /var/log/rabbitmq/rabbit@horizon.log
=INFO REPORT==== 23-Jun-2019::12:34:21 ===
accepting AMQP connection <0.1031.0> (10.0.0.5:46342 -> 10.0.0.5:5672)

=INFO REPORT==== 23-Jun-2019::12:34:22 ===
Connection <0.1031.0> (10.0.0.5:46342 -> 10.0.0.5:5672) has a client-provided name: nova-conductor:28525:d9a97e37-ba7b-4eeb-b9d1-0a8a82cb1e48

=INFO REPORT==== 23-Jun-2019::12:34:22 ===
connection <0.1031.0> (10.0.0.5:46342 -> 10.0.0.5:5672 - nova-conductor:28525:d9a97e37-ba7b-4eeb-b9d1-0a8a82cb1e48): user 'openstack' authenticated and granted access to vhost '/'

=INFO REPORT==== 23-Jun-2019::12:34:22 ===
accepting AMQP connection <0.1049.0> (10.0.0.5:46344 -> 10.0.0.5:5672)

=INFO REPORT==== 23-Jun-2019::12:34:22 ===
Connection <0.1049.0> (10.0.0.5:46344 -> 10.0.0.5:5672) has a client-provided name: nova-conductor:28526:48c254f4-7aa5-4ac4-9a97-e3de5e854f70

=INFO REPORT==== 23-Jun-2019::12:34:22 ===
connection <0.1049.0> (10.0.0.5:46344 -> 10.0.0.5:5672 - nova-conductor:28526:48c254f4-7aa5-4ac4-9a97-e3de5e854f70): user 'openstack' authenticated and granted access to vhost '/'

=INFO REPORT==== 23-Jun-2019::12:34:22 ===
accepting AMQP connection <0.1067.0> (10.0.0.5:46346 -> 10.0.0.5:5672)

=INFO REPORT==== 23-Jun-2019::12:34:22 ===
Connection <0.1067.0> (10.0.0.5:46346 -> 10.0.0.5:5672) has a client-provided name: nova-conductor:28525:8767e474-d319-4acb-951c-612cc4b7148e

=INFO REPORT==== 23-Jun-2019::12:34:22 ===
connection <0.1067.0> (10.0.0.5:46346 -> 10.0.0.5:5672 - nova-conductor:28525:8767e474-d319-4acb-951c-612cc4b7148e): user 'openstack' authenticated and granted access to vhost '/'

=INFO REPORT==== 23-Jun-2019::12:34:32 ===
accepting AMQP connection <0.1078.0> (10.0.0.5:46348 -> 10.0.0.5:5672)

=INFO REPORT==== 23-Jun-2019::12:34:32 ===
Connection <0.1078.0> (10.0.0.5:46348 -> 10.0.0.5:5672) has a client-provided name: nova-conductor:28526:15b68eaf-a921-4a2e-95ca-849a5be3d558

=INFO REPORT==== 23-Jun-2019::12:34:32 ===
    connection <0.1078.0> (10.0.0.5:46348 -> 10.0.0.5:5672 - nova-conductor:28526:15b68eaf-a921-4a2e-95ca-849a5be3d558): user 'openstack' authenticated and granted access to vhost '/'

I also checked the output of lsof

➜ root@horizon /root # lsof -ni :5672 | grep cond
nova-cond 28525     nova    7u  IPv4 129366      0t0  TCP 10.0.0.5:46342->10.0.0.5:amqp (ESTABLISHED)
nova-cond 28525     nova    8u  IPv4 129368      0t0  TCP 10.0.0.5:46346->10.0.0.5:amqp (ESTABLISHED)
nova-cond 28526     nova    7u  IPv4 129367      0t0  TCP 10.0.0.5:46344->10.0.0.5:amqp (ESTABLISHED)
nova-cond 28526     nova    8u  IPv4 129396      0t0  TCP 10.0.0.5:46348->10.0.0.5:amqp (ESTABLISHED)

Now I want to launch a Instance. Doesn't matter if I use the CLI or via Dashboard.

➜ root@horizon /root # source adminrc
➜ root@horizon /root # openstack server create --flavor m1.nano --image cirros --nic net-id=6dda2525-282c-4075-8a22-d25151fc91d5 --security-group default --key-name admin_pubkey provider-instance

I don't see any errors in nova-api.log, nova-compute.log, nova-scheduler.log but I get a error in nova-conductor.log. The transport_url ist correct, since the other services are not complaining about a authentication error.

# /var/log/nova/nova-conductor.log
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server [req-a160bb04-1041-45ae-97e5-b66391d4968b b098d14e920c4a76aefc8e566928f4b9 44eea4c7fb1f402087aadc02afd5b8d4 - default default] Exception during message handling: AccessRefused
: (0, 0): (403) ACCESS_REFUSED - Login was refused using authentication mechanism AMQPLAIN. For details see the broker logfile.
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 166, in _process_incoming
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     res = self.dispatcher.dispatch(message)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 265, in dispatch
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     return self._do_dispatch(endpoint, method, ctxt, args)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 194, in _do_dispatch
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     result = func(ctxt, **new_args)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/conductor/manager.py", line 1518, in schedule_and_build_instances
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     limits=host.limits, host_list=host_list)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/compute/rpcapi.py", line 1082, in build_and_run_instance
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     cctxt.cast(ctxt, 'build_and_run_instance', **kwargs)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 153, in cast
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     self.transport._send(self.target, msg_ctxt, msg, retry=self.retry)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 128, in _send
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     retry=retry)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 645, in send
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     call_monitor_timeout, retry=retry)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 605, in _send
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     with self._get_connection(rpc_common.PURPOSE_SEND) as conn:
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 559, in _get_connection
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     purpose=purpose)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/common.py", line 404, in __init__
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     self.connection = connection_pool.get()
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/pool.py", line 107, in get
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     return self.create()
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/pool.py", line 144, in create
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     return self.connection_cls(self.conf, self.url, purpose)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/impl_rabbit.py", line 531, in __init__
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     self.ensure_connection()
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/impl_rabbit.py", line 646, in ensure_connection
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     self.connection.ensure_connection(errback=on_error)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/kombu/connection.py", line 405, in ensure_connection
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     callback)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/kombu/utils/functional.py", line 332, in retry_over_time
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     return fun(*args, **kwargs)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/kombu/connection.py", line 261, in connect
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     return self.connection
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/kombu/connection.py", line 802, in connection
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     self._connection = self._establish_connection()
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/kombu/connection.py", line 757, in _establish_connection
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     conn = self.transport.establish_connection()
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/kombu/transport/pyamqp.py", line 130, in establish_connection
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     conn.connect()
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/amqp/connection.py", line 313, in connect
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     self.drain_events(timeout=self.connect_timeout)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/amqp/connection.py", line 500, in drain_events
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     while not self.blocking_read(timeout):
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/amqp/connection.py", line 506, in blocking_read
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     return self.on_inbound_frame(frame)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/amqp/method_framing.py", line 55, in on_frame
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     callback(channel, method_sig, buf, None)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/amqp/connection.py", line 510, in on_inbound_method
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     method_sig, payload, content,
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/amqp/abstract_channel.py", line 126, in dispatch_method
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     method_sig, payload, content,
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/amqp/abstract_channel.py", line 126, in dispatch_method
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     listener(*args)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/amqp/connection.py", line 639, in _on_close
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server     (class_id, method_id), ConnectionError)
2019-06-23 12:30:17.856 24366 ERROR oslo_messaging.rpc.server AccessRefused: (0, 0): (403) ACCESS_REFUSED - Login was refused using authentication mechanism AMQPLAIN. For details see the broker logfile.

The error says I should look into the broker logfiles:

=INFO REPORT==== 23-Jun-2019::12:30:17 ===
accepting AMQP connection <0.1011.0> (10.0.0.5:46320 -> 10.0.0.5:5672)

=INFO REPORT==== 23-Jun-2019::12:30:17 ===
Connection <0.1011.0> (10.0.0.5:46320 -> 10.0.0.5:5672) has a client-provided name: nova-conductor:24366:f052ecf8-342e-445a-bfaa-58d68c33d385

=ERROR REPORT==== 23-Jun-2019::12:30:17 ===
Error on AMQP connection <0.1011.0> (10.0.0.5:46320 -> 10.0.0.5:5672, state: starting):
AMQPLAIN login refused: user 'openstack' - invalid credentials

=INFO REPORT==== 23-Jun-2019::12:30:17 ===
closing AMQP connection <0.1011.0> (10.0.0.5:46320 -> 10.0.0.5:5672 - nova-conductor:24366:f052ecf8-342e-445a-bfaa-58d68c33d385)

I checked the transport_url again, and also checked the values in the database - they are correct:

➜ root@horizon /root # nova-manage cell_v2 list_cells
+-------+--------------------------------------+----------------------------------------------+-----------------------------------------------------------+----------+
|  Name |                 UUID                 |                Transport URL                 |                    Database Connection                    | Disabled |
+-------+--------------------------------------+----------------------------------------------+-----------------------------------------------------------+----------+
| cell0 | 00000000-0000-0000-0000-000000000000 |                    none:/                    | mysql+pymysql://nova:****@horizon.aurora.local/nova_cell0 |  False   |
| cell1 | 222cce20-8ff1-417c-abb0-305f7e3c9efd | rabbit://openstack:****@horizon.aurora.local |    mysql+pymysql://nova:****@horizon.aurora.local/nova    |  False   |
+-------+--------------------------------------+----------------------------------------------+-----------------------------------------------------------+----------+

This is mit nova.conf, I've removed the comments from the file for better readability and replaced the passwords:

[DEFAULT]
enabled_apis = osapi_compute,metadata
transport_url = rabbit://openstack:RABBIT_PASS@horizon.aurora.local
my_ip = 10.0.0.5
use_neutron = true
firewall_driver = nova.virt.firewall.NoopFirewallDriver

#debug=true

[api]
auth_strategy = keystone

[api_database]
connection = mysql+pymysql://nova:NOVA_DBPASS@horizon.aurora.local/nova_api

[barbican]
[cache]
[cells]
[cinder]
[compute]
[conductor]
[console]
[consoleauth]
[cors]

[database]
connection = mysql+pymysql://nova:NOVA_DBPASS@horizon.aurora.local/nova

[devices]
[ephemeral_storage_encryption]
[filter_scheduler]

[glance]
api_servers = http://horizon.aurora.local:9292

[guestfs]
[healthcheck]
[hyperv]
[ironic]
[key_manager]
[keystone]

[keystone_authtoken]
auth_url = http://horizon.aurora.local:5000/v3
memcached_servers = horizon.aurora.local:11211
auth_type = password
project_domain_name = Default
user_domain_name = Default
project_name = service
username = nova
password = NOVA_PASS

[libvirt]
[metrics]
[mks]

[neutron]
url = http://horizon.aurora.local:9696
auth_url = http://horizon.aurora.local:5000
auth_type = password
project_domain_name = default
user_domain_name = default
region_name = Aurora
project_name = service
username = neutron
password = NEUTRON_PASS
service_metadata_proxy = true
metadata_proxy_shared_secret = METADATA_SECRET

[notifications]
[osapi_v21]

[oslo_concurrency]
lock_path = /var/lib/nova/tmp

[oslo_messaging_amqp]
[oslo_messaging_kafka]
[oslo_messaging_notifications]
[oslo_messaging_rabbit]
[oslo_middleware]
[oslo_policy]
[pci]

[placement]
region_name = Aurora
project_domain_name = Default
project_name = service
auth_type = password
user_domain_name = Default
auth_url = http://horizon.aurora.local:5000/v3
username = placement
password = PLACEMENT_PASS

[placement_database]
connection = mysql+pymysql://placement:PLACEMENT_DBPASS@horizon.aurora.local/placement

[powervm]
[privsep]
[profiler]
[quota]
[rdp]
[remote_debug]
[scheduler]
[serial_console]
[service_user]
[spice]
[upgrade_levels]
[vault]
[vendordata_dynamic_auth]
[vmware]

[vnc]
enabled = true
server_listen = 0.0.0.0
server_proxyclient_address = $my_ip
novncproxy_base_url = http://horizon.aurora.local:6080/vnc_auto.html

[workarounds]
[wsgi]
[xenserver]
[xvp]

[zvm]

I don't really know how to fix this. Or am I on a wrong trail and the issue is somewhere else? If I need to provide more informations, please let me know.

Thank you for taking time and reading my post.

Edit:

Just captured the traffic of rabbitmq. tcp.stream 32 is a successful request. tcp.stream 33 is the that doesn't work. And that is correct - the last letter of the password is missing.

The password has a length of 24 characters, I will try to lower it.

image description