229

Is it possible to decorate/extend the python standard logging system, so that when a logging method is invoked it also logs the file and the line number where it was invoked or maybe the method that invoked it?

8 Answers 8

402

Sure, check formatters in logging docs. Specifically the lineno and pathname variables.

%(pathname)s Full pathname of the source file where the logging call was issued(if available).

%(filename)s Filename portion of pathname.

%(module)s Module (name portion of filename).

%(funcName)s Name of function containing the logging call.

%(lineno)d Source line number where the logging call was issued (if available).

Looks something like this:

formatter = logging.Formatter('[%(asctime)s] p%(process)s {%(pathname)s:%(lineno)d} %(levelname)s - %(message)s','%m-%d %H:%M:%S')
7
  • 5
    And, yes, the upper/lower case mess in the variables needs to be considered.
    – Tom Pohl
    Commented May 15, 2019 at 9:05
  • 4
    Otherwise referred to as "very poorly implemented camel case". Commented Aug 6, 2019 at 21:38
  • 2
    I'm using Logger.py file to share my logger between my files and when I use this syntax I get the filename and lineno of the Logger and not the file and line used to call the logger method. Any way of solving that ? Commented May 12, 2022 at 15:54
  • why do you have the {} and the ...)d}? Commented Jun 17, 2022 at 17:02
  • 1
    what does p%(process)s do? especially the p and s. Commented Jun 20, 2022 at 15:30
171

On top of Seb's very useful answer, here is a handy code snippet that demonstrates the logger usage with a reasonable format:

#!/usr/bin/env python
import logging

logging.basicConfig(format='%(asctime)s,%(msecs)03d %(levelname)-8s [%(filename)s:%(lineno)d] %(message)s',
    datefmt='%Y-%m-%d:%H:%M:%S',
    level=logging.DEBUG)

logger = logging.getLogger(__name__)
logger.debug("This is a debug log")
logger.info("This is an info log")
logger.critical("This is critical")
logger.error("An error occurred")

Generates this output:

2017-06-06:17:07:02,158 DEBUG    [log.py:11] This is a debug log
2017-06-06:17:07:02,158 INFO     [log.py:12] This is an info log
2017-06-06:17:07:02,158 CRITICAL [log.py:13] This is critical
2017-06-06:17:07:02,158 ERROR    [log.py:14] An error occurred
2
  • 8
    Use this for more details: formatter = logging.Formatter( '%(asctime)s, %(levelname)-8s [%(filename)s:%(module)s:%(funcName)s:%(lineno)d] %(message)s') Commented Mar 8, 2018 at 9:43
  • is there a way to change just in one place at the top of the code whether or not the logging messages get printed? I would like two modes, one with lots of prints to see what exactly the program does; and one, for when it's stable enough, where no output is shown.
    – Marie. P.
    Commented Mar 10, 2020 at 16:03
14
import logging

# your imports above ...


logging.basicConfig(
    format='%(asctime)s,%(msecs)d %(levelname)-8s [%(pathname)s:%(lineno)d in ' \
           'function %(funcName)s] %(message)s',
    datefmt='%Y-%m-%d:%H:%M:%S',
    level=logging.DEBUG
)

logger = logging.getLogger(__name__)

# your classes and methods below ...
# A very naive sample of usage:
try:
    logger.info('Sample of info log')
    # your code here
except Exception as e:
    logger.error(e)

Different from the other answers, this will log the full path of file and the function name that might have occurred an error. This is useful if you have a project with more than one module and several files with the same name distributed in these modules.

Example output:

2022-12-02:10:00:00,000 INFO     [<stdin>:2 in function <module>] Sample of info log
2022-12-02:10:00:00,000 INFO     [<full path>/logging_test_file.py:15 in function <module>] Sample of info log
11

To build on the above in a way that sends debug logging to standard out:

import logging
import sys

root = logging.getLogger()
root.setLevel(logging.DEBUG)

ch = logging.StreamHandler(sys.stdout)
ch.setLevel(logging.DEBUG)
FORMAT = "[%(filename)s:%(lineno)s - %(funcName)20s() ] %(message)s"
formatter = logging.Formatter(FORMAT)
ch.setFormatter(formatter)
root.addHandler(ch)

logging.debug("I am sent to standard out.")

Putting the above into a file called debug_logging_example.py produces the output:

[debug_logging_example.py:14 -             <module>() ] I am sent to standard out.

Then if you want to turn off logging comment out root.setLevel(logging.DEBUG).

For single files (e.g. class assignments) I've found this a far better way of doing this as opposed to using print() statements. Where it allows you to turn the debug output off in a single place before you submit it.

7

For devs using PyCharm or Eclipse pydev, the following will produce a link to the source of the log statement in the console log output:

import logging, sys, os
logging.basicConfig(stream=sys.stdout, level=logging.DEBUG, format='%(message)s | \'%(name)s:%(lineno)s\'')
log = logging.getLogger(os.path.basename(__file__))


log.debug("hello logging linked to source")

See Pydev source file hyperlinks in Eclipse console for longer discussion and history.

1

If the logger is set with the GetLogger(name) option, where the name is a name that you specified you can also format the logger using %(name)s. You can specify a different name in every file with the GetLogger function, and when a log is produced you will know from which file comes through the name you set.

Example:

import logging

logging.getLogger("main")
logging.basicConfig(#filename=log_fpath, 
                    level=log_level,
                    format='[%(asctime)s] src:%(name)s %(levelname)s:%(message)s',
                    handlers=[logging.FileHandler(log_fpath)])
1

the original question mentioned "decorate/extend". not sure if it's just i think too much or everyone else goes a wrong direction. if we're going to decorate python default logging facility, while having stack info works as expected, such as "filename" and "lineno" showing desired stack outside decorate. then there is an answer from @Tony S Yu in another post: https://stackoverflow.com/a/55998744/8013269

the key is to use stacklevel attribute, i'll demonstrate with a piece of code:

logging.basicConfig(
    format=('%(asctime)s,%(msecs)03d %(levelname)-8s '
            '[%(filename)s:%(lineno)d] %(message)s'),
    level=logging.DEBUG,
    datefmt='%H:%M:%S')

def my_log(*args, **kwargs):
    indent = kwargs.pop('indent', 0)
    msg = ' ' * indent + ' '.join([str(a) for a in args])
    print(f'[MYLOG] {msg}')
    return logging.info(msg, stacklevel=2, **kwargs)
0
0

Create pytest.ini file with log_format

pytest.ini

log_format = %(asctime)s %(levelname) %(message)s (%(pathname)s:%(lineno)s)
log_cli_level = DEBUG

Not the answer you're looking for? Browse other questions tagged or ask your own question.