Unexpected service token warning message in keystone log

[prashkre]

WARNING keystone.middleware.auth [req-d7a12f33-ef93-47c8-b27e-a808860d1cff - - - - -] A valid token was submitted as a service token, but it was not a valid service token. This is incorrect but backwards compatible behaviour. This will be removed in future releases.

In compute quota API request[0] flow, nova is making a rest call to keystone invoking identity project API[1] at [2] for project verification. In this service call, a valid service token is being passed in addition to user_token in request headers.

With reference to keystone pipeline [3], the above request is going through 'build_auth_context' middleware which is defined as [4]. Meanwhile build_auth_context middleware[5] is loading keystonemiddleware auth_token.BaseAuthProtocol[6] where 'service_token_roles', 'service_token_roles_required' params are not passed during initialization due to which execution flow is going through else block [7] and triggering above warning message in keystone log.

[0] GET /compute/v2.1/3d1ad9e3223e4cadb8a0d1f8a893e6a3/os-quota-sets/3d1ad9e3223e4cadb8a0d1f8a893e6a3/detail
[1] GET /v3/projects/3d1ad9e3223e4cadb8a0d1f8a893e6a3
[2] https://github.com/openstack/nova/blob/master/nova/api/openstack/compute/quota_sets.py#L155
[3] [pipeline:api_v3]
    pipeline = ........ url_normalize request_id build_auth_context token_auth json_body service_v3
[4] build_auth_context = keystone.middleware:AuthContextMiddleware.factory
[5] https://github.com/openstack/keystone/blob/master/keystone/middleware/auth.py#L43-L45
[6] https://github.com/openstack/keystonemiddleware/blob/stable/pike/keystonemiddleware/auth_token/__init__.py#L315-L320
[7] https://github.com/openstack/keystonemiddleware/blob/stable/pike/keystonemiddleware/auth_token/__init__.py#L383

[prashkre (prashkre)]

Warning message is triggered only if some service makes a call to keystone, but in case of non-keystone service calls like nova calling cinder, the request is going through 'authtoken' middleware[0] in paste pipeline which initializes keystonemiddleware.auth_token.BaseAuthProtocol[1] by loading 'service_token_roles', 'service_token_roles_required'[2] from cinder.conf file .

[0][filter:authtoken]
   paste.filter_factory = keystonemiddleware.auth_token:filter_factory

[1] https://github.com/openstack/keystonemiddleware/blob/stable/pike/keystonemiddleware/auth_token/__init__.py#L565-L570

[2]
[keystone_authtoken]
service_token_roles_required = True
service_token_roles = admin

[Lance Bragstad (lbragstad)]

It sounds like the workaround here is to define those configuration values in nova's authtoken section, right?

[yangweiwei (496176919-6)]

I think we should remove the warning log from keystonemiddleware.
The service token is from nova to keystone, and the keystone service does not contain this parameter. And keystone service just authenticates the token wether it is user token or service token. If the keystonemiddleware judge the token is allowed expired and then the keystone service authenticate the token with 'allow_expired' parameter.

So I think it is just the log waning confuses.
See https://review.openstack.org/#/c/548736/

[Colleen Murphy (krinkle)]

prashkre - just to clarify, in nova.conf's [keystone_authtoken] section you have service_token_roles_required set to true (which should suppress this log warning), and this message is appearing in the nova logs anyways?

Lance - I think these parameters are already defined in keystonemiddleware.auth_token so we shouldn't have to change anything about nova, or if we do it will be more work than just adding parameters.

yangweiwei - Removing the log warning entirely is not an option, it is there for a valid reason. It's unfortunately not well documented, except for in the release notes that added it: https://docs.openstack.org/releasenotes/keystonemiddleware/ocata.html

[Lance Bragstad (lbragstad)]

Given Colleen's response, is there anything left to do for this? I suppose we could clarify documentation or the log warning to be more clear per the last bit of comment #4.

[Colleen Murphy (krinkle)]

Still waiting for clarification on my question to prashkre. Also re-reading prashkre's description, if the warning is appearing in the keystone log rather than the nova or cinder log that is really unexpected.

I also read Lance's comment incorrectly, I agree that defining the service token settings in the [keystone_authtoken] in nova.conf should probably fix the issue.

[prashkre (prashkre)]

cmurphy - I see the warning message in keystone log. My environment has service token settings under [keystone_authtoken] section in nova.conf and cinder.conf as well. As explained through execution flow in bug description, warning message is being triggered because of not passing argument value at [0] for "service_token_roles_required" param by loading it from the conf, it should be something like at [1]

[keystone_authtoken]
service_token_roles_required = True
service_token_roles = admin

[0] https://github.com/openstack/keystone/blob/master/keystone/middleware/auth.py#L43-L45

[1] https://github.com/openstack/keystonemiddleware/blob/stable/pike/keystonemiddleware/auth_token/__init__.py#L565-L570

[Matthew Edmonds (edmondsw)]

@Lance @Colleen it sounds to me like this is a valid issue with a couple potential solutions:

1) somehow the middleware needs to distinguish if it is being run by keystoner (in which case it should not log this warning) or something else (in which case it should).

or...

2) we have to require that the same service_token_roles and service_token_roles_required conf options are set in keystone's conf as in the other services, and then need to make sure they are passed to the middleware when it is used in the keystone pipeline.

I don't know if #2 is either possible or advisable, so I would lean toward #1. Either way this needs to be resolved before "This will be removed in future releases" becomes a reality.

[Morgan Fainberg (mdrnstm)]

@Matthew,

The correct fix is your #1 preferred fix. KSM's code needs some adjusting in general to be more in-line with how keystone would *prefer* to run it (e.g. not as an explicit middleware).