Python logging: use milliseconds in time format
By default logging.Formatter(‘%(asctime)s’) prints with the following format:
where 638 is the millisecond. I need to change the comma to a dot:
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') Solution – 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. Solution – 2
logging.Formatter( fmt='%(asctime)s.%(msecs)03d', datefmt='%Y-%m-%d,%H:%M:%S' ) Solution – 3
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 Solution – 4
The simplest way I found was to override default_msec_format:
formatter = logging.Formatter('%(asctime)s') formatter.default_msec_format = '%s.%03d' Solution – 5
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 Solution – 6
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.
Solution – 7
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") Solution – 8
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
Solution – 9
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 - - DEBUG - Jackdaws love my big sphinx of quartz. Solution – 10
If you prefer to use style=’.» will 0-pad your microseconds to three places for consistency.
Solution – 11
Many outdated, over-complicated and weird answers here. The reason is that the documentation is inadequate and the simple solution is to just use basicConfig() and set it as follows:
logging.basicConfig(datefmt='%Y-%m-%d %H:%M:%S', format='. : ', style='<') The trick here was that you have to also set the datefmt argument, as the default messes it up and is not what is (currently) shown in the how-to python docs. So rather look here.
An alternative and possibly cleaner way, would have been to override the default_msec_format variable with:
formatter = logging.Formatter('%(asctime)s') formatter.default_msec_format = '%s.%03d' However, that did not work for unknown reasons.
Solution – 12
I figured out a two-liner to get the Python logging module to output timestamps in RFC 3339 (ISO 1801 compliant) format, with both properly formatted milliseconds and timezone and without external dependencies:
import datetime import logging # Output timestamp, as the default format string does not include it logging.basicConfig(format="%(asctime)s: level=%(levelname)s module=%(module)s msg=%(message)s") # Produce RFC 3339 timestamps logging.Formatter.formatTime = (lambda self, record, datefmt=None: datetime.datetime.fromtimestamp(record.created, datetime.timezone.utc).astimezone().isoformat()) >>> logging.getLogger().error("Hello, world!") 2021-06-03T13:20:49.417084+02:00: level=ERROR module= msg=Hello, world! Alternatively, that last line could be written out as follows:
def formatTime_RFC3339(self, record, datefmt=None): return ( datetime.datetime.fromtimestamp(record.created, datetime.timezone.utc) .astimezone() .isoformat() ) logging.Formatter.formatTime = formatTime_RFC3339 That method could also be used on specific formatter instances, rather than overriding at the class level, in which case you will need to remove self from the method signature.
Solution – 13
After burning some of my precious time the below hack worked for me. I just updated my formatter in settings.py and added datefmt as %y/%b/%Y %H:%M:%S and appended the milliseconds to the asctime like this .
'formatters': < 'verbose': < 'format': '[.] [] → ', 'datefmt': "%y/%b/%Y %H:%M:%S", 'style': ', > Solution – 14
Using this smart answer for the timezone and the chosen answer, you can construct the millisecond and timezone with your desired format:
import logging import time if __name__ == "__main__": tz = time.strftime('%z') logging.basicConfig( format=( "%(asctime)s.%(msecs)03d" + tz + " %(levelname)s " "%(pathname)s:%(lineno)d[%(threadName)s]: %(message)s" ), level=logging.DEBUG, datefmt="%Y-%m-%dT%H:%M:%S", ) logging.info("log example") Personally, I like to keep all the logs in UTC but also have this explicitly in the log as a datetime without a timezone is meaningless in a multizone application:
logging.Formatter.converter = time.gmtime logging.basicConfig( format=( "%(asctime)s.%(msecs)03d+0000 %(levelname)s " "%(pathname)s:%(lineno)d[%(threadName)s]: %(message)s" ), level=logging.DEBUG, datefmt="%Y-%m-%dT%H:%M:%S", ) Python logging: use milliseconds in time format
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. Solution 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") Solution 4
The simplest way I found was to override default_msec_format:
formatter = logging.Formatter('%(asctime)s') formatter.default_msec_format = '%s.%03d' Solution 5
Many outdated, over-complicated and weird answers here. The reason is that the documentation is inadequate and the simple solution is to just use basicConfig() and set it as follows:
logging.basicConfig(datefmt='%Y-%m-%d %H:%M:%S', format='. : ', style='<') The trick here was that you have to also set the datefmt argument, as the default messes it up and is not what is (currently) shown in the how-to python docs. So rather look here.
An alternative and possibly cleaner way, would have been to override the default_msec_format variable with:
formatter = logging.Formatter('%(asctime)s') formatter.default_msec_format = '%s.%03d' However, that did not work for unknown reasons.