OpenStack Compute (nova)

nova-api crash - keystone.middleware.auth_token broken

Bug #1143998 reported by Sandeep Raman
24
This bug affects 4 people
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Invalid
Undecided
Unassigned
OpenStack Identity (keystone)
Fix Released
Medium
Dolph Mathews
OpenStack Identity (keystone) 2013.1 "grizzly"

Bug Description

OS: Ubuntu Raring
nova-api version: 1:2013.1+git201303021031~raring-0ubuntu1

Problem Description: Fresh install of Raring and Grizzly, nova-api crashes. The following message is logged in nova-api.log.

TRACE nova File "/usr/lib/python2.7/dist-packages/oslo/config/cfg.py", line 1244, in register_cli_opts
TRACE nova self.register_cli_opt(opt, group, clear_cache=False)
TRACE nova File "/usr/lib/python2.7/dist-packages/oslo/config/cfg.py", line 1091, in __inner
TRACE nova return f(self, *args, **kwargs)
TRACE nova File "/usr/lib/python2.7/dist-packages/oslo/config/cfg.py", line 1236, in register_cli_opt
TRACE nova raise ArgsAlreadyParsedError("cannot register CLI option")
TRACE nova ArgsAlreadyParsedError: arguments already parsed: cannot register CLI option
TRACE nova
INFO nova.service [-] Parent process has died unexpectedly, exiting
INFO nova.wsgi [-] Stopping WSGI server.

Revision history for this message
Chuck Short (zulcss) wrote :

Can you please attach your nova.conf file?

Changed in nova:
status: New → Incomplete
Revision history for this message
Sandeep Raman (sandeep-raman) wrote :

Attached the following:
1. api-paste.ini
2. nova-compute.conf
3. nova.conf

controller and compute is the same vm.

Revision history for this message
Mark McLoughlin (markmc) wrote :

This error basically means that CONF.register_cli_opt() is being called after CONF()

We should be able to fix that, but could you attached the full traceback showing where CONF.register_cli_opt() is being called from?

Revision history for this message
Ionuț Arțăriși (mapleoin) wrote :

@Mark: just try running nova-api. nova-config calls cfg.CONF. Then it imports keystone which tries to set more config options in keystone.config.

Revision history for this message
Mark McLoughlin (markmc) wrote :

ionut: a traceback please

Revision history for this message
Ionuț Arțăriși (mapleoin) wrote :
Download full text (6.1 KiB)

# nova-api
2013-03-05 14:48:11.823 26837 INFO nova.wsgi [-] ec2 listening on 0.0.0.0:8773
2013-03-05 14:48:11.823 26837 INFO nova.service [-] Starting 1 workers
2013-03-05 14:48:11.825 26837 INFO nova.service [-] Started child 26844
2013-03-05 14:48:11.835 26844 INFO nova.ec2.wsgi.server [-] (26844) wsgi starting up on http://0.0.0.0:8773/

2013-03-05 14:48:11.846 26837 CRITICAL nova [-] arguments already parsed: cannot register CLI option
2013-03-05 14:48:11.846 26837 TRACE nova Traceback (most recent call last):
2013-03-05 14:48:11.846 26837 TRACE nova File "/usr/bin/nova-api", line 61, in <module>
2013-03-05 14:48:11.846 26837 TRACE nova server = service.WSGIService(api, use_ssl=should_use_ssl)
2013-03-05 14:48:11.846 26837 TRACE nova File "/usr/lib64/python2.6/site-packages/nova/service.py", line 598, in __init__
2013-03-05 14:48:11.846 26837 TRACE nova self.app = self.loader.load_app(name)
2013-03-05 14:48:11.846 26837 TRACE nova File "/usr/lib64/python2.6/site-packages/nova/wsgi.py", line 481, in load_app
2013-03-05 14:48:11.846 26837 TRACE nova return deploy.loadapp("config:%s" % self.config_path, name=name)
2013-03-05 14:48:11.846 26837 TRACE nova File "/usr/lib64/python2.6/site-packages/paste/deploy/loadwsgi.py", line 247, in loadapp
2013-03-05 14:48:11.846 26837 TRACE nova return loadobj(APP, uri, name=name, **kw)
2013-03-05 14:48:11.846 26837 TRACE nova File "/usr/lib64/python2.6/site-packages/paste/deploy/loadwsgi.py", line 272, in loadobj
2013-03-05 14:48:11.846 26837 TRACE nova return context.create()
2013-03-05 14:48:11.846 26837 TRACE nova File "/usr/lib64/python2.6/site-packages/paste/deploy/loadwsgi.py", line 710, in create
2013-03-05 14:48:11.846 26837 TRACE nova return self.object_type.invoke(self)
2013-03-05 14:48:11.846 26837 TRACE nova File "/usr/lib64/python2.6/site-packages/paste/deploy/loadwsgi.py", line 144, in invoke
2013-03-05 14:48:11.846 26837 TRACE nova **context.local_conf)
2013-03-05 14:48:11.846 26837 TRACE nova File "/usr/lib64/python2.6/site-packages/paste/deploy/util.py", line 56, in fix_call
2013-03-05 14:48:11.846 26837 TRACE nova val = callable(*args, **kw)
2013-03-05 14:48:11.846 26837 TRACE nova File "/usr/lib64/python2.6/site-packages/nova/api/openstack/urlmap.py", line 163, in urlmap_factory
2013-03-05 14:48:11.846 26837 TRACE nova app = loader.get_app(app_name, global_conf=global_conf)
2013-03-05 14:48:11.846 26837 TRACE nova File "/usr/lib64/python2.6/site-packages/paste/deploy/loadwsgi.py", line 350, in get_app
2013-03-05 14:48:11.846 26837 TRACE nova name=name, global_conf=global_conf).create()
2013-03-05 14:48:11.846 26837 TRACE nova File "/usr/lib64/python2.6/site-packages/paste/deploy/loadwsgi.py", line 362, in app_context
2013-03-05 14:48:11.846 26837 TRACE nova APP, name=name, global_conf=global_conf)
2013-03-05 14:48:11.846 26837 TRACE nova File "/usr/lib64/python2.6/site-packages/paste/deploy/loadwsgi.py", line 450, in get_context
2013-03-05 14:48:11.846 26837 TRACE nova global_additions=global_additions)
2013-03-05 14:48:11.846 26837 TRACE nova File "/usr/lib64/python2.6/site-packages/paste/deploy/loadwsgi.py", li...

