Open Stack

Excerpts from Saverio Proto's message of 2018-01-22 18:45:15 +0100:
> Hello Doug,
> 
> in the extra session I see just {"project": "unknown", "version": "unknown"}
> 
> here a full line from nova-api:
> 
> {"thread_name": "MainThread", "extra": {"project": "unknown", "version":
> "unknown"}, "process": 31142, "relative_created": 3459415335.4091644,
> "module": "wsgi", "message":
> "2001:xxx:xxxx:8100::80,2001:xxx:xxxx:81ff::b0 \"GET
> /v2/64b5b50eb21d4efe9783eb1d81a9ec65/os-services HTTP/1.1\" status: 200
> len: 1812 time: 0.1813300", "hostname": "nova-0", "filename": "wsgi.py",
> "levelno": 20, "lineno": 555, "asctime": "2018-01-22 18:37:02,312",
> "msg": "2001:xxx:xxxx:8100::80,2001:xxx:xxxx:81ff::b0 \"GET
> /v2/64b5b50eb21d4efe9783eb1d81a9ec65/os-services HTTP/1.1\" status: 200
> len: 1812 time: 0.1813300", "args": [], "process_name": "MainProcess",
> "name": "nova.osapi_compute.wsgi.server", "thread": 140414249163824,
> "created": 1516642622.312235, "traceback": null, "msecs":
> 312.23511695861816, "funcname": "handle_one_response", "pathname":
> "/usr/lib/python2.7/dist-packages/eventlet/wsgi.py", "levelname": "INFO"}

It looks like you're running into a limitation of the older version of
the library where the context was only logged from openstack source
code. This particular log message is coming from the eventlet library.

Try running the script below and saving the output to a pastebin.

Under the newton version of oslo.log, I get
http://paste.openstack.org/show/650566/ and under the queens version I
get http://paste.openstack.org/show/650569/ which shows me that the
"extra" handling is working more or less the same way but the "context"
handling is improved in the newer version (lots of the values are null
because I don't fully set up the context, but the request_id field has a
valid value).

Doug


#!/usr/bin/env python

from __future__ import print_function

import logging

from oslo_context import context
from oslo_log import formatters, log


ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)

formatter = formatters.JSONFormatter()
ch.setFormatter(formatter)

LOG = logging.getLogger()
LOG.setLevel(logging.DEBUG)
LOG.addHandler(ch)

ctx = context.RequestContext(request_id='the-request-id')

LOG.debug('without extra')
print()

LOG.debug('with extra', extra={'context': ctx})
print()

log.getLogger().debug('via KeywordArgumentAdapter', context=ctx)