I just ran into this issue - and it can be solved. It just requires a little hacking on some of the logging infrastructure. See below example:
import logging
import time
try: # Python >= 3.7
from time import time_ns
except: # Python <= 3.6
from time import time as _time_
time_ns = lambda: int(_time_() * 1e9)
class LogRecord_ns(logging.LogRecord):
def __init__(self, *args, **kwargs):
self.created_ns = time_ns() # Fetch precise timestamp
super().__init__(*args, **kwargs)
class Formatter_ns(logging.Formatter):
default_nsec_format = '%s,%09d'
def formatTime(self, record, datefmt=None):
if datefmt is not None: # Do not handle custom formats here ...
return super().formatTime(record, datefmt) # ... leave to original implementation
ct = self.converter(record.created_ns / 1e9)
t = time.strftime(self.default_time_format, ct)
s = self.default_nsec_format % (t, record.created_ns - (record.created_ns // 10**9) * 10**9)
return s
logging.setLogRecordFactory(LogRecord_ns)
# +++++ DEMO +++++
log_formater = Formatter_ns('%(asctime)s (%(name)s) %(message)s')
logger = logging.getLogger('demo-log')
logger.setLevel(logging.DEBUG)
ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)
ch.setFormatter(log_formater)
logger.addHandler(ch)
logger.info('foo bar')
This will happily print: 2019-04-10 14:08:28,819931368 (demo-log) foo bar
Key to this is a modified logging.Formatter class, which has a custom implementation of formatTime. Just to be on the safe side, I also recommend to use time.time_ns, which will return an integer in nano seconds in Python 3.7 and beyond. The original time.time returns a float in seconds, which therefore obviously has precision issues. Getting the more precise timestamp into a log record is achieved through a modified logging.LogRecord class, which simply fetches its created_ns field from time.time_ns in its extended constructor method.
