[Feature Request] Allow configuration of the logger the package should use

[michelcrypt4d4mus]

Description

I'd like to be able to configure a package wide logger so i can fold the output of the package's logs into the logs of the application that uses the package. currently however the logging setup is not configurable and dependent on the __name__ property of the current file:

import logging
logger = logging.getLogger(__name__)

i think (don't quote me, i haven't checked) that this sets up desktop-notifier to use a bunch of different loggers, one for each file. even if that's not exactly right it still means the logging configuration is predetermined. that's fine for casual use but in a production app people (like me) will want more control over how logging output is configured (where it's going, how it's formatted, etc).

i'm planning to implement this feature but wanted to get some thoughts from @samschott as to how you prefer this to be implemented (if you have any such thoughts).

UPDATE

I did a quick check to see what loggers are configured in my application:

import logging

def show_loggers():
    print(f"ALL LOGGERS")

    for name in sorted(logging.root.manager.loggerDict.keys()):
        print(f"  - {name}")

here's an abridged list of configured loggers that are or are at least suspected to be related to this package:

• asyncio
• concurrent
• concurrent.futures
• desktop_notifier
• desktop_notifier.base
• desktop_notifier.macos
• desktop_notifier.main

[samschott]

Only the loggers starting with desktop_notifier are actually from this package, the others are from the respective libraries such as asyncio.

Each library and each module using its own logger from logging.getLogger(__name__) is actually idiomatic Python usage. This is why you see core libraries such as concurrent and asyncio do the same!

The intended approach is customize the all logging for you app is through the root logger, which will affect all installed "child" loggers.

From the docs at https://docs.python.org/3/library/logging.html:

The key feature of this idiomatic usage is that the majority of code is simply creating a module level logger with getLogger(name), and using that logger to do any needed logging. This is concise, while allowing downstream code fine-grained control if needed.

and

In most cases, like the one above, only the root logger needs to be so configured, since all the lower level loggers at module level eventually forward their messages to its handlers.

Is there anything that you are trying to do which you cannot achieve this way? Sticking with the Python standard has the significant advantage that most users expect such a setup and know how to deal with it. Deviating requires additional documentation and cause significant confusion, so I'd only want to do so if at has corresponding significant advantages.

[michelcrypt4d4mus]

logging.getLogger(__name__) is actually idiomatic Python usage. This is why you see core libraries such as concurrent and asyncio do the same!

yeah i'm pretty familiar w/the python logging system (though by no means an expert - the fact that you can have . separated names for logger hierarchies is news to me so i'll have to chew that over for a bit). though one thing i did notice is that the core libraries have just one named logger in the list I dumped (e.g. asyncio) and not one sublogger per file, like desktop-notifier does. (concurrent.futures is kind of a special case).

Is there anything that you are trying to do which you cannot achieve this way?

yes and no... i'm working with a codebase that occasionally has an extremely complicated logger setup, with up to 15 different loggers of all shapes and sizes (files, streams, slack channels, web hooks, and so on are all logging endpoints), with different levels, handlers, and formatters spread among them. packages like this one that use calls to logging.getLogger() have a knack for escaping their cages and losing various kinds of formatting or going to the wrong place.

