Logging /w several modules/libraries

[Lou]

I’m on my ragged edge here with getting logging to live up to the hip. My current project with several modules and two library files has an error (maybe more than one). When I stated the project I just keep adding print statements wrapped in “if VERBOSE:” statements to keep track of what was going on. Now with a real problem this isn’t working. So added logging to my learning curve.
Replaced all the “prints” with “logger” statements and got things to work. Nice logger names for each module/class, several levels that seem logical. However, still lots of clutter hiding where the problem(s) is.
Using HOWTO, as a starting point looks like there should be at least 2 ways to filter out some of the log entries.

1. At the module level assign a nul handler to a logger to send entries to the bit bucket. In the code below in module fan, line 18, trying to block those entries. This is suggested for a library module. logging.getLogger(__name__).addHandler(logging.NullHandler())
   
2. At a global level useing filters to block selected entries. What little I can find to read suggest to me these are inclusive filters not exclusive filters. I haven’t found enough information to even try this approach.
   

Either approach is better than removing logger lines then later wishing I had them. Conceptually filters could be more granular than just blocking a whole module. BUT I could use some pointers to get either to work. As you can see from the output all the "INFO:fan:Level x" clutter hides what is going on between traffic and command.

Running the code from the IDE or using this short script .

cd /……………/testing
python3 TT3.py 2> testout.txt

#!/usr/bin/python3.7
"""
===========
Module TT_3
===========

"""
import logging
import fan
# import signals


def main():

    logging.basicConfig(filename='TT3.log', filemode='w', level=logging.DEBUG)
    logging.info("starting TT3")

    import traffic
    # import a fan module to run the fan and call FanLib

    f = fan.Run()                   # start updating the fan display
    t = traffic.Traffic()
    logging.debug("Got Here")
    try:
        while True:
            pass

    except KeyboardInterrupt:
        logging.info("Clean up")
        f.stop()
# end of main


if __name__ == '__main__':
    main()
logging.info("The End")

#!/usr/bin/python3.7
"""
==============
Module traffic
==============
"""

import threading
from command import Command
from time import sleep
import logging
logger = logging.getLogger(__name__)


class Traffic:
    def __init__(self) -> None:

        logger.info("starting Traffic")

        # Class to process all RPi commands
        self.com = Command()
        # initialize Monitor LEDs
        self.led = Monitor()

        # start thread to listen for LapTop
        thread_lt = threading.Thread(target=self.read_lt)
        thread_lt.start()

    def read_lt(self):
        for i in range(3):
            sleep(3)
            msg = "msg " + str(i)
            cmd_type = self.com.check(str(msg))
            logger.debug("Command type: %s", str(cmd_type))

        print("Should be done")
        logger.debug("Should be done")

# end class traffic


class Monitor:
    def __init__(self) -> None:
        self.logger = logging.getLogger("Monitor")

#!/usr/bin/python3.7
"""
==========
Module fan
==========

"""

import logging
import threading
from time import sleep
logger = logging.getLogger(__name__)


class Run:
    def __init__(self) -> None:
        logger.info("starting Fan")
        logging.getLogger(__name__).addHandler(logging.NullHandler())

        self.run_forever = True
        thread = threading.Thread(target=self.main, args='')
        thread.start()
    # end of __init__

    def main(self) -> None:

        count = 0
        while self.run_forever:
            sleep(1)
            logger.info("Level %d", count)
            count += 1

    def stop(self):
        self.run_forever = False
        logger.info(" stopping")

#!/usr/bin/python3.7
"""
===============
Module command
===============

"""
import logging
logger = logging.getLogger(__name__)


class Command:
    """
    """

    def __init__(self):
        """
        """

        logger.info("starting Command")

    def check(self, msg: str) -> int:
        """
        """
        logger.info("Message: %s", msg)
        return 42

Output:
INFO:root:starting TT3
INFO:fan:starting Fan
INFO:traffic:starting Traffic
INFO:command:starting Command
DEBUG:root:Got Here
INFO:fan:Level 0
INFO:fan:Level 1
INFO:command:Message: msg 0
DEBUG:traffic:Command type: 42
INFO:fan:Level 2
INFO:fan:Level 3
INFO:fan:Level 4
INFO:command:Message: msg 1
DEBUG:traffic:Command type: 42
INFO:fan:Level 5
INFO:fan:Level 6
INFO:fan:Level 7
INFO:command:Message: msg 2
DEBUG:traffic:Command type: 42
DEBUG:traffic:Should be done
INFO:fan:Level 8
INFO:fan:Level 9
INFO:fan:Level 10
INFO:fan:Level 11
INFO:fan:Level 12
INFO:fan:Level 13
INFO:fan:Level 14
INFO:root:Clean up
INFO:fan: stopping
INFO:root:The End
INFO:fan:Level 15