Authenticating with user 'admin' from the UI fails - Error in keystone.log

Bug #1636607 reported by kiran-vemuri
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Dashboard (Horizon)
Expired
Undecided
Unassigned
OpenStack Identity (keystone)
Expired
Undecided
Unassigned

Bug Description

I am setting up OpenStack Mitaka on Ubuntu 14.04 server by following : http://docs.openstack.org/mitaka/install-guide-ubuntu/

Once I install the dashboard, when I try to login using the 'admin' account, it gives me the following error on the UI 'An error occurred authenticating. Please try again later.'

On further investigation, I see the following error in /var/log/apache2/keystone.log

If you notice the last line, it is referring to 'build_auth_contet' in keystone-paste.ini which might be a typo for build_auth_context

========================================================================

2016-10-25 12:11:24.768822 2016-10-25 12:11:24.768 30696 WARNING keystone.assignment.core [-] Deprecated: Use of the identity driver config to automatically configure the same assignment driver has been deprecated, in the "O" release, the assignment driver will need to be expicitly configured if different than the default (SQL).
2016-10-25 12:11:24.887918 mod_wsgi (pid=30696): Target WSGI script '/usr/bin/keystone-wsgi-public' cannot be loaded as Python module.
2016-10-25 12:11:24.887945 mod_wsgi (pid=30696): Exception occurred processing WSGI script '/usr/bin/keystone-wsgi-public'.
2016-10-25 12:11:24.887979 Traceback (most recent call last):
2016-10-25 12:11:24.887995 File "/usr/bin/keystone-wsgi-public", line 36, in <module>
2016-10-25 12:11:24.888020 application = initialize_public_application()
2016-10-25 12:11:24.888033 File "/usr/lib/python2.7/dist-packages/keystone/server/wsgi.py", line 62, in initialize_public_application
2016-10-25 12:11:24.888062 return initialize_application('main')
2016-10-25 12:11:24.888071 File "/usr/lib/python2.7/dist-packages/keystone/server/wsgi.py", line 53, in initialize_application
2016-10-25 12:11:24.888083 startup_application_fn=loadapp)
2016-10-25 12:11:24.888092 File "/usr/lib/python2.7/dist-packages/keystone/server/common.py", line 51, in setup_backends
2016-10-25 12:11:24.888118 res = startup_application_fn()
2016-10-25 12:11:24.888126 File "/usr/lib/python2.7/dist-packages/keystone/server/wsgi.py", line 50, in loadapp
2016-10-25 12:11:24.888139 'config:%s' % config.find_paste_config(), name)
2016-10-25 12:11:24.888147 File "/usr/lib/python2.7/dist-packages/keystone/version/service.py", line 53, in loadapp
2016-10-25 12:11:24.888252 controllers.latest_app = deploy.loadapp(conf, name=name)
2016-10-25 12:11:24.888267 File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 247, in loadapp
2016-10-25 12:11:24.888448 return loadobj(APP, uri, name=name, **kw)
2016-10-25 12:11:24.888461 File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 272, in loadobj
2016-10-25 12:11:24.888475 return context.create()
2016-10-25 12:11:24.888484 File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 710, in create
2016-10-25 12:11:24.888498 return self.object_type.invoke(self)
2016-10-25 12:11:24.888508 File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 144, in invoke
2016-10-25 12:11:24.888534 **context.local_conf)
2016-10-25 12:11:24.888544 File "/usr/lib/python2.7/dist-packages/paste/deploy/util.py", line 55, in fix_call
2016-10-25 12:11:24.888593 val = callable(*args, **kw)
2016-10-25 12:11:24.888605 File "/usr/lib/python2.7/dist-packages/paste/urlmap.py", line 28, in urlmap_factory
2016-10-25 12:11:24.888685 app = loader.get_app(app_name, global_conf=global_conf)
2016-10-25 12:11:24.888710 File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 350, in get_app
2016-10-25 12:11:24.888726 name=name, global_conf=global_conf).create()
2016-10-25 12:11:24.888738 File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 362, in app_context
2016-10-25 12:11:24.888765 APP, name=name, global_conf=global_conf)
2016-10-25 12:11:24.888774 File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 450, in get_context
2016-10-25 12:11:24.888788 global_additions=global_additions)
2016-10-25 12:11:24.888797 File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 562, in _pipeline_app_context
2016-10-25 12:11:24.888810 for name in pipeline[:-1]]
2016-10-25 12:11:24.888819 File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 408, in get_context
2016-10-25 12:11:24.888833 object_type, name=name)
2016-10-25 12:11:24.888841 File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 587, in find_config_section
2016-10-25 12:11:24.888854 self.filename))
2016-10-25 12:11:24.888871 LookupError: No section 'build_auth_contet' (prefixed by 'filter') found in config /etc/keystone/keystone-paste.ini

