puppet-neutron

Nova_admin_tenant_id_setter runs after Service['neutron-server'] causing Auth issues in notification callbacks

Bug #1343009 reported by Andrew Woodward on 2014-07-16

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	puppet-neutron	Fix Released	Undecided	Andrew Woodward	puppet-neutron 5.0.0 "5.0.0"

Bug Description

After spending a LOT of time troubleshooting this issue, I found that its possible for the Nova_admin_tenant_id_setter to run after starting neutron-server. If you are using neutron::server::notifications, this will cause the below errors in neutron.notifiers.nova when attempting to start nodes.

2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova Traceback (most recent call last):
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/neutron/notifiers/nova.py", line 221, in send_events
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova batched_events)
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/v1_1/contrib/server_external_events.py", line 39, in create
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova return_raw=True)
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/base.py", line 152, in _create
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova _resp, body = self.api.client.post(url, body=body)
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 286, in post
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova return self._cs_request(url, 'POST', **kwargs)
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 249, in _cs_request
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova self.authenticate()
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 382, in authenticate
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova auth_url = self._v2_auth(auth_url)
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 469, in _v2_auth
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova return self._authenticate(url, body)
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 484, in _authenticate
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova return self._extract_service_catalog(url, resp, respbody)
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 324, in _extract_service_catalog
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova raise exceptions.AuthorizationFailure()
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova AuthorizationFailure
2014-07-15 04:02:55.105 26566 TRACE neutron.notifiers.nova

after adding debug, and dropping the raise AuthorizationFailure catching KeyError:

2014-07-16 22:03:44.241 7382 DEBUG urllib3.connectionpool [-] "POST /v2.0/tokens HTTP/1.1" 200 327 _make_request /usr/lib/python2.6/site-packages/urllib3/connectionpool.py:330
2014-07-16 22:03:44.251 7382 DEBUG neutron.notifiers.nova [-] auth with user: nova, pass: 5nmhZfOp, tenant: None, url: http://192.168.0.5:35357/v2.0 send_events /usr/lib/python
2.6/site-packages/neutron/notifiers/nova.py:227
2014-07-16 22:03:44.252 7382 ERROR neutron.notifiers.nova [-] Failed to notify nova on events: [{'status': 'completed', 'tag': u'053d956d-5905-4674-9f84-3f5c9ec5989d', 'name':
'network-vif-plugged', 'server_uuid': u'c0edc003-e28d-401b-a2b2-3f28935b7832'}]
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova Traceback (most recent call last):
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/neutron/notifiers/nova.py", line 221, in send_events
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova batched_events)
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/v1_1/contrib/server_external_events.py", line 39, in create
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova return_raw=True)
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/base.py", line 152, in _create
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova _resp, body = self.api.client.post(url, body=body)
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 286, in post
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova return self._cs_request(url, 'POST', **kwargs)
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 269, in _cs_request
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova self.authenticate()
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 383, in authenticate
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova auth_url = self._v2_auth(auth_url)
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 470, in _v2_auth
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova return self._authenticate(url, body)
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 485, in _authenticate
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova return self._extract_service_catalog(url, resp, respbody)
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 308, in _extract_service_catalog
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova self.tenant_id = self.service_catalog.get_tenant_id()
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/service_catalog.py", line 32, in get_tenant_id
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova return self.catalog['access']['token']['tenant']['id']
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova KeyError: 'tenant'
2014-07-16 22:03:44.252 7382 TRACE neutron.notifiers.nova

this variant also occurred on occasion.

