logging: local functions ==> loss of lineno

[Hellmut Weber]

Hi Vinay Sajip,
I'm very glad discoverd your logging module ;-)
(That's what I would have liked 25 years ago when I was working as a
technical software developper!)

Now I'm writing just some personal tools, I like python and want to use
logging on a regular basis.

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?

TIA

Hellmut

 

[Peter Otten]

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

 

[Hellmut Weber]

Am 11.03.2010 12:14, schrieb Peter Otten:

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,
thanks for your help ;-)

I've been offline for a few days so I found your message only today.
I'll try your proposal tomorrow.

Thanks again

Hellmut

 

[Hellmut Weber]

Am 11.03.2010 12:14, schrieb Peter Otten:

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

 

[Peter Otten]

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.

Have a look at Logger.findCaller() in logging/__init__.py. To find the
calling function it does something like

for frame in walk_callstack():
if filename_of(frame) == _srcfile:
continue
return filename_lineno_and_functionname_of(frame)

The _srcfile is normally logging/__init__.py, and it is skipped because a
user typically is interested only in what happens outside the logging
package.

My hack under the hood changes

filename_of(frame) == _srcfile

from a string comparison to a

filename_of(frame) in set_of_files

containment test (see SrcFile.__eq__() posted above).

Peter

 

[Jean-Michel Pichavant]

Am 11.03.2010 12:14, schrieb Peter Otten:

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'

JM

 

[Peter Otten]

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

 

[Jean-Michel Pichavant]

Jean-Michel Pichavant 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'reviousFrame.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

 

[Peter Otten]

You are still accessing the private attribute of the module logging.

Just reading it is a significantly more conservative approach than setting
it to an object with an unusual notion of equality

My previous remark was misleading, in fact there's nothing you can do
about it.

How about replacing logging._srcfile with fixname(logging.__file__)?

_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).

Yeah, I had hoped that I could get away without drawing the "consenting
adults" wildcard...

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.

Having two filename/lineno sets ist likely to confuse.

Peter

 

[Vinay Sajip]

Just reading it is a significantly more conservative approach than setting
it to an object with an unusual notion of equality


How about replacinglogging._srcfile with fixname(logging.__file__)?


Yeah, I had hoped that I could get away without drawing the "consenting
adults" wildcard...



Having two filename/lineno sets ist likely to confuse.

Peter

Guys,

Sorry I'm a little late to this discussion. I could add a _findCaller
function to the module (not part of the public API, but replaceable by
someone who really needs to) which does the heavy lifting, and
Logger.findCaller just calls it. Then those who need to can implement
their own strategy, without needing to jump through hoops. Does that
approach sound helpful?

Regards,

Vinay Sajip

 

[Peter Otten]

Sorry I'm a little late to this discussion. I could add a _findCaller
function to the module (not part of the public API, but replaceable by
someone who really needs to) which does the heavy lifting, and
Logger.findCaller just calls it. Then those who need to can implement
their own strategy, without needing to jump through hoops. Does that
approach sound helpful?

You mean you'd have to monkey-patch logging._findCaller() instead of
overriding logging.Logger.findCaller()?

I don't see a big advantage in that.

Here's an alternative proposal: simplify findCaller() by moving part of the
code into a generator:

def callers(self):
"""
Walk up the call stack.
Helper for findCaller().
"""
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
while hasattr(f, "f_code"):
co = f.f_code
filename = os.path.normcase(co.co_filename)
yield filename, f.f_lineno, co.co_name
f = f.f_back


def findCaller(self):
"""
Find the stack frame of the caller so that we can note the source
file name, line number and function name.
"""
for filename, lineno, funcname in self.callers():
if filename != _srcfile:
return filename, lineno, funcname
return UNKNOWN_CALLER

Another simplification might be to have setLoggerClass() implicitly set the
root logger and to drop the distinct RootLogger class completely.

Note that I have no strong opinion on all this. If you leave things as is
I'm fine with that.

Peter

 

[Jean-Michel Pichavant]

Vinay Sajip wrote:

Sorry I'm a little late to this discussion. I could add a _findCaller
function to the module (not part of the public API, but replaceable by
someone who really needs to) which does the heavy lifting, and
Logger.findCaller just calls it. Then those who need to can implement
their own strategy, without needing to jump through hoops. Does that
approach sound helpful?

[snip]

Note that I have no strong opinion on all this. If you leave things as is
I'm fine with that.

Peter

Agreed, I'm not sure it's worth the effort Vinay.

JM

 

[Vinay Sajip]

You mean you'd have to monkey-patchlogging._findCaller() instead of
overridinglogging.Logger.findCaller()?

I don't see a big advantage in that.

Only that you just have to replace a function, and not have to
subclass Logger + override findCaller. And it's not especially monkey-
patching if the function is put there specifically to be replaced when
needed

Another simplification might be to have setLoggerClass() implicitly set the
root logger and to drop the distinct RootLogger class completely.

I can't remember now why I created a separate class for the root - I
thought it might have some specialization which never happened. Of
course, I'm not sure if anyone is using it, so I can't just get rid of
it. Anyway, the root logger is in some sense special so it might be
more useful in the future.

Note that I have no strong opinion on all this. If you leave things as is
I'm fine with that.

Yes, it's hardly a common case that the OP is mentioning. AFAIK this
is the first time it's come up. I just thought from your and Jean-
Michel's solutions that there might be a need felt by more people to
have this functionality be more flexible.

Regards,

Vinay Sajip

 

[Hellmut Weber]

Hi Peter and Jean-Michel,
thanks for all your hints and pieces of code.