========================================================================

Thanks,
Kiran Vemuri

-- Update:

I was able to work around the previous error by copying 'build_auth_context' filter to 'build_auth_contet' as follows

[filter:build_auth_contet]
use = egg:keystone#build_auth_context

[filter:build_auth_context]
use = egg:keystone#build_auth_context

and restart apache2

But now I see the following error in /var/log/apache2/error.log

============================================
 Login successful for user "admin".
[Tue Oct 25 20:45:29.480341 2016] [:error] [pid 26652:tid 139681872803584] Internal Server Error: /horizon/auth/login/
[Tue Oct 25 20:45:29.480374 2016] [:error] [pid 26652:tid 139681872803584] Traceback (most recent call last):
[Tue Oct 25 20:45:29.480386 2016] [:error] [pid 26652:tid 139681872803584] File "/usr/lib/python2.7/dist-packages/django/core/handlers/base.py", line 132, in get_response
[Tue Oct 25 20:45:29.480390 2016] [:error] [pid 26652:tid 139681872803584] response = wrapped_callback(request, *callback_args, **callback_kwargs)
[Tue Oct 25 20:45:29.480393 2016] [:error] [pid 26652:tid 139681872803584] File "/usr/lib/python2.7/dist-packages/django/views/decorators/debug.py", line 76, in sensitive_post_parameters_wrapper
[Tue Oct 25 20:45:29.480396 2016] [:error] [pid 26652:tid 139681872803584] return view(request, *args, **kwargs)
[Tue Oct 25 20:45:29.480399 2016] [:error] [pid 26652:tid 139681872803584] File "/usr/lib/python2.7/dist-packages/django/utils/decorators.py", line 110, in _wrapped_view
[Tue Oct 25 20:45:29.480401 2016] [:error] [pid 26652:tid 139681872803584] response = view_func(request, *args, **kwargs)
[Tue Oct 25 20:45:29.480404 2016] [:error] [pid 26652:tid 139681872803584] File "/usr/lib/python2.7/dist-packages/django/views/decorators/cache.py", line 57, in _wrapped_view_func
[Tue Oct 25 20:45:29.480418 2016] [:error] [pid 26652:tid 139681872803584] response = view_func(request, *args, **kwargs)
[Tue Oct 25 20:45:29.480421 2016] [:error] [pid 26652:tid 139681872803584] File "/usr/lib/python2.7/dist-packages/openstack_auth/views.py", line 111, in login
[Tue Oct 25 20:45:29.480423 2016] [:error] [pid 26652:tid 139681872803584] **kwargs)
[Tue Oct 25 20:45:29.480426 2016] [:error] [pid 26652:tid 139681872803584] File "/usr/lib/python2.7/dist-packages/django/views/decorators/debug.py", line 76, in sensitive_post_parameters_wrapper
[Tue Oct 25 20:45:29.480429 2016] [:error] [pid 26652:tid 139681872803584] return view(request, *args, **kwargs)
[Tue Oct 25 20:45:29.480431 2016] [:error] [pid 26652:tid 139681872803584] File "/usr/lib/python2.7/dist-packages/django/utils/decorators.py", line 110, in _wrapped_view
[Tue Oct 25 20:45:29.480434 2016] [:error] [pid 26652:tid 139681872803584] response = view_func(request, *args, **kwargs)
[Tue Oct 25 20:45:29.480436 2016] [:error] [pid 26652:tid 139681872803584] File "/usr/lib/python2.7/dist-packages/django/views/decorators/cache.py", line 57, in _wrapped_view_func
[Tue Oct 25 20:45:29.480439 2016] [:error] [pid 26652:tid 139681872803584] response = view_func(request, *args, **kwargs)
[Tue Oct 25 20:45:29.480441 2016] [:error] [pid 26652:tid 139681872803584] File "/usr/lib/python2.7/dist-packages/django/contrib/auth/views.py", line 51, in login
[Tue Oct 25 20:45:29.480444 2016] [:error] [pid 26652:tid 139681872803584] auth_login(request, form.get_user())
[Tue Oct 25 20:45:29.480446 2016] [:error] [pid 26652:tid 139681872803584] File "/usr/lib/python2.7/dist-packages/django/contrib/auth/__init__.py", line 110, in login
[Tue Oct 25 20:45:29.480449 2016] [:error] [pid 26652:tid 139681872803584] request.session.cycle_key()
[Tue Oct 25 20:45:29.480452 2016] [:error] [pid 26652:tid 139681872803584] File "/usr/lib/python2.7/dist-packages/django/contrib/sessions/backends/base.py", line 285, in cycle_key
[Tue Oct 25 20:45:29.480454 2016] [:error] [pid 26652:tid 139681872803584] self.create()
[Tue Oct 25 20:45:29.480457 2016] [:error] [pid 26652:tid 139681872803584] File "/usr/lib/python2.7/dist-packages/django/contrib/sessions/backends/cache.py", line 48, in create
[Tue Oct 25 20:45:29.480459 2016] [:error] [pid 26652:tid 139681872803584] "Unable to create a new session key. "
[Tue Oct 25 20:45:29.480462 2016] [:error] [pid 26652:tid 139681872803584] RuntimeError: Unable to create a new session key. It is likely that the cache is unavailable.

