13

I'm using Pythons logging module. I want to log the full path of a message, like
"msg packagename.modulename.functionName lineNumber", but how can I get the package name of a message?

The logging configuration is:

LOGGING = {    
'formatters': {
    'simple': {
    'format': '[%(levelname)s] %(message)s [%(module)s %(funcName)s %(lineno)d]'
    },  
},
'handlers': {
'console': {
        'level':'INFO',
        'class':'logging.StreamHandler',
        'formatter':'simple',
    }
},
'loggers': {
    'develop': {
        'handlers': ['console'],
        'level': 'DEBUG',
        'propagate': True,
    },
}

}

and I get a logger like this:

logger = logging.getLogger('develop')
Martin Thoma
  • 124,992
  • 159
  • 614
  • 958
remy
  • 1,255
  • 6
  • 20
  • 27
  • 3
    What do you mean by 'package name' which is different from what `%(module)s` produces? – Vinay Sajip Apr 18 '12 at 23:39
  • As of Python 3 (>=3.6, at least), it can be achieved with a simple filter: https://stackoverflow.com/a/72873684/687896 – Brandt Jul 05 '22 at 18:00

7 Answers7

8

I don't know how to get a "package name" like Java does by default, but to add the filename (which gives you just as much context), use %(pathname)s in your format string:

'format': '[%(levelname)s] %(message)s [%(pathname)s %(funcName)s %(lineno)d]'

See the documentation here: https://docs.python.org/2/library/logging.html#logrecord-attributes

dongle man
  • 133
  • 1
  • 7
3

I would recommend generating your package's logger with logging.getLogger(__name__.split('.')[0]), configure it with a formatter that includes the name parameter and then generate your module's logger with logging.getLogger(__name__).

For example:

import logging

formatter = logging.Formatter('%(name)s - %(message)s')
handler = logging.StreamHandler()
handler.setFormatter(formatter)
handler.setLevel(logging.INFO)

package_logger = logging.getLogger(__name__.split('.')[0])
package_logger.setLevel(logging.INFO)
package_logger.addHandler(handler)

logger = logging.getLogger(__name__)
logger.info('message')

For a module module.py located inside of a package named package, the logger.info() call should generate the following message to STDERR:

package.module - message

Inside of other modules within the same package, you can simply setup your logger as follows to get similar functionality to work in it:

import logging

logger = logging.getLogger(__name__)

logger.info('another message')

For a module another.py inside of the package package, called from the module.py module of the same package, this should generate the following text to STDERR:

package.another - another message
Jitsusama
  • 617
  • 7
  • 20
2

I see two solutions to the problem.

One, pass in the filename with every call to log.[debug,info,error,...] as obtained by the __file__ magic variable. This does not give you the package name, but it's as good as that for finding out where the log message originated. The downside is that you'd need to modify every logging call in your application.

Two, make a subclass of logging.Logger which overrides the Logger.log instance method. In your new log method, use the inspect.stack() and inspect.getframeinfo() methods to find the stack frame which caused the call to log in your code and extract filename and line numbers. You can then modify the log message which was passed in accordingly. Finally, tell the logging module to use your subclass by calling logging.setLoggerClass().

Simon
  • 12,018
  • 4
  • 34
  • 39
2

I have a utils.py file inside a package called common and it has the below.

utils.py

import logging
log = logging
log.basicConfig(level=log.INFO, format='%(asctime)s:%(filename)s:%(funcName)s'
                                       ':%(levelname)s :%(message)s')

In any other file that I need to use the log, i use the below.

from pkg.common.utils import log
log.info("some msg")
NullPointer
  • 241
  • 1
  • 2
  • 7
1

Here's an example of how I implemented this: https://github.com/JensTimmerman/vsc-base/blob/master/lib/vsc/utils/fancylogger.py

as Simon suggests, I extended to python logger to add custom fields. But you can also just define a new getLogger function that does this:

rootmodulename = inspect.stack()[-1][1].split('/')[-1].split('.')[0]
callingfunctionname = inspect.stack()[2][3]
logger = logging.getLogger("%s.%s" % (rootmodulename, callingfunctionname))

But look into fancylogger.py for a complete worked out example.

