logging: local functions ==> loss of lineno
Jean-Michel Pichavant
jeanmichel at sequans.com
Fri Mar 19 09:49:22 EDT 2010
Peter Otten wrote:
> 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
You are still accessing the private attribute of the module logging.
My previous remark was misleading, in fact there's nothing you can do
about it.
_srcfile is not meant to be used elsewhere than in the logging module
itself.
However, I don't wanna sound like I'm rejecting this solution, 1st the
OP is satisified with it and since this solution is working, it is still
more helpful than anyone noticing that you've accessed a private
attribute (some will successfully argue that python allows to do so).
At the very begining of this thread I've provided a complete different
approach, instead of using the builtin 'filename' and 'lineno' field of
the logging, use custom fileds with the extra parameter.
It has also some drawbacks but could be a possible alternative.
Cheers,
JM
in test.py:
import logging
import inspect
_logger = logging.getLogger(__name__)
class Foo:
def __init__(self):
self._logger = _logger
def info(self, msg):
# this is the method you don't want to appear in the logs,
instead the lineno and filename of this method caller
previousFrame = inspect.currentframe().f_back
self._logger.info(msg,
extra={'custom_lineno':previousFrame.f_lineno, 'custom_filename':
previousFrame.f_code.co_filename})
if __name__ == '__main__':
_logger.handlers=[]
_logger.addHandler(logging.StreamHandler())
_logger.handlers[-1].setFormatter(logging.Formatter('file
%(custom_filename)s line %(custom_lineno)d : %(message)s'))
_logger.setLevel(logging.DEBUG)
foo = Foo()
foo.info('a foo info')
In [3]: run test.py
file test.py line 20 : a foo info
More information about the Python-list
mailing list