user32147
user32147

Reputation: 1083

python logging module outputs extra information to the console

I would like to use logging to log information (currently same information) to both console and to a file.

However, I am seeing extra unwanted information being printed to the console.

I would like to get the following output to both console and the file:

INFO - thisuser executed the pipeline at 2019-04-17 13:44:50,626
default log message
other default log message
INFO - pipeline execution completed at 2019-04-17 13:44:50,627
INFO - total time elapsed: 100.4 minutes

I am getting the expected output in the file, but console outputs the following:

INFO:start_log:thisuser
INFO - thisuser executed the pipeline at 2019-04-17 13:44:50,626
INFO:root:default log message
default log message
INFO:root:other default log message
other default log message
INFO:end_log:-
INFO - pipeline execution completed at 2019-04-17 13:44:50,627
INFO:duration_log:100.4
INFO - total time elapsed: 100.4 minutes

I would like to remove extra information (odd lines above) printed to the console. Any help will be greatly appreciated!

Below is the code I am running:

import logging
import getpass

class DispatchingFormatter:

    def __init__(self, formatters, default_formatter):
        self._formatters = formatters
        self._default_formatter = default_formatter

    def format(self, record):
        formatter = self._formatters.get(record.name, self._default_formatter)
        return formatter.format(record)

logging.basicConfig(level=logging.INFO)

formatter = DispatchingFormatter({
        'start_log': logging.Formatter('%(levelname)s - %(message)s executed the pipeline at %(asctime)s'),
        'end_log': logging.Formatter('%(levelname)s - pipeline execution completed at %(asctime)s'),
        'duration_log': logging.Formatter('%(levelname)s - total time elapsed: %(message)s minutes')
    },
    logging.Formatter('%(message)s'),
)


c_handler = logging.StreamHandler()
c_handler.setFormatter(formatter)
f_handler = logging.FileHandler('log.txt')
f_handler.setFormatter(formatter)

logging.getLogger().addHandler(c_handler)
logging.getLogger().addHandler(f_handler)

logging.getLogger('start_log').info(f'{getpass.getuser()}')

logging.info('default log message')
logging.info('other default log message')

logging.getLogger('end_log').info('-')
time_elapsed = 100.4
logging.getLogger('duration_log').info(f'{time_elapsed}')

The pipeline will be printing ~100 lines of information (results of the analysis), which I would not like to prepend by any logging level, hence I tried to implement using multiple formatters.

I know this is somewhat hacky solution.. if someone has general suggestions for improvements, this will also be appreciated!

Upvotes: 2

Views: 1129

Answers (2)

a_guest
a_guest

Reputation: 36339

As the documentation for logging.basicConfig states:

Does basic configuration for the logging system by creating a StreamHandler with a default Formatter and adding it to the root logger.

So there is already a stream handler attached. You can remove it by calling:

logging.getLogger().handlers.clear()

before you add the other handlers.

Alternatively you can use logging.getLogger().setLevel(logging.INFO) instead of basicConfig. In that case you don't have to clear the handlers since they are none attached by default.

Upvotes: 2

user32147
user32147

Reputation: 1083

Upon searching around (Replace default handler of Python logger) and reading up more on the documentation (https://docs.python.org/3.7/library/logging.html#), I found a working solution.

I was adding two handlers (one to print to console and another to print to file with the specified formatting) to the logger's default handler, and apparently the logger's default handler prints to the console those lines that I did not want.

A solution (perhaps a hacky one) is to first empty out the handlers by doing the following:

logging.basicConfig(level=logging.INFO, filemode='w')

# Added two lines below to first empty out (remove original handler) handlers
root_logger = logging.getLogger()
root_logger.handlers = []

Then continue on to create formatter objects I want and add two handlers that I wanted (same code as in the question):

formatter = DispatchingFormatter({
    'start_log': logging.Formatter('%(levelname)s - %(message)s executed the pipeline at %(asctime)s', datefmt='%Y-%m-%d %H:%M:%S'),
    'end_log': logging.Formatter('%(levelname)s - pipeline execution completed at %(asctime)s', datefmt='%Y-%m-%d %H:%M:%S'),
    'duration_log': logging.Formatter('%(levelname)s - total time elapsed: %(message)s minutes')
},
logging.Formatter('%(message)s'),
)


c_handler = logging.StreamHandler()
c_handler.setFormatter(formatter)
f_handler = logging.FileHandler('log.txt', 'w+')
f_handler.setFormatter(formatter)

logging.getLogger().addHandler(c_handler)
logging.getLogger().addHandler(f_handler)

Upvotes: 0

Related Questions