Python logging with a custom clock
Dear list, log records in the Python logging library always use timestamps provided by `time.time()`, i.e. the usual system clock (UTC, CLOCK_REALTIME). This time is used as absolute timestamp in log records and for timestamps relative to the load of the library (Lib/logging/__init__.py: `_startTime`). I would like to receive feedback to and propose the attached (and possibly incomplete) patch that allows the programmer to provide a custom callable to get the time instead of `time.time()`. For example, this could be: clock = lambda: time.clock_gettime(time.CLOCK_TAI) and the callable could be provided during initial logging setup logging.basicConfig(clock=clock, ...) There is a similar approach in log4j to specify a custom clock [0]. This change enables the use of non-UTC clocks, e.g. `CLOCK_TAI` or `CLOCK_MONOTONIC`, which are unaffected by leap seconds and count SI seconds. (In fact, logging's use of differences of UTC timestamps could make users believe that the obtained duration reflects SI seconds, which it doesn't in all cases.) Combining a custom absolute clock such as `CLOCK_TAI` with custom log formatters allows users to /store or transfer/ log records with TAI timestamps, and /display/ them with UTC timestamps (e.g. properly converted from TAI to UTC with a "60" second during active leap second). This resolves the ambiguity when analysing and correlating logs from different machines also during leap seconds. Attached is a simple example showing the different timestamps based on UTC and TAI (assuming the current offset of +37 seconds [1] is properly configured on the host, e.g. through PTP or `adjtimex()` with `ADJ_TAI`). $ export TZ=GMT $ date --iso-8601=seconds && python3 example.py 2020-09-02T14:34:14+00:00 2020-09-02T14:34:51+0000 INFO message According to the documentation `time.CLOCK_TAI` was introduced in Python 3.9 [2], but already today the system constant can be used (e.g. on Debian Buster, Linux 4.19.0, Python 3.7.3 it is 11). The two patches provided are for Python 3.7.3 (Debian Buster) and Python 3.8.5 (python.org). In the latter case, it may need to be considered how changing the Python logging clock works: it probably should fail if handlers are already configured, unless `force` is also provided and handlers are reset. Kind regards, -- nicolas benes [0] `log4j.Clock` in https://logging.apache.org/log4j/log4j-2.8/manual/configuration.html [1] https://www.timeanddate.com/worldclock/other/tai [2] https://docs.python.org/dev/library/time.html#time.CLOCK_TAI -------------------------------------------------------------- Nicolas Benes nbenes@eso.org + Software Engineer +E S+ European Southern Observatory https://www.eso.org O Karl-Schwarzschild-Strasse 2 + D-85748 Garching b. Muenchen Germany --------------------------------------------------------------
participants (1)
-
N. Benes