The `autologging` API¶

Release:	0.4.0

autologging.TRACE = 1¶: A custom tracing log level, lower in severity than logging.DEBUG. Autologging’s traced() and TracedMethods() create log records with this custom level.

autologging.logged(obj)[source]¶

Add a logger member to a decorated class or function.

Parameters:	obj – the class or function object being decorated, or an optional `logging.Logger` object to be used as the parent logger (instead of the default module-named logger)
Returns:	obj if obj is a class or function; otherwise, if obj is a logger, returns a lambda decorator that will in turn set the logger attribute and return obj

If obj is a class, then obj.__logger will have the logger name “module-name.class-name”:

>>> import sys
>>> logging.basicConfig(
...     level=logging.DEBUG, stream=sys.stdout,
...     format="%(levelname)s:%(name)s:%(funcName)s:%(message)s")
>>> @logged
... class Sample:
... 
...     def test(self):
...         self.__logger.debug("This is a test.")
... 
>>> Sample().test()
DEBUG:autologging.Sample:test:This is a test.

Note

Autologging will prefer to use the class’s __qualname__ when it is available (Python 3.3+). Otherwise, the class’s __name__ is used. For example:

class Outer:

   @logged
   class Nested: pass

Under Python 3.3+, Nested.__logger will have the name “autologging.Outer.Nested”, while under Python 2.7 or 3.2, the logger name will be “autologging.Nested”.

Changed in version 0.4.0: Functions decorated with @logged now use a single underscore in the logger variable name (e.g. my_function._logger) rather than a double underscore.

If obj is a function, then obj._logger will have the logger name “module-name”:

>>> import sys
>>> logging.basicConfig(
...     level=logging.DEBUG, stream=sys.stdout,
...     format="%(levelname)s:%(name)s:%(funcName)s:%(message)s")
>>> @logged
... def test():
...     test._logger.debug("This is a test.")
... 
>>> test()
DEBUG:autologging:test:This is a test.

Note

Within a logged function, the _logger attribute must be qualified by the function name.

In the example above, note the call to test._logger.debug.

If obj is a logging.Logger object, then that logger is used as the parent logger (instead of the default module-named logger):

>>> import sys
>>> logging.basicConfig(
...     level=logging.DEBUG, stream=sys.stdout,
...     format="%(levelname)s:%(name)s:%(funcName)s:%(message)s")
>>> _logger = logging.getLogger("test.parent")
>>> @logged(_logger)
... class Sample:
... 
...     def test(self):
...         self.__logger.debug("This is a test.")
... 
>>> Sample().test()
DEBUG:test.parent.Sample:test:This is a test.

Again, functions are similar:

>>> import sys
>>> logging.basicConfig(
...     level=logging.DEBUG, stream=sys.stdout,
...     format="%(levelname)s:%(name)s:%(funcName)s:%(message)s")
>>> _logger = logging.getLogger("test.parent")
>>> @logged(_logger)
... def test():
...     test._logger.debug("This is a test.")
... 
>>> test()
DEBUG:test.parent:test:This is a test.

Note

For classes, the logger member is made “private” (i.e. __logger with double underscore) to ensure that log messages that include the %(name)s format placeholder are written with the correct name.

Consider a subclass of a @logged-decorated parent class. If the subclass were not decorated with @logged and could access the parent’s logger member directly to make logging calls, those log messages would display the name of the parent class, not the subclass.

Therefore, subclasses of a @logged-decorated parent class that wish to use a provided self.__logger object must themselves be decorated with @logged.

Warning

Although the @logged and @traced decorators will “do the right thing” regardless of the order in which they are applied to the same function, it is recommended that @logged always be used as the innermost decorator:

@traced
@logged
def my_function():
    my_function._logger.info("message")

This is because @logged simply sets the _logger attribute and then returns the original function, making it “safe” to use in combination with any other decorator.

autologging.traced(obj)[source]¶

Add call and return tracing to an unbound function.

Parameters:	obj – the function object being decorated, or an optional `logging.Logger` object to be used as the parent logger (instead of the default module-named logger)
Returns:	if obj is a function, returns a proxy function that wraps obj to provide the call and return tracing; otherwise, if obj is a logger, returns another function decorator that creates and returns the tracing proxy function

Note

The original (proxied) function is available as the __wrapped__ attribute of the returned proxy function. For example:

>>> import sys
>>> logging.basicConfig(
...     level=TRACE, stream=sys.stdout,
...     format="%(levelname)s:%(name)s:%(funcName)s:%(message)s")
>>> @traced
... def my_function(arg):
...     return arg.upper()
... 
>>> my_function.__wrapped__("test")
'TEST'

(Note that the tracing log records were not written because the original, non-traced function was called.)

Warning

This decorator will not quite work as expected (or may fail entirely) for class methods. To automatically trace class method call/return, please see the TracedMethods metaclass factory.

In the following example, tracing log messages are written to a log whose name defaults to the function’s module name:

