From 528d028b50c3f632591b84511a873302ea27c14d Mon Sep 17 00:00:00 2001 From: Max Hirschhorn Date: Mon, 22 Jun 2015 20:18:10 -0400 Subject: SERVER-18572 Use the same timestamp format as MongoDB log messages. --- buildscripts/resmokeconfig/loggers/buildlogger.yml | 8 ++-- buildscripts/resmokeconfig/loggers/console.yml | 4 +- buildscripts/resmokeconfig/loggers/file.yml | 4 +- buildscripts/resmokelib/logging/config.py | 9 ++-- buildscripts/resmokelib/logging/formatters.py | 50 ++++++++++++++++++++++ 5 files changed, 63 insertions(+), 12 deletions(-) create mode 100644 buildscripts/resmokelib/logging/formatters.py (limited to 'buildscripts') diff --git a/buildscripts/resmokeconfig/loggers/buildlogger.yml b/buildscripts/resmokeconfig/loggers/buildlogger.yml index a11b4c7bacf..302d2677491 100644 --- a/buildscripts/resmokeconfig/loggers/buildlogger.yml +++ b/buildscripts/resmokeconfig/loggers/buildlogger.yml @@ -1,13 +1,13 @@ logging: executor: - format: '[%(name)s] %(message)s' + format: '[%(name)s] %(asctime)s %(message)s' handlers: - class: logging.StreamHandler - tests: + fixture: format: '[%(name)s] %(message)s' handlers: - class: buildlogger - fixture: - format: '%(message)s' + tests: + format: '[%(name)s] %(asctime)s %(message)s' handlers: - class: buildlogger diff --git a/buildscripts/resmokeconfig/loggers/console.yml b/buildscripts/resmokeconfig/loggers/console.yml index 0280f41c7ed..b233de409b3 100644 --- a/buildscripts/resmokeconfig/loggers/console.yml +++ b/buildscripts/resmokeconfig/loggers/console.yml @@ -1,6 +1,6 @@ logging: executor: - format: '%(asctime)s [%(name)s] %(message)s' + format: '[%(name)s] %(asctime)s %(message)s' handlers: - class: logging.StreamHandler fixture: @@ -8,6 +8,6 @@ logging: handlers: - class: logging.StreamHandler tests: - format: '%(asctime)s [%(name)s] %(message)s' + format: '[%(name)s] %(asctime)s %(message)s' handlers: - class: logging.StreamHandler diff --git a/buildscripts/resmokeconfig/loggers/file.yml b/buildscripts/resmokeconfig/loggers/file.yml index 012aed5d331..3d2d15cd5bc 100644 --- a/buildscripts/resmokeconfig/loggers/file.yml +++ b/buildscripts/resmokeconfig/loggers/file.yml @@ -1,6 +1,6 @@ logging: executor: - format: '%(asctime)s [%(name)s] %(message)s' + format: '[%(name)s] %(asctime)s %(message)s' handlers: - class: logging.FileHandler filename: executor.log @@ -12,7 +12,7 @@ logging: filename: fixture.log mode: w tests: - format: '%(asctime)s [%(name)s] %(message)s' + format: '[%(name)s] %(asctime)s %(message)s' handlers: - class: logging.FileHandler filename: tests.log diff --git a/buildscripts/resmokelib/logging/config.py b/buildscripts/resmokelib/logging/config.py index 9f3ca94dc82..c3960bbafd3 100644 --- a/buildscripts/resmokelib/logging/config.py +++ b/buildscripts/resmokelib/logging/config.py @@ -8,6 +8,7 @@ import logging import sys from . import buildlogger +from . import formatters from . import loggers @@ -64,7 +65,7 @@ def apply_buildlogger_global_handler(logger, logging_config, build_id=None, buil if all(x is not None for x in (build_id, build_config)): log_format = logger_info.get("format", _DEFAULT_FORMAT) - formatter = logging.Formatter(fmt=log_format) + formatter = formatters.ISO8601Formatter(fmt=log_format) handler = buildlogger.BuildloggerGlobalHandler(build_id, build_config, @@ -95,7 +96,7 @@ def apply_buildlogger_test_handler(logger, if all(x is not None for x in (build_id, build_config, test_id)): log_format = logger_info.get("format", _DEFAULT_FORMAT) - formatter = logging.Formatter(fmt=log_format) + formatter = formatters.ISO8601Formatter(fmt=log_format) handler = buildlogger.BuildloggerTestHandler(build_id, build_config, @@ -115,7 +116,7 @@ def _configure_logger(logger, logger_info): """ log_format = logger_info.get("format", _DEFAULT_FORMAT) - formatter = logging.Formatter(fmt=log_format) + formatter = formatters.ISO8601Formatter(fmt=log_format) for handler_info in logger_info.get("handlers", []): handler_class = handler_info["class"] @@ -140,7 +141,7 @@ def _fallback_buildlogger_handler(): """ log_format = "[buildlogger:%(name)s] %(message)s" - formatter = logging.Formatter(fmt=log_format) + formatter = formatters.ISO8601Formatter(fmt=log_format) handler = logging.StreamHandler(sys.stderr) handler.setFormatter(formatter) diff --git a/buildscripts/resmokelib/logging/formatters.py b/buildscripts/resmokelib/logging/formatters.py new file mode 100644 index 00000000000..4cc36da32d4 --- /dev/null +++ b/buildscripts/resmokelib/logging/formatters.py @@ -0,0 +1,50 @@ +""" +Custom formatters for the logging handlers. +""" + +from __future__ import absolute_import + +import logging +import sys +import time + + +class ISO8601Formatter(logging.Formatter): + """ + An ISO 8601 compliant formatter for log messages. It formats the + timezone as an hour/minute offset and uses a period as the + millisecond separator in order to match the log messages of MongoDB. + """ + + def formatTime(self, record, datefmt=None): + converted_time = self.converter(record.created) + + if datefmt is not None: + return time.strftime(datefmt, converted_time) + + formatted_time = time.strftime("%Y-%m-%dT%H:%M:%S", converted_time) + timezone = ISO8601Formatter._format_timezone_offset(converted_time) + return "%s.%03d%s" % (formatted_time, record.msecs, timezone) + + @staticmethod + def _format_timezone_offset(converted_time): + """ + Returns the timezone as an hour/minute offset in the form + "+HHMM" or "-HHMM". + """ + + # Windows treats %z in the format string as %Z, so we compute the hour/minute offset + # manually. + if converted_time.tm_isdst == 1 and time.daylight: + utc_offset_secs = time.altzone + else: + utc_offset_secs = time.timezone + + # The offset is positive if the local timezone is behind (east of) UTC, and negative if it + # is ahead (west) of UTC. + utc_offset_prefix = "-" if utc_offset_secs > 0 else "+" + utc_offset_secs = abs(utc_offset_secs) + + utc_offset_mins = (utc_offset_secs / 60) % 60 + utc_offset_hours = utc_offset_secs / 3600 + return "%s%02d%02d" % (utc_offset_prefix, utc_offset_hours, utc_offset_mins) -- cgit v1.2.1