WARNING message related to keystone is present in all services API logs

[Abhishek Sharma M]

2017-08-31 02:57:29.236 23010 WARNING keystonemiddleware._common.config [-] The option "__file__" in conf is not known to auth_token
2017-08-31 02:57:29.244 23010 WARNING keystonemiddleware._common.config [-] The option "configkey" in conf is not known to auth_token
2017-08-31 02:57:29.245 23010 WARNING keystonemiddleware._common.config [-] The option "here" in conf is not known to auth_token

The above warning messages are cluttering all the service api log files because of this change https://github.com/openstack/keystonemiddleware/commit/ba78db0b4b559dcc3b22c37834e430d8b27c45ae

[Lance Bragstad (lbragstad)]

This looks specific to how you're configuration is set up. Can you share how you have keystone configured at each of the services (omitting sensitive information)?

[Roger Luethi (rl-o)]

I am seeing that, too. There seems to be one such entry per paste file.

It happens when in _conf_values_type_convert, conf is something like "{'__file__': '/etc/heat/api-paste.ini', 'here': '/etc/heat'}".

The configuration is vanilla Pike OpenStack training-labs, i.e. it should match the official install-guide.

[Divya K Konoor (dikonoor)]

This is seen for all the services. "The option "configkey" in conf is not known to auth_token" is seen specifically only for Panko and Gnocchi.

The logging happens at https://github.com/openstack/keystonemiddleware/blob/stable/pike/keystonemiddleware/_common/config.py#L57 where all the key-values in the global variables list is looped through. Every middleware/filter in the paste pipeline can update this information.

For eg. the configkey referred to above comes from https://github.com/openstack/panko/blob/stable/pike/panko/api/app.py#L80

and for Gnocchi from here >> https://github.com/gnocchixyz/gnocchi/blob/master/gnocchi/rest/app.py#L118

So, there are always going to be some values that are not relevant from the authtoken middleware perspective and they will get logged. I am not sure where __file__ and here are coming from but those two seem to be common across all services.

[Divya K Konoor (dikonoor)]

The flow where this gets logged is
>> https://github.com/openstack/keystonemiddleware/blob/master/keystonemiddleware/auth_token/__init__.py#L993
>> https://github.com/openstack/keystonemiddleware/blob/master/keystonemiddleware/auth_token/__init__.py#L555
>> https://github.com/openstack/keystonemiddleware/blob/stable/pike/keystonemiddleware/_common/config.py#L78
>> https://github.com/openstack/keystonemiddleware/blob/stable/pike/keystonemiddleware/_common/config.py#L58

[Divya K Konoor (dikonoor)]

A simple approach to fix this is to convert the warning logging to debug.I don't see a reason this should be logged and we should be OK removing it..but it anyone has concerns with it, we could change it to debug.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/515291

[Matthew Edmonds (edmondsw)]

__file__ and here come from paste.deploy:

https://bitbucket.org/ianb/pastedeploy/src/4b27133a2a7db58b213ae55b580039c11d2055c0/paste/deploy/loadwsgi.py?at=default&fileviewer=file-view-default#loadwsgi.py-387

[Pavlo Shchelokovskyy (pshchelo)]

Not sure if ironic does something wrong, but it its case it seems keystonemiddleware tries to parse the whole CONF (all config options from [DEFAULT] and all sections)

http://logs.openstack.org/11/518411/4/gate/ironic-tempest-dsvm-ipa-wholedisk-agent_ipmitool-tinyipa-multinode/6ebe0f8/logs/screen-ir-api.txt.gz#_Dec_06_11_42_05_773127

[Roger Luethi (rl-o)]

@pshchelo Appears to be worth its own bug report.

[Luca Cervigni (cervigni)]

Is this affecting all APIs ? I have the issue with glance particularly.
Is this going to be patched for Pike as well?

[Ben Silverman (tersian)]

I have it coming from cinder-api as well:

Jul 22 03:25:24 osp1 loom/Cinder_api: 2018-07-22 02:12:03.740 11008 WARNING keystonemiddleware._common.config [req-64f299e8-29e8-4b83-a039-8bf7f09fce0a - - - - -] The option "here" in conf is not known to auth_token

as well as:

Jul 22 03:25:24 osp1 loom/Cinder_api: 2018-07-22 02:12:03.739 11008 WARNING keystonemiddleware._common.config [req-64f299e8-29e8-4b83-a039-8bf7f09fce0a - - - - -] The option "__file__" in conf is not known to auth_token

Running queens RDO in this install.

[Artur Ruta (artur-ruta)]

same on nova-api log on the controller node.
Rocky vanilla install with latest patches applied under ubuntu 18.04
I would risk to say it would be desirable to fix the root cause rathar than just hidding the message so that it appears only on debut. Otherwise it could be missleading when researching other issues.

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/515291
Committed: https://git.openstack.org/cgit/openstack/keystonemiddleware/commit/?id=0c0eae3b1eb537159f26c82647fb61cc3de8536a
Submitter: Zuul
Branch: master

commit 0c0eae3b1eb537159f26c82647fb61cc3de8536a
Author: Abhishek Sharma <email address hidden>
Date: Thu Oct 26 01:30:54 2017 -0500

    Expect paste.deploy and gnocchi/panko options

    The authtoken middleware has been printing warning log messages to
    the API logs for all services, reporting unexpected conf keys. This
    was traced back to paste.deploy adding 'here' and '__file__' and
    both gnocchi and panko adding 'configkey' keys in wsgi apps though
    these do not actually exist in the conf file. This change allows
    for those keys without printing a warning that unnecessarily
    confuses operators.

    But it's kind of a hack, especially the configkey bit. We shouldn't
    have to know about gnocchi/panko specifics like this. And it doesn't
    address the comment in the bug about what is seen for ironic. So I
    think there will still be more to do here.

    Change-Id: I678482309c7dd35ce147bebf13ebefc84251fe91
    Partial-Bug: 1722444