devstack installation of masakari fails with rabbitmq ACCESS_REFUSED

[Dinesh Bhor]

The Devstack script fails with below error on current devstack and masakari master:

2017-10-30 06:29:14.263 | +functions-common:service_check:1539 for service in '${ENABLED_SERVICES//,/ }'
2017-10-30 06:29:14.267 | +functions-common:service_check:1541 sudo systemctl is-enabled <email address hidden>
2017-10-30 06:29:14.273 | Failed to get unit file state for <email address hidden>: No such file or directory
2017-10-30 06:29:14.277 | +functions-common:service_check:1539 for service in '${ENABLED_SERVICES//,/ }'
2017-10-30 06:29:14.281 | +functions-common:service_check:1541 sudo systemctl is-enabled <email address hidden>
2017-10-30 06:29:14.290 | enabled
2017-10-30 06:29:14.294 | +functions-common:service_check:1545 sudo systemctl status <email address hidden> --no-pager
2017-10-30 06:29:14.302 | ● <email address hidden> - Devstack <email address hidden>
2017-10-30 06:29:14.302 | Loaded: loaded (/<email address hidden>; enabled; vendor preset: enabled)
2017-10-30 06:29:14.302 | Active: active (running) since Mon 2017-10-30 11:58:53 IST; 20s ago
2017-10-30 06:29:14.302 | Main PID: 14634 (masakari-api)
2017-10-30 06:29:14.302 | CGroup: /<email address hidden>
2017-10-30 06:29:14.302 | ├─14634 /usr/bin/python /usr/local/bin/masakari-api --config-file=/etc/masakari/masakari.conf --debug
2017-10-30 06:29:14.303 | ├─15149 /usr/bin/python /usr/local/bin/masakari-api --config-file=/etc/masakari/masakari.conf --debug
2017-10-30 06:29:14.303 | └─15150 /usr/bin/python /usr/local/bin/masakari-api --config-file=/etc/masakari/masakari.conf --debug
2017-10-30 06:29:14.303 |
2017-10-30 06:29:14.303 | Oct 30 11:58:55 dbopenstack-VirtualBox masakari-api[14634]: 2017-10-30 11:58:55.999 DEBUG oslo_service.service [-] keystone_authtoken.service_token_roles_required = False from (pid=14634) log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2886
2017-10-30 06:29:14.303 | Oct 30 11:58:55 dbopenstack-VirtualBox masakari-api[14634]: 2017-10-30 11:58:55.999 DEBUG oslo_service.service [-] keystone_authtoken.signing_dir = /var/cache/masakari from (pid=14634) log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2886
2017-10-30 06:29:14.303 | Oct 30 11:58:55 dbopenstack-VirtualBox masakari-api[14634]: 2017-10-30 11:58:55.999 DEBUG oslo_service.service [-] keystone_authtoken.token_cache_time = 300 from (pid=14634) log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2886
2017-10-30 06:29:14.303 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-api[14634]: 2017-10-30 11:58:55.999 DEBUG oslo_service.service [-] keystone_authtoken.trust_id = None from (pid=14634) log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2886
2017-10-30 06:29:14.303 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-api[14634]: 2017-10-30 11:58:55.999 DEBUG oslo_service.service [-] keystone_authtoken.user_domain_id = None from (pid=14634) log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2886
2017-10-30 06:29:14.303 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-api[14634]: 2017-10-30 11:58:56.000 DEBUG oslo_service.service [-] keystone_authtoken.user_domain_name = Default from (pid=14634) log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2886
2017-10-30 06:29:14.303 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-api[14634]: 2017-10-30 11:58:56.000 DEBUG oslo_service.service [-] keystone_authtoken.user_id = None from (pid=14634) log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2886
2017-10-30 06:29:14.303 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-api[14634]: 2017-10-30 11:58:56.000 DEBUG oslo_service.service [-] keystone_authtoken.username = masakari from (pid=14634) log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2886
2017-10-30 06:29:14.303 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-api[14634]: 2017-10-30 11:58:56.000 DEBUG oslo_service.service [-] oslo_versionedobjects.fatal_exception_format_errors = False from (pid=14634) log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2886
2017-10-30 06:29:14.303 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-api[14634]: 2017-10-30 11:58:56.000 DEBUG oslo_service.service [-] ******************************************************************************** from (pid=14634) log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:2888
2017-10-30 06:29:14.309 | +functions-common:service_check:1539 for service in '${ENABLED_SERVICES//,/ }'
2017-10-30 06:29:14.313 | +functions-common:service_check:1541 sudo systemctl is-enabled <email address hidden>
2017-10-30 06:29:14.320 | enabled
2017-10-30 06:29:14.324 | +functions-common:service_check:1545 sudo systemctl status <email address hidden> --no-pager
2017-10-30 06:29:14.333 | ● <email address hidden> - Devstack <email address hidden>
2017-10-30 06:29:14.333 | Loaded: loaded (/<email address hidden>; enabled; vendor preset: enabled)
2017-10-30 06:29:14.333 | Active: inactive (dead) since Mon 2017-10-30 11:58:56 IST; 17s ago
2017-10-30 06:29:14.333 | Main PID: 14772 (code=exited, status=0/SUCCESS)
2017-10-30 06:29:14.333 |
2017-10-30 06:29:14.333 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-engine[14772]: 2017-10-30 11:58:56.302 TRACE oslo_service.service File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/impl_rabbit.py", line 614, in __init__
2017-10-30 06:29:14.333 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-engine[14772]: 2017-10-30 11:58:56.302 TRACE oslo_service.service self.ensure_connection()
2017-10-30 06:29:14.333 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-engine[14772]: 2017-10-30 11:58:56.302 TRACE oslo_service.service File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/impl_rabbit.py", line 713, in ensure_connection
2017-10-30 06:29:14.333 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-engine[14772]: 2017-10-30 11:58:56.302 TRACE oslo_service.service self.ensure(method=self.connection.connect)
2017-10-30 06:29:14.333 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-engine[14772]: 2017-10-30 11:58:56.302 TRACE oslo_service.service File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/impl_rabbit.py", line 825, in ensure
2017-10-30 06:29:14.333 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-engine[14772]: 2017-10-30 11:58:56.302 TRACE oslo_service.service raise exceptions.MessageDeliveryFailure(msg)
2017-10-30 06:29:14.333 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-engine[14772]: 2017-10-30 11:58:56.302 TRACE oslo_service.service MessageDeliveryFailure: Unable to connect to AMQP server on 127.0.0.1:5672 after None tries: (0, 0): (403) ACCESS_REFUSED - Login was refused using authentication mechanism AMQPLAIN. For details see the broker logfile.
2017-10-30 06:29:14.333 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-engine[14772]: 2017-10-30 11:58:56.302 TRACE oslo_service.service
2017-10-30 06:29:14.334 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-engine[14772]: 2017-10-30 11:58:56.320 DEBUG oslo_concurrency.lockutils [-] Acquired semaphore "singleton_lock" from (pid=14772) lock /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:212
2017-10-30 06:29:14.334 | Oct 30 11:58:56 dbopenstack-VirtualBox masakari-engine[14772]: 2017-10-30 11:58:56.321 DEBUG oslo_concurrency.lockutils [-] Releasing semaphore "singleton_lock" from (pid=14772) lock /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:228
2017-10-30 06:29:14.339 | +functions-common:service_check:1 exit_trap
2017-10-30 06:29:14.343 | +./stack.sh:exit_trap:493 local r=3
2017-10-30 06:29:14.349 | ++./stack.sh:exit_trap:494 jobs -p
2017-10-30 06:29:14.353 | +./stack.sh:exit_trap:494 jobs=
2017-10-30 06:29:14.358 | +./stack.sh:exit_trap:497 [[ -n '' ]]
2017-10-30 06:29:14.367 | +./stack.sh:exit_trap:503 '[' -f /tmp/tmp.YWYqUGKzRp ']'
2017-10-30 06:29:14.374 | +./stack.sh:exit_trap:504 rm /tmp/tmp.YWYqUGKzRp
2017-10-30 06:29:14.410 | +./stack.sh:exit_trap:508 kill_spinner
2017-10-30 06:29:14.415 | +./stack.sh:kill_spinner:407 '[' '!' -z '' ']'
2017-10-30 06:29:14.419 | +./stack.sh:exit_trap:510 [[ 3 -ne 0 ]]
2017-10-30 06:29:14.424 | +./stack.sh:exit_trap:511 echo 'Error on exit'
2017-10-30 06:29:14.424 | Error on exit
2017-10-30 06:29:14.428 | +./stack.sh:exit_trap:513 type -p generate-subunit
2017-10-30 06:29:14.433 | +./stack.sh:exit_trap:514 generate-subunit 1509343428 1526 fail
2017-10-30 06:29:14.886 | +./stack.sh:exit_trap:516 [[ -z /opt/stack/logs ]]
2017-10-30 06:29:14.891 | +./stack.sh:exit_trap:519 /home/dbopenstack/devstack/tools/worlddump.py -d /opt/stack/logs
2017-10-30 06:29:21.553 | +./stack.sh:exit_trap:528 exit 3
dbopenstack@dbopenstack-VirtualBox:~/devstack$

