logging: local functions ==> loss of lineno

[Peter Otten]

Jean-Michel Pichavant wrote:

> Hellmut Weber wrote:
>> Am 11.03.2010 12:14, schrieb Peter Otten:
>>> Hellmut Weber wrote:
>>>
>>>> Logging works very well giving the filename and line number of the
>>>> point
>>>> where it is called. As long as I use the loggers directly.
>>>> BUT when I have to wrap the logger call in some other function, I
>>>> always
>>>> get file name and line number of the call of the logger inside the
>>>> wrapping function.
>>>>
>>>> Is there a possibility to get this information in this situation too?
>>>
>>> The official way is probably to write a custom Logger class that
>>> overrides
>>> the findCaller() method.
>>>
>>> Below is a hack that monkey-patches the logging._srcfile attribute to
>>> ignore
>>> user-specified modules in the call stack:
>>>
>>> $ cat wrapper.py
>>> import logging
>>> import os
>>> import sys
>>>
>>> logger = logging.getLogger()
>>>
>>> class SrcFile(object):
>>>      def __init__(self, exclude_files):
>>>          self.files = set(exclude_files)
>>>      def __eq__(self, other):
>>>          return other in self.files
>>>
>>> def fixname(filename):
>>>      if filename.lower().endswith((".pyc", ".pyo")):
>>>          filename = filename[:-4] + ".py"
>>>      return os.path.normcase(filename)
>>>
>>> if "--monkey" in sys.argv:
>>>      print "patching"
>>>      logging._srcfile = SrcFile([logging._srcfile, fixname(__file__)])
>>>
>>> def warn(*args, **kw):
>>>      logger.warn(*args, **kw)
>>>
>>> $ cat main.py
>>> import logging
>>> logging.basicConfig(format="%(filename)s<%(lineno)s>: %(message)s")
>>> import wrapper
>>> wrapper.warn("foo")
>>> wrapper.warn("bar")
>>> wrapper.warn("baz")
>>>
>>> $ python main.py
>>> wrapper.py<23>: foo
>>> wrapper.py<23>: bar
>>> wrapper.py<23>: baz
>>>
>>> $ python main.py --monkey
>>> patching
>>> main.py<4>: foo
>>> main.py<5>: bar
>>> main.py<6>: baz
>>>
>>> $ python -V
>>> Python 2.6.4
>>>
>>> Peter
>>
>> Hi Peter,
>> your hack is exactly what I was looking for.
>> It permits to configure my logging messages as I want, e.g. using
>> different colors for different classes of messages.
>>
>> I do not yet understand all details WHY it is working but suppose some
>> study of the logging module will help me to understand.
>>
>> Thank you very much
>>
> _scrFile is a private attribute of the logging module. Don't change it.
> 
> As you said yourself, 'The official way is probably to write a custom
> Logger class that overrides
> the findCaller() method'

OK, I tried the this approach, too:

import logging
import os
import sys

from logging import currentframe

def fixname(filename):
    if filename.lower().endswith((".pyc", ".pyo")):
        filename = filename[:-4] + ".py"
    return os.path.normcase(filename)

class MyLogger(logging.Logger):
    exclude_files = set([logging._srcfile, fixname(__file__)])

    def findCaller(self):
        """
        Find the stack frame of the caller so that we can note the source
        file name, line number and function name.
        """
        f = currentframe()
        #On some versions of IronPython, currentframe() returns None if
        #IronPython isn't run with -X:Frames.
        if f is not None:
            f = f.f_back
        rv = "(unknown file)", 0, "(unknown function)"
        while hasattr(f, "f_code"):
            co = f.f_code
            filename = os.path.normcase(co.co_filename)
            if filename in self.exclude_files:
                f = f.f_back
                continue
            rv = (filename, f.f_lineno, co.co_name)
            break
        return rv

if "--custom-logger" in sys.argv:
    print "setting custom logger"
    logging.setLoggerClass(MyLogger)
    logging.root = MyLogger("root", logging.WARNING)

logger = logging.getLogger()
def warn(*args, **kw):
    logger.warn(*args, **kw)

I had to duplicate the original findCaller() method with only one line 
changed. This means I have now some code duplication and I still have to 
monitor future changes in the logging source.

In this case the "official way" seems to be more intrusive than the "hack".

Peter