How does autologging
work?¶
Release: | 1.3.2 |
---|
The autologging.logged
decorator is rather boring - it simply
creates a logging.Logger
object and sets it as an attribute
of the decorated class (or function).
However, in order to automate tracing while preserving introspection
and subclassing capabilities, the autologging.traced
decorator
has a tougher job.
To trace the call and return of a particular function, Autologging performs the following steps:
- Intercept the function call, capturing all positional and keyword arguments that were passed.
- Log the call at the
autologging.TRACE
log level. - Call the original function, passing the positional and keyword arguments, and capturing the return value.
- Log the return at the
autologging.TRACE
log level. - Return the value.
Autologging installs a replacement function for any traced class method or function. That replacement function is responsible for the steps described above.
Additionally, if a traced function/method is a generator function,
Autologging wraps the returned generator iterator in a “proxy”
generator iterator that intercepts and logs (at autologging.TRACE
level) yielded values, StopIteration
, and any calls to the generator
iterator’s send()
, throw()
or close()
methods.
Note
If the TRACE
level is disabled for the tracing logger when a
traced function is called, the replacement function delegates
directly to the original function.
One important consquence is that a generator function’s returned generator iterator will not be proxied in this case.
Which functions are traced?
A quick way to determine which functions have been traced is to look for
the __autologging_traced__
attribute. Autologging sets this
attribute to the value True
on every replacement function. For
example:
>>> from autologging import traced
>>> @traced
... def example():
... return "OK"
...
>>> hasattr(example, "__autologging_traced__")
True
>>> @traced
... class Example:
... @classmethod
... def class_method(cls):
... return "OK"
... @staticmethod
... def static_method():
... return "OK"
... def method(self):
... return "OK"
...
>>> hasattr(Example.class_method, "__autologging_traced__")
True
>>> hasattr(Example.static_method, "__autologging_traced__")
True
>>> hasattr(Example.method, "__autologging_traced__")
True
Introspecting traced functions
When Autologging installs a replacement function for tracing, a
reference to the original function is stored as the __wrapped__
attribute of the replacement function.
>>> from autologging import traced
>>> def example():
... return "OK"
...
>>> traced(example).__wrapped__ is example
True
>>> from autologging import traced
>>> class Example:
... def method(self):
... return "OK"
...
>>> original_method = Example.__dict__["method"]
>>> traced(Example).__dict__["method"].__wrapped__ is original_method
True
Traced classmethod
and staticmethod
functions are also
replaced by Autologging, but in addition to creating a replacement
function, Autologging also creates a replacement method descriptor. To
access the original function of a classmethod or staticmethod, you must
use the __wrapped__
attribute of the __func__ attribute of the
replacement classmethod or staticmethod. An example makes this clear:
>>> from autologging import traced
>>> class Example:
... @classmethod
... def class_method(cls):
... return "OK"
... @staticmethod
... def static_method():
... return "OK"
...
>>> original_classmethod = Example.__dict__["class_method"]
>>> original_staticmethod = Example.__dict__["static_method"]
>>> Example = traced(Example)
>>> Example.__dict__["class_method"].__func__.__wrapped__ is original_classmethod.__func__
True
>>> Example.__dict__["static_method"].__func__.__wrapped__ is original_staticmethod.__func__
True
Inheritance and subclassing with traced methods
Autologging is careful to not “break” assumptions about the types of methods, or how those methods are inherited or overridden.
A replacement tracing method (or method descriptor, in the case of classmethods and staticmethods) has the same type, name and signature as the original method:
>>> import inspect
>>> from types import FunctionType, MethodType
>>> from autologging import traced
>>> @traced
... class Example:
... @classmethod
... def class_method(cls, arg, keyword=None):
... return "OK"
... @staticmethod
... def static_method(arg, keyword=None):
... return "OK"
... def method(self, arg, keyword=None):
... return "OK"
...
>>> type(Example.__dict__["class_method"]) is classmethod
True
>>> Example.class_method.__name__
'class_method'
>>> inspect.signature(Example.class_method)
<Signature (arg, keyword=None)>
>>> type(Example.__dict__["static_method"]) is staticmethod
True
>>> Example.static_method.__name__
'static_method'
>>> inspect.signature(Example.static_method)
<Signature (arg, keyword=None)>
>>> type(Example.__dict__["method"]) is FunctionType
True
>>> type(Example().method) is MethodType
True
>>> Example.method.__name__
'method'
>>> inspect.signature(Example().method)
<Signature (arg, keyword=None)>