2014-07-14 21:19:56.022 20159 DEBUG neutron.notifiers.nova [-] Sending events: [{'status': 'completed', 'tag': u'e46a8661-b586-4c04-83e4-b9d5ad0c377f', 'name': 'network-vif-unp
lugged', 'server_uuid': u'30ec68d8-c2de-4adc-8321-8465f4c0ae79'}] send_events /usr/lib/python2.6/site-packages/neutron/notifiers/nova.py:218
2014-07-14 21:19:56.074 20159 DEBUG urllib3.connectionpool [-] "POST /v2.0/tokens HTTP/1.1" 401 119 _make_request /usr/lib/python2.6/site-packages/urllib3/connectionpool.py:330
2014-07-14 21:19:56.076 20159 ERROR neutron.notifiers.nova [-] Failed to notify nova on events: [{'status': 'completed', 'tag': u'e46a8661-b586-4c04-83e4-b9d5ad0c377f', 'name':
'network-vif-unplugged', 'server_uuid': u'30ec68d8-c2de-4adc-8321-8465f4c0ae79'}]
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova Traceback (most recent call last):
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/neutron/notifiers/nova.py", line 221, in send_events
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova batched_events)
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/v1_1/contrib/server_external_events.py", line 39, in create
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova return_raw=True)
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/base.py", line 152, in _create
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova _resp, body = self.api.client.post(url, body=body)
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 286, in post
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova return self._cs_request(url, 'POST', **kwargs)
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 249, in _cs_request
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova self.authenticate()
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 382, in authenticate
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova auth_url = self._v2_auth(auth_url)
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 469, in _v2_auth
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova return self._authenticate(url, body)
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 482, in _authenticate
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova **kwargs)
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 242, in _time_request
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova resp, body = self.request(url, method, **kwargs)
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 236, in request
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova raise exceptions.from_response(resp, body, url, method)
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova Unauthorized: Could not find token, 0437272dd8c048c4a440bc436353867d. (HTTP 401)
2014-07-14 21:19:56.076 20159 TRACE neutron.notifiers.nova
2014-07-14 21:19:57.931 20159 DEBUG neutron.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'admin'], u'_context_request_id': u'req-cbbb411d-81db-4cec-9590-eea144e
be401', u'_context_read_deleted': u'no', u'_context_user_name': None, u'_context_project_name': None, u'namespace': None, u'_context_tenant_id': None, u'args': {u'agent_state':
{u'agent_state': {u'topic': u'dhcp_agent', u'binary': u'neutron-dhcp-agent', u'host': u'node-5.test.domain.local', u'agent_type': u'DHCP agent', u'configurations': {u'subnets'
: 1, u'use_namespaces': True, u'dhcp_lease_duration': 120, u'dhcp_driver': u'neutron.agent.linux.dhcp.Dnsmasq', u'networks': 1, u'ports': 2}}}, u'time': u'2014-07-14T21:19:57.9
23886'}, u'_context_tenant': None, u'_unique_id': u'd1cd800bfc294c55acd7d847a5964f73', u'_context_is_admin': True, u'version': u'1.0', u'_context_timestamp': u'2014-07-14 21:19
:57.923766', u'_context_tenant_name': None, u'_context_user': None, u'_context_user_id': None, u'method': u'report_state', u'_context_project_id': None} _safe_log /usr/lib/pyth
on2.6/site-packages/neutron/openstack/common/rpc/common.py:280

Tags:

Andrew Woodward (xarses) on 2014-07-16

Changed in puppet-neutron:
assignee:	nobody → Andrew Woodward (xarses)
status:	New → Confirmed

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2014-07-16: Fix proposed to puppet-neutron (master)

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

Changed in puppet-neutron:
status:	Confirmed → In Progress

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2014-07-23: Fix merged to puppet-neutron (master)

Reviewed: https://review.openstack.org/107529
Committed: https://git.openstack.org/cgit/stackforge/puppet-neutron/commit/?id=c40f3008d51a4d45716240f93dbd7b325797d042
Submitter: Jenkins
Branch: master

commit c40f3008d51a4d45716240f93dbd7b325797d042
Author: Andrew Woodward <email address hidden>
Date: Wed Jul 16 16:34:06 2014 -0700

Make Nova_admin_tenant_id_setter notify neutron-server.

    Add notification to ensure that changes in Nova_admin_tenant_id_setter
     will result with neutron-server restarting. This is necessary, otherwise
     it is possible for neutron.conf DEFAULT/nova_admin_tenant_id to not be set
     which will result in odd looking auth failures and cause instances to fail
     booting

Change-Id: Idbb2fe9ce63985e4236e41a642ef1b783bec3753
Closes-bug: #1343009

Changed in puppet-neutron:
status:	In Progress → Fix Committed

Mathieu Gagné (mgagne) on 2015-03-27

Changed in puppet-neutron:
milestone:	none → 5.0.0
status:	Fix Committed → Fix Released

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.