keystone token warning flood

[Armando Migliaccio]

gate logs are being flooded with:

2016-12-25 18:40:10.451 2936 WARNING keystonemiddleware.auth_token [req-b68e933b-a6c4-4f51-bd7f-5c01acb9ab36 tempest-TestVolumeBootPattern-766347691 -] 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.

An example:

http://logs.openstack.org/41/412141/11/check/gate-tempest-dsvm-neutron-full-ubuntu-xenial/5d1fde3/logs/screen-q-svc.txt.gz?level=TRACE

It happens on master.

[Lance Bragstad (lbragstad)]

This is actually a side-effect of keystone's work to valid expired tokens [0]. Jamie detailed the intended behavior in some comments here [1].

[0] https://github.com/openstack/keystonemiddleware/commit/4c6282ff70e22710ebf0c806d3ce8cc388e6510a
[1] https://github.com/openstack/keystonemiddleware/blob/master/keystonemiddleware/auth_token/__init__.py#L367-L391

[OpenStack Infra (hudson-openstack)]

Change abandoned by Boris Bobrov (<email address hidden>) on branch: master
Review: https://review.openstack.org/415886
Reason: lets go with another patch

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/415856
Committed: https://git.openstack.org/cgit/openstack/keystonemiddleware/commit/?id=dfd53e55512cba6a8b7e69ac5bf7bea172dfe6b1
Submitter: Jenkins
Branch: master

commit dfd53e55512cba6a8b7e69ac5bf7bea172dfe6b1
Author: Kevin Benton <email address hidden>
Date: Fri Dec 30 02:29:39 2016 -0800

    Limit deprecated token message to single warning

    The current behavior of a deprecation warning on every single
    request is making the logs very difficult to scan for other
    problems. One deprecation warning per run should be enough to
    get the message across. This patch ensures only one warning per
    lifetime of the middleware object.

    Change-Id: I481a1b11305cc1c90edf7e26c686824c32fe781f
    Closes-Bug: #1652929

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/keystonemiddleware 4.13.0 release.

[Lance Bragstad (lbragstad)]

I want to confirm that the merged patch [0] is the proper fix for this. According to the logic in auth_token, keystonemiddleware throws that warning because the service user being used doesn't actually have the service role associated to it [1]. Suppressing the message might get around the excessive flooding of the logs, but could still be an issue when keystonemiddleware decides to remove the ability for non-service users to use the ?allow_expired functionality.

Are we sure the service account has the proper service role? Would that be a patch to devstack?

[0]https://review.openstack.org/#/c/415856/
[1] https://github.com/openstack/keystonemiddleware/blob/master/keystonemiddleware/auth_token/__init__.py#L375-L377

[Armando Migliaccio (armando-migliaccio)]

Yes, I'd be tempted to say that the long term fix should be in devstack's nova setup.

[Kevin Benton (kevinbenton)]

Yes, the fix that merged was just to prevent the log spam. It made the logs very difficult to use for something the Neutron team has no control over.

[Kevin Benton (kevinbenton)]

The bug was specifically about the flooding, not about addressing the way Nova communicates with Neutron.

[Lance Bragstad (lbragstad)]

Sounds good - thanks for the follow up!