nova api error Malformed request URL: URL's project_id '$project_id' doesn't match Context's project_id '$request_token'

Bug #1317854 reported by Robert Collins
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
tripleo
Fix Released
Critical
Robert Collins

Bug Description

Folk in TripleO are seeing nova list fail with an error about Malformed url - but the claimed context.project_id has the same context as the request token novaclient is given by keystone.

sample trace at http://paste.ubuntu.com/7420801/ (nova --debug list) (and throwaway setup :))

description: updated
Revision history for this message
Robert Collins (lifeless) wrote :

adding insult to injury, the code for this doesn't emit a stacktrace, so I need to either patch it or use ta debugg to inspect whats going on.

Revision history for this message
Robert Collins (lifeless) wrote :

2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack Traceback (most recent call last):
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/api/openstack/__init__.py", line 125, in __call__
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack return req.get_response(self.application)
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1320, in send
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack application, catch_exc_info=False)
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1284, in call_application
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack app_iter = application(self.environ, start_response)
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack return resp(environ, start_response)
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack return resp(environ, start_response)
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack return resp(environ, start_response)
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack return resp(environ, start_response)
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/routes/middleware.py", line 131, in __call__
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack response = self.app(environ, start_response)
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack return resp(environ, start_response)
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack resp = self.call_func(req, *args, **self.kwargs)
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack return self.func(req, *args, **kwargs)
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 917, in __call__
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack content_type, body, accept)
2014-05-09 11:00:35.959 6512 TRACE nova.api.openstack File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 974, in _process_stack

Revision history for this message
Robert Collins (lifeless) wrote :

I've tested with latest git novaclient and it made no difference.

Revision history for this message
Robert Collins (lifeless) wrote :

python-novaclient==2.17.0.93.g02940f2 specifically

Revision history for this message
Robert Collins (lifeless) wrote :
Download full text (9.6 KiB)

The API context is all messed up:

(Pdb) request.environ['nova.context']
<nova.context.RequestContext object at 0x7f700b413590>

