Python日志记录：使用毫秒格式的时间

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

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.

This should work too:

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

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

The simplest way I found was to override default_msec_format:

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

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

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

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.

tl;dr for folks looking here for an ISO formatted date:

instead of using something like ‘%Y-%m-%d %H:%M:%S.%03d%z’, create your own class as @unutbu indicated. Here’s one for iso date format:

import logging
from time import gmtime, strftime

class ISOFormatter(logging.Formatter):
    def formatTime(self, record, datefmt=None):
        t = strftime("%Y-%m-%dT%H:%M:%S", gmtime(record.created))
        z = strftime("%z",gmtime(record.created))
        s = "%s.%03d%s" % (t, record.msecs,z)        
        return s

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

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

formatter = ISOFormatter(fmt='%(asctime)s - %(module)s - %(levelname)s - %(message)s')
console.setFormatter(formatter)

logger.debug('Jackdaws love my big sphinx of quartz.')
#2020-10-23T17:25:48.310-0800 - <stdin> - DEBUG - Jackdaws love my big sphinx of quartz.

As of now the following works perfectly with python 3 .

         logging.basicConfig(level=logging.DEBUG,
                     format='%(asctime)s %(levelname)-8s %(message)s',
                     datefmt='%Y/%m/%d %H:%M:%S.%03d',
                     filename=self.log_filepath,
                     filemode='w')

gives the following output

2020/01/11 18:51:19.011 INFO