Read more...

Revision history for this message
Mark McLoughlin (markmc) wrote :

This:

  [filter:authtoken]
  paste.filter_factory = keystone.middleware.auth_token:filter_factory

is the issue, it should be this:

  [filter:authtoken]
  paste.filter_factory = keystoneclient.middleware.auth_token:filter_factory

the auth_token middleware in keystone should probably be deleted

moving there

Changed in nova:
status: Incomplete → Invalid
summary: - nova-api crash - grizzly/raring
+ nova-api crash - keystone.middleware.auth_token broken
Revision history for this message
Mark McLoughlin (markmc) wrote :

If keystone.middleware.auth_token sticks around, it shouldn't cause CONF.register_cli_opt() to be called

Revision history for this message
Sandeep Raman (sandeep-raman) wrote :

Thanks MarkMc, changing to keystoneclient got the nova api service running. The "keystone" without "client" worked in Folsom and perhaps the nova build prior to the current one. Does it mean there has been a change in the new nova build which caused the issue?

Revision history for this message
Dolph Mathews (dolph) wrote :

Sounds like this is resolved? auth_token has been moved to keystoneclient in Grizzly.

Changed in keystone:
status: New → Invalid
Revision history for this message
Mark McLoughlin (markmc) wrote :

Dolph - there's still a keystone.middleware.auth_token module in there for compatibility. I suspect it's broken because keystone.config registers CLI options

Either needs to be removed or fixed, I guess

Changed in keystone:
status: Invalid → Confirmed
Revision history for this message
Dolph Mathews (dolph) wrote :

Ah, so keystone.middleware.auth_token triggers keystone.middleware.__init__ to be imported, which imports everything from keystone.middleware.core, which imports keystone.config :)

I'm not sure what the best fix is here?

Changed in keystone:
importance: Undecided → Medium
milestone: none → grizzly-rc1
Revision history for this message
Sandeep Raman (sandeep-raman) wrote :

I saw the same issue with cinder-api and solved after changing to keystoneclient. I'll log a separate defect for cinder for tracking?

Adam Young (ayoung)
Changed in keystone:
assignee: nobody → Dolph Mathews (dolph)
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to keystone (master)

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

Changed in keystone:
status: Confirmed → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to python-keystoneclient (master)

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

Changed in python-keystoneclient:
assignee: nobody → Dolph Mathews (dolph)
status: New → In Progress
Dolph Mathews (dolph)
Changed in python-keystoneclient:
importance: Undecided → Medium
Dolph Mathews (dolph)
no longer affects: python-keystoneclient
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to keystone (master)

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

Revision history for this message
Dolph Mathews (dolph) wrote :

Sandeep- would you be able to test this patch in your configuration? https://review.openstack.org/#/c/24701/

Revision history for this message
Sandeep Raman (sandeep-raman) wrote :

Dolph, during the recent installs i have noticed the package by default has keystoneclient set. Do i still need to test the patch? If yes, please help me with the steps to test the patch.

Revision history for this message
Dolph Mathews (dolph) wrote :

Sandeep: it should just be a matter of setting your authtoken middleware back to 'keystone' in nova.conf:

  [filter:authtoken]
  paste.filter_factory = keystone.middleware.auth_token:filter_factory

Revision history for this message
Dolph Mathews (dolph) wrote :