Note how:
user_id *and* project_id are both set to the auth token, and the authtoken is set to None.
(Pdb) request.environ['nova.context'].__dict__
{'project_name': None, 'user_id': 'MIINbwYJKoZIhvcNAQcCoIINYDCCDVwCAQExDTALBglghkgBZQMEAgEwggu9BgkqhkiG9w0BBwGggguuBIILqnsiYWNjZXNzIjogeyJ0b2tlbiI6IHsiaXNzdWVkX2F0IjogIjIwMTQtMDUtMDlUMTE6MjQ6MDguNjI5MjYzIiwgImV4cGlyZXMiOiAiMjAxNC0wNS0wOVQxMjoyNDowOFoiLCAiaWQiOiAicGxhY2Vob2xkZXIiLCAidGVuYW50IjogeyJkZXNjcmlwdGlvbiI6IG51bGwsICJlbmFibGVkIjogdHJ1ZSwgImlkIjogIjYxZmQ3MzIzMmRkODRjZGY5NDVmZTA4OWQ0YWYzNjVhIiwgIm5hbWUiOiAiYWRtaW4ifX0sICJzZXJ2aWNlQ2F0YWxvZyI6IFt7ImVuZHBvaW50cyI6IFt7ImFkbWluVVJMIjogImh0dHA6Ly8xMC4yMi4xNTcuMTQ1Ojg3NzQvdjIvNjFmZDczMjMyZGQ4NGNkZjk0NWZlMDg5ZDRhZjM2NWEiLCAicmVnaW9uIjogInJlZ2lvbk9uZSIsICJpbnRlcm5hbFVSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo4Nzc0L3YyLzYxZmQ3MzIzMmRkODRjZGY5NDVmZTA4OWQ0YWYzNjVhIiwgImlkIjogImViYjM4NzZmODlkMjRmMDk5MzI5ZTI2NzczZmYzZTBkIiwgInB1YmxpY1VSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo4Nzc0L3YyLzYxZmQ3MzIzMmRkODRjZGY5NDVmZTA4OWQ0YWYzNjVhIn1dLCAiZW5kcG9pbnRzX2xpbmtzIjogW10sICJ0eXBlIjogImNvbXB1dGUiLCAibmFtZSI6ICJub3ZhIn0sIHsiZW5kcG9pbnRzIjogW3siYWRtaW5VUkwiOiAiaHR0cDovLzEwLjIyLjE1Ny4xNDU6OTY5Ni8iLCAicmVnaW9uIjogInJlZ2lvbk9uZSIsICJpbnRlcm5hbFVSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo5Njk2LyIsICJpZCI6ICIwMGQ5OGZkYmM5YTM0YmFhOTYwYTRlZDFiNWJkYTM2NiIsICJwdWJsaWNVUkwiOiAiaHR0cDovLzEwLjIyLjE1Ny4xNDU6OTY5Ni8ifV0sICJlbmRwb2ludHNfbGlua3MiOiBbXSwgInR5cGUiOiAibmV0d29yayIsICJuYW1lIjogIm5ldXRyb24ifSwgeyJlbmRwb2ludHMiOiBbeyJhZG1pblVSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo4Nzc0L3YzIiwgInJlZ2lvbiI6ICJyZWdpb25PbmUiLCAiaW50ZXJuYWxVUkwiOiAiaHR0cDovLzEwLjIyLjE1Ny4xNDU6ODc3NC92MyIsICJpZCI6ICIxOTU2MjlhZTc1ZWY0MDEyOWMwNTFkNTExMThmZDY4NCIsICJwdWJsaWNVUkwiOiAiaHR0cDovLzEwLjIyLjE1Ny4xNDU6ODc3NC92MyJ9XSwgImVuZHBvaW50c19saW5rcyI6IFtdLCAidHlwZSI6ICJjb21wdXRldjMiLCAibmFtZSI6ICJub3ZhIn0sIHsiZW5kcG9pbnRzIjogW3siYWRtaW5VUkwiOiAiaHR0cDovLzEwLjIyLjE1Ny4xNDU6OTI5Mi8iLCAicmVnaW9uIjogInJlZ2lvbk9uZSIsICJpbnRlcm5hbFVSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo5MjkyLyIsICJpZCI6ICIxNWNmYmYyN2QyNmU0NTJmYjk0NTYyNTViOTA3ZTAwOSIsICJwdWJsaWNVUkwiOiAiaHR0cDovLzEwLjIyLjE1Ny4xNDU6OTI5Mi8ifV0sICJlbmRwb2ludHNfbGlua3MiOiBbXSwgInR5cGUiOiAiaW1hZ2UiLCAibmFtZSI6ICJnbGFuY2UifSwgeyJlbmRwb2ludHMiOiBbeyJhZG1pblVSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo2Mzg1LyIsICJyZWdpb24iOiAicmVnaW9uT25lIiwgImludGVybmFsVVJMIjogImh0dHA6Ly8xMC4yMi4xNTcuMTQ1OjYzODUvIiwgImlkIjogIjFmNjNmZjEyYWY5ODQxNTRhOTc0Mjk5MzQ0ZjU3M2UwIiwgInB1YmxpY1VSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo2Mzg1LyJ9XSwgImVuZHBvaW50c19saW5rcyI6IFtdLCAidHlwZSI6ICJiYXJlbWV0YWwiLCAibmFtZSI6ICJpcm9uaWMifSwgeyJlbmRwb2ludHMiOiBbeyJhZG1pblVSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo4NzczL3NlcnZpY2VzL0FkbWluIiwgInJlZ2lvbiI6ICJyZWdpb25PbmUiLCAiaW50ZXJuYWxVUkwiOiAiaHR0cDovLzEwLjIyLjE1Ny4xNDU6ODc3My9zZXJ2aWNlcy9DbG91ZCIsICJpZCI6ICIzNDNkMGFiM2M5M2E0ZmVmYTE3MzU2ZDhjYjYwYjA2MCIsICJwdWJsaWNVUkwiOiAiaHR0cDovLzEwLjIyLjE1Ny4xNDU6ODc3My9zZXJ2aWNlcy9DbG91ZCJ9XSwgImVuZHBvaW50c19saW5rcyI6IFtdLCAidHlwZSI6ICJlYzIiLCAibmFtZSI6ICJlYzIifSwgeyJlbmRwb2ludHMiOiBbeyJhZG1pblVSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo4MDA0L3YxLzYxZmQ3...

Read more...

Revision history for this message
Robert Collins (lifeless) wrote :
Download full text (9.5 KiB)

RequestContext is being created with auth_token None and user_id and project_id wrong.

-> return self.func(req, *args, **kwargs)
  /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/api/openstack/auth.py(69)__call__()
-> return self.base_call(req, True)
  /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/api/openstack/auth.py(59)base_call()
-> remote_address=remote_address)
> /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/context.py(68)__init__()
-> self.user_id = user_id
(Pdb) print auth_token
None
(Pdb) print user_id
MIINbwYJKoZIhvcNAQcCoIINYDCCDVwCAQExDTALBglghkgBZQMEAgEwggu9BgkqhkiG9w0BBwGggguuBIILqnsiYWNjZXNzIjogeyJ0b2tlbiI6IHsiaXNzdWVkX2F0IjogIjIwMTQtMDUtMDlUMTE6Mjk6MDQuOTE2OTM3IiwgImV4cGlyZXMiOiAiMjAxNC0wNS0wOVQxMjoyOTowNFoiLCAiaWQiOiAicGxhY2Vob2xkZXIiLCAidGVuYW50IjogeyJkZXNjcmlwdGlvbiI6IG51bGwsICJlbmFibGVkIjogdHJ1ZSwgImlkIjogIjYxZmQ3MzIzMmRkODRjZGY5NDVmZTA4OWQ0YWYzNjVhIiwgIm5hbWUiOiAiYWRtaW4ifX0sICJzZXJ2aWNlQ2F0YWxvZyI6IFt7ImVuZHBvaW50cyI6IFt7ImFkbWluVVJMIjogImh0dHA6Ly8xMC4yMi4xNTcuMTQ1Ojg3NzQvdjIvNjFmZDczMjMyZGQ4NGNkZjk0NWZlMDg5ZDRhZjM2NWEiLCAicmVnaW9uIjogInJlZ2lvbk9uZSIsICJpbnRlcm5hbFVSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo4Nzc0L3YyLzYxZmQ3MzIzMmRkODRjZGY5NDVmZTA4OWQ0YWYzNjVhIiwgImlkIjogImViYjM4NzZmODlkMjRmMDk5MzI5ZTI2NzczZmYzZTBkIiwgInB1YmxpY1VSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo4Nzc0L3YyLzYxZmQ3MzIzMmRkODRjZGY5NDVmZTA4OWQ0YWYzNjVhIn1dLCAiZW5kcG9pbnRzX2xpbmtzIjogW10sICJ0eXBlIjogImNvbXB1dGUiLCAibmFtZSI6ICJub3ZhIn0sIHsiZW5kcG9pbnRzIjogW3siYWRtaW5VUkwiOiAiaHR0cDovLzEwLjIyLjE1Ny4xNDU6OTY5Ni8iLCAicmVnaW9uIjogInJlZ2lvbk9uZSIsICJpbnRlcm5hbFVSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo5Njk2LyIsICJpZCI6ICIwMGQ5OGZkYmM5YTM0YmFhOTYwYTRlZDFiNWJkYTM2NiIsICJwdWJsaWNVUkwiOiAiaHR0cDovLzEwLjIyLjE1Ny4xNDU6OTY5Ni8ifV0sICJlbmRwb2ludHNfbGlua3MiOiBbXSwgInR5cGUiOiAibmV0d29yayIsICJuYW1lIjogIm5ldXRyb24ifSwgeyJlbmRwb2ludHMiOiBbeyJhZG1pblVSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo4Nzc0L3YzIiwgInJlZ2lvbiI6ICJyZWdpb25PbmUiLCAiaW50ZXJuYWxVUkwiOiAiaHR0cDovLzEwLjIyLjE1Ny4xNDU6ODc3NC92MyIsICJpZCI6ICIxOTU2MjlhZTc1ZWY0MDEyOWMwNTFkNTExMThmZDY4NCIsICJwdWJsaWNVUkwiOiAiaHR0cDovLzEwLjIyLjE1Ny4xNDU6ODc3NC92MyJ9XSwgImVuZHBvaW50c19saW5rcyI6IFtdLCAidHlwZSI6ICJjb21wdXRldjMiLCAibmFtZSI6ICJub3ZhIn0sIHsiZW5kcG9pbnRzIjogW3siYWRtaW5VUkwiOiAiaHR0cDovLzEwLjIyLjE1Ny4xNDU6OTI5Mi8iLCAicmVnaW9uIjogInJlZ2lvbk9uZSIsICJpbnRlcm5hbFVSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo5MjkyLyIsICJpZCI6ICIxNWNmYmYyN2QyNmU0NTJmYjk0NTYyNTViOTA3ZTAwOSIsICJwdWJsaWNVUkwiOiAiaHR0cDovLzEwLjIyLjE1Ny4xNDU6OTI5Mi8ifV0sICJlbmRwb2ludHNfbGlua3MiOiBbXSwgInR5cGUiOiAiaW1hZ2UiLCAibmFtZSI6ICJnbGFuY2UifSwgeyJlbmRwb2ludHMiOiBbeyJhZG1pblVSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo2Mzg1LyIsICJyZWdpb24iOiAicmVnaW9uT25lIiwgImludGVybmFsVVJMIjogImh0dHA6Ly8xMC4yMi4xNTcuMTQ1OjYzODUvIiwgImlkIjogIjFmNjNmZjEyYWY5ODQxNTRhOTc0Mjk5MzQ0ZjU3M2UwIiwgInB1YmxpY1VSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo2Mzg1LyJ9XSwgImVuZHBvaW50c19saW5rcyI6IFtdLCAidHlwZSI6ICJiYXJlbWV0YWwiLCAibmFtZSI6ICJpcm9uaWMifSwgeyJlbmRwb2ludHMiOiBbeyJhZG1pblVSTCI6ICJodHRwOi8vMTAuMjIuMTU3LjE0NTo4NzczL3NlcnZpY2VzL0FkbWluIiwgInJlZ2lvbiI6ICJyZWdpb25PbmUiLCAiaW50ZXJuYWxVUkwiOiAiaHR0cDovLzEwLjIyLjE1Ny4xNDU6ODc3My9zZXJ2aWNlcy9DbG91ZCIsICJpZCI6ICIzNDNkMGFiM2M5M2E0ZmVmYTE3MzU2ZDh...

