9

I have this setup:

main.py
/module
/module/__init__.py (empty)
/module.py

And here is the code for my two files, main.py and module.py respectively:

main.py

import logging
from module import module

logger = logging.getLogger(__name__)

def test():
    logger.warning('in main.py/test')

def main():
    handler = logging.StreamHandler()
    handler.setLevel(logging.INFO)
    formatter = logging.Formatter('%(asctime)s %(name)s/%(module)s [%(levelname)s]: %(message)s', '%Y-%m-%d %H:%M:%S')
    handler.setFormatter(formatter)
    logger.addHandler(handler)

    logger.warning('in main.py/main')
    module.something()

if __name__ == "__main__":
    main()

module.py

import logging
logger = logging.getLogger(__name__)

def something():
    logger.warning('in module.py/something')

So, what I noticed is that this outputs the following (notice how the module logger has no formatting):

2019-10-01 09:03:40 __main__/main [WARNING]: in main.py/main
in module.py/something

It only seems like only after I make an edit in main.py to change logger = logging.getLogger( __ name __ ) to logger = logging.getLogger() or add logger = logging.getLogger() after def main(): that it logs like this (which is what I want):

2019-10-01 09:04:13 root/main [WARNING]: in main.py/main
2019-10-01 09:04:13 module.module/module [WARNING]: in module.py/something

Why is that? I thought that because main.py is importing module.py, it is naturally higher on the hierarchical scale so module.py would inherit the logger settings as defined in main.py. Do need to explicitly set the root logger (with logger = logging.getLogger()) in main for the inheritance to work? Did I not configure my folder structure correctly to make module.py's logger inherit main.py's logger settings, or is folder structure irrelevant?

The reason I ask is because I thought one should use logger = logging.getLogger( __ name __ ) throughout (even in main.py) and then based on the import structure (or folder structure?), that would determine the hierarchy and loggers would inherit accordingly. And the reason I was making that assumption is because what if I was importing main.py into another program? I guess my point is, I want to make logging as generic as possible such that I can import one module into another and it always inherits the parent's logger settings. Is there a way to display the underlying hierarchy of all the modules for debugging/learning purposes?

codeforester
  • 39,467
  • 16
  • 112
  • 140
Mike
  • 504
  • 7
  • 23
  • having a file named `module.py` and a directory with the same name (without.the .py) that contains an `__init__.py` is not a good idea. Probably you confuse yourself and anybody who reads the code. There is probably a rule, that says what will really be imported, but I don't think this is a good idea. – gelonida Oct 06 '19 at 22:18
  • The code does work and I don't find it particularly confusing, and for an example it did highlight what I was trying to convey. I could rename it to module_folder, but it would mess up the answer below. I think based on the information provided people should be able to figure it out... – Mike Oct 08 '19 at 20:16
  • what is confusing for me is not the code, but in my opinion the file names, You have a file named module.py and a directory named module, that contains an `__init__.py`. I think most people do not know by heart what file will be looked at if you do an `import module`. Will it read and compile `module.py` or `module/__init__.py` or both and if both in which order. And what file will be looked at if you have `from module import module`. Avoiding to have a directory with the same name as a directory makes it easier. but you're right you got your answer. so perhaps it's just me. – gelonida Oct 08 '19 at 22:58
  • correction: Avoiding to have a directory with the same name as a filename.py makes it easier. On my machine `module/__init__.py` is imported and `module.py` is ignored, so I could not even have reproduced your issue. – gelonida Oct 08 '19 at 23:21

1 Answers1

9

The logging hierarchy has nothing to do with file structure in your program. The hierarchy is determined only by the names of the loggers. When you configure a logger, all loggers with its name in the prefix of their name are its children and inherit its configuration unless explicitly stated otherwise.

In your example, logging setup has more to do with execution sequence and the names you've chosen than anything else. When your program runs, it does the following:

  1. Runs logging.py from the standard library because of import logging
  2. Runs module.py to fulfill from module import module
  3. Sets the logger attribute in main to a Logger named __main__.
  4. Create a test function
  5. Create a main function
  6. Run the main function

Some consequences of this sequence of events:

  • module.logger is created before main.logger. This doesn't affect the behavior you're seeing, but it's worth noting under the circumstances.
  • main.logger is named __main__ if you invoke main as a script. The behavior you see wouldn't change if it was called main, e.g. from python -m main.
  • module is clearly not in the same hierarchy as main. Both are descendants of the root logger along different branches.

The last item is really the answer to your question. If you want all the loggers in your program to share the same default logging method, you should configure the root logger, or ensure that they have the same name prefix, which you then configure as if it was the root logger.

You could make all the loggers inherit from main. In module/module.py, you would do

logger = logging.getLogger('__main__.' + __name__)

The issue here is that the name __main__ is hard coded. You don't have a guarantee that it will be __main__ vs main. You could try import main in module so you could do main.__name__ + '.' + __name__, but that wouldn't work as expected. If main was run as __main__, importing it will actually create a second module object with an entirely separate logging hierarchy.

This is why the root logger has no name. It provides exactly the maintainability and consistency you want. You don't have to jump through hoops trying to figure out the root name.

That being said, you should still have main.py logging to the __main__ or main logger. The root logger should only be set up in the import guard. That way, if main is imported as a regular module, it will respect the logging setup of the driver it is running under.

TL;DR

It is conventional to set up the anonymous root logger in the driver of your program. Don't try to inherit loggers from __main__ or the driver module name.

