logging: add a decorator to log timing of functions or methods

Use it like that:

	from entrouvert.logging.decorators import timing

	@timing(0, 1, logger='timing')
	def method(arg0, arg1):
		etc...
		return arg0

	It will output lines to the logger named 'timing' at the DEBUG level::

		DEBUG module.method args: [arg0,arg1] entry: 23232.23232323
		DEBUG module.method args: [arg0,arg1] exit: 232334.23232323 duration: 232.2323
This commit is contained in:
Benjamin Dauvergne 2013-05-30 10:21:45 +02:00
parent 7b0a8d292e
commit 85fba042d1
1 changed files with 41 additions and 0 deletions

View File

@ -0,0 +1,41 @@
import logging
import time
from functools import wraps
__all__ = [ 'timing' ]
class TimingDecorator(object):
def __init__(self, *args_to_report, **kwargs):
if kwargs.get('logger'):
self.logger = logging.getLogger(kwargs.get('logger'))
else:
self.logger = logging.getLogger(__name__)
self.args_to_report = args_to_report
def __call__(self, func):
if hasattr(func, '__module__'): # functions
name = '{0}.{1}'.format(func.__name__, func.__module__)
else: # methods
name = '{0}.{1}.{2}'.format(func.__name__,
func.__objclass__.__name__, func.__objclass__.__module__)
@wraps(func)
def f(*args, **kwargs):
print 'coin'
a = []
for i in self.args_to_report:
a.append(args[i])
a = unicode(a)
entry = time.time()
self.logger.debug('%(name)s args: %(args)s entry: %(entry)s', dict(
name=name, args=a, entry=entry))
try:
result = func(*args, **kwargs)
finally:
exit = time.time()
duration = exit - entry
self.logger.debug('%(name)s args: %(args)s exit: %(exit)s duration: %(duration)s', dict(
name=name, args=a, exit=exit, duration=duration))
return result
return f
timing = TimingDecorator