============================================

description: updated
description: updated
description: updated
Revision history for this message
Itxaka Serrano (itxaka) wrote :

Kiran,

can you obtain a token through the CLI? Maybe keystone is not set up properly so we should first check if it works properly.

Revision history for this message
kiran-vemuri (kiran-vemuri) wrote :

Itxaka,

I am able to fetch token and run all openstack cli commands after sourcing admin-openrc file.

Revision history for this message
Rob Cresswell (robcresswell-deactivatedaccount) wrote :

What cache do you have set up? Specifically the value for `CACHES` in openstack_dashboard/local/local_settings.py

Changed in horizon:
status: New → Incomplete
Revision history for this message
Steve Martinelli (stevemar) wrote :

The typo is a bit unsettling, were you using a specific distribution of openstack/keystone ? It should definitely not be "build_auth_contet". I checked our sample files and they look OK.

Changed in keystone:
status: New → Incomplete
Revision history for this message
kiran-vemuri (kiran-vemuri) wrote :

Rob,

I have the following in my /etc/openstack-dashboard/local_settings.py and /usr/share/openstack-dashboard/openstack_dashboard/local/local_settings.py

CACHES = {
    'default': {
        'BACKEND': 'django.core.cache.backends.memcached.MemcachedCache',
        'LOCATION': 'IP_Address:11211',
    },
}

Were you referring to local_settings in some other location?

Revision history for this message
kiran-vemuri (kiran-vemuri) wrote :

Steve,

I am just following the Mitaka installation document on docs.openstack.org to setup OpenStack. So I have the keystone distribution that is installed by running the commands in the guide.

Could you please let me know if there's a way to check keystone distribution? When I do keystone --version, it gives me the CLI version 2.3.1 and since it is Mitaka, I am using keystonV3

Also, I tried removing the workaround 'build_auth_contet' I added in keystone-paste.ini and I see the following behavior.

1. sourcing admin-openrc and token issue works perfectly.
2. sourcing demo-openrc and token issue gives the following error.
Discovering versions from the identity service failed when creating the password plugin. Attempting to determine version from URL.
Internal Server Error (HTTP 500)

3. Horizon gives the error I described earlier when I try to login.
LookupError: No section 'build_auth_contet' (prefixed by 'filter') found in config /etc/keystone/keystone-paste.ini

But when I re add it and restart apache2, everything works perfectly.

Revision history for this message
Launchpad Janitor (janitor) wrote :

[Expired for OpenStack Dashboard (Horizon) because there has been no activity for 60 days.]

Changed in horizon:
status: Incomplete → Expired
Revision history for this message
Launchpad Janitor (janitor) wrote :

[Expired for OpenStack Identity (keystone) because there has been no activity for 60 days.]

Changed in keystone:
status: Incomplete → Expired
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.