oslo changes to logging_context_format_string not compatible with nova

Bug #1083218 reported by Sean Dague
16
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Fix Released
Critical
Davanum Srinivas (DIMS)
oslo-incubator
Fix Released
Critical
Davanum Srinivas (DIMS)
Grizzly
Fix Released
Critical
Davanum Srinivas (DIMS)

Bug Description

oslo changeset efba20239c1253c3e6ce4a68eed97585a74b8a46 made a change to logging_context_format_string to fix a ceilo issue - https://bugs.launchpad.net/oslo/+bug/1075095.

This changed default for logging_context_format_string doesn't work for nova, as it assumes the prior keys in it's use of logging in many places. Running unit tests with the new logging_context_format_string passes, however many many logging stack traces are thrown in the process, like:

    test_init_host Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 850, in emit
    msg = self.format(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 723, in format
    return fmt.format(record)
  File "/home/sdague/code/openstack/nova/nova/openstack/common/log.py", line 427, in format
    return logging.Formatter.format(self, record)
  File "/usr/lib/python2.7/logging/__init__.py", line 467, in format
    s = self._fmt % record.__dict__
KeyError: 'user'
Logged from file vm_utils.py, line 1860

We need to either revert the oslo change, or come up with a way for nova to specify a new default, otherwise nova can't use the oslo logging code as is.

Revision history for this message
Mark McLoughlin (markmc) wrote :

The review that introduced the probelm - https://review.openstack.org/15956

A workaround nova can use is to do CONF.set_default('logging_context_format_string') but that method is really intended for testing not runtime

We don't have a great answer to this generally - how do we add a hooks to an API to allow the defaults of cfg-registered config options to be tweaked by the projects consuming the API

Hmm, maybe we could do something like this:

  opts = [
      StrOpt('foo'),
      BoolOpt('bar', default=False),
  ]

  def set_defaults(bar=False):
      cfg.set_defaults(opts, bar=bar)

i.e. each module would explicitly say which defaults it encourages tweaking

and cfg would have:

  def set_defaults(self, opts, **kwargs):
      for name, default in kwargs.items():
          for opt in opts:
              if opt.dest == name:
                  opt.default = default
                  break

and nova/config would do:

  def parse_args(argv):
      logging.set_defaults(bar=True)
      cfg.CONF(argv[1:], project='nova')

Michael Still (mikal)
Changed in nova:
importance: Undecided → Critical
status: New → Triaged
Changed in oslo:
status: New → Triaged
importance: Undecided → Critical
Revision history for this message
Sean Dague (sdague) wrote :

To reproduce the current issue you need to copy the new oslo log library into nova (update.py will do it), then run the nova unit tests. Until we have a solution we can't synchronize the log library from oslo into nova.

Revision history for this message
Davanum Srinivas (DIMS) (dims-v) wrote :

git review here for oslo:
https://review.openstack.org/17205

once that change is in, then it's easy to edit nova to set what's needed.

 def parse_args(argv, default_config_files=None):
     cfg.CONF.disable_interspersed_args()
+ log.set_defaults(logging_context_format_string=
+ '%(asctime)s %(levelname)s %(name)s [%(request_id)s '
+ '%(user_id)s %(project_id)s] %(instance)s'
+ '%(message)s')
     return argv[:1] + cfg.CONF(argv[1:],
                                project='nova',
                                default_config_files=default_config_files)

Changed in oslo:
assignee: nobody → Davanum Srinivas (dims-v)
Changed in nova:
assignee: nobody → Davanum Srinivas (dims-v)
Revision history for this message
Russell Bryant (russellb) wrote :

Davanum pointed out that this applies to the rpc control_exchange option, as well. See https://bugs.launchpad.net/nova/+bug/1083944

Mark McLoughlin (markmc)
Changed in oslo:
status: Triaged → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to oslo-incubator (master)

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

Changed in nova:
status: Triaged → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to oslo-incubator (master)

Reviewed: https://review.openstack.org/17558
Committed: http://github.com/openstack/oslo-incubator/commit/9b8128910787ac5f3e80ab81266d971ff20d1805
Submitter: Jenkins
Branch: master

commit 9b8128910787ac5f3e80ab81266d971ff20d1805
Author: Davanum Srinivas <email address hidden>
Date: Wed Dec 5 16:11:48 2012 -0500

    Allow nova and others to override some logging defaults

    - In log.py, indicate that logging module allows tweaking
    of just logging_context_format_string option
    - In cfg.py, add a method that can alter the default given
    the options and new default
    - add testcases for log.set_defaults and cfg.set_defaults

    Fixes LP #1083218

    Change-Id: Iefdbce8505eb7a07f2b59d4ed7564b0146f1b0cd

Changed in oslo:
status: In Progress → Fix Committed
Changed in nova:
status: In Progress → Fix Committed
Thierry Carrez (ttx)
Changed in nova:
milestone: none → grizzly-2
status: Fix Committed → Fix Released
Thierry Carrez (ttx)
Changed in oslo:
milestone: none → grizzly-2
status: Fix Committed → Fix Released
Thierry Carrez (ttx)
Changed in nova:
milestone: grizzly-2 → 2013.1
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.