Mailing List Archive

Trouble propagating logging configuration
Hi,

I am having difficulty getting the my logging configuration passed on
to imported modules.

My initial structure was as follows:

$ tree blorp/
blorp/
|-- blorp
| |-- __init__.py
| |-- bar.py
| |-- foo.py
| `-- main.py
`-- pyproject.toml

whereby the logging configuration is done in main.py.

After thinking about it, I decided maybe the inheritance wasn't working
because main.py is in the same directory as the other files. So I
changed the structure to

$ tree blorp/
blorp/
|-- blorp
| |-- __init__.py
| |-- bar.py
| `-- foo.py
|-- main.py
`-- pyproject.toml

but the logging configuration still is not propagated.

Can anyone at least confirm that moving main.py to the directory above
the other files is the correct thing to do and thus the problem is being
caused by something else?

Cheers,

Loris

--
This signature is currently under construction.
--
https://mail.python.org/mailman/listinfo/python-list
Re: Trouble propagating logging configuration [ In reply to ]
"Loris Bennett" <loris.bennett@fu-berlin.de> writes:

> Hi,
>
> I am having difficulty getting the my logging configuration passed on
> to imported modules.
>
> My initial structure was as follows:
>
> $ tree blorp/
> blorp/
> |-- blorp
> | |-- __init__.py
> | |-- bar.py
> | |-- foo.py
> | `-- main.py
> `-- pyproject.toml
>
> whereby the logging configuration is done in main.py.
>
> After thinking about it, I decided maybe the inheritance wasn't working
> because main.py is in the same directory as the other files. So I
> changed the structure to
>
> $ tree blorp/
> blorp/
> |-- blorp
> | |-- __init__.py
> | |-- bar.py
> | `-- foo.py
> |-- main.py
> `-- pyproject.toml
>
> but the logging configuration still is not propagated.
>
> Can anyone at least confirm that moving main.py to the directory above
> the other files is the correct thing to do and thus the problem is being
> caused by something else?

I should mention that I am using poetry and thus the program is called
via an entry in the pyproject.toml file such as

[tool.poetry.scripts]
blorp_out = "main:blorp_out"

I have a suspicion that this way of calling the program somehow
interferes with the inheritance mechanism used by logging.

Cheers,

Loris

--
This signature is currently under construction.
--
https://mail.python.org/mailman/listinfo/python-list
Re: Trouble propagating logging configuration [ In reply to ]
Loris Bennett wrote at 2021-8-31 15:25 +0200:
>I am having difficulty getting the my logging configuration passed on
>to imported modules.
>
>My initial structure was as follows:
>
> $ tree blorp/
> blorp/
> |-- blorp
> | |-- __init__.py
> | |-- bar.py
> | |-- foo.py
> | `-- main.py
> `-- pyproject.toml
>
>whereby the logging configuration is done in main.py.
>
>After thinking about it, I decided maybe the inheritance wasn't working
>because main.py is in the same directory as the other files.

Should you speak about Python's `logging` module, then
the "inheritance" does not depend on the source layout.
Instead, it is based on the hierarchy of dotted names.
It is completely up to you which dotted names you are using
in your `getLogger` calls.

Furthermore, the place of the configuration (and where in the
code it is activated) is completely irrelevant for the "inheritance".

For details, read the Python documentation for the `logging` module.
--
https://mail.python.org/mailman/listinfo/python-list
Re: Trouble propagating logging configuration [ In reply to ]
"Dieter Maurer" <dieter@handshake.de> writes:

> Loris Bennett wrote at 2021-8-31 15:25 +0200:
>>I am having difficulty getting the my logging configuration passed on
>>to imported modules.
>>
>>My initial structure was as follows:
>>
>> $ tree blorp/
>> blorp/
>> |-- blorp
>> | |-- __init__.py
>> | |-- bar.py
>> | |-- foo.py
>> | `-- main.py
>> `-- pyproject.toml
>>
>>whereby the logging configuration is done in main.py.
>>
>>After thinking about it, I decided maybe the inheritance wasn't working
>>because main.py is in the same directory as the other files.
>
> Should you speak about Python's `logging` module, then
> the "inheritance" does not depend on the source layout.
> Instead, it is based on the hierarchy of dotted names.
> It is completely up to you which dotted names you are using
> in your `getLogger` calls.

Yes, but to quote from https://docs.python.org/3.6/howto/logging.html#logging-basic-tutorial:

