RBAC Enforcer Programming Error raised for malformed federation protocol request

[Colleen Murphy]

On devstack, I mistakenly tried to create a federation protocol without providing its name in the request path:

curl -H "x-auth-token: $token" -H "content-type: application/json" http://localhost/identity/v3/OS-FEDERATION/identity_providers/myidp/protocols -X PUT -d '{"protocol": {"mapping_id": "myidp_mapping"}}'

This caused the RBACEnforcer programming error to be raised:

http://paste.openstack.org/show/745721/

Also, the error message spells RBACEnforcer incorrectly.

Expected behavior: this should result in a 404, not a 500.

[Lance Bragstad (lbragstad)]

I can confirm this on 2a380f001e5a886ebd80e3f1e8c9750a8a563e34

[Adam Young (ayoung)]

Feb 22 11:53:48 mysp <email address hidden>[2532]: [pid: 2536|app: 0|req: 1/1] ::1 () {58 vars in 1224 bytes} [Fri Feb 22 11:53:48 2019] PUT /identity/v3/OS-FEDERATION/identity_providers/myidp/protocols => generated 0 bytes in 101 msecs (HTTP/1.1 500) 0 headers in 0 b
Feb 22 11:54:28 mysp <email address hidden>[2532]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [-] Authenticating user token {{(pid=2537) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}}
Feb 22 11:54:28 mysp <email address hidden>[2532]: DEBUG oslo_db.sqlalchemy.engines [None req-74a4b46e-d794-49d2-8d33-ed8111390158 None None] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITI
Feb 22 11:54:28 mysp <email address hidden>[2532]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-6449c38c-ac54-4d8c-aa36-3e5e68eb4b55 admin admin] RBAC: auth_context: {'service_project_id': None, 'service_user_id': None, 'service_use
Feb 22 11:54:28 mysp <email address hidden>[2532]: DEBUG keystone.server.flask.request_processing.req_logging [None req-6449c38c-ac54-4d8c-aa36-3e5e68eb4b55 admin admin] REQUEST_METHOD: `PUT` {{(pid=2537) log_request_info /opt/stack/keystone/keystone/server/flask/requ
Feb 22 11:54:28 mysp <email address hidden>[2532]: DEBUG keystone.server.flask.request_processing.req_logging [None req-6449c38c-ac54-4d8c-aa36-3e5e68eb4b55 admin admin] SCRIPT_NAME: `/identity` {{(pid=2537) log_request_info /opt/stack/keystone/keystone/server/flask/r
Feb 22 11:54:28 mysp <email address hidden>[2532]: DEBUG keystone.server.flask.request_processing.req_logging [None req-6449c38c-ac54-4d8c-aa36-3e5e68eb4b55 admin admin] PATH_INFO: `/v3/OS-FEDERATION/identity_providers/myidp/protocols` {{(pid=2537) log_request_info /o
Feb 22 11:54:28 mysp <email address hidden>[2532]: WARNING keystone.server.flask.application [None req-6449c38c-ac54-4d8c-aa36-3e5e68eb4b55 admin admin] put() takes exactly 3 arguments (2 given)
Feb 22 11:54:28 mysp <email address hidden>[2532]: CRITICAL keystone [None req-6449c38c-ac54-4d8c-aa36-3e5e68eb4b55 admin admin] Unhandled error: AssertionError: PROGRAMMING ERROR: enforcement (`keystone.common.rbac_enforcer.enforcer.RBACKEnforcer.enforce_call()`) has
Feb 22 11:54:28 mysp <email address hidden>[2532]: ERROR keystone Traceback (most recent call last):
Feb 22 11:54:28 mysp <email address hidden>[2532]: ERROR keystone File "/usr/local/lib/python2.7/dist-packages/flask/app.py", line 2309, in __call__
Feb 22 11:54:28 mysp <email address hidden>[2532]: ERROR keystone return self.wsgi_app(environ, start_response)
Feb 22 11:54:28 mysp <email address hidden>[2532]: ERROR keystone File "/usr/local/lib/python2.7/dist-packages/werkzeug/contrib/fixers.py", line 152, in __call__
Feb 22 11:54:28 mysp <email address hidden>[2532]: ERROR keystone return self.app(environ, start_response)
Feb 22 11:54:28 mysp <email address hidden>[2532]: ERROR keystone File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 129, in __call__
Feb 22 11:54:28 ...

[Morgan Fainberg (mdrnstm)]

Feb 22 11:53:48 mysp <email address hidden>[2532]: [pid: 2536|app: 0|req: 1/1] ::1 () {58 vars in 1224 bytes} [Fri Feb 22 11:53:48 2019] PUT /identity/v3/OS-FEDERATION/identity_providers/myidp/protocols => generated 0 bytes in 101 msecs (HTTP/1.1 500) 0 headers in 0 b
Feb 22 11:54:28 mysp <email address hidden>[2532]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [-] Authenticating user token {{(pid=2537) process_request /usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:401}}
Feb 22 11:54:28 mysp <email address hidden>[2532]: DEBUG oslo_db.sqlalchemy.engines [None req-74a4b46e-d794-49d2-8d33-ed8111390158 None None] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITI
Feb 22 11:54:28 mysp <email address hidden>[2532]: DEBUG keystone.server.flask.request_processing.middleware.auth_context [None req-6449c38c-ac54-4d8c-aa36-3e5e68eb4b55 admin admin] RBAC: auth_context: {'service_project_id': None, 'service_user_id': None, 'service_use
Feb 22 11:54:28 mysp <email address hidden>[2532]: DEBUG keystone.server.flask.request_processing.req_logging [None req-6449c38c-ac54-4d8c-aa36-3e5e68eb4b55 admin admin] REQUEST_METHOD: `PUT` {{(pid=2537) log_request_info /opt/stack/keystone/keystone/server/flask/requ
Feb 22 11:54:28 mysp <email address hidden>[2532]: DEBUG keystone.server.flask.request_processing.req_logging [None req-6449c38c-ac54-4d8c-aa36-3e5e68eb4b55 admin admin] SCRIPT_NAME: `/identity` {{(pid=2537) log_request_info /opt/stack/keystone/keystone/server/flask/r
Feb 22 11:54:28 mysp <email address hidden>[2532]: DEBUG keystone.server.flask.request_processing.req_logging [None req-6449c38c-ac54-4d8c-aa36-3e5e68eb4b55 admin admin] PATH_INFO: `/v3/OS-FEDERATION/identity_providers/myidp/protocols` {{(pid=2537) log_request_info /o
Feb 22 11:54:28 mysp <email address hidden>[2532]: WARNING keystone.server.flask.application [None req-6449c38c-ac54-4d8c-aa36-3e5e68eb4b55 admin admin] put() takes exactly 3 arguments (2 given)
Feb 22 11:54:28 mysp <email address hidden>[2532]: CRITICAL keystone [None req-6449c38c-ac54-4d8c-aa36-3e5e68eb4b55 admin admin] Unhandled error: AssertionError: PROGRAMMING ERROR: enforcement (`keystone.common.rbac_enforcer.enforcer.RBACKEnforcer.enforce_call()`) has
Feb 22 11:54:28 mysp <email address hidden>[2532]: ERROR keystone Traceback (most recent call last):
Feb 22 11:54:28 mysp <email address hidden>[2532]: ERROR keystone File "/usr/local/lib/python2.7/dist-packages/flask/app.py", line 2309, in __call__
Feb 22 11:54:28 mysp <email address hidden>[2532]: ERROR keystone return self.wsgi_app(environ, start_response)
Feb 22 11:54:28 mysp <email address hidden>[2532]: ERROR keystone File "/usr/local/lib/python2.7/dist-packages/werkzeug/contrib/fixers.py", line 152, in __call__
Feb 22 11:54:28 mysp <email address hidden>[2532]: ERROR keystone return self.app(environ, start_response)
Feb 22 11:54:28 mysp <email address hidden>[2532]: ERROR keystone File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 129, in __call__
Feb 22 11:54:28 ...

[Morgan Fainberg (mdrnstm)]

Looks like the issue is https://github.com/openstack/keystone/blob/f0c2e798f7e706acbaf600bd06521a0e4c514477/keystone/api/os_federation.py#L161 needs to be it's own resource to ensure the protocol ID is required in the routing map, note that the resource object only enforces the first substitution via https://github.com/openstack/keystone/blob/f0c2e798f7e706acbaf600bd06521a0e4c514477/keystone/api/os_federation.py#L482 since it is a "resource".

Alternatively a resource_mapping can be used explicitly for each method allowing the resource object to remain combined.

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/648241
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=9717f0c12f225a70fcecebcfcfc6dd4f1e248b28
Submitter: Zuul
Branch: master

commit 9717f0c12f225a70fcecebcfcfc6dd4f1e248b28
Author: Morgan Fainberg <email address hidden>
Date: Wed Mar 27 13:49:39 2019 -0700

    Raise METHOD NOT ALLOWED instead of 500 error on protocol CRUD

    Raise METHOD NOT ALLOWED for OS-Federation protocols creation
    if the protocol_id is not in the URL. The corrective action was to split
    the LIST from CRUD resources so that the routing regexes can work as
    expected.

    Change-Id: I063e3afa1ef8dbf957d62fb4d44dac0f0860ec94
    closes-bug: #1817313

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/stein
Review: https://review.openstack.org/648709

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/648709
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=95442b7dda8475210f8badb284eb6d8f6bf21045
Submitter: Zuul
Branch: stable/stein

commit 95442b7dda8475210f8badb284eb6d8f6bf21045
Author: Morgan Fainberg <email address hidden>
Date: Wed Mar 27 13:49:39 2019 -0700

    Raise METHOD NOT ALLOWED instead of 500 error on protocol CRUD

    Raise METHOD NOT ALLOWED for OS-Federation protocols creation
    if the protocol_id is not in the URL. The corrective action was to split
    the LIST from CRUD resources so that the routing regexes can work as
    expected.

    Change-Id: I063e3afa1ef8dbf957d62fb4d44dac0f0860ec94
    closes-bug: #1817313
    (cherry picked from commit 9717f0c12f225a70fcecebcfcfc6dd4f1e248b28)

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/keystone 15.0.0.0rc2 release candidate.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/keystone 16.0.0.0rc1 release candidate.