Read more...

Revision history for this message
Robert Collins (lifeless) wrote :

We know the request had -H "X-Auth-Token: MIINbwYJK ....

        token = req.headers['X-Auth-Token']
        user_id, _sep, project_id = token.partition(':')

is how the token is processed by the middleware code to get user_id,project_id out of it.

Unfortunately, the token isn't in that format!

Revision history for this message
Robert Collins (lifeless) wrote :

(Pdb) print CONF.auth_strategy
noauth
(Pdb) bt
  /opt/stack/venvs/nova/bin/nova-api(10)<module>()
-> sys.exit(main())
  /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/cmd/api.py(51)main()
-> max_url_len=16384)
  /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/service.py(331)__init__()
-> self.app = self.loader.load_app(name)
  /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/wsgi.py(502)load_app()
-> return deploy.loadapp("config:%s" % self.config_path, name=name)
  /opt/stack/venvs/nova/local/lib/python2.7/site-packages/paste/deploy/loadwsgi.py(247)loadapp()
-> return loadobj(APP, uri, name=name, **kw)
  /opt/stack/venvs/nova/local/lib/python2.7/site-packages/paste/deploy/loadwsgi.py(272)loadobj()
-> return context.create()
  /opt/stack/venvs/nova/local/lib/python2.7/site-packages/paste/deploy/loadwsgi.py(710)create()
