Datetime with milliseconds or microseconds AND timezone offset

Question

This is the representation desired for dates:

>>> tz = pytz.timezone('US/Central')
>>> datefmt = '%Y-%m-%d %H:%M:%S.%f%z(%Z)'
>>> datetime.now(tz).strftime(datefmt)
'2017-04-27 15:09:59.606921-0500(CDT)'

This is how it's logged (Python 3.6.0 on Linux):

>>> logrecord_format = '%(asctime)s %(levelname)s %(message)s'
>>> logging.basicConfig(format=logrecord_format, datefmt=datefmt)
>>> logging.error('ruh-roh!')
2017-04-27 15:10:35.%f-0500(CDT) ERROR ruh-roh!

It's not filling the microseconds properly. I've tried changing the logrecord_format to a few other things, but I could not figure it out - how to configure the logger to show microseconds and timezone in the correct way to match the strftime output exactly?

---

Edit: I could settle for milliseconds with offset, i.e. 2017-04-27 15:09:59,606-0500(CDT). Is that possible? logging provides %(msecs)03d directive, but I can't seem to get the timezone offset to appear after the milliseconds.

Answer 1

Personally, instead of integrating the timezone into the date format, I add it directly to the logged message format. Usually, the timezone should not change during the program execution.

import logging
import time

tz = time.strftime('%z')
fmt = '%(asctime)s' + tz + ' %(levelname)s %(message)s'

logging.basicConfig(format=fmt)

logging.error("This is an error message.")

# 2017-07-28 19:34:53,336+0200 ERROR This is an error message.

Answer 2

More formally than the accepted answer, and to get microseconds, you need to use datetime instead of time for the string formatting.

import logging
import pytz
from datetime import datetime

class TZAwareFormatter(logging.Formatter):
    """
    A timezone-aware logging formatter.

    By default, Python's `logging` module uses the `time` module for conversion
    of timestamps to time tuples, which doesn't support %f for microsecond formatting
    """
    def __init__(self, tz, *args, **kwargs):
        super().__init__(*args, **kwargs)
        self.tz = tz
        
    def converter(self, timestamp):
        return datetime.fromtimestamp(timestamp, self.tz)

    def formatTime(self, record, datefmt=None):
        dt = self.converter(record.created)
        if datefmt:
            s = dt.strftime(datefmt)
        else:
            s = dt.strftime(self.default_time_format)
            if self.default_msec_format:
                s = self.default_msec_format % (s, record.msecs)

        return s

And how to use it:

# Update the logging root handler to use correct Formatter
logging.basicConfig()
root_logger = logging.getLogger()
root_handler = root_logger.handlers[0]

root_handler.setFormatter(
    TZAwareFormatter(
        tz=pytz.timezone('US/Central'),
        fmt='%(asctime)s %(levelname)s %(message)s',
        datefmt='%Y-%m-%d %H:%M:%S.%f%z (%Z)'
    )
)
logging.error('uh-oh!')