>>> import sys
>>> logging.basicConfig(
...     level=TRACE, stream=sys.stdout,
...     format="%(levelname)s:%(name)s:%(funcName)s:%(message)s")
>>> @traced
... def my_function(arg, keyword=None):
...     return "%s and %s" % (arg, keyword)
... 
>>> my_function("spam", keyword="eggs")
TRACE:autologging:my_function:CALL *('spam',) **{'keyword': 'eggs'}
TRACE:autologging:my_function:RETURN 'spam and eggs'
'spam and eggs'

In the following example, tracing log messages are written to a user-named log:

>>> import sys
>>> logging.basicConfig(
...     level=TRACE, stream=sys.stdout,
...     format="%(levelname)s:%(name)s:%(funcName)s:%(message)s")
>>> _logger = logging.getLogger("test.ing")
>>> @traced(_logger)
... def my_function(arg, keyword=None):
...     return "%s and %s" % (arg, keyword)
... 
>>> my_function("spam", keyword="eggs")
TRACE:test.ing:my_function:CALL *('spam',) **{'keyword': 'eggs'}
TRACE:test.ing:my_function:RETURN 'spam and eggs'
'spam and eggs'

Warning

Although the @traced and @logged decorators will “do the right thing” regardless of the order in which they are applied to the same function, it is recommended that @logged always be used as the innermost decorator:

@traced
@logged
def my_function():
    my_function._logger.info("message")

This is because @logged simply sets the _logger attribute and then returns the original function, making it “safe” to use in combination with any other decorator.

autologging.TracedMethods(*args, **options)[source]¶

Return a metaclass that provides call and return tracing for a class’s methods.

The contents of args and options determine which methods will be traced, and which logger will be used for tracing messages:

TracedMethods()

In the simplest configuration, all “public”, “_nonpublic”, and “__private” methods that are defined in the class body (as well as the special __init__ method, if defined) will be traced. The class __dict__ will be inspected to identify these methods and replace them with tracing proxy methods. (Inherited methods are never traced. See the note below.) Tracing messages will be logged to the “module-name.class-name” logger at the autologging.TRACE level.

Example:

>>> import sys
>>> logging.basicConfig(
...     level=TRACE, stream=sys.stdout,
...     format="%(levelname)s:%(name)s:%(funcName)s:%(message)s")
>>> class Sample(metaclass=TracedMethods()):
...     @staticmethod
...     def static_method():
...         return "STATIC"
...     @classmethod
...     def class_method(cls):
...         return "CLASS"
...     def __init__(self):
...         self.public = "PUBLIC"
...     def method(self, arg, kw=None):
...         return "%s%s" % (self.public if kw is None else kw,
...                          arg)
...     def _nonpublic(self):
...         return "NON_PUBLIC"
...     def __private(self):
...         return "PRIVATE"
...     def __eq__(self, other):
...         return False
... 
>>> Sample.static_method()
TRACE:autologging.Sample:static_method:CALL *() **{}
TRACE:autologging.Sample:static_method:RETURN 'STATIC'
'STATIC'
>>> Sample.class_method()
TRACE:autologging.Sample:class_method:CALL *() **{}
TRACE:autologging.Sample:class_method:RETURN 'CLASS'
'CLASS'
>>> sample = Sample()
TRACE:autologging.Sample:__init__:CALL *() **{}
TRACE:autologging.Sample:__init__:RETURN None
>>> sample.method(1)
TRACE:autologging.Sample:method:CALL *(1,) **{}
TRACE:autologging.Sample:method:RETURN 'PUBLIC1'
'PUBLIC1'
>>> sample.method(2, kw="METHOD")
TRACE:autologging.Sample:method:CALL *(2,) **{'kw': 'METHOD'}
TRACE:autologging.Sample:method:RETURN 'METHOD2'
'METHOD2'
>>> sample._nonpublic()
TRACE:autologging.Sample:_nonpublic:CALL *() **{}
TRACE:autologging.Sample:_nonpublic:RETURN 'NON_PUBLIC'
'NON_PUBLIC'
>>> sample._Sample__private()
TRACE:autologging.Sample:__private:CALL *() **{}
TRACE:autologging.Sample:__private:RETURN 'PRIVATE'
'PRIVATE'
>>> sample == 79  # calls __eq__ (not traced by default)
False

TracedMethods(logger)

In this configuration, args[0] is a logging.Logger object. This configuration is identical to TracedMethods(), except that tracing messages will be logged to the “logger-name.class-name” logger.

Example:

>>> import sys
>>> logging.basicConfig(
...     level=TRACE, stream=sys.stdout,
...     format="%(levelname)s:%(name)s:%(funcName)s:%(message)s")
>>> _logger = logging.getLogger("my.named.logger")
>>> class Sample(metaclass=TracedMethods(_logger)):
...     def method(self):
...         return "METHOD"
... 
>>> sample = Sample()  # inherited __init__ is not traced
>>> sample.method()
TRACE:my.named.logger.Sample:method:CALL *() **{}
TRACE:my.named.logger.Sample:method:RETURN 'METHOD'
'METHOD'

TracedMethods(“method_1”, ... , “method_N”)

In this configuration, only the explicitly-named methods will be traced.

