Internal error Enabling Federation Extension

[Marcos Lobo]

Following steps here http://docs.openstack.org/developer/keystone/extensions/federation.html I've realized of a possible bug, but I'm not sure, let me explain myself.

Step 3 of http://docs.openstack.org/developer/keystone/extensions/federation.html
[pipeline:api_v3]
pipeline = access_log sizelimit url_normalize token_auth admin_token_auth xml_body json_body ec2_extension s3_extension federation_extension service_v3

Ok, no problems. Restart keystone (under apache) and type keystone tenant-list command and every is fine, no problems.

Now, modify again keystone-paste.ini file (by the way, on a fresh keystone installation this file is called keystone-dist-paste.ini by default) and put "federation_extenstion" at the end of the line, like:

[pipeline:api_v3]
pipeline = access_log sizelimit url_normalize token_auth admin_token_auth xml_body json_body ec2_extension s3_extension service_v3 federation_extension

Restart keystone and when you type keystone tenant-list command, keystone raises: Internal Server Error 500

This is the log information about this error:

[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] mod_wsgi (pid=24803): Target WSGI script '/var/www/cgi-bin/keystone/main' cannot be loaded as Python module.
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] mod_wsgi (pid=24803): Exception occurred processing WSGI script '/var/www/cgi-bin/keystone/main'.
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] Traceback (most recent call last):
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] File "/var/www/cgi-bin/keystone/main", line 58, in <module>
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] name=name)
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] File "/usr/lib/python2.6/site-packages/paste/deploy/loadwsgi.py", line 247, in loadapp
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] return loadobj(APP, uri, name=name, **kw)
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] File "/usr/lib/python2.6/site-packages/paste/deploy/loadwsgi.py", line 272, in loadobj
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] return context.create()
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] File "/usr/lib/python2.6/site-packages/paste/deploy/loadwsgi.py", line 710, in create
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] return self.object_type.invoke(self)
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] File "/usr/lib/python2.6/site-packages/paste/deploy/loadwsgi.py", line 144, in invoke
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] **context.local_conf)
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] File "/usr/lib/python2.6/site-packages/paste/deploy/util.py", line 56, in fix_call
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] val = callable(*args, **kw)
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] File "/usr/lib/python2.6/site-packages/paste/urlmap.py", line 25, in urlmap_factory
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] app = loader.get_app(app_name, global_conf=global_conf)
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] File "/usr/lib/python2.6/site-packages/paste/deploy/loadwsgi.py", line 350, in get_app
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] name=name, global_conf=global_conf).create()
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] File "/usr/lib/python2.6/site-packages/paste/deploy/loadwsgi.py", line 362, in app_context
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] APP, name=name, global_conf=global_conf)
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] File "/usr/lib/python2.6/site-packages/paste/deploy/loadwsgi.py", line 450, in get_context
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] global_additions=global_additions)
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] File "/usr/lib/python2.6/site-packages/paste/deploy/loadwsgi.py", line 559, in _pipeline_app_context
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] APP, pipeline[-1], global_conf)
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] File "/usr/lib/python2.6/site-packages/paste/deploy/loadwsgi.py", line 408, in get_context
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] object_type, name=name)
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] File "/usr/lib/python2.6/site-packages/paste/deploy/loadwsgi.py", line 587, in find_config_section
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] self.filename))
[Mon Sep 01 11:28:56 2014] [error] [client 128.142.145.164] LookupError: No section 'federation_extension' (prefixed by 'app' or 'application' or 'composite' or 'composit' or 'pipeline' or 'filter-app') found in config /usr/share/keystone/keystone-dist-paste.ini

My question is: Is the order of the middleware extensions really important or this is a bug?

[Dolph Mathews (dolph)]

Do you have a [filter:federation_extension] in your paste configuration?

  https://github.com/openstack/keystone/blob/7d9b8dcb1221ea9e3ea5988a1c0498fb90b84c98/etc/keystone-paste.ini#L39-L40

[Steve Martinelli (stevemar)]

I think the error here is that the federation_extension was placed at the END of the file.

Note that service_v3 should always be at END, and any other extensions should be placed before that one.

[Steve Martinelli (stevemar)]

s/end of the file/end of the line

[Steve Martinelli (stevemar)]

I think this will happen if you place service_v3 any where but the end.
If you had revoke_extension or oauth_extension at the end (or json_body for that matter), the behaviour would be the same.

[OpenStack Infra (hudson-openstack)]

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

[David Stanek (dstanek)]

This is definitely not a bug. An application has to be the last item in the pipeline for it to work properly. We can probably address this as documentation...

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/119827
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=ae07431be441d5d0c8d6be0ec4f7e604f0fc3bc7
Submitter: Jenkins
Branch: master

commit ae07431be441d5d0c8d6be0ec4f7e604f0fc3bc7
Author: David Stanek <email address hidden>
Date: Mon Sep 8 17:04:25 2014 +0000

    Adds pipeline hints to the example paste config

    The order of entries in the pipeline matters. The is especially true for
    the application. It must always come last. None of the configuration
    documentation for extensions calls this out when they tell the user to
    add something to their pipeline.

    Change-Id: I46b9b1ac59865d996caa4174867bcf54318035a3
    Closes-Bug: #1363932

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/119834
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=9e8c3794124db57f3e0daad22d50049d63d649f2
Submitter: Jenkins
Branch: master

commit 9e8c3794124db57f3e0daad22d50049d63d649f2
Author: David Stanek <email address hidden>
Date: Mon Sep 8 17:21:11 2014 +0000

    Adds hint about filter placement to extension docs

    Since a filter cannot be the last entry in a pipeline it makes sense to
    call that out in the extension documentation.

    Change-Id: Idf73bdb6d6d237cbf9d108f67eeb8020caeaa364
    Related-Bug: #1363932