Python logging: use milliseconds in time format

Answer #1:

Please note Craig McDaniel’s solution is clearly better.

logging.Formatter’s formatTime method looks like this:

def formatTime(self, record, datefmt=None):
    ct = self.converter(record.created)
    if datefmt:
        s = time.strftime(datefmt, ct)
    else:
        t = time.strftime("%Y-%m-%d %H:%M:%S", ct)
        s = "%s,%03d" % (t, record.msecs)
    return s

Notice the comma in "%s,%03d". This can not be fixed by specifying a datefmt because ct is a time.struct_time and these objects do not record milliseconds.

If we change the definition of ct to make it a datetime object instead of a struct_time, then (at least with modern versions of Python) we can call ct.strftime and then we can use %f to format microseconds:

import logging
import datetime as dt

class MyFormatter(logging.Formatter):
    converter=dt.datetime.fromtimestamp
    def formatTime(self, record, datefmt=None):
        ct = self.converter(record.created)
        if datefmt:
            s = ct.strftime(datefmt)
        else:
            t = ct.strftime("%Y-%m-%d %H:%M:%S")
            s = "%s,%03d" % (t, record.msecs)
        return s

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)

console = logging.StreamHandler()
logger.addHandler(console)

formatter = MyFormatter(fmt='%(asctime)s %(message)s',datefmt='%Y-%m-%d,%H:%M:%S.%f')
console.setFormatter(formatter)

logger.debug('Jackdaws love my big sphinx of quartz.')
# 2011-06-09,07:12:36.553554 Jackdaws love my big sphinx of quartz.

Or, to get milliseconds, change the comma to a decimal point, and omit the datefmt argument:

class MyFormatter(logging.Formatter):
    converter=dt.datetime.fromtimestamp
    def formatTime(self, record, datefmt=None):
        ct = self.converter(record.created)
        if datefmt:
            s = ct.strftime(datefmt)
        else:
            t = ct.strftime("%Y-%m-%d %H:%M:%S")
            s = "%s.%03d" % (t, record.msecs)
        return s

...
formatter = MyFormatter(fmt='%(asctime)s %(message)s')
...
logger.debug('Jackdaws love my big sphinx of quartz.')
# 2011-06-09 08:14:38.343 Jackdaws love my big sphinx of quartz.

Answer #2:

This should work too:

logging.Formatter(fmt='%(asctime)s.%(msecs)03d',datefmt='%Y-%m-%d,%H:%M:%S')

Answer #3:

Adding msecs was the better option, Thanks.
Here is my amendment using this with Python 3.5.3 in Blender

import logging
logging.basicConfig(level=logging.DEBUG, format='%(asctime)s.%(msecs)03d %(levelname)s:t%(message)s', datefmt='%Y-%m-%d %H:%M:%S')
log = logging.getLogger(__name__)
log.info("Logging Info")
log.debug("Logging Debug")

Answer #4:

The simplest way I found was to override default_msec_format:

formatter = logging.Formatter('%(asctime)s')
formatter.default_msec_format = '%s.%03d'

Answer #5:

After instantiating a Formatter I usually set formatter.converter = gmtime. So in order for @unutbu’s answer to work in this case you’ll need:

class MyFormatter(logging.Formatter):
    def formatTime(self, record, datefmt=None):
        ct = self.converter(record.created)
        if datefmt:
            s = time.strftime(datefmt, ct)
        else:
            t = time.strftime("%Y-%m-%d %H:%M:%S", ct)
            s = "%s.%03d" % (t, record.msecs)
        return s

Answer #6:

A simple expansion that doesn’t require the datetime module and isn’t handicapped like some other solutions is to use simple string replacement like so:

import logging
import time

class MyFormatter(logging.Formatter):
    def formatTime(self, record, datefmt=None):
        ct = self.converter(record.created)
        if datefmt:
            if "%F" in datefmt:
                msec = "%03d" % record.msecs
                datefmt = datefmt.replace("%F", msec)
            s = time.strftime(datefmt, ct)
        else:
            t = time.strftime("%Y-%m-%d %H:%M:%S", ct)
            s = "%s,%03d" % (t, record.msecs)
        return s

This way a date format can be written however you want, even allowing for region differences, by using %F for milliseconds. For example:

log = logging.getLogger(__name__)
log.setLevel(logging.INFO)

sh = logging.StreamHandler()
log.addHandler(sh)

fm = MyFormatter(fmt='%(asctime)s-%(levelname)s-%(message)s',datefmt='%H:%M:%S.%F')
sh.setFormatter(fm)

log.info("Foo, Bar, Baz")
# 03:26:33.757-INFO-Foo, Bar, Baz

Answer #7:

If you are using arrow or if you don’t mind using arrow. You can substitute python’s time formatting for arrow’s one.

import logging

from arrow.arrow import Arrow


class ArrowTimeFormatter(logging.Formatter):

    def formatTime(self, record, datefmt=None):
        arrow_time = Arrow.fromtimestamp(record.created)

        if datefmt:
            arrow_time = arrow_time.format(datefmt)

        return str(arrow_time)


logger = logging.getLogger(__name__)

default_handler = logging.StreamHandler()
default_handler.setFormatter(ArrowTimeFormatter(
    fmt='%(asctime)s',
    datefmt='YYYY-MM-DD HH:mm:ss.SSS'
))

logger.setLevel(logging.DEBUG)
logger.addHandler(default_handler)

Now you can use all of arrow’s time formatting in datefmt attribute.

Answer #8:

If you prefer to use style='{', fmt="{asctime}.{msecs:0<3.0f}" will 0-pad your microseconds to three places for consistency.