A good convention to use when naming loggers is to use a module-level
logger, in each module which uses logging, named as follows:

logger = logging.getLogger(__name__)

This means that logger names track the package/module hierarchy, and
it’s intuitively obvious where events are logged just from the logger
name.

so in this case the source layout is relevant, isn't it?

> Furthermore, the place of the configuration (and where in the
> code it is activated) is completely irrelevant for the "inheritance".

OK, so one issue is that I was getting confused by the *order* in which
modules are being called. If I have two modules, 'foo' and 'bar', in
the same directory, configure the logging just in 'foo' and then call


foo.some_method()
bar.some_method()

then both methods will be logged. If I do

bar.some_method()
foo.some_method()

then only the method in 'foo' will be logged.

However, I still have the following problem. With the structure

$ tree .
.
|-- log_test
| |-- __init__.py
| |-- first.py
| `-- second.py
|-- pyproject.toml
|-- README.rst
|-- run.py
`-- tests
|-- __init__.py
|-- config
`-- test_log_test.py

I have __name__ variables as follows:

__file__: /home/loris/log_test/log_test/first.py, __name__: log_test.first
__file__: /home/loris/log_test/log_test/second.py, __name__: log_test.second
__file__: ./run.py, __name__: __main__

If I have

[loggers]
keys=root,main,log_test

in my logging configuration and initialise the logging in run.py with

logging.config.fileConfig("/home/loris/log_test/tests/config")
logger = logging.getLogger()

or

logging.config.fileConfig("/home/loris/log_test/tests/config")
logger = logging.getLogger("log_test")

then only calls in 'run.py' are logged.

I can obviously initialise the logging within the subordinate package,
i.e. in 'log_test/__init__.py', but that seems wrong to me.

So what is the correct way to initialise logging from a top-level script
such that logging is activated in all modules requested in the logging
configuration?

> For details, read the Python documentation for the `logging` module.

If they were sufficient, I wouldn't need the newsgroup :-)

Thanks for the help,

Loris
--
This signature is currently under construction.
--
https://mail.python.org/mailman/listinfo/python-list
Re: Trouble propagating logging configuration [ In reply to ]
On 01/09/2021 13:48, Loris Bennett wrote:
> "Dieter Maurer" <dieter@handshake.de> writes:
>
>> Loris Bennett wrote at 2021-8-31 15:25 +0200:
>>> I am having difficulty getting the my logging configuration passed on
>>> to imported modules.
>>>
>>> My initial structure was as follows:
>>>
>>> $ tree blorp/
>>> blorp/
>>> |-- blorp
>>> | |-- __init__.py
>>> | |-- bar.py
>>> | |-- foo.py
>>> | `-- main.py
>>> `-- pyproject.toml
>>>
>>> whereby the logging configuration is done in main.py.
>>>
>>> After thinking about it, I decided maybe the inheritance wasn't working
>>> because main.py is in the same directory as the other files.
>>
>> Should you speak about Python's `logging` module, then
>> the "inheritance" does not depend on the source layout.
>> Instead, it is based on the hierarchy of dotted names.
>> It is completely up to you which dotted names you are using
>> in your `getLogger` calls.
>
> Yes, but to quote from https://docs.python.org/3.6/howto/logging.html#logging-basic-tutorial:
>
> A good convention to use when naming loggers is to use a module-level
> logger, in each module which uses logging, named as follows:
>
> logger = logging.getLogger(__name__)
>
> This means that logger names track the package/module hierarchy, and
> it’s intuitively obvious where events are logged just from the logger
> name.
>
> so in this case the source layout is relevant, isn't it?

In most cases you will only add handlers to the root logger. If you want
special treatment of a specific logger you need to know its name
including its package, i. e. log_test.first, not first. If you have the
log_test directory in your path and use

import first

instead of

import log_test.first

then not only the __name__ will be wrong/unexpected, relative imports
will fail, too.
In other words, this is generally a bad idea.

>> Furthermore, the place of the configuration (and where in the
>> code it is activated) is completely irrelevant for the "inheritance".
>
> OK, so one issue is that I was getting confused by the *order* in which
> modules are being called. If I have two modules, 'foo' and 'bar', in
> the same directory, configure the logging just in 'foo' and then call
>
>
> foo.some_method()
> bar.some_method()
>
> then both methods will be logged. If I do
>
> bar.some_method()
> foo.some_method()
>
> then only the method in 'foo' will be logged.
>
> However, I still have the following problem. With the structure
>
> $ tree .
> .
> |-- log_test
> | |-- __init__.py
> | |-- first.py
> | `-- second.py
> |-- pyproject.toml
> |-- README.rst
> |-- run.py
> `-- tests
> |-- __init__.py
> |-- config
> `-- test_log_test.py
>
> I have __name__ variables as follows:
>
> __file__: /home/loris/log_test/log_test/first.py, __name__: log_test.first
> __file__: /home/loris/log_test/log_test/second.py, __name__: log_test.second
> __file__: ./run.py, __name__: __main__
>
> If I have
>
> [loggers]
> keys=root,main,log_test
>
> in my logging configuration and initialise the logging in run.py with
>
> logging.config.fileConfig("/home/loris/log_test/tests/config")
> logger = logging.getLogger()
>
> or
>
> logging.config.fileConfig("/home/loris/log_test/tests/config")
> logger = logging.getLogger("log_test")
>
> then only calls in 'run.py' are logged.
>
> I can obviously initialise the logging within the subordinate package,
> i.e. in 'log_test/__init__.py', but that seems wrong to me.
>
> So what is the correct way to initialise logging from a top-level script
> such that logging is activated in all modules requested in the logging
> configuration?
>
>> For details, read the Python documentation for the `logging` module.
>
> If they were sufficient, I wouldn't need the newsgroup :-)
>
> Thanks for the help,

