openstack
/
oslo.log
Code Issues Proposed changes

enable isotime for exceptions 

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 commit is contained in:
Doug Hellmann 2016-01-04 21:24:22 +00:00
parent 648e2f5a6a
commit 149041df41
2 changed files with 44 additions and 13 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

31
oslo_log/formatters.py
View File

@ -254,19 +254,7 @@ class ContextFormatter(logging.Formatter):
self.conf.logging_debug_format_suffix):
fmt += " " + self.conf.logging_debug_format_suffix
# set iso8601 timestamp
localtz = tz.tzlocal()
record.isotime = datetime.datetime.fromtimestamp(
record.created).replace(tzinfo=localtz).isoformat()
if record.created == int(record.created):
# NOTE(stpierre): when the timestamp includes no
# microseconds -- e.g., 1450274066.000000 -- then the
# microseconds aren't included in the isoformat() time. As
# a result, in literally one in a million cases
# isoformat() looks different. This adds microseconds when
# that happens.
record.isotime = "%s.000000%s" % (record.isotime[:-6],
record.isotime[-6:])
self._compute_iso_time(record)
if sys.version_info < (3, 2):
self._fmt = fmt
@ -292,9 +280,26 @@ class ContextFormatter(logging.Formatter):
if self.conf.logging_exception_prefix.find('%(asctime)') != -1:
record.asctime = self.formatTime(record, self.datefmt)
self._compute_iso_time(record)
formatted_lines = []
for line in lines:
pl = self.conf.logging_exception_prefix % record.__dict__
fl = '%s%s' % (pl, line)
formatted_lines.append(fl)
return '\n'.join(formatted_lines)
def _compute_iso_time(self, record):
# set iso8601 timestamp
localtz = tz.tzlocal()
record.isotime = datetime.datetime.fromtimestamp(
record.created).replace(tzinfo=localtz).isoformat()
if record.created == int(record.created):
# NOTE(stpierre): when the timestamp includes no
# microseconds -- e.g., 1450274066.000000 -- then the
# microseconds aren't included in the isoformat() time. As
# a result, in literally one in a million cases
# isoformat() looks different. This adds microseconds when
# that happens.
record.isotime = "%s.000000%s" % (record.isotime[:-6],
record.isotime[-6:])

26
oslo_log/tests/unit/test_log.py
View File

@ -528,6 +528,32 @@ class ExceptionLoggingTestCase(LogTestBase):
log.setup(self.CONF, "test_excepthook_installed")
self.assertTrue(sys.excepthook != sys.__excepthook__)
@mock.patch("datetime.datetime",
get_fake_datetime(
datetime.datetime(2015, 12, 16, 13, 54, 26, 517893)))
@mock.patch("dateutil.tz.tzlocal", new=mock.Mock(return_value=tz.tzutc()))
def test_rfc5424_isotime_format(self):
self.config(
logging_default_format_string="%(isotime)s %(message)s",
logging_exception_prefix="%(isotime)s ",
)
product_name = 'somename'
exc_log = log.getLogger(product_name)
self._add_handler_with_cleanup(exc_log)
excepthook = log._create_logging_excepthook(product_name)
try:
raise Exception('Some error happened')
except Exception:
excepthook(*sys.exc_info())
expected_string = ("2015-12-16T13:54:26.517893+00:00 "
"Exception: Some error happened")
self.assertIn(expected_string,
self.stream.getvalue())
class FancyRecordTestCase(LogTestBase):
"""Test how we handle fancy record keys that are not in the