179

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?

codeforester
  • 34,080
  • 14
  • 96
  • 122
digy
  • 2,293
  • 3
  • 17
  • 14

5 Answers5

325

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')
Community
  • 1
  • 1
Seb
  • 16,118
  • 7
  • 36
  • 27
  • 3
    And, yes, the **upper/lower case mess** in the variables needs to be considered. – Tom Pohl May 15 '19 at 09:05
  • 1
    Otherwise referred to as "very poorly implemented camel case". – Jon Spencer Aug 06 '19 at 21:38
  • 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 ? – user2396640 May 12 '22 at 15:54
135

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)d %(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
codeforester
  • 34,080
  • 14
  • 96
  • 122
  • 6
    Use this for more details: formatter = logging.Formatter( '%(asctime)s, %(levelname)-8s [%(filename)s:%(module)s:%(funcName)s:%(lineno)d] %(message)s') – Girish Gupta Mar 08 '18 at 09: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. Mar 10 '20 at 16:03
  • 4
    @Marie.P. don't ask different questions in comments. The answer is logging levels though. – bugmenot123 Apr 28 '20 at 18:28
13
# 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.

Hosana Gomes
  • 327
  • 4
  • 6
9

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.

orangepips
  • 9,741
  • 6
  • 31
  • 56
5

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.

jonrsharpe
  • 107,083
  • 22
  • 201
  • 376
chars
  • 181
  • 1
  • 9