2

I have a project that consists of several modules. There is main module (main.py) that creates a TK GUI and loads the data. It passes this data to process.py which processes the data using functions from checks.py. I am trying to implement logging for all the modules to log to a file. In the main.py log messages are written to the log file but in the other modules they are only written to the console. I assume its to do with the import module line executing part of the code before the code in main.py has set up the logger, but i can't work out how to arrange it to avoid that. It seems like a reasonably common question on Stackoverflow, but i couldn't get the other answers to work for me. I am sure I am not missing much. Simplified code is shown below:

Moving the logging code inside and outside of various functions in the modules. The code I used to start me off is the code from Corey Schaffer's Youtube channel.

Main.py

import logging
from process import process_data

def main():

    logger = logging.getLogger()
    logger.setLevel(logging.DEBUG)

    formatter = logging.Formatter('%(asctime)s:%(name)s:%(message)s')
    templogfile = tempfile.gettempdir() + '\\' + 'TST_HA_Debug.log'
    file_handler = logging.FileHandler(templogfile)
    file_handler.setLevel(logging.DEBUG)
    file_handler.setFormatter(formatter)

    stream_handler = logging.StreamHandler()
    stream_handler.setFormatter(formatter)

    logger.addHandler(file_handler)
    logger.addHandler(stream_handler)

    logger.debug('Logging has started') # This gets written to the file

    process_data(data_object) # call process_data in process.py

process.py

import logging

def process_data(data):

    logger = logging.getLogger(__name__)

    logger.debug('This message is logged by process') #This wont get written to the log file but get written to the console

   #do some stuff with data here and log some msgs

   return

Main.py will write to the log file, process.py will only write to the console.

almonde
  • 111
  • 10

1 Answers1

2

I've rewritten your scripts a little so that this code can stand alone. If I changed this too much let me know and I can revisit it. These two files are an example of having it log to file. Note my comments:

##  main.py

import logging
from process import process_data
import os

def main():
    # Give this logger a name
    logger = logging.getLogger("Example")
    logger.setLevel(logging.DEBUG)

    formatter = logging.Formatter('%(asctime)s:%(name)s:%(message)s')
    # I changed this to the same directory, for convenience 
    templogfile = os.path.join(os.getcwd(), 'TST_HA_Debug.log')
    file_handler = logging.FileHandler(templogfile)
    file_handler.setLevel(logging.DEBUG)
    file_handler.setFormatter(formatter)

    stream_handler = logging.StreamHandler()
    stream_handler.setFormatter(formatter)

    logger.addHandler(file_handler)
    logger.addHandler(stream_handler)

    logging.getLogger("Example").debug('Logging has started') # This still gets written to the file

    process_data() # call process_data in process.py

if __name__ == '__main__':
    main()
##  process.py

import logging

def process_data(data=None):

    # make sure to grab the correct logger
    logger = logging.getLogger("Example")

    logger.debug('This message is logged by process') # This does get logged to file now

   #do some stuff with data here and log some msgs

    return

Why does this work? Because the module-level functions use the default root logger, which is not the one you've configured. For more details on this see these docs. There is a similar question that goes more into depth here.

By getting the configured logger before you start logging, you are able to log to the right configuration. Hope this helps!

OrionTheHunter
  • 276
  • 1
  • 7
  • 2
    Thank you, I got sucked into using __name__ without really thinking what the consequence of that was. I then modified my formatter to be more clear about which function was generating the message – almonde Aug 01 '19 at 20:51
  • "All calls to this function with a given name return the same logger instance. This means that logger instances never need to be passed between different parts of an application." Thanks, all these years working with Python and I did not know this. :-) – Julius Jun 25 '21 at 15:11