0

I am importing 2 modules I built into a Python script. I want to have logging from the script plus the both modules go into a single log file. The logging cookbook and related forum posts (example), show how to do it for one script and one imported module, with the limitation that they both use the same logger name. The module's logger is named after the module (using __name__), so the script can find and re-use it using the top-level package name.

So one script and one imported module can share a logger. But how do I attach the second imported module to that logger? And what if I want the script's log name to be distinct from the imported module's name? Here is the solution I came up with. It works, but it's ugly. I need three logger objects! Is there a better way?

# Code for module maps.publish.upload
import logging
logger = logging.getLogger(__name__)
class ServicePublisher(object):
    def __init__(self):
        logger.debug(f'start constructor {__class__.__name__}')

Class charts.staffing.report.StaffingReport is identical to ServicePublisher

# log_test.py script
import logging
from pathlib import Path
from charts.staffing.report import StaffingReport
from maps.publish.upload import ServicePublisher

filename = Path(__file__).parts[-1]
logger = logging.getLogger(filename)
logger.setLevel(logging.DEBUG)
fh = logging.FileHandler('log_test.log')
fh.setLevel(logging.DEBUG)
formatter = logging.Formatter('%(name)s - %(levelname)s - %(message)s')
fh.setFormatter(formatter)
logger.addHandler(fh)

logger_maps = logging.getLogger('maps')
logger_maps.setLevel(logging.DEBUG)
logger_maps.addHandler(fh)

logger_charts = logging.getLogger('charts')
logger_charts.setLevel(logging.DEBUG)
logger_charts.addHandler(fh)

logger.debug(f'start {filename}')
publisher = ServicePublisher()
report = StaffingReport()

Here is the log output, exactly as expected:

log_test.py - DEBUG - start log_test.py
maps.publish.upload - DEBUG - start constructor ServicePublisher
charts.staffing.report - DEBUG - start constructor StaffingReport

Is there a way to use my logger object for all three cases, so I don't need logger_maps and logger_charts, while still maintaining distinct names in the log output?

mapgeek
  • 13
  • 2
  • What's wrong with 3 logger objects? That said, if you add your handler to, say `getLogger('foo')`, then `getLogger('foo.maps')` and `getLogger(foo.charts)` will (I think) inherit the handler without needing to add the handler to each individually. – chepner Mar 25 '22 at 22:10
  • @chepner - I guess as long as it works, it's fine, but code with such redundancy doesn't seem pythonic. This is as much for me to learn to be a better programmer as solve a problem. You are correct that if they all have the same prefix (`foo`), then the first one will pick up the next two in your example. I guess that's a win for starting packages with an orgname prefix. – mapgeek Mar 25 '22 at 22:47

1 Answers1

0

I worked on this a bit more and didn't really come up with a better solution, but I'll share what I learned below.

1. I tried going to the root manager's logger dict and creating a logger for everything there. You don't need to create loggers for sub-modules in your package structure. E.g.: charts.staffing.report will have a parent logger charts.staffing, which has a parent charts, which is all you need, so I removed anything with a . in it.

logger_names = [name for name in logging.root.manager.loggerDict
                if '.' not in name]

Then, I used logging.getLogger(<name>) on each name in the list and attached my handlers to it. This was so simple that I was in love with this solution, until I tested it some more. I was using debug level logging, and this turned on logging from every imported package in some APIs I use. Those APIs also import packages with loggers, so this got really spammy. By default, I think those loggers all bubble up to the root logger at the warning level, which seems more appropriate. So my first lesson is to be intentional about which loggers you tinker with, rather than just going through all of them.

2. As I mentioned above, Python bubbles logging up from sub-modules to parent modules' loggers. If I had it to do all over again, I would name all my packages starting with an org name prefix. For example, with packages charts and maps, if I work for the Acme Corporation, then I would name these acme.charts and acme.maps so I can just create a single logger acme that handles all my packages. That's harder once you have lots of code using your package, so it's something to consider when you start.

Note that the convention is to use the package name for your loggers, but the name is just a string and you can name them whatever you want. I could do something like this to add an artificial prefix that unifies all of them:

logger = logging.getLogger(f"acme.{__name__}")

Even though the user still imports my example packages as charts and maps, the loggers would be named acme.charts and acme.maps, which you could get with a single logger named acme. It's a good technical trick, but I would have to document and communicate that to my users, since it's not intuitive that a package charts would use a logger named acme.

3. I'm still creating a logger for each custom package I'm importing. I don't think it will have any significant overhead for my code, but might be something to consider at massive scale. At scale, you wouldn't want to be logging below warning level, which you get by default from your root logger, so this may all be moot.

4. To simplify my code, I wrote a little function that accepts a list of package names and a list of handlers as inputs. It gets a logger for each name and attaches the handlers. For one or two additional loggers, it's probably just as easy to create them in your code as it is to call my def. But if you had a big list of packages to create loggers for, then it would really clean up your code.

mapgeek
  • 13
  • 2