Mad Physicist
  • 107,652
  • 25
  • 181
  • 264
  • I'm still a bit confused, but that's ok. First question: line 3 "Sets the logger attribute in main to a Logger named __main__." - is that referring to "logger = logging.getLogger(__name__)" right before the definition of the test()? If so, why would it set a logger named __main__ as it is called before main is executed. Second question: should I even have that "logger = logging.getLogger(__name__)" before the definition of test()? Third question, should I do a "logger = logging.getLogger() in main() to define the root logger? I'm trying to see if I'm understanding what you're saying. – Mike Oct 07 '19 at 23:45
  • Yes, #3 is referring to `logger = logging.getLogger(__name__)`. When you run a module as a command line script, the module's name is `__main__`. That's true for any reference to `__name__` anywhere in the module. `__name__` actually gets set by the interpreter and assigned to the module's global dictionary. – Mad Physicist Oct 08 '19 at 02:58
  • You generally want a globally accessible logger for your entire module assigned somewhere early in the code, so that you can use it. You don't want to fetch the logger every time you need it, so assigning to a global variable is the standard practice. – Mad Physicist Oct 08 '19 at 03:01
  • You can configure the root logger in the `main` function, but keep `logger = logging.getLogger(__name__)` at the module level. This will ensure that your module level logger has all the same settings as the other modules. – Mad Physicist Oct 08 '19 at 03:06
  • Hopefully that helps answer your questions. If not, keep asking away. – Mad Physicist Oct 08 '19 at 03:07
  • Let me see if I got this right. As a general rule, pretty much always use getLogger(__name__) globally at the top of any module you want to import and have logging, as this will allow it to be a child of whatever Python file that would want to import it. If the file will be run from the CLI, keep getLogger(__name__) up top and also add getLogger() within main() (essentially overriding the global getLogger(__name__) declaration) and then apply any custom settings to the root logger created in main(). And if you're loading settings from a file, be sure to set disable_existing_loggers=False – Mike Oct 08 '19 at 20:10
  • @Mike. I don't think that's quite right. Loggers are arranged hierarchically by name, but you don't *have* to use the name of your module. That's just the simplest thing to do. You can distribute logger in any way you want, namesirrespective of the modules and other namespaces. Loggers inherit properties that are not set explicitly from parent loggers. If you configure the unnamed root logger, all the other loggers in your program will inherit the configured properties until you override them. Doing setup from a configuration file is pretty much mutually exclusive to what I am suggesting here – Mad Physicist Oct 08 '19 at 20:14
  • Dang!! It was supposed to be getLogger( __ name __ )!! – Mike Oct 08 '19 at 20:17
  • @Mike. I understand the frustration with the formatting, especially in comments. I had no trouble understanding what you meant. Use backticks `\`` to surround text that you don't want changes in. – Mad Physicist Oct 08 '19 at 20:20
  • Ok, this is making sense. My goal with this question was to find a simple, and essentially automatic, way of handling logging such that all of my modules inherited the root logger and my main logging would identify in which module certain logging was happening (which unfortunately was not how my current app worked!). I couldn't seem to find any articles that explained the hierarchy very well, or for what I was trying to accomplish. What nobody mentioned is overriding `getLogger(__name__)` with `getLogger()` in main(), and that seems to be the key to making work right. – Mike Oct 08 '19 at 21:15
  • @Mike. The override goes the other way. Individual loggers override what is configured in the root. Setting up the root properly ensures that all loggers that don't have an explicit configuration (don't override anything), are also set up correctly. By the way, https://docs.python.org/3/howto/logging-cookbook.html is quite good. Might have a lot of extraneous info for your particular case, but still very good. – Mad Physicist Oct 08 '19 at 21:18
  • I was speaking more towards main.py - in the case of that file I still have both the global `logger = logging.getLogger(__name__)` at the top (to handle if it's imported by another script) and `logger = logging.getLogger()` (and whatever associated custom configuration) in main() if it's called from the CLI (which in-turn overrides the global logger declared at the top) and becomes the parent for all of the child loggers within imported modules, of which the child-modules inherit the settings of the root logger declared in main.py's main(). Is that right? – Mike Oct 08 '19 at 23:04
  • The global logger is global only to the module its in. If your module is imported, you'll have a logger named `main`. If run as a script, the module logger will be `__main__`. You can even end up with both in the same program. In either case, these loggers are under root. Only loggers named `main.something` or `__main__.something` will inherit from that configuration. Configuring the root logger, `logging.getLogger()` is what creates the inheritable configuration. You generally want to do that once for the entire program, which is why you put it early in the cli code. – Mad Physicist Oct 08 '19 at 23:55
  • Keep in mind that logger names are arbitrary. You can define three loggers in the same module `mod` named `foo.bar`, `foo.baz` and `foo.bat`. You can then configure the basics for all of them by setting up an otherwise unused logger `foo`. Using the module name and having one logger per module is just a convenient convention that works well out of the box for most simple applications. It's certainly not the only way.e – Mad Physicist Oct 08 '19 at 23:59
  • @MadPhysicist so is there a way if I want to log across multiple modules with a predefined root logger name? I want the modules which are called by my main application have prefix which is defined by my main application. So If I define the logger's name as `my_application`, I want the sub-modules to have this name `my_application.sub_modules` in the logger. Is it doable? – addicted Dec 29 '19 at 08:23
  • @addicted. Yes. Why not? – Mad Physicist Dec 29 '19 at 13:59
  • The thing is I have 2 main module that calls a common sub module. So I dont want to hardcode the application name in the submodule's logger. I want the submodule logger to have dynamic prefix name depending on which main application calls it. – addicted Dec 29 '19 at 14:56
  • Then make that something you pass in somewhere. I'd recommend asking a question about that. Ping me when you do. I'll take a look. – Mad Physicist Dec 29 '19 at 21:37