From 85f7bddef0b2f37de3812d81e3e2f2a051786923 Mon Sep 17 00:00:00 2001 From: A_D <aunderscored@gmail.com> Date: Thu, 20 Jan 2022 15:52:44 +0200 Subject: [PATCH 1/5] use gmtime as time formatter --- EDMCLogging.py | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/EDMCLogging.py b/EDMCLogging.py index c00b7ab9..c98ebe04 100644 --- a/EDMCLogging.py +++ b/EDMCLogging.py @@ -46,6 +46,7 @@ from fnmatch import fnmatch # So that any warning about accessing a protected member is only in one place. from sys import _getframe as getframe from threading import get_native_id as thread_native_id +from time import gmtime from traceback import print_exc from typing import TYPE_CHECKING, Tuple, cast @@ -91,6 +92,9 @@ logging.Logger.trace = lambda self, message, *args, **kwargs: self._log( # type **kwargs ) +# make logging use UTC for times +logging.Formatter.converter = gmtime + def _trace_if(self: logging.Logger, condition: str, message: str, *args, **kwargs) -> None: if any(fnmatch(condition, p) for p in config_mod.trace_on): From 66a212f7c46d6ca603618477f556ffef8208411a Mon Sep 17 00:00:00 2001 From: A_D <aunderscored@gmail.com> Date: Thu, 20 Jan 2022 16:26:04 +0200 Subject: [PATCH 2/5] move UTC to hardcoded, add comment --- EDMCLogging.py | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/EDMCLogging.py b/EDMCLogging.py index c98ebe04..3f08f436 100644 --- a/EDMCLogging.py +++ b/EDMCLogging.py @@ -166,7 +166,10 @@ class Logger: self.logger_formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(process)d:%(thread)d:%(osthreadid)d %(module)s.%(qualname)s:%(lineno)d: %(message)s') # noqa: E501 self.logger_formatter.default_time_format = '%Y-%m-%d %H:%M:%S' - self.logger_formatter.default_msec_format = '%s.%03d' + # WORKAROUND n/a | 2022-01-20: This is concatted to the above time format, so including %Z there is broken + # As a sidenote, this will not always match with journal time etc. As that's based + # on the elite server side time + self.logger_formatter.default_msec_format = '%s.%03d UTC' self.logger_channel.setFormatter(self.logger_formatter) self.logger.addHandler(self.logger_channel) From 5f007b3f77bd62204960bdf9c778547924e60f7d Mon Sep 17 00:00:00 2001 From: A_D <aunderscored@gmail.com> Date: Thu, 20 Jan 2022 16:32:36 +0200 Subject: [PATCH 3/5] more clarifying logs --- EDMCLogging.py | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/EDMCLogging.py b/EDMCLogging.py index 3f08f436..85e7d843 100644 --- a/EDMCLogging.py +++ b/EDMCLogging.py @@ -92,7 +92,9 @@ logging.Logger.trace = lambda self, message, *args, **kwargs: self._log( # type **kwargs ) -# make logging use UTC for times +# make logging use UTC for times, to help make our logs congruent with journals etc. +# Note that as this is the local system vs the remote system (ED servers, for journals), times may not be perfectly +# in sync. (something something NTP) logging.Formatter.converter = gmtime From 3b4f6a4e859773d2534307a876719a1d4f1c77d5 Mon Sep 17 00:00:00 2001 From: A_D <aunderscored@gmail.com> Date: Thu, 20 Jan 2022 16:41:18 +0200 Subject: [PATCH 4/5] switch comments to MAGIC tags --- EDMCLogging.py | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/EDMCLogging.py b/EDMCLogging.py index 85e7d843..82807c90 100644 --- a/EDMCLogging.py +++ b/EDMCLogging.py @@ -92,9 +92,10 @@ logging.Logger.trace = lambda self, message, *args, **kwargs: self._log( # type **kwargs ) -# make logging use UTC for times, to help make our logs congruent with journals etc. -# Note that as this is the local system vs the remote system (ED servers, for journals), times may not be perfectly -# in sync. (something something NTP) +# MAGIC n/a: 2020-01-20: make logging use UTC for times, to help make our logs congruent with journals etc. +# MAGIC-CONT: Note that as this is the local system vs the remote system (ED servers, for journals), +# MAGIC-CONT: times may not be perfectly in sync. (something something NTP). +# MAGIC-CONT: See MAGIC tagged comment in Logger.__init__() logging.Formatter.converter = gmtime @@ -168,9 +169,9 @@ class Logger: self.logger_formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(process)d:%(thread)d:%(osthreadid)d %(module)s.%(qualname)s:%(lineno)d: %(message)s') # noqa: E501 self.logger_formatter.default_time_format = '%Y-%m-%d %H:%M:%S' - # WORKAROUND n/a | 2022-01-20: This is concatted to the above time format, so including %Z there is broken - # As a sidenote, this will not always match with journal time etc. As that's based - # on the elite server side time + # MAGIC n/a | 2022-01-20: As of Python 3.10.2 you can *not* use either `%s.%03.d` in default_time_format + # MAGIC-CONT: *or* use `%Z` in default_time_msec (as its concatted to default_msec). + # MAGIC-CONT: UTC is hardcoded here because we know it always will be (see above MAGIC comment) self.logger_formatter.default_msec_format = '%s.%03d UTC' self.logger_channel.setFormatter(self.logger_formatter) From 71261fc3d9eb84320de4cc9fee83f42856fd40d6 Mon Sep 17 00:00:00 2001 From: A_D <aunderscored@gmail.com> Date: Thu, 20 Jan 2022 16:48:29 +0200 Subject: [PATCH 5/5] Reorder and clarify some comments --- EDMCLogging.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/EDMCLogging.py b/EDMCLogging.py index 82807c90..82f56ca3 100644 --- a/EDMCLogging.py +++ b/EDMCLogging.py @@ -170,8 +170,8 @@ class Logger: self.logger_formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(process)d:%(thread)d:%(osthreadid)d %(module)s.%(qualname)s:%(lineno)d: %(message)s') # noqa: E501 self.logger_formatter.default_time_format = '%Y-%m-%d %H:%M:%S' # MAGIC n/a | 2022-01-20: As of Python 3.10.2 you can *not* use either `%s.%03.d` in default_time_format - # MAGIC-CONT: *or* use `%Z` in default_time_msec (as its concatted to default_msec). - # MAGIC-CONT: UTC is hardcoded here because we know it always will be (see above MAGIC comment) + # MAGIC-CONT: (throws exceptions), *or* use `%Z` in default_time_msec (formatting issues). + # UTC is hardcoded here because we know it always will be (see above MAGIC comment) self.logger_formatter.default_msec_format = '%s.%03d UTC' self.logger_channel.setFormatter(self.logger_formatter)