Sorry, nova's api-paste.ini *

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

Reviewed: https://review.openstack.org/24701
Committed: http://github.com/openstack/keystone/commit/7db01cd64be2ab3ed5ffc00636d187ef432294b2
Submitter: Jenkins
Branch: master

commit 7db01cd64be2ab3ed5ffc00636d187ef432294b2
Author: Dolph Mathews <email address hidden>
Date: Tue Mar 19 17:15:25 2013 -0500

    Wrap config module and require manual setup (bug 1143998)

    This moves keystone.config to keystone.common.config, which requires
    .configure() to be called manually in order for options to be
    registered.

    keystone.config preserves the existing behavior of automatically
    registering options when imported.

    keystone.middleware.auth_token and it's dependencies within keystone no
    longer cause config options to be automatically registered.

    This is an alternative to https://review.openstack.org/#/c/24251/

    Change-Id: If9eb5799bf77595ecb71f2000f8b6d1610ea9700

Changed in keystone:
status: In Progress → Fix Committed
Thierry Carrez (ttx)
Changed in keystone:
status: Fix Committed → Fix Released
Thierry Carrez (ttx)
Changed in keystone:
milestone: grizzly-rc1 → 2013.1
Revision history for this message
Nitisha Jain (nitishajain15) wrote :
Download full text (7.0 KiB)

hi

I have a similar issue , when I run nova-api and nova-compute on Nova grizzly ,Ubuntu Precise..

I already have following settings in api-paste.ini :

[filter:authtoken]
paste.filter_factory = keystoneclient.middleware.auth_token:filter_factory

Still the issue persists.. what can I do to resolve this ??

2013-06-03 14:53:10.797 18356 CRITICAL nova [-] arguments already parsed: cannot register CLI option
2013-06-03 14:53:10.797 18356 TRACE nova Traceback (most recent call last):
2013-06-03 14:53:10.797 18356 TRACE nova File "./nova-api", line 5, in <module>
2013-06-03 14:53:10.797 18356 TRACE nova pkg_resources.run_script('nova==2013.1.1', 'nova-api')
2013-06-03 14:53:10.797 18356 TRACE nova File "/usr/lib/python2.7/dist-packages/pkg_resources.py", line 499, in run_script
2013-06-03 14:53:10.797 18356 TRACE nova self.require(requires)[0].run_script(script_name, ns)
2013-06-03 14:53:10.797 18356 TRACE nova File "/usr/lib/python2.7/dist-packages/pkg_resources.py", line 1235, in run_script
2013-06-03 14:53:10.797 18356 TRACE nova execfile(script_filename, namespace, namespace)
2013-06-03 14:53:10.797 18356 TRACE nova File "/usr/local/lib/python2.7/dist-packages/nova-2013.1.1-py2.7.egg/EGG-INFO/scripts/nova-api", line 59, in <module>
2013-06-03 14:53:10.797 18356 TRACE nova max_url_len=16384)
2013-06-03 14:53:10.797 18356 TRACE nova File "/usr/local/lib/python2.7/dist-packages/nova-2013.1.1-py2.7.egg/nova/service.py", line 598, in __init__
2013-06-03 14:53:10.797 18356 TRACE nova self.app = self.loader.load_app(name)
2013-06-03 14:53:10.797 18356 TRACE nova File "/usr/local/lib/python2.7/dist-packages/nova-2013.1.1-py2.7.egg/nova/wsgi.py", line 482, in load_app
2013-06-03 14:53:10.797 18356 TRACE nova return deploy.loadapp("config:%s" % self.config_path, name=name)
2013-06-03 14:53:10.797 18356 TRACE nova File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 247, in loadapp
2013-06-03 14:53:10.797 18356 TRACE nova return loadobj(APP, uri, name=name, **kw)
2013-06-03 14:53:10.797 18356 TRACE nova File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 272, in loadobj
2013-06-03 14:53:10.797 18356 TRACE nova return context.create()
2013-06-03 14:53:10.797 18356 TRACE nova File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 710, in create
2013-06-03 14:53:10.797 18356 TRACE nova return self.object_type.invoke(self)
2013-06-03 14:53:10.797 18356 TRACE nova File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 144, in invoke
2013-06-03 14:53:10.797 18356 TRACE nova **context.local_conf)
2013-06-03 14:53:10.797 18356 TRACE nova File "/usr/lib/python2.7/dist-packages/paste/deploy/util.py", line 56, in fix_call
2013-06-03 14:53:10.797 18356 TRACE nova val = callable(*args, **kw)
2013-06-03 14:53:10.797 18356 TRACE nova File "/usr/lib/python2.7/dist-packages/paste/urlmap.py", line 25, in urlmap_factory
2013-06-03 14:53:10.797 18356 TRACE nova app = loader.get_app(app_name, global_conf=global_conf)
2013-06-03 14:53:10.797 18356 TRACE nova File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 3...

Read more...

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

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