tokenless auth is logging excessively on every call

Bug #1497132 reported by Steve Martinelli
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Identity (keystone)
Fix Released
Low
Steve Martinelli

Bug Description

This logic in being run far too often:
https://github.com/openstack/keystone/blob/master/keystone/middleware/core.py#L253-L281

resulting in logs like the following:
2015-09-16 23:34:04.261007 108719 INFO keystone.middleware.core [req-f715dbbe-8dac-490e-a02c-4a430eefb1a0 - - - - -] Cannot find client issuer in env by the issuer attribute - SSL_CLIENT_I_DN.
2015-09-16 23:34:04.265523 108719 DEBUG keystone.middleware.core [req-f715dbbe-8dac-490e-a02c-4a430eefb1a0 - - - - -] There is either no auth token in the request or the certificate issuer is not trusted. No auth context will be set. process_request /opt/stack/keystone/keystone/middleware/core.py:307
2015-09-16 23:34:04.304670 108719 INFO keystone.common.wsgi [req-f715dbbe-8dac-490e-a02c-4a430eefb1a0 - - - - -] GET http://172.16.240.136:35357/v2.0/
2015-09-16 23:34:04.454396 108722 INFO keystone.middleware.core [req-3c130a0f-8147-46bd-83d3-c55d873ed3a6 - - - - -] Cannot find client issuer in env by the issuer attribute - SSL_CLIENT_I_DN.
2015-09-16 23:34:04.460344 108722 DEBUG keystone.middleware.core [req-3c130a0f-8147-46bd-83d3-c55d873ed3a6 - - - - -] There is either no auth token in the request or the certificate issuer is not trusted. No auth context will be set. process_request /opt/stack/keystone/keystone/middleware/core.py:307
2015-09-16 23:34:04.501183 108722 INFO keystone.common.wsgi [req-3c130a0f-8147-46bd-83d3-c55d873ed3a6 - - - - -] POST http://172.16.240.136:35357/v2.0/tokens
2015-09-16 23:34:05.002308 108721 INFO keystone.middleware.core [req-feba423f-afb7-4650-a6cc-a83242d69d39 - - - - -] Cannot find client issuer in env by the issuer attribute - SSL_CLIENT_I_DN.
2015-09-16 23:34:05.006774 108721 DEBUG keystone.middleware.core [req-feba423f-afb7-4650-a6cc-a83242d69d39 - - - - -] There is either no auth token in the request or the certificate issuer is not trusted. No auth context will be set. process_request /opt/stack/keystone/keystone/middleware/core.py:307
2015-09-16 23:34:05.053912 108721 INFO keystone.common.wsgi [req-feba423f-afb7-4650-a6cc-a83242d69d39 - - - - -] POST http://172.16.240.136:35357/v2.0/tokens
2015-09-16 23:34:05.290813 108720 INFO keystone.common.wsgi [req-9b96e50a-f4c9-4dc0-b3bf-7fc26f44c59a - - - - -] GET http://172.16.240.136:35357/
2015-09-16 23:34:05.304653 108718 DEBUG keystone.middleware.core [req-ff998f4d-0df5-4bc8-9ad5-dbc498b04dc7 - - - - -] RBAC: auth_context: {'is_delegated_auth': False, 'access_token_id': None, 'user_id': u'b95ea3fcaf8a49309ee2b406c02f383e', 'roles': [u'anotherrole', u'Member'], 'trustee_id': None, 'trustor_id': None, 'consumer_id': None, 'token': <KeystoneToken (audit_id=yQcilB0WSMa9Ys6OejFAjg, audit_chain_id=yQcilB0WSMa9Ys6OejFAjg) at 0x7fef3e216990>, 'project_id': u'ae819f8aeda04d8488b4412baed1730b', 'trust_id': None} process_request /opt/stack/keystone/keystone/middleware/core.py:311
2015-09-16 23:34:05.306174 108718 INFO keystone.common.wsgi [req-ff998f4d-0df5-4bc8-9ad5-dbc498b04dc7 - - - - -] GET http://172.16.240.136:35357/v2.0/users
2015-09-16 23:34:05.306694 108718 DEBUG keystone.policy.backends.rules [req-ff998f4d-0df5-4bc8-9ad5-dbc498b04dc7 - - - - -] enforce admin_required: {'user_id': u'b95ea3fcaf8a49309ee2b406c02f383e', u'is_admin': 0, u'roles': [u'anotherrole', u'Member'], 'tenant_id': u'ae819f8aeda04d8488b4412baed1730b'} enforce /opt/stack/keystone/keystone/policy/backends/rules.py:76
2015-09-16 23:34:05.331264 108718 WARNING keystone.common.wsgi [req-ff998f4d-0df5-4bc8-9ad5-dbc498b04dc7 - - - - -] You are not authorized to perform the requested action: admin_required (Disable debug mode to suppress these details.)

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/225039

Changed in keystone:
assignee: nobody → Steve Martinelli (stevemar)
status: New → In Progress
Changed in keystone:
assignee: Steve Martinelli (stevemar) → Dave Chen (wei-d-chen)
Dave Chen (wei-d-chen)
Changed in keystone:
assignee: Dave Chen (wei-d-chen) → Steve Martinelli (stevemar)
importance: Undecided → Low
Dolph Mathews (dolph)
summary: - tokenless auth is being too chatty on every call
+ tokenless auth is logging excessively on every call
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to keystone (master)

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

commit 1bac1dfb0a71de4f28ca6aba36a39b1e4ca284d8
Author: Steve Martinelli <email address hidden>
Date: Fri Sep 18 03:13:43 2015 -0400

    check if tokenless auth is configured before validating

    we could reduce the amount of logging that the tokenless
    validation performs by simply checking if there are any
    trusted issuers before proceeding.

    Change-Id: Idcbddf7bf87ada18ee44ae31878201f41c499c7c
    Closes-Bug: #1497132

Changed in keystone:
status: In Progress → Fix Committed
Thierry Carrez (ttx)
Changed in keystone:
milestone: none → liberty-rc1
status: Fix Committed → Fix Released
Thierry Carrez (ttx)
Changed in keystone:
milestone: liberty-rc1 → 8.0.0
Revision history for this message
zzxwill (zzxwill) wrote :

For me, this is not an issue.
I hit the same problem as I configured the version of OPENSTACK_API_VERSIONS to '2' in /horizon/openstack_dashboard/local/local_settings.py, while the keystone version is '3'. When I try to login via Horizon, I hit the issue. FYI.

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.