Example:

>>> import sys
>>> logging.basicConfig(
...     level=TRACE, stream=sys.stdout,
...     format="%(levelname)s:%(name)s:%(funcName)s:%(message)s")
>>> class Sample(metaclass=TracedMethods("test", "_calc")):
...     def __init__(self, multiplicand):
...         self._multiplicand = multiplicand
...     def test(self, multiplier):
...         return "%.2f" % self._calc(abs(multiplier))
...     def _calc(self, multiplier):
...         return multiplier * self._multiplicand
... 
>>> sample = Sample(7)  # __init__ is not named, so not traced
>>> sample.test(-9)
TRACE:autologging.Sample:test:CALL *(-9,) **{}
TRACE:autologging.Sample:_calc:CALL *(9,) **{}
TRACE:autologging.Sample:_calc:RETURN 63
TRACE:autologging.Sample:test:RETURN '63.00'
'63.00'

TracedMethods(logger, “method_1”, ... , “method_N”)

This configuration is identical to TracedMethods("method_1", ... , "method_N"), except that tracing messages will be logged to the “logger-name.class-name” logger.

Example:

>>> import sys
>>> logging.basicConfig(
...     level=TRACE, stream=sys.stdout,
...     format="%(levelname)s:%(name)s:%(funcName)s:%(message)s")
>>> _logger = logging.getLogger("my.named.logger")
>>> class Sample(
...         metaclass=TracedMethods(_logger, "test", "_calc")):
...     def __init__(self, multiplicand):
...         self._multiplicand = multiplicand
...     def test(self, multiplier):
...         return "%.2f" % self._calc(abs(multiplier))
...     def _calc(self, multiplier):
...         return multiplier * self._multiplicand
... 
>>> sample = Sample(7)  # __init__ is not named, so not traced
>>> sample.test(-9)
TRACE:my.named.logger.Sample:test:CALL *(-9,) **{}
TRACE:my.named.logger.Sample:_calc:CALL *(9,) **{}
TRACE:my.named.logger.Sample:_calc:RETURN 63
TRACE:my.named.logger.Sample:test:RETURN '63.00'
'63.00'

TracedMethods(trace_special_methods=True)

This configuration is identical to TracedMethods(), except that “__special__” methods (e.g. __eq__, __iter__, etc.) will also be traced.

Example:

>>> import sys
>>> logging.basicConfig(
...     level=TRACE, stream=sys.stdout,
...     format="%(levelname)s:%(name)s:%(funcName)s:%(message)s")
>>> class Sample(
...         metaclass=TracedMethods(trace_special_methods=True)):
...     def method(self):
...         return "METHOD"
...     def __eq__(self, other):
...         return False
... 
>>> sample = Sample()  # inherited __init__ is not traced
>>> sample.method()
TRACE:autologging.Sample:method:CALL *() **{}
TRACE:autologging.Sample:method:RETURN 'METHOD'
'METHOD'
>>> sample == 79  # calls __eq__
TRACE:autologging.Sample:__eq__:CALL *(79,) **{}
TRACE:autologging.Sample:__eq__:RETURN False
False

Note

The trace_special_methods option is ignored when methods are named explicitly in args.

TracedMethods(logger, trace_special_methods=True)

This configuration is identical to TracedMethods(trace_special_methods=True), except that tracing messages are logged to the “logger-name.class-name” logger.

Example:

>>> import sys
>>> logging.basicConfig(
...     level=TRACE, stream=sys.stdout,
...     format="%(levelname)s:%(name)s:%(funcName)s:%(message)s")
>>> _logger = logging.getLogger("my.named.logger")
>>> class Sample(
...         metaclass=TracedMethods(_logger,
...                                 trace_special_methods=True)):
...     def method(self):
...         return "METHOD"
...     def __eq__(self, other):
...         return False
... 
>>> sample = Sample()  # inherited __init__ is not traced
>>> sample.method()
TRACE:my.named.logger.Sample:method:CALL *() **{}
TRACE:my.named.logger.Sample:method:RETURN 'METHOD'
'METHOD'
>>> sample == 79  # calls __eq__
TRACE:my.named.logger.Sample:__eq__:CALL *(79,) **{}
TRACE:my.named.logger.Sample:__eq__:RETURN False
False

Warning

Inherited methods are never traced, even if they are named explicitly in args.

If you wish to trace a method from a super class, you have two options:

Use TracedMethods in the super class.

Override the method in the subclass and trace it there. For example:

class SubClass(SuperClass,
               metaclass=TracedMethods("method_name")):
    ...
    def method_name(self):
        return super().method_name()
    ...

Warning

When method names are specified explicitly via args, Autologging ensures that each method is actually defined in the body of the class being traced.

If a defintion for any named method is not found in the class body, either because the method is inherited or because the name is misspelled, Autologging will issue a UserWarning.

Note

Regardless of whether a logger was explicitly passed in or not, the logger used by tracing methods is not available to the class or its instances.

Note

A class may be decorated by logged() and use TracedMethods as a metaclass without conflict.

The autologging API¶

The `autologging` API¶