-> return self.object_type.invoke(self)
  /opt/stack/venvs/nova/local/lib/python2.7/site-packages/paste/deploy/loadwsgi.py(144)invoke()
-> **context.local_conf)
  /opt/stack/venvs/nova/local/lib/python2.7/site-packages/paste/deploy/util.py(55)fix_call()
-> val = callable(*args, **kw)
  /usr/lib/python2.7/dist-packages/paste/urlmap.py(28)urlmap_factory()
-> app = loader.get_app(app_name, global_conf=global_conf)
  /opt/stack/venvs/nova/local/lib/python2.7/site-packages/paste/deploy/loadwsgi.py(350)get_app()
-> name=name, global_conf=global_conf).create()
  /opt/stack/venvs/nova/local/lib/python2.7/site-packages/paste/deploy/loadwsgi.py(710)create()
-> return self.object_type.invoke(self)
  /opt/stack/venvs/nova/local/lib/python2.7/site-packages/paste/deploy/loadwsgi.py(144)invoke()
-> **context.local_conf)
  /opt/stack/venvs/nova/local/lib/python2.7/site-packages/paste/deploy/util.py(55)fix_call()
-> val = callable(*args, **kw)
> /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/api/auth.py(74)pipeline_factory()
-> return _load_pipeline(loader, pipeline)
  /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/api/auth.py(53)_load_pipeline()
-> filters = [loader.get_filter(n) for n in pipeline[:-1]]

so - the question is why.

no longer affects: nova
Changed in tripleo:
assignee: nobody → Robert Collins (lifeless)
status: Triaged → In Progress
Revision history for this message
Robert Collins (lifeless) wrote :

The why is: building with --offline for speed, I had an icehouse era nova tree. Which we should be able to deploy, as while we don't consider tripleo *finished*, we do want to be useful to a wide variety of use cases.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to tripleo-image-elements (master)

Reviewed: https://review.openstack.org/93027
Committed: https://git.openstack.org/cgit/openstack/tripleo-image-elements/commit/?id=e519de3b62b99e0d823cbd0825517f5a3d69db70
Submitter: Jenkins
Branch: master

commit e519de3b62b99e0d823cbd0825517f5a3d69db70
Author: Robert Collins <email address hidden>
Date: Sat May 10 00:01:35 2014 +1200

    Revert "Remove auth_strategy from nova.conf"

    This reverts commit a3fdcba84f6f3d6e47ee112b934a839773f27582.

    While trunk Nova has indeed made the referenced changed to default to
    keystone, Icehouse has not, and we want to deploy current stable +
    trunk from TripleO trunk.

    Closes-Bug: #1317854
    Change-Id: I42acc3851811703960feb40bc4ce0e895ee57c05

Changed in tripleo:
status: In Progress → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

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