Log configuration causes error in applications that have already processed configuration arguments

Bug #1521265 reported by Michael McCune
10
This bug affects 2 people
Affects Status Importance Assigned to Milestone
castellan
Fix Released
Undecided
Fernando Diaz

Bug Description

The module castellan.common.config will attempt to set some logging defaults and then register the configuration options. This causes an error for castellan consumers that have already registered and processed their configuration options. Additionally, the behavior in this module could overwrite the existing default logging message template, and might affect log levels in general.

Steps to reproduce:

1. create a simple application to demonstrate the error, this application follows a design pattern that is used for many OpenStack applications:

    from oslo_config import cfg
    from oslo_log import log
    from castellan import key_manager

    log.register_options(cfg.CONF)

    cfg.CONF()

    castellan_api = key_manager.API()

2. run the application

    $ python log_error_test.py
    Traceback (most recent call last):
      File "log_error_test.py", line 10, in <module>
        castellan_api = key_manager.API()
      File "/home/mike/.venvs/sahara/lib/python2.7/site-packages/castellan/key_manager/__init__.py", line 34, in API
        config.configure_logging()
      File "/home/mike/.venvs/sahara/lib/python2.7/site-packages/castellan/common/config.py", line 31, in configure_logging
        log.register_options(CONF)
      File "/home/mike/.venvs/sahara/lib/python2.7/site-packages/oslo_log/log.py", line 242, in register_options
        conf.register_cli_opts(_options.common_cli_opts)
      File "/home/mike/.venvs/sahara/lib/python2.7/site-packages/oslo_config/cfg.py", line 1902, in __inner
        result = f(self, *args, **kwargs)
      File "/home/mike/.venvs/sahara/lib/python2.7/site-packages/oslo_config/cfg.py", line 2084, in register_cli_opts
        self.register_cli_opt(opt, group, clear_cache=False)
      File "/home/mike/.venvs/sahara/lib/python2.7/site-packages/oslo_config/cfg.py", line 1906, in __inner
        return f(self, *args, **kwargs)
      File "/home/mike/.venvs/sahara/lib/python2.7/site-packages/oslo_config/cfg.py", line 2076, in register_cli_opt
        raise ArgsAlreadyParsedError("cannot register CLI option")
    oslo_config.cfg.ArgsAlreadyParsedError: arguments already parsed: cannot register CLI option

Recommended action.

This logging configuration should be re-assessed as it is being called everytime a user might acquire the API object for castellan. I don't think the library should be performing the action of configuring the log style or levels, these decisions should be left up to the application that consumes castellan.

I think the best possible option would be to provide this functionality as a configuration call that the user could make at an appropriate time in their application. There should also be documentation about how to increase the logging level for castellan.

description: updated
Fernando Diaz (diazjf)
Changed in castellan:
assignee: nobody → Fernando Diaz (diazjf)
Revision history for this message
Michael McCune (mimccune) wrote :

Fernando, another issue with the configure_logging function is that it should accept a ConfigOpt object instead of using the global oslo_config CONF object. The other configuration options have all been set to accept a user defined ConfigOpt and only use the global CONF is nothing is provided. This allows the consumer of castellan to be in full control of the configuration object that is used by their application.

Revision history for this message
Fernando Diaz (diazjf) wrote :

I think something like this can be done http://paste.openstack.org/show/480419/

It will allow the user to specify new configuration options for logging later, if None are specified then just use the defaults. In a patch for this I will also include information on adding your own LOG options.

We can then run "manager = key_manager.API()" and "key_manager.configure_logging()" anytime after to change the logging.

Note: This is a WIP.

Revision history for this message
Michael McCune (mimccune) wrote :

Fernando, that patch is a step in a better direction but it has a couple issues.

The configuration that is passed to configure_logging should be used instead of the global CONF, if None is passed in then we should use the global CONF. Look at the example in the API(), it does something similar.

I am also concerned about calling log.setup as that will configure the logging name for the entire application. This is something that the end user should know explicitly so that they do not overwrite their own application name.

Maybe, instead of configure_logging, we should call this enable_logging, to be used in a situation where the application using castellan has no logging of its own? Because, if the application in question has logging enabled, then castellan will just use the log configuration that has been created by the calling application.

Revision history for this message
Fernando Diaz (diazjf) wrote :

Sounds good, just wanted to ask, what can be called instead of log.setup() for the changes to take place?
Thanks!!

Revision history for this message
Michael McCune (mimccune) wrote :

It depends on what we are trying to do. If we want to provide a one-stop convenience function for users that are not using oslo logging, then we can use the original version with the log.register_options. But, i think we need to more clearly define what we are trying to do, and in what cases this function will be used.

As i see it, we are creating something for users that do not already have a configuration for their logging. In this case, i can seen wrapping all the configuration stuff, but it might be problematic for the end user as they might not have considered adding these configuration options to their command line, and are they processing command line options, etc. For me, the whole thing comes down to how we use the library from an application.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to castellan (master)

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

Changed in castellan:
status: New → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix proposed to castellan (master)

Related fix proposed to branch: master
Review: https://review.openstack.org/251649

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to castellan (master)

Reviewed: https://review.openstack.org/251558
Committed: https://git.openstack.org/cgit/openstack/castellan/commit/?id=b018f15e2e891c8409168a1ce3ef0d149fe60c60
Submitter: Jenkins
Branch: master

commit b018f15e2e891c8409168a1ce3ef0d149fe60c60
Author: “Fernando <email address hidden>
Date: Mon Nov 30 16:14:37 2015 -0600

    Allow for default logging configuration to be user enabled

    Allows a user to be able to set logging defaults if they have not
    created a configuration for logging.

    Change-Id: I7e7ce2f7904aefa30db63264d9e0702f0db57513
    Co-Authored-By: Michael McCune <email address hidden>
    Closes-Bug: #1521265

Changed in castellan:
status: In Progress → Fix Committed
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix merged to castellan (master)

Reviewed: https://review.openstack.org/251649
Committed: https://git.openstack.org/cgit/openstack/castellan/commit/?id=96df616023a784bd872df7c2dcac75b98153a7f7
Submitter: Jenkins
Branch: master

commit 96df616023a784bd872df7c2dcac75b98153a7f7
Author: “Fernando <email address hidden>
Date: Tue Dec 1 00:01:17 2015 -0600

    Add some documentation on enabling logging

    This patch adds documentation on how to enable logging.
    Related-Bug: #1521265

    Change-Id: Ib0a84bcf1af12a5b489cee8abcb4231f8e34151e

Revision history for this message
Kaitlin Farr (kaitlin-farr) wrote :

These patches were released with Castellan version 0.3.1

Changed in castellan:
status: Fix Committed → Fix Released
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.