Python logging: use milliseconds in time format

Question

By default logging.Formatter('%(asctime)s') prints with the following format:

2011-06-09 10:54:40,638

where 638 is the millisecond. I need to change the comma to a dot:

2011-06-09 10:54:40.638

To format the time I can use:

logging.Formatter(fmt='%(asctime)s',datestr=date_format_str)

however the documentation doesn't specify how to format milliseconds. I've found this SO question which talks about microseconds, but a) I would prefer milliseconds and b) the following doesn't work on Python 2.6 (which I'm working on) due to the %f:

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

Answer 1

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 2

This should work too:

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

Answer 3

The simplest way I found was to override default_msec_format:

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

Answer 4

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 5

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 6

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")