Perhaps you can start with logging.basicConfig() in run.py. If the
imported modules contain module-level logging messages you have to put
the import statements after the basicConfig() invocation.

You should see that simple changes like setting the logging level affect
messages from all loggers. If that's not enough to get the granularity
you want give your loggers fixed names

# in test_log/first.py
logger = logging.getLogger("test_log.first")

or make sure that __name__ is what you expect

# in test_log/first.py
assert __name__ == "test_log.first"

during the debugging phase.


--
https://mail.python.org/mailman/listinfo/python-list
Re: Trouble propagating logging configuration [ In reply to ]
Loris Bennett wrote at 2021-9-1 13:48 +0200:
> ...
>Yes, but to quote from https://docs.python.org/3.6/howto/logging.html#logging-basic-tutorial:
>
> A good convention to use when naming loggers is to use a module-level
> logger, in each module which uses logging, named as follows:
>
> logger = logging.getLogger(__name__)
>
> This means that logger names track the package/module hierarchy, and
> it’s intuitively obvious where events are logged just from the logger
> name.
>
>so in this case the source layout is relevant, isn't it?

Relevant in this case is the package/module hierarchy.

Often the package/module hierarchy follows the source layout
**BUT** this is not necessarily the case.

In particular, the "start" module of a script is called `__main__`
indepently of its location.
Furthermore, so called "namespace packages" consist of
decentralized (i.e. located at different places in the file system)
subpackages.

Thus, in general, the connection between pachage/module hierarchy
and the source layout is loose.


>> Furthermore, the place of the configuration (and where in the
>> code it is activated) is completely irrelevant for the "inheritance".
>
>OK, so one issue is that I was getting confused by the *order* in which
>modules are being called. If I have two modules, 'foo' and 'bar', in
>the same directory, configure the logging just in 'foo' and then call
>
>
> foo.some_method()
> bar.some_method()
>
>then both methods will be logged. If I do
>
> bar.some_method()
> foo.some_method()
>
>then only the method in 'foo' will be logged.

Usually, log configuration is considered a (global) application
(not a (local) package/module) concern:
The components (modules) decide what to log at what level
and global configuration decides what to do with those messages.

Thus, typically, you configure the complete logging in
your main application module and then start to import modules
and call their functions.

> ...
>If I have
>
> [loggers]
> keys=root,main,log_test
>
>in my logging configuration and initialise the logging in run.py ...

This logging configuration is obviously not complete (thus, I cannot
check what happens in your case).
You may have made errors at other places in your configuration
which may explain your observations.

At your place, I would look at the `logging` source code
to find out where you can see (in an interactive Python session)
which loggers have been created by your configuration and
how they are configured. For the last part you use "vars(logger)".



--
Dieter
--
https://mail.python.org/mailman/listinfo/python-list
Re: Trouble propagating logging configuration [ In reply to ]
"Dieter Maurer" <dieter@handshake.de> writes:

> Loris Bennett wrote at 2021-9-1 13:48 +0200:
>> ...
>>Yes, but to quote from https://docs.python.org/3.6/howto/logging.html#logging-basic-tutorial:
>>
>> A good convention to use when naming loggers is to use a module-level
>> logger, in each module which uses logging, named as follows:
>>
>> logger = logging.getLogger(__name__)
>>
>> This means that logger names track the package/module hierarchy, and
>> it’s intuitively obvious where events are logged just from the logger
>> name.
>>
>>so in this case the source layout is relevant, isn't it?
>
> Relevant in this case is the package/module hierarchy.
>
> Often the package/module hierarchy follows the source layout
> **BUT** this is not necessarily the case.
>
> In particular, the "start" module of a script is called `__main__`
> indepently of its location.
> Furthermore, so called "namespace packages" consist of
> decentralized (i.e. located at different places in the file system)
> subpackages.
>
> Thus, in general, the connection between pachage/module hierarchy
> and the source layout is loose.
>
>
>>> Furthermore, the place of the configuration (and where in the
>>> code it is activated) is completely irrelevant for the "inheritance".
>>
>>OK, so one issue is that I was getting confused by the *order* in which
>>modules are being called. If I have two modules, 'foo' and 'bar', in
>>the same directory, configure the logging just in 'foo' and then call
>>
>>
>> foo.some_method()
>> bar.some_method()
>>
>>then both methods will be logged. If I do
>>
>> bar.some_method()
>> foo.some_method()
>>
>>then only the method in 'foo' will be logged.
>
> Usually, log configuration is considered a (global) application
> (not a (local) package/module) concern:
> The components (modules) decide what to log at what level
> and global configuration decides what to do with those messages.
>
> Thus, typically, you configure the complete logging in
> your main application module and then start to import modules
> and call their functions.
>
>> ...
>>If I have
>>
>> [loggers]
>> keys=root,main,log_test
>>
>>in my logging configuration and initialise the logging in run.py ...
>
> This logging configuration is obviously not complete (thus, I cannot
> check what happens in your case).
> You may have made errors at other places in your configuration
> which may explain your observations.
>
> At your place, I would look at the `logging` source code
> to find out where you can see (in an interactive Python session)
> which loggers have been created by your configuration and
> how they are configured. For the last part you use "vars(logger)".

Thanks Peter and Dieter for all the help. I have finally figured out
what my problem was. If in a module 'mylibs.mylib' I have

import logging

logger = logging.getLogger(__name__)

and in my main script have

import logger
import logger.config

import mylibs.mylib

logging.config.fileConfig("/home/loris/config")
logger = logging.getLogger(__name__)

then 'logger' in 'mylibs.mylib' is defined before
'logging.config.fileConfig' is called and the logger in the module is
not configured.

If change the order and write

import logger
import logger.config

logging.config.fileConfig("/home/loris/config")
logger = logging.getLogger(__name__)

import mylibs.mylib

then the 'logger' in 'mylibs.mylibs' does get configured properly.

I'm still thinking what implications this has if I want to load a
configuration file via a command-line option.

Cheers,

Loris

--
This signature is currently under construction.
--
https://mail.python.org/mailman/listinfo/python-list
Re: Trouble propagating logging configuration [ In reply to ]
On 2021-09-02 09:06:53 +0200, Loris Bennett wrote:
> Thanks Peter and Dieter for all the help. I have finally figured out
> what my problem was. If in a module 'mylibs.mylib' I have
>
> import logging
>
> logger = logging.getLogger(__name__)
>
> and in my main script have
>
> import logger
> import logger.config
>
> import mylibs.mylib
>
> logging.config.fileConfig("/home/loris/config")
> logger = logging.getLogger(__name__)
>
> then 'logger' in 'mylibs.mylib' is defined before
> 'logging.config.fileConfig' is called and the logger in the module is
> not configured.
>
> If change the order and write
>
> import logger
> import logger.config
>
> logging.config.fileConfig("/home/loris/config")
> logger = logging.getLogger(__name__)
>
> import mylibs.mylib
>
> then the 'logger' in 'mylibs.mylibs' does get configured properly.

That normally shouldn't make any difference, since any functions in
mylibs.mylib would be called only after the logger is initialized.

Does your mylibs.mylib contain code which is run on import (other than
class, function and variable definitions)?

hp

--
_ | Peter J. Holzer | Story must make more sense than reality.
|_|_) | |
| | | hjp@hjp.at | -- Charles Stross, "Creative writing
__/ | http://www.hjp.at/ | challenge!"