devstack master:
commit 2c9343e5db44fa7a41ca6924737331dd9088ef8f
Merge: 464d6e0 e8db867
Author: Zuul <email address hidden>
Date: Fri Oct 27 08:28:49 2017 +0000

    Merge "Change ENABLE_KSM to $ENABLE_KSM"

masakari master:
commit 7ef4e969494085b7c336a82e252b0337b6dd3d3c
Merge: 26f00f4 db67c44
Author: Jenkins <email address hidden>
Date: Fri Oct 13 05:45:04 2017 +0000

    Merge "Upgrade oslo.db and Replace DbMigrationError with DBMigrationError"

It looks like the masakari-engine service is not able to get a proper 'tansport_url' to connect with rabbitmq from masakari.conf which results into ACCESS_REFUSED.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/516506

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/516506
Committed: https://git.openstack.org/cgit/openstack/masakari/commit/?id=57bbe7deada89ad35da885451315f216d2f53919
Submitter: Zuul
Branch: master

commit 57bbe7deada89ad35da885451315f216d2f53919
Author: Dinesh Bhor <email address hidden>
Date: Mon Oct 30 12:58:14 2017 +0530

    Fix devstack installation of masakari

    Recently a commit: 188173a8072b143a28779b875af617ac7f35a92d got
    merged into masakari which replaces a rpc method 'get_transport'
    with 'get_rpc_transport'. The 'get_rpc_transport' expects the
    oslo.messaging config option 'transport_url' [1] to be present in
    the [DEFAULT] section of masakari.conf. The current masakari devstack
    script doesn't add 'transport_url' in masakari.conf which results
    into failure of devstack installation of masakari.

    This patch fixes this issue by using an inbuilt devstack function
    'iniset_rpc_backend' to add the 'transport_url' config option in
    masakari.conf.

    [1] * https://github.com/openstack/oslo.messaging/blob/master/oslo_messaging/transport.py#L44
        * https://github.com/openstack/oslo.messaging/blob/master/oslo_messaging/transport.py#L201

    Closes-Bug: #1728544
    Change-Id: I75da054c6669aa90dd96c3ede3ae98de74275de2