Ceilometer-api logs a WARNING when a request is made from ceilometer-alarm-evaluator with an expired token

[Lukas Vacek]

ceilometer-api logs a warning every hour "Authorization failed for token"

This appears to come from ceilometer-alarm-evaluator requests to the API because after stopping the alarm-evaluator the message does not appear in the log anymore.

Alarm-evaluator is set to query the API every 60 seconds, token expiration is 60 minutes.

Relevant part from debug logs:

ceilometer-api.log:
2015-06-11 16:27:41.045 32083 WARNING keystonemiddleware.auth_token [req-de391a60-e230-4fd2-b873-da3466c5ea53 - - - - -] Authorization failed for token
2015-06-11 16:27:41.047 32083 WARNING keystonemiddleware.auth_token [req-de391a60-e230-4fd2-b873-da3466c5ea53 - - - - -] Identity response: {"error": {"message": "Could not find token: 5d6ee8f13ea649ca962f4e29799ebb24", "code": 404, "title": "Not Found"}}
2015-06-11 16:27:41.050 32083 WARNING keystonemiddleware.auth_token [req-de391a60-e230-4fd2-b873-da3466c5ea53 - - - - -] Authorization failed for token
2015-06-11 16:27:41.051 32083 INFO werkzeug [req-de391a60-e230-4fd2-b873-da3466c5ea53 - - - - -] 10.13.37.1 - - [11/Jun/2015 16:27:41] "GET /v2/alarms?q.field=enabled&q.op=&q.type=&q.value=True HTTP/1.1" 401 -

ceilometer-alarm-evaluator.log:
2015-06-11 16:27:41.054 15512 DEBUG ceilometerclient.openstack.common.apiclient.client [-] Request returned failure status: 401 request /openstack/ceilometer/local/lib/python2.7/site-packages/ceilometerclient/openstack/common/apiclient/client.py:200
2015-06-11 16:27:41.386 15512 DEBUG ceilometer.coordination [-] Members of group: ['d7835e42-9975-446c-b470-28a6ed2a4173'] extract_my_subset /openstack/ceilometer/local/lib/python2.7/site-packages/ceilometer/coordination.py:170
2015-06-11 16:27:41.387 15512 DEBUG ceilometer.coordination [-] My subset: [] extract_my_subset /openstack/ceilometer/local/lib/python2.7/site-packages/ceilometer/coordination.py:174
2015-06-11 16:27:41.388 15512 INFO ceilometer.alarm.service [-] initiating evaluation cycle on 0 alarms

And the token 5d6ee8f13ea649ca962f4e29799ebb24 in the db:
MariaDB [keystone]> select id,expires,valid,trust_id,user_id from token where id="5d6ee8f13ea649ca962f4e29799ebb24";
+----------------------------------+---------------------+-------+----------+----------------------------------+
| id | expires | valid | trust_id | user_id |
+----------------------------------+---------------------+-------+----------+----------------------------------+
| 5d6ee8f13ea649ca962f4e29799ebb24 | 2015-06-11 14:27:40 | 1 | NULL | d16f4edc395f4e72bb66153269bd8f16 |
+----------------------------------+---------------------+-------+----------+----------------------------------+

Timezone is CEST (UTC+2) - that'why we get 16:27 in the log but expires is 14:27.

You can see in the log that ceilometer-alarm-evaluator tries again with a new token after the fail so everything works fine.

But the warning should not be logged because it clutters the logs and other openstack services do handle token expiration without "warnings" in the logs.

Thanks!

[Lukas Vacek (lukas-vacek)]

This is ceilometer from current git master (91ad3bcd969615f250348cfd60079e1841b5e464)

[Lukas Vacek (lukas-vacek)]

I'm having a second look at keystone-error.log and it seems this issue is in other binaries in ceilometer as well.

There were no WARNINGs in keystone-error.log until I installed ceilometer.

After installing ceilometer, there is a lot of WARNINGs in keystone-error.log:

Just an example from the log:

2015-06-11 15:57:58.898230 2015-06-11 15:57:58.897 15175 WARNING keystone.common.wsgi [-] Could not find token: 5830917b19a542f5b4560d22f212619c
2015-06-11 16:27:41.042920 2015-06-11 16:27:41.042 15175 WARNING keystone.common.wsgi [-] Could not find token: 5d6ee8f13ea649ca962f4e29799ebb24
2015-06-11 16:38:42.003294 2015-06-11 16:38:42.002 15173 WARNING keystone.common.wsgi [-] Failed to validate token
2015-06-11 16:57:59.010376 2015-06-11 16:57:59.010 15177 WARNING keystone.common.wsgi [-] Could not find token: 4de74f34b0144b60a67dfb6977ae3427
2015-06-11 16:57:59.177034 2015-06-11 16:57:59.176 15173 WARNING keystone.common.wsgi [-] Could not find token: 4de74f34b0144b60a67dfb6977ae3427

All these tokens belong to ceilometer user and I can also see a relevant warning in nova-api.log as well:

nova/nova-api.log:2015-06-11 16:57:59.181 2709 WARNING keystonemiddleware.auth_token [-] Identity response: {"error": {"message": "Could not find token: 4de74f34b0144b60a67dfb6977ae3427", "code": 404, "title": "Not Found"}}

[Tyler Bishop (tyler-bishop)]

What is the status of this issue? We are running into it as well.

[gordon chung (chungg)]

we use keystone sessions in Mitaka. i imagine this is fixed in Mitaka stream