指定Logger配置文件datefmt后日志时间戳始终相同的问题

问题场景 #

有一个供多脚本共用的日志配置文件logger_settings.py，核心配置如下：

import logging
import sys
from datetime import datetime

logging_config = dict(
    version=1,
    formatters={
        'verbose': {
            'format': ("%(asctime)s %(levelname)s "
                       "[%(name)s:%(lineno)s] %(message)s"),
            'datefmt': datetime.now().isoformat(sep='T',timespec='milliseconds')
        },
        'simple': {
            'format': '%(asctime)s %(levelname)-8s %(message)s',
            'datefmt': datetime.now().isoformat(sep='T',timespec='milliseconds')
        },
    },
    handlers={
        'tte-logger': {'class': 'logging.FileHandler',
                       'formatter': 'verbose',
                       'level': logging.DEBUG,
                       'filename': '/home/abc/efg/logs/logtest_'+datetime.now().strftime("%Y%m%d-%H%M%S")+'.log'},
        'console': {
            'class': 'logging.StreamHandler',
            'level': 'DEBUG',
            'formatter': 'simple',
            'stream': sys.stdout,
        },
    },
    loggers={
        'logger': {
            'handlers': ['logger', 'console'],
            'level': logging.DEBUG
        },
    }
)

业务脚本try.py中引入并使用日志：

from logger_settings import logging_config
from logging.config import dictConfig
import logging

dictConfig(logging_config)
logger = logging.getLogger('logger')

# 测试输出
logger.info("there")
logger.info("here")
logger.info("again")

运行后所有日志时间戳完全一致：

**2024-01-04T03:18:18.123 INFO**     there
**2024-01-04T03:18:18.123 INFO**     here
**2024-01-04T03:18:18.123 INFO**     again

将datefmt设为None后时间戳恢复正常，但无法使用期望的ISO格式：

**2024-01-04 03:30:11,595 INFO**     there
**2024-01-04 03:30:11,598 INFO**     here
**2024-01-04 03:30:11,603 INFO**     again

问题原因 #

1. 时间戳固定的核心原因：配置里的datefmt直接使用datetime.now().isoformat(...)的返回值——这是一个静态字符串，会在logger_settings.py模块被导入的瞬间生成并固定，后续所有日志都会复用这个时间值，不会动态获取每条日志生成时的当前时间。
2. 日志文件名的同类问题：filename中的datetime.now().strftime(...)同样是模块导入时生成的静态字符串，只会创建一个固定时间命名的日志文件，脚本运行期间不会生成新文件。

解决方法 #

1. 配置ISO格式的动态时间戳 #

datefmt需要传入格式字符串模板，而非直接生成的时间字符串。针对ISO 8601带毫秒的格式，可按以下方式修改配置：

方式一：使用标准格式字符串

修改logger_settings.py中的formatters部分：

'formatters': {
    'verbose': {
        'format': "%(asctime)s %(levelname)s [%(name)s:%(lineno)s] %(message)s",
        # %f表示微秒，取前三位即为毫秒，符合ISO 8601格式
        'datefmt': "%Y-%m-%dT%H:%M:%S.%f"
    },
    'simple': {
        'format': '%(asctime)s %(levelname)-8s %(message)s',
        'datefmt': "%Y-%m-%dT%H:%M:%S.%f"
    },
},

方式二：自定义格式化类（严格保留三位毫秒）

如果需要精确截断微秒到毫秒级别，可自定义格式化类：

from logging import Formatter
from datetime import datetime

class ISOFormatter(Formatter):
    def formatTime(self, record, datefmt=None):
        dt = datetime.fromtimestamp(record.created)
        return dt.isoformat(sep='T', timespec='milliseconds')

# 替换配置中的formatter定义
'formatters': {
    'verbose': {
        '()': ISOFormatter,
        'format': "%(asctime)s %(levelname)s [%(name)s:%(lineno)s] %(message)s"
    },
    'simple': {
        '()': ISOFormatter,
        'format': '%(asctime)s %(levelname)-8s %(message)s'
    },
},

2. 动态生成日志文件名 #

避免在模块导入时生成静态文件名，在业务脚本中动态替换配置：

from logger_settings import logging_config
from logging.config import dictConfig
import logging
from datetime import datetime

# 动态生成当前时间命名的日志文件
log_filename = f'/home/abc/efg/logs/logtest_{datetime.now().strftime("%Y%m%d-%H%M%S")}.log'
logging_config['handlers']['tte-logger']['filename'] = log_filename

dictConfig(logging_config)
logger = logging.getLogger('logger')

修改后的效果 #

日志输出会显示动态的ISO格式时间戳：

**2024-01-04T03:30:11.595 INFO**     there
**2024-01-04T03:30:11.598 INFO**     here
**2024-01-04T03:30:11.603 INFO**     again

内容的提问来源于stack exchange，提问作者Tasha Saxena