使用 f 字符串样式格式规范记录浮点数(特别是 "msecs")时防止舍入(或至少长度溢出)

Prevent rounding (or at least length overflow) when logging floats (specifically "msecs") using f-string style format specification

一些背景知识:

Python docs 说:

In the case of {}-formatting, you can specify formatting flags by placing them after the attribute name, separated from it with a colon. For example: a placeholder of {msecs:03d} would format a millisecond value of 4 as 004.

但是,这 工作,因为日志记录的 msecs 值实际上是 float:

>>> record.msecs
275.38108825683594

因此尝试使用文档中的示例 {} 格式会引发 ValueError:

>>> f'{record.msecs:03d}'
*** ValueError: Unknown format code 'd' for object of type 'float'

旧式 %-使用 03d 的格式适用于 float:

>>> '%03d' % record.msecs
'275'

基于以上发现,我在日志记录定义中使用了 float 格式规范,如下所示:

logging.basicConfig(
    level=logging.INFO,
    format="{asctime}.{msecs:0>3.0f} [{levelname:.1s}] {message}",
    datefmt="%Y-%m-%d %H:%M:%S",
    style="{",
)

这似乎运行良好,直到我注意到这个日志条目:

2021-03-25 22:37:18.993 [I] ...
2021-03-25 22:37:18.997 [I] ...
2021-03-25 22:37:18.1000 [I] ...
2021-03-25 22:37:19.002 [I] ...
2021-03-25 22:37:19.004 [I] ...

当日志记录的 msecs 浮点值 >= 999.5:

时发生
>>> t1 = 999.499999
>>> t2 = 999.5
>>> print(f"{t1:0>3.0f} {t2:0>3.0f}")
999 1000

显然我希望 .1000 被记录为 .000(四舍五入 不溢出 3 位数长度)如果有办法还将时间戳的 {asctime} 部分增加一秒。 但是 我只记录 .999 就可以了(截断为 int 而不是四舍五入)因为这种溢出只发生在非常小的时间内,并且出于我的目的,此日志记录不是 关键。

除了回到旧式 % 格式之外,其他 有什么办法吗?

您可以覆盖 default millisecond format:

logging.basicConfig(
    level=logging.INFO,
    format="{asctime} ...{msecs:3.1f} ...{msecs:3.0f} [{levelname:.1s}] {message}",
    # datefmt="%Y-%m-%d %H:%M:%S",
    style="{",
)
logging.Formatter.default_msec_format = '%s.%03d'

我认为实现了你想要的毫秒被截断为三位数。不幸的是,指定 datefmt 搞砸了,并且不显示毫秒数。


这里有自定义 converterformatTime 函数,可用于替换默认的 Formatter 方法。这些将允许您在配置中指定 datefmt。他们一起工作,所以他们都必须使用。

import logging

def converter(self,t):
    '''Returns a tuple (time.struct_time, int)
    '''

    # separate seconds from fractional seconds 
    # round the fraction,
    # adjust the seconds if needed
    # turn the fraction into an integer
    seconds = int(t)
    msec = round(t - seconds,3)
    if msec > .9995:
        msec = 0
        seconds += 1
    else:
        msec = int(1000 * msec)
    # parts = list(time.localtime(seconds))
    # parts[-2] = msec
    t = time.localtime(seconds)
    return t,msec

def formatTime(self, record, datefmt=None):
    """
    Return the creation time of the specified LogRecord as formatted text.
    This method should be called from format() by a formatter which
    wants to make use of a formatted time. This method expects the
    converter to return a (time.struct_time,int) tuple where the int is
    between 0 and 999.
    The int is the rounded msec of the record's creation time.
    """
    ct,msec = self.converter(record.created)
    if datefmt:
        s = time.strftime(datefmt, ct)
    else:
        s = time.strftime(self.default_time_format, ct)
    s = f'{s}.{msec:03d}'
    return s

logging.basicConfig(
    level=logging.INFO,
    format="{asctime} | {message}",
    datefmt="%Y-%m-%d %H:%M:%S",
    style="{",
)

logging.Formatter.converter = converter
logging.Formatter.formatTime = formatTime
logging.info('foo')

该日志看起来像:

2021-03-27 16:12:05.498 | foo

如果 datefmt 参数不以秒结尾,那么添加毫秒将是愚蠢的,所以也许应该检查一下。

def formatTime(self, record, datefmt=None):
    """
    Return the creation time of the specified LogRecord as formatted text.
    This method should be called from format() by a formatter which
    wants to make use of a formatted time. This method expects the
    converter to return a (time.struct_time,int) tuple where the int is
    between 0 and 999.
    The int is the rounded msec of the record's creation time.
    """
    ct,msec = self.converter(record.created)
    if datefmt:
        s = time.strftime(datefmt, ct)
    else:
        s = time.strftime(self.default_time_format, ct)
        # s = f'{s}.{msec:03d}'
        # if self.default_msec_format:
        #     s = self.default_msec_format % (s, record.msecs)
    if datefmt[-1] == 'S':
        s = f'{s}.{msec:03d}'
    return s