使用 ptb 进行 Python 日志记录：同一行记录了两次，但只添加了一个处理程序

Question

• 蟒蛇：3.6.6
• python-telegram-bot：10.0.2

我有这个问题：我定义了一个带有 SMTPHandler、TimedRotatingFileHandler 和 StreamHandler 的 python 记录器。

StreamHandler 工作正常，但是当我尝试从 python-telegram-bot 处理程序中使用它时，该行以两种不同的格式在标准输出上打印两次，我不知道如何避免一种和让另一个（定时的）留下。

我已经找到原因了。添加带有 CallbackQueryHandler 的 ConversationHandler 时，启动时会显示此消息。

WARNING:root:If 'per_message=False', 'CallbackQueryHandler' will not be tracked for every message.

然后每次都出现不希望出现的日志行。

下面的代码为 log_config.py 。我还添加了用于测试 my_main_file.py 的示例代码和作为多行注释的当前输出。

config/log_config.py：

import os

import logging
from logging import Formatter

from datetime import datetime


VERSION_NUM = '1.2.0'
LOG_MSG_FORMAT = '%(asctime)s - ({0}) %(levelname)s - %(name)s - %(message)s'
LOGFILE_PATH = os.path.join(os.path.dirname(os.path.dirname(__file__)),
                            'log',
                            'alfred.log')
logging.getLogger('telegram').setLevel(logging.WARNING)
logging.getLogger('chardet.charsetprober').setLevel(logging.WARNING)


def my_timezone_time(*args):
    # I simplified this line, because it's irrelevant
    return datetime.now().timetuple()


handlers = []


#
# ... different handlers added
#


# last handler to add, this one works just as I want

ch = logging.StreamHandler()
formatter = Formatter(LOG_MSG_FORMAT.format(VERSION_NUM))
formatter.converter = my_timezone_time
ch.setFormatter(formatter)
ch.setLevel(logging.INFO)
handlers.append(ch)


def getLogger(name):
    """
    Returns a logger for the file. Works fine but when used,
       it always outputs the same line with the last handler 
       and also with an unknown handler not added by me 
       (must be some default instance)
    :param name: the file name
    :return: a logger
    """
    logger = logging.getLogger(name)
    logger.setLevel(logging.DEBUG)
    for h in handlers:
        logger.addHandler(h)

    return logger

my_main_file.py：

#!/usr/bin/python3
from telegram.ext import (Updater, CommandHandler, ConversationHandler,
                          run_async, CallbackQueryHandler)
from config.log_config import getLogger

# Enable logging
logger = getLogger(__name__)

updater = Updater('......')  # Replace with your bot token

# ************************** HANDLERS
# Define a few command handlers. These usually take the two arguments bot and
# update. Error handlers also receive the raised TelegramError object in error.


@run_async
def show_help(bot, update):
    logger.info('HELP!')


def error_handler(bot, update, error):
    logger.warning('La actualización "%s" causó el error "%s"', update, error)


def dumb_handler(bot, update, user_data):
    return ConversationHandler.END


def main():
    """Start the bot."""
    # Create the EventHandler and pass it your bot's token.
    global updater

    # Get the dispatcher to register handlers
    dp = updater.dispatcher

    # on different commands - answer in Telegram
    dp.add_handler(CommandHandler('help', show_help))

    # Add conversation handler with the states
    # The telegram conversation handler needs a handler_list with functions
    # so it can execute desired code in each state/step

    conv_handler = ConversationHandler(
        entry_points=[CommandHandler('irrelevant', dumb_handler,
                                     pass_user_data=True)
                      ],
        states={
            0: [CallbackQueryHandler(dumb_handler, pass_user_data=True)],
        },
        fallbacks=[],
    )
    dp.add_handler(conv_handler)

    # log all errors
    dp.add_error_handler(error_handler)

    updater.start_polling()
    updater.idle()


if __name__ == '__main__':
    main()

"""
OUTPUT when used /help from the bot chat
(First is my wished output, second is the line I want to avoid)
------

2018-11-08 16:41:51,115 - (1.2.0) INFO - __main__ - HELP!
INFO:__main__:HELP!
"""

Answer 1

telegram.ext.ConversationHandler 包括几个使用logging.warning 而不是他们可能应该使用的self.logger 记录器的记录调用，例如this call：

for handler in all_handlers:
    if isinstance(handler, CallbackQueryHandler):
        logging.warning("If 'per_message=False', 'CallbackQueryHandler' will not be "
                        "tracked for every message.")

logging.warning 和其他模块级日志记录便利函数调用logging.basicConfig，如果根记录器上不存在处理程序，它会向根记录器添加处理程序。这个处理程序负责处理不需要的人

INFO:__main__:HELP!

记录输出。

使用logging.warning 而不是self.logger.warning 可能应该被认为是python-telegram-bot 错误。我在他们的issue tracker 上没有看到它的未解决问题，因此您可能需要提交错误报告。

与此同时，或者如果 python-telegram-bot 开发人员认为行为正常，您可以将 null 处理程序添加到根记录器，以防止 basicConfig 添加自己的处理程序。这必须在创建ConversationHandler 之前完成，以抢占basicConfig：

logging.getLogger().addHandler(logging.NullHandler())