Wsrtjtyk

• python: 3.6.6


• python-telegram-bot: 10.0.2

I have this problem: I have defined a python logger with a SMTPHandler, a TimedRotatingFileHandler and a StreamHandler.

The StreamHandler works fine, but when I try to use it from a python-telegram-bot handler, the line is being printed twice on the standard output with two different formats and I can't find out how to avoid one and get the another one (the timed one) to remain.

I have discovered the cause. When adding a ConversationHandler with a CallbackQueryHandler, this message is shown when starting.

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

And then the unwished log line appears every time.

The code is here below as log_config.py . I have added also the sample code for testing my_main_file.py and the current output as a multiline comment.

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!

"""

telegram.ext.ConversationHandler includes several logging calls that use logging.warning instead of the self.logger logger they probably should use, such as 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 and the other module-level logging convenience functions call logging.basicConfig, which adds a handler to the root logger if no handlers on the root logger are present. This handler is the one responsible for the unwanted

INFO:__main__:HELP!

logging output.

The use of logging.warning instead of self.logger.warning should probably be considered a python-telegram-bot bug. I don't see an open issue for it on their issue tracker, so you might want to file a bug report.

In the meantime, or if the python-telegram-bot developers decide the behavior is fine, you can add a null handler to the root logger to prevent basicConfig from adding its own handler. This must be done before the ConversationHandler is created, to preempt the basicConfig:

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