Initialize by default the `global_request_id` if not passed
in the given context to avoid error with logging.
Change-Id: I6bd63c1d6a1331a4e47b923ccf6df50c930c8162
Closes-Bug: #1972974
When running under uwsgi a new key "uwsgi_name" is added to log
events when using FluentFormatter that could be used for further
analysis. It's value is taken from uwsgi configuration upon
formatter initialization.
Change-Id: I158409677523978246c26bf1168f323974d817a5
Closes-Bug: 1887232
This was optionally being enabled to handle the case where we did not
have oslo.serialization 2.21.1. Our minimum version is now 2.25.0 so
this will never be the case. Remove this optionality logic.
Change-Id: Ib61e1fd02a5ec98ddcaed2ce42f049636598870f
Signed-off-by: Stephen Finucane <sfinucan@redhat.com>
This change introduces the serialization with basically json dumps,
falling back to repr for non-serializable object. We check the types
of the top level objects passed to the formatter, as for example
an object enclosed into dictionary passed to the logger should be a
much more rare case.
Closes-Bug: 1782361
Change-Id: Ib214f95abfadd91f85b6cce853057a572ec287f6
Special characters in regular strings now cause DeprecationWarnings
starting with Python 3.6. This frequently happens with regex strings.
Oslo.log had one instance of a regex string containing '\' that would
cause deprecation warnings in logs. This switches that instance over to
be a raw string to avoid these warnings.
Change-Id: Ia5637f35315127c5cc46e01f5e38eccb094e772d
Signed-off-by: Sean McGinnis <sean.mcginnis@gmail.com>
Since process_name value defaults to "MainProcess" a new field cmdline
has been added in order to get information which process (daemon)
triggers the event.
Change-Id: I1d7713ff7de930e40fc5b8ceb2cf2af54082c9cc
Closes-Bug: 1822101
In most formatters, any unused keys in the args dict will just be
discarded. Because JSONFormatter logged the entire dict in addition
to the message, some values were included in the output that may
not have been intended. This could include sensitive data, so we
should stop that.
In the interest of maintaining compatibility with any tools that are
reading the args dict, we leave the dict but filter out any unused
keys.
Change-Id: Ib64837c1ae93a27bef3d30a776320a373f18dd1c
Closes-Bug: 1571714
Closes-Bug: 1787214
Python 3.2 added the 'style' parameter to 'logging.Formatter.__init__'.
This is provided by 'logging.config.fileConfig' meaning this currently
raises a 'TypeError' similar to the below when the incompatible
formatters, JSONFormatter and FluentFormatter, are used with Python 3.2
or greater.
TypeError: __init__() got an unexpected keyword argument 'style'
Resolve this by simply adding the parameter to the list. There is more
work we can do here (like actually supporting this parameter) but that's
a job for another patch.
Note that we can't actually test this as doing so would involve invoking
'logging.config.fileConfig', which in turn would modify the global state
of the 'logging' module. You can thank the singleton pattern for that.
Change-Id: I9b339163ddfe440bc6782ced33595a0dcf60f658
Closes-Bug: 1739743
Co-Authored-By: Stephen Finucane <stephenfin@redhat.com>
Currently, when logging at level >= WARNING, exception information is
added to the log message as an "error summary" for operators. The error
summary includes the exception type and the message. However, when the
exception is a _Remote exception generated from oslo.messaging and sent
over RPC, the full traceback from the exception is appended to the
exception message [1] to preserve it. So, the error summary ends up
outputting the full traceback, unintentionally.
This truncates the error_summary to keep only the first line unless
exc_info was explicitly passed, via LOG.exception(), for example.
Closes-Bug: #1729475
[1] https://github.com/openstack/oslo.messaging/blob/8d42484/oslo_messaging/_drivers/common.py#L208
Change-Id: I2e4e356d23dff2e6ac1946fe9e994c4d962ab55a
The JSON formatter used to rely on services making their logging calls
and passing the context there. A call it expted would be
LOG.debug("Some message", context=context)
This would end up in the "extra" section of the logging record. This is
not usually the case, as projects don't always pass the context on that
call. This also applies to the Fluent formatter which is based on the
JSON one.
For the JSON formatter, we already are getting the context from the
record. So lets use that if no context was provided in the record's
'extra' section. Finally, this places the context in its own section,
which is named 'context'.
Closes-Bug: #1730329
Depends-On: I2b245c1665c3587be3c476b803122788d186e5d5
Change-Id: I765dae17d2ecadce1672f16e432e748d5233acf8
The JSONFormatter formatter now converts unserializable objects with
repr() to prevent JSON serialization errors on logging.
The fix requires oslo.serialization 2.21.1 or newer to get the new
fallback parameter of jsonutils.to_primitive().
Closes-Bug: #1593641
Change-Id: Ibda7d145af95903b2bf8d87113804350330a93b4
A bug in the Python 3 standard library,
https://bugs.python.org/issue28603 means that calling the traceback
module with an exception chain that includes an unhashable exception
results in a TypeError being raised. (In Python 3, any classes that
define __eq__() without also explicitly defining - not inheriting -
__hash__() will be unhashable.) The TypeError itself is also part of
such a chain, since its __context__ will be the unhashable exception. If
we don't catch it then the thread will simply exit mysteriously, and no
amount of logging will be able to reveal to the user what happened.
Change-Id: I6768574f38b075c15e829df5593a45c6be66b1bc
Closes-Bug: #1724366
Further reduce the clutter from error_summary by only including it when
the log message will be emitted for the warning level or above.
Change-Id: Ia46a7e569b875cd75fec652dfe8a4d73661dfda8
Signed-off-by: Doug Hellmann <doug@doughellmann.com>
We catch exceptions and log debug messages a lot, which results in extra
occurrences of the exception when we don't need them.
Change-Id: I4dd3bf65fb456afc07a8fa7d0c9869bcc266b800
Related-Bug: #1696213
Related-Bug: #1696855
Signed-off-by: Doug Hellmann <doug@doughellmann.com>
In some projects, we conditionally import modules that may be not
installed, for example in Neutron where we import from ibm_db_alembic
but ignore ImportError in alembic env.py.
It turned out that ImportError is not cleared by except: pass in py2
(but is correctly cleared in py3), as can be seen in the snippet below
(kudos to @dhellmann for providing it):
apu:~$ cat testme.py
import sys
print('before:', sys.exc_info()[0])
try:
import nonesuch
except ImportError:
pass
print('after:', sys.exc_info()[0])
apu:~$ python2 ./testme.py
('before:', None)
('after:', <type 'exceptions.ImportError'>)
apu:~$ python3 ./testme.py
before: None
after: None
The patch makes the formatter skip ImportErrors. We could in theory
limit it to py2 only but to simplify matters and to stick to identical
behavior across python runtimes, we will just unconditionally skip it
for all library consumers.
This is a follow up to Ifecb831c0adf4086a9d39feb3eb7e3865db780e6 ("skip
built-in exceptions when adding error_summary") that already skipped
some builtin exceptions.
Change-Id: Ia8f7e2501a49345b8d828ec3ee4a7cc870c8a0a8
We have a lot of cases where we catch a built-in exception then
log. Those exceptions don't add useful information, so do not include
them automatically in the log output.
Change-Id: Ifecb831c0adf4086a9d39feb3eb7e3865db780e6
Signed-off-by: Doug Hellmann <doug@doughellmann.com>
Allow operators to override the location of the error summary within the
format string, if they choose.
Change-Id: I85fe5abaa0781d033638e3b6f120184726d205ac
Signed-off-by: Doug Hellmann <doug@doughellmann.com>
Normally when logging while there is an active exception, the exception
is formatted as a traceback and the log message string ends up on a
separate line. This change adds the 1-line summary of the exception,
including the exception class name and the text of the exception, to the
end of the log line. The traceback is retained, so that the full details
are still logged.
Adding the exception info in the formatter means that the default
excepthook function no longer needs to do that (otherwise we end up with
duplicate information on the lines logged by the excepthook). Fix the
duplication by replacing the extra traceback formatting with a static
message that there is an unhandled error.
Depends-On: Icb2e1c6d9fe40229119467e9261055d9464d331d
Change-Id: Ib29883a1b7aa665b5d3c728dd7bd53d449987191
Signed-off-by: Doug Hellmann <doug@doughellmann.com>
In ContextFormatter.format(), for python2 it checks each arg to
determine whether unicode should be used for the format message.
The problem is the code assumes the args are a list, when they can
also be a dict, for example:
LOG.info('%(thing)s', {'thing': '...'})
and in that case, the dict keys were implicitly being used for the
checks. The checks will always pass on string dict keys, so the
format message gets converted to unicode even though the corresponding
args will ultimately fail decoding to unicode. Then, the logging fails
with:
UnicodeDecodeError: 'ascii' codec can't decode byte 0xc6 in
position 0: ordinal not in range(128)
when the unicode format message causes an implicit conversion attempt
of the args to unicode [1].
This adds a check for the args type and uses the dict values for the
unicode checks so that dict args with values that fail decoding will
have: should_use_unicode = False.
Closes-Bug: #1580728
[1] https://github.com/python/cpython/blob/2e576f5/Lib/logging/__init__.py#L338
Change-Id: I8c479e507efcf8acd3e3faa4a702fa6e1f18772f
Also included a unit test which will validate that scenario.
Error occured at oslo_privsep implementation, which is fixed upstream:
3c47348ced
Change-Id: I6dd34f80662d2733b37f8d8d1b9f81eb6161f346
We have moved properties that no longer make directly accessing
the __dict__ a good practice to go forward with (because those
properties redirect to other members) so prefer to go through
the correct conversion method to get at the dict that represents
a context.
Change-Id: I6fbf2192f477f62b1843321d2ec2147a3536a888
This change implements FluentFormatter, a formatter for fluentd.
It enables oslo_log to output logs to fluentd directly.
FluentFormatter expects it will be used by fluent.handler.FluentHandler.
DocImpact
Implements: blueprint fluent-formatter
Change-Id: I67be5079f9370e93e5e3d4c715d2b8011154a2ce
Pure python logging library allows to log encoded strings
but in oslo_log it causes UnicodeDecodeError for arguments
which contains unicode symbols.
Changes add additional check whether all arguments can be converted to
unicode. If it isn't possible then leave it as is.
Change-Id: I76e75c35a74b146fae52c0ea60156e1cf78540e7
Closes-Bug: #1563295
Use new dedicated method for context aware attributes in oslo.log which
will enable future improvements for common and project specific logging
format parameters. Fall back to legacy method if not found in passed
context object and provide a deprecated warning of missing method.
Change-Id: Ica445ad5dfe9bd27dfcf1b1bcb6401a0bc9496a5
Implements: blueprint app-agnostic-logging-parameters
Depends-On: I963a6db4aef74f7348e75a642e2e195cedacecaa
Depends-On: I5450e105dc914f822a2b4c03b759a682d8b4a3e7
Depends-On: I9025770693d4b15efe4bd3556e6704326b1c915e
Change Id4754c18935940cc7c738e4a91880267fdeb808f only added isotime to
the formatting for regular log messages, and not exceptions. This change
adds support for the isotime variable in the log prefix string for
tracebacks.
Change-Id: I7203839a2366692e7d54597eacadb17ee24a1f0a
This patch-set add a new config string option
for user_identity format.
Default of "logging_context_format_string" format is followings,
'%(asctime)s.%(msecs)03d %(process)d %(levelname)s '
'%(name)s [%(request_id)s %(user_identity)s] '
'%(instance)s%(message)s',
which is defined in oslo_log/_option.py, or config file.
And default of "%(user_identity)s" field format is followings,
user_idt_format = '{user} {tenant} {domain} {user_domain} {p_domain}'
which is defined in oslo_context/context.py
So, adding new config string option for user_identity format,
we are able to control the user_identity format.
For example, add following line to config file.
logging_user_identity_format = U:%(user)s T:%(tenant)s
Change-Id: I249ef7a8d144a4d5a34c3f80113f96fa4730ce28
Implements: blueprint user-identity-format-flexibility
This change adds 'hostname' field to JSONFormatter.
The field is helpful to distinguish which host sent the logs.
Closes-Bug: #1501232
Change-Id: Ie4ba197543bc8ebd0e22c509a9fe3190069aa5a6
Exception happened if user_name and project_name would be used in some
case. e.g. calling notifier in oslo_messaging with empty context.
Change-Id: I4bc5ed4e6caa18c5adc889151c0c9dd75227af8f
Closes-Bug:#1476955
Nova has moved to oslo.log, however one specific usecase is
blowing up in Nova. when they use instance=instance in say
LOG.info to pass in instance, they expect the uuid in the
instance dict/object to be printed in the log. However we
end up with the string-ified version of the Instance object
or the entire instance dict which is not good.
Closes-Bug: #1426544
Change-Id: I2d1b09015bead2012327f973f45f3f6728160c69
Cleaning up log messages and thought it
would be useful to make it "easier" to log the
volume/snapshot/backup/image id's more easily.
Unlike the Nova Instance work that was submitted this
key will work with any db ref object that has a "name"
member. Most OpenStack objects have an internal name
that is built using the UUID of the resource object.
Resource objects in Cinder for example use:
"<resourceName-uuid>"
For those that don't have the name member, we also
give the ability to set resource as a dict, with
keys 'type' and 'id' that will form the same string.
With this change, LOG calls in projects can be sent like:
LOG.info(_LI('begin some operation'), resource=dbref)
or
LOG.info(_LI('begin some operation'), resource=
mydict{'type': 'volume',
'id': '40e0f194-0ccb-422f-a543-c5f9022acb6f')
The result will be the resource identifier prepended to the msg:
INFO cinder.volume.manager [-]\
[volume-40e0f194-0ccb-422f-a543-c5f9022acb6f] \
succesfully deleted volume
This will be in addition to work being done to put the same info in context,
then we'll automatically pick this info up from context if it's there but still
allow it to be overridden with the extra keys in this change.
Change-Id: I67b31f666172451fd6b061520b0f171ec8e7387b
Partially-Implements: blueprint app-agnostic-logging-parameters
Remove the _local store as we don't need it anymore. We should
fetch the context directly from oslo_context's context module
using the get_current() method. Use the fixture in oslo_context
to adapt the test cases to work with the change outlined above.
Since we are using RequestContext from oslo_context, adjust a
bit of code to use resource_uuid in addition to instance_uuid
as well. Added a fixture in the base test case itself to make
sure that the context thread local store is cleared in between
tests
Change-Id: I09442d824400041768dbcddfbce932b175c767ab
Move oslo.log to oslo_log. Since this library has not been released, we
do not need to retain the old interface for compatibility.
bp/drop-namespace-packages
Change-Id: Id8e2312a72af171918fa4d40117ec652018a37bf
Hervé Beraud