this is all once again complicated by the presence of Twisted, which is a framework that likes to manipulate the core logging module in insidious ways and redirect streams hither and thither (for example Twisted by default tries to capture all STDOUT and STDERR log streams and "wrap" them in their own ancient system. it's horrifying, to say the least). that's not the fault of desktop-notifier, that's just Twisted being janky af, but it does make me want a simple way to be sure i'm configuring my logs correctly.

i guess given the context i described, where there's a whole mess of formatters, handlers, and loggers, my question would be w/things as they stand now how might one construct a dict accepted by logging.config.dictConfig() that would capture the logs from desktop-notifier only and apply a custom logging.formatter via a custom logging.handler and then send that to 2-10 different log sinks? is there some way i can use the logger hierarchy with the . separated names to do that?

[michelcrypt4d4mus]

here's a bit more context in the form of a simplified logging.config.dictConfig() argument similar to what i'm vaguely thinking of using in my application that has custom handling for desktop-notifier:

LOG_CONFIG = {
    "formatters": {
        "default": {
            "format": "[%(asctime)s] %(levelname)s %(message)s",
            "datefmt": "%Y-%m-%d %H:%M:%S"
        },
        "desktop-notifier-fmt": {
            "format": "[%(asctime)s] %(levelname)s [notifier] %(message)s"
        },
        "rich": {
            "format": "%(module)s %(message)s"
        }
    },
    "handlers": {
        "webserver": {
            "class": "logging.FileHandler",
            "filename": "/var/tmp/illmatic/log/nasir.log",
            "formatter": "default",
            "level": 10
        },
        "desktop-notifier-handler": {
            "class": "logging.FileHandler",
            "filename": "/var/tmp/illmatic/log/desktop-notifier.log",
            "formatter": "desktop-notifier-fmt",
            "level": 20
        },
        "stdout": {
            "class": "rich.logging.RichHandler",
            "level": 10,
            "formatter": "rich",
            "omit_repeated_times": false,
            "rich_tracebacks": true
        },
        "webhook": {
            "class": "illmatic.logger.WebhookHandler",
            "url": "http://domain.example.com/path",
            "method": "POST",
            "data": {"message": "%(message)s"},
            "status_code": 200
        }        
    },
    "loggers": {
        "webserver": {
            "handlers": [
                "webserver",
                "stdout"
            ],
            "level": 10
        },
        "desktop-notifier": {
            "handlers": [
                "desktop-notifier-handler",
                "stdout"
            ],
            "level": 20
        },
        "public": {
            "handlers": [
                "notifications",
                "webhook",
                "webserver"
            ],
            "level": 10
        }
    },
    "version": 1
}

in the real world i'm not usually doing per-package logs this customized (though i definitely might want to for some critical situations down the line) but just trying to make it illustrative of what i have in mind... the end steps look vaguely like:

import logging
import logging.config

logging.config.dictConfig(LOG_CONFIG)  # set up loggers
notifier_logger = logging.getLogger('desktop-notifier')
desktop_notifier.somehow.set_logger(notifier_logger)

maybe i'm being dumb and just bc of the hierarchichal naming this approach would work even w/out a centralized point in this package to call set_logger()? happy to be enlightened.

[michelcrypt4d4mus]

The intended approach is customize the all logging for you app is through the root logger, which will affect all installed "child" loggers.

fwiw i'm just perusing this list of best practices w/r/t python logging in packages and #1 on the list is Avoid the root logger which definitely jibes with my own experience w/the python logging module though the author also gives some other good reasons i wasn't even aware of to do so.

also recommends centralizing logging to a single module as the 2nd point which is roughly my goal. while i am by no means wedded to the draft implementation over on #149 i can throw out there that it's always a very much appreciated feature when package authors make it easy for pkg users to integrate the logging machinery of the application using the package and the package itself.

[samschott]

Configuring logging for a tree of modules

Sure you can! Python's loggers are set up as a tree, with the . separating levels in the hierarchy. For example, to list all loggers of desktop-notifier recursively:

import logging

dn_logger = logging.getLogger("desktop_notifier")

def print_subtree(node):
   print(node)
   for child in node.getChildren():
      print_subtree(child)

print_subtree(dn_logger)

Similarly, all log events of the "desktop_notifier" sub-tree get bubbled up to the dn_logger logger, so you only need to configure this one (and potentially the root logger, if you want). Using the dictConfig API, it would look like this:

LOG_CONFIG = {
    "formatters": {
        "desktop-notifier-fmt": {
            "format": "[%(asctime)s] %(levelname)s [notifier] %(message)s"
        },
    },
    "handlers": {
        "desktop-notifier-handler": {
            "class": "logging.StreamHandler",
            "formatter": "desktop-notifier-fmt",
        },   
    },
    "loggers": {
        "desktop_notifier": {
            "handlers": [
                "desktop-notifier-handler",
            ],
            "level": 20
        },
    },
    "version": 1
}

Though if you do decide to configure logging on a per-module basis, ~I would recommend~ you can consider disabling propagating events up from the module with custom configuration. For the example above, I would set dn_logger.propagate = False so that you whatever events get logged from the desktop-notifier sub-tree don't also end up getting emitted by the root logger to similar handlers.

Suggestions from the cited article

I don't agree with everything written there, but I think that you are also misinterpreting some of the given advice:

1. Avoid the root logger: IIUC, this means that you should not emit log events from the root logger. In fact, it specifically recommends creating loggers for each module with logger = logging.getLogger(__name__) instead of using the root logger.

2. Centralize your logging configuration: We need to distinguish between apps and libraries here. As a library, desktop-notifier does not perform any logging configurations at all, because it has no idea how apps that use it want to perform logging. As an app which uses desktop-notifier, go ahead and configure its handlers, formatting, etc. Ideally centrally! And if the config it should apply to all modules that your app uses, set it at the root level :)

[michelcrypt4d4mus]

cool; when i get a chance i'll mess around more with the logging setup in my app and see if i can get away without the kind of changes on #149 🤞