4

Following Python's documentation, I'm trying to override logging.Formatter.converter in order to control the time logged.
As you can see below - the milliseconds were not overriden (they are the current time milliseconds).

How come? How can I control the milliseconds as well?

>>> import logging, datetime
>>> formatter = logging.Formatter('%(asctime)s:%(message)s')
>>> handler = logging.StreamHandler()
>>> handler.setFormatter(formatter)
>>> def sim_time(t):
...     return datetime.datetime(2000,1,2,3,4,5,678).timetuple()
...
>>> formatter.converter = sim_time
>>> log = logging.getLogger('test')
>>> log.addHandler(handler)
>>> log.info('hi')
2000-01-02 03:04:05,898:hi
>>> log.info('hi')
2000-01-02 03:04:05,914:hi
>>> log.info('hi')
2000-01-02 03:04:05,434:hi
Jonathan Livni
  • 101,334
  • 104
  • 266
  • 359

3 Answers3

3

override logging.Formatter.formatTime() instead with this:

def sim_time(record, datefmt=None):
    return datetime.datetime(2000,1,2,3,4,5,678).strftime('%Y-%m-%d %H:%M:%S,%f')[:-3]

formatter.formatTime = sim_time

If you need it for all loggers in this process, you can override the class function itself, but do this right after the first import logging statement your code encounters:

def sim_time(self, record, datefmt=None):
    return datetime.datetime(2000,1,2,3,4,5,678).strftime('%Y-%m-%d %H:%M:%S,%f')[:-3]

import logging
logging.Formatter.formatTime = sim_time
Jonathan Livni
  • 101,334
  • 104
  • 266
  • 359
1

timetuple() doesn't use milliseconds, so that the ms information contained in the datetime object is lost once the method is called:

>>> d
datetime.datetime(2000, 1, 2, 3, 4, 5, 678)
>>> d.timetuple()
time.struct_time(tm_year=2000, tm_mon=1, tm_mday=2, tm_hour=3, tm_min=4, tm_sec=5, tm_wday=6, tm_yday=2, tm_isdst=-1)

Note that this is not a limitation of this particular method, but rather of the time.struct_time type.

The bottom line is: if you need to override the timestamp, don't pass through a time.struct_time object. You could - for example - pass the timestamp already formatted as a string, rather than a fake time. Depending on your needs there might be better methods, of course!

mac
  • 42,153
  • 26
  • 121
  • 131
0

Here's a better example that allows you to replace the time that was generated, as the accepted answer didn't really do that. 

def inSimulatedTime(self,secs=None):
    global myTimeKeeper
    try:
       ts=myTimeKeeper.getCurrentTimeLocal() # returns a datetime.datetime object
       return ts.timetuple()
except Exception as e:
    #sometimes my timekeeper hasn't been initialized yet.
    return time.localtime(secs)

To enable it:

logging.Formatter.converter=inSimulatedTime
gbronner
  • 1,907
  • 24
  • 39