Jens Timmerman
  • 9,316
  • 1
  • 42
  • 48
1

I guess we're talking about the same thing. My issue now was that I wanted to have precise indication of where each message was being logged (especially in DEBUG mode).

TL;DR: add a simple filter to your handler:

, through which you can modify the current LogRecord (with the package/module's path, for instance).


Example

My lib is called npt, and some message is being logged inside the module npt/search/_ode.py, inside the function "parse" more precisely. I want to have this information in my log messages: the function name, module name, and the (sub)packages where the module is. Something like "INFO: npt.search._ode.parse(): file <whatever> parsed"

The formatter provides lots of attributes (see LogRecord attributes), of interest here, for instance (from the docs):

  • pathname: Full pathname of the source file where the logging call was issued (if available). E.g, /Users/chbrandt/repos/npt/npt/search/_ode.py.
  • filename: Filename portion of pathname. E.g, _ode.py.
  • module: Module (name portion of filename). E.g, _ode.

There is not a single parameter that provides the relative path of the module inside the library only; pathname will log the absolute path of the module in your system (we don't wanna do that, right). But it is useful to get what you want, obviously, we just have to cut the absolute part of the path.

So, what I did was: I initialize my log/handler at the very top of my package, inside npt/_log.py, call it log, and use from npt import log everywhere inside npt. During logging setup, I get the path of npt inside the system, and then define a filter() function where an attribute package is added to the record with the relative path of my module inside my library (npt).

Here is the code I currently have:

import logging

# Get the current path (/path/to/lib/npt/_log.py) from __file__
# and compute the size of the string up-until npt's position
#
from pathlib import Path
_lib_path = Path(__file__).parents[1]
_leng_path = len(_lib_path.as_posix())

def filter(record: logging.LogRecord):
    # I'm using the _leng_path because is simple/fast,
    # just chop the system path from `pathname`.
    # Define `package` attribute with the relative path.
    record.package = record.pathname[_leng_path+1:]
    return record

# Notice `package` attribute, which is adhoc inside `filter()`
fmt="%(levelname)s: [%(name)s - %(package)s] %(funcName)s: %(message)s"

# Then...proceed as usual...

log = logging.getLogger('npt')
log.setLevel(logging.INFO)

formatter = logging.Formatter(fmt)
handler = logging.StreamHandler()

handler.setFormatter(formatter)
handler.addFilter(filter)
log.addHandler(handler)

Now I have messages like:

> import npt
> df_search = npt.search.ode(dataset=dataset, product_id=pid)
INFO: [npt - npt/search/_ode.py] parse: 1 products found

Which solves the issue perfectly for my/this case.

Brandt
  • 5,058
  • 3
  • 28
  • 46
  • what if I want this for all my files in the application but do not have a single root package for alle code files? Do I need to create n such _log.py files for every of the n packages? – Kaspatoo Aug 09 '22 at 20:26
  • @Kaspatoo It depends on the structure of files in your application, and what you want to achieve. If you want to use this code as it is, without modifications, then _yes_, you'd copy it to the N packages you have. That would log the relative path inside _each package_. If you want, instead, to log the relative path inside _the application_ then you just have to have this module in a path common to all the packages (eg, the app's root); you just have to put such path in your PYTHONPATH env. variable (the code would still work as it is, as far as I can see). – Brandt Aug 10 '22 at 00:35
  • @Kaspatoo check also this other answer: https://stackoverflow.com/a/54956419/687896 . I don't know if I understood correctly your case, maybe useful. – Brandt Aug 10 '22 at 00:38
0

Just use style '{' with {module} as explained https://docs.djangoproject.com/en/2.2/topics/logging/

Example:

'formatters': {
    'standard': {
        'format': '{asctime}: [{levelname}] [{name}] [{module}.{funcName} linenr: {lineno}]: {message}',
        'style': '{',
    },
    'report': {
        'format': '{asctime}: [{name}.{module}.{funcName} linenr: {lineno}]: {message}',
        'style': '{',
    },
    'simple': {
        'format': '{levelname} {message}',
        'style': '{',
    },
},
openHBP
  • 627
  • 4
  • 11