It took me a while to play around with what I got from you (and some
study of Vinay's module documentation.

Now I have come up with a more complete solution I'm quite satisfied
with. And I would be very glad to receive your comments on my code
indicating what I could do better, given that I'm still at the very
beginning with python.


Cheers + TIA

Hellmut


Here is my module and a corresponding test program:

leo@sylvester hw_logg $ cat loc_logg.py

#!/bin/env python

# -*- coding: utf-8 -*-

"""Hw's local logging module


To be done:
Factorize 'trace' decorator to own module
(to permit dependency on debug level) ???
"""

import sys # Basic system functions

import logging # Logging base
import logging.handlers

import inspect # monkey patch caller filename

# --- color change strings for terminal output ---
#
pc_yell = '\033[01;93m'
pc_purp = '\033[01;33m'
pc_gren = '\033[01;92m'
pc_blue = '\033[01;94m'
#
pc_bold = '\033[01;1m'
pc_norm = '\033[0m'
#
pc_reed = '\033[01;91m'
pc_cyan = '\033[01;96m'

level_color = {
'fatal': pc_yell,
'error': pc_yell,
'warning': pc_purp,
'info': pc_gren,
'debug': pc_blue,
'bold': pc_bold,
'normal': pc_norm
}

# --- define string building help function ---
#
def argskw_2_string(*args, **kwargs):
"""Generate String from *args and **kwargs

Return string with
*args list (comma separated) in first line
**kwargs key=val list (comma separated) in second line
"""
_str_lines = []

if args:
_args_strings = ''
for a in args:
_args_strings += str(a) + ', '
_str_lines.append(_args_strings)

if kwargs:
_kwargs_strings = ''
for k in kwargs:
_kwargs_strings += str(k)+' = '+str(kwargs[k]) + ', '
_str_lines.append(_kwargs_strings)
return ''.join(_str_lines)


# --- Class for all logging functionality ---
#
class locLogg():
_logger = None

def __init__(self, newlogg=None):
if not locLogg._logger:
locLogg._logger = newlogg

def init_logging(self,
loclogg_output='line', # stream or/and file
loclogg_fname='loggfile.txt',
loclogg_dblevel='DEBUG'
):
"""Initiate logging with locLogg._logger

Defines the logging handler to be used
and initiates it.

Possible values for loclogg_output:
line ==> output to console
file ==> log_file must be given
both ==> log_file must be given
null ==> no logging (NullHandler)
"""
locLogg._logger.handlers=[]
if loclogg_output in ('null'):
class NullHandler(logging.Handler):
def emit(self, record):
pass
locLogg._logger.addHandler(NullHandler())
if loclogg_output in ('line', 'both'):
locLogg._logger.addHandler(logging.StreamHandler())
if loclogg_output in ('file', 'both'):
locLogg._logger.addHandler(
logging.handlers.RotatingFileHandler(loclogg_fname,
maxBytes=200000, backupCount=5)
)
for _loc_logger in locLogg._logger.handlers:
_loc_logger.setFormatter(logging.Formatter(
'%(asctime)s ' + \
'%(custom_filename)s <%(custom_lineno)d>:' + \
'%(levelname)s %(message)s'))
# Can this be done better ?
_loc_levels = {'NOTSET': 0, 'DEBUG': 10,
'INFO': 20, 'WARNING': 30, 'ERROR': 40, 'CRITICAL': 50}
locLogg._logger.setLevel(_loc_levels[loclogg_dblevel])

def info_log(self, msg, *args, **kwargs):
previousFrame = inspect.currentframe().f_back
locLogg._logger.info(str(level_color['info'])+msg+pc_norm + \
' ' + argskw_2_string(*args, **kwargs),
extra={'custom_lineno': previousFrame.f_lineno,
'custom_filename': previousFrame.f_code.co_filename })

def debug_log(self, msg, *args, **kwargs):
previousFrame = inspect.currentframe().f_back
locLogg._logger.debug(str(level_color['debug'])+msg+pc_norm + \
' ' + argskw_2_string(*args, **kwargs),
extra={'custom_lineno'reviousFrame.f_lineno,
'custom_filename': previousFrame.f_code.co_filename })

def warn_log(self, msg, *args, **kwargs):
previousFrame = inspect.currentframe().f_back
locLogg._logger.debug(str(level_color['warning'])+msg+pc_norm + \
' ' + argskw_2_string(*args, **kwargs),
extra={'custom_lineno'reviousFrame.f_lineno,
'custom_filename': previousFrame.f_code.co_filename })

def error_log(self, msg, *args, **kwargs):
previousFrame = inspect.currentframe().f_back
locLogg._logger.error(str(level_color['error'])+msg+pc_norm + \
' ' + argskw_2_string(*args, **kwargs),
extra={'custom_lineno'reviousFrame.f_lineno,
'custom_filename': previousFrame.f_code.co_filename })

def fatal_log(self, msg, *args, **kwargs):
previousFrame = inspect.currentframe().f_back
locLogg._logger.fatal(str(level_color['fatal'])+msg+pc_norm + \
' ' + argskw_2_string(*args, **kwargs),
extra={'custom_lineno'reviousFrame.f_lineno,
'custom_filename': previousFrame.f_code.co_filename })

# --- Permit definition of a tracing decorator ---
from decorator import decorator

@decorator
def trace(f, *args, **kw):
print "@trace: calling %s with args %s, %s" % (f.func_name, args, kw)
return f(*args, **kw)
# cf. doc of Michele Simoniato's decorator module


if __name__ == '__main__':

_logger = logging.getLogger('jmp_logg__main__')
foo = locLogg(_logger)
foo.init_logging()

foo.info_log('a foo info')
foo.info_log('another bar info', 1,2,3, a=11, b=22, c=44)
foo.debug_log('a debug bar info', 'a', '1aA', qwe=2, asd=99)
foo.warn_log('a test info', 'ggg', '2U2', yxcv=2, asdf=99)

try:
b = 123
c = 0
a = b / c
except:
foo.fatal_log('Division by zero', b=123, c=0)

leo@sylvester hw_logg $ cat test_loclogg.py
#!/bin/env python
# -*- coding: utf-8 -*-

import logging
_logger = logging.getLogger()

import sys
pyDevelDir = '/home/leo/leo/brbeit/py-devel/Modules'
sys.path.append(pyDevelDir)

from hw_logg.loc_logg import locLogg
foo = locLogg(_logger)
foo.init_logging(
loclogg_output='both',
loclogg_dblevel='DEBUG')

import loc_module as jm

foo.info_log('First info with args in string: %d %d %d' % (1,2,3))
foo.warn_log('First warning')
foo.debug_log('First debug message TestTestTest', '----------', 4,5,6,
12*25, d=34, e='qwe')

foo.debug_log('Before calling jm.doIt()')
jm.doIt(True)

foo.info_log('Second info with kwargs separate:', a=11,b=22,c=33)

x = jm.MyClass(1, 2, 'abc')
x.mymethod()
x.mymethod(123, 234, a=1, b=2, c=3)

try:
jm.doIt(0)
except Exception, e:
foo.error_log(str(e), 1,5,8)
foo.fatal_log('Fatal message')

leo@sylvester hw_logg $ cat loc_module.py
# -*- coding: utf-8 -*-

import logging
_logger = logging.getLogger('jmp_logger')

import sys
pyDevelDir = '/home/leo/leo/brbeit/py-devel/Modules'
sys.path.append(pyDevelDir)

from hw_logg.loc_logg import locLogg, trace
foo = locLogg(_logger)

foo.info_log("Start importing "+__name__)

def doIt(yn=None):
foo.debug_log("doin' stuff, yn =", str(yn)) # logLevel at calling
point !
print '=====> Output from doIt:', yn
#do stuff...but suppose an error occurs?
if yn:
foo.info_log('yn: good value')
else:
raise TypeError, "bogus type error for testing"

class MyClass(object):
@trace
def __init__(self, *args, **kwargs):
print 'MyClass.__init__'
@trace
def mymethod(self, *args, **kwargs):
print 'MyClass.mymethod'

foo.info_log("End importing "+__name__)

 

[Peter Otten]

Hi Peter and Jean-Michel,
thanks for all your hints and pieces of code.

It took me a while to play around with what I got from you (and some
study of Vinay's module documentation.

Now I have come up with a more complete solution I'm quite satisfied
with. And I would be very glad to receive your comments on my code
indicating what I could do better, given that I'm still at the very
beginning with python.

Here is my module and a corresponding test program:

# --- color change strings for terminal output ---
#
pc_yell = '\033[01;93m'
pc_purp = '\033[01;33m'
pc_gren = '\033[01;92m'

Hw lng wld psts + prgrms b wr it nt 4 z art of clvr + ez 2 mmrz
abbreviations

# --- Class for all logging functionality ---
#
class locLogg():
_logger = None

def debug_log(self, msg, *args, **kwargs):
def warn_log(self, msg, *args, **kwargs):
def error_log(self, msg, *args, **kwargs):

It should be easy to factor out most the code in your xxx_log() methods into
a common helper.

def fatal_log(self, msg, *args, **kwargs):
previousFrame = inspect.currentframe().f_back
locLogg._logger.fatal(str(level_color['fatal'])+msg+pc_norm + \
' ' + argskw_2_string(*args, **kwargs),
extra={'custom_lineno'reviousFrame.f_lineno,
'custom_filename': previousFrame.f_code.co_filename })

I think the formatting belongs into another layer. That's the purpose of the
logging.Formatter class. You could enhance it along those lines:

class Formatter(logging.Formatter):
markers = {
logging.INFO: ("<info>", "</info>"),
logging.WARN: ("<warn>", "</warn>"),
}
def format(self, record):
message = logging.Formatter.format(self, record)
try:
prefix, suffix = self.markers[record.levelno]
except KeyError:
pass
else:
message = prefix + message + suffix
return message

My general impression is that you are fighting the logging library's
structure rather than trying to use it as effectively as possible.

foo.info_log('another bar info', 1,2,3, a=11, b=22, c=44)

You could achieve something similar with a standard logger by passing your
extra information through the extra parameter, e. g:

def extra(*args, **kw):
return dict(argskw=(args, kw))
foo.info("another...", extra=extra(1, 2, 3, a=11, b=22))

Peter