Pelicanux

Just A Few Random Words

Python Decorators

The more I learn about python programming language, the more I like it. As a developper, I like its straightforward and sparse syntax, its philosophy made of simple statments (try import this on python cli), leading to product easy-to-read code. As a Sysadmin, I never had to care much about the installation processes, as most of python packages are available on the debian or redhat packaging system, and the standard library is really substancial. Most applications may be executed with python 2.7, and differences between versions remain minor (except maybe for the transition between python2.7 and python3).

The feature of the day is named decorators. I will not explain deep into the details how they work, as the is a lot of documentation about it (another plus of python, its documentation is amazing). I am just providing some scripts which may be useful, as a reminder or for someone else. Most of them are inspired from here.

As a timer

Simple case

It may be useful to determine how long each functions take to execute its tasks. Here is how to do so:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20

import time
from random import randint

def time_exec(f):

  def wrapper(*args):
      t = time.time()
      r = f(*args)
      print str(time.time() - t),f.func_name
      return r
  return wrapper

@time_exec
def long_function(n):

  for i in range(0,n):
      time.sleep(randint(1,n))

if __name__ == '__main__':
  long_function(int(sys.argv[1]))

Whether the decorator itself gets some arguments or not

We prefer if the execution time printing occurs only when debugging.

In other words, having a condition to trigger the timer process.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19

def time_exec_args(mode = 'debug'):

  def time_exec(f):

      def wrapper(*args):
          if mode == 'debug':
              t = time.time()
              r = f(*args)
              print str(time.time() -t),f.func_name
              return r
          else:
              return f
      return wrapper
  
  return time_exec

@time_exec_args('debug')
def long_function(n):
      ...

Finally I do want to keep track of my function property

Let’s say I want to provide some documentation around my long_function().

1
2
3
4
5
6
7

@time_exec_args('debug')
def long_function(n):
  """ Mine is better """

print long_function.doc

-> None

I need to modify my decorator to make use of the functools library:

1
2
3
4
5
6
7

from functools import wraps

def time_exec(f):
  @wraps
  def wrapper(*args):
      t = time.time()
      r = f(*args)

As a logging process

Ok, I like print command for debugging purpose. Everyone does this I guess. But, when it comes to production, I prefer printing into log files instead.

Here is a simple way to redirect stdout to a logging object when a production variable is triggered:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41

lf = 'decorator.log'
MODE = 'PROD'

class LogPrinter:

  def __init__(self, logfile):
      self.mylogger = logging.getLogger('my_process')
      mylogger = self.mylogger
      logging.basicConfig(filename=logfile)
      mylogger.setLevel(logging.INFO)

  def write(self, msg):
      self.mylogger.info(msg)

def logprinter(logfile):

  def lprinter(f):
      def wrapper(*args):
          if MODE == 'PROD':
              stdbak = sys.stdout
              log = LogPrinter(logfile)
              sys.stdout = log
              try:
                  return f(*args)
              finally:
                  stdout = stdbak
          else:
              return f(*args)
      return wrapper
  return lprinter

@logprinter(lf)
def long_time(t):

  sys.stdout.write('entering')
  for i in range(1,t):
      time.sleep(1)
  sys.stdout.write('exiting')

if __name__ == '__main__':
  long_time(int(sys.argv[1]))

I used sys.stdout.write instead of print which has the habit to add extra \n while printing.

Every print, stdout.write, and other craps spitting on stdout will be logged instead.

How many time my function is getting called?

Let’s continue in the spirit of the timer decorator.

Function calls counter

This time, I want to know how many times my function is getting called.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19

def counter(f):

  def wrapper(*args):
      wrapper.count = wrapper.count+1
      print 'function has been called ',str(wrapper.count),' times'
      return f(*args)

  wrapper.count = 0
  return wrapper

if __name__ == '__main__':
  long_function()
  long_function()
  long_function()

>>> function has been called 1 times
>>> function has been called 2 times
>>> function has been called 3 times

Average execution time

Let’s go further!

This let us compute the average execution time of my function:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15

def average(f):

  @wraps(f)
  def wraper(*args):
      wraper.count = wraper.count + 1
      t = time.time()
      r = f(*args)
      wraper.total_time = wraper.total_time + time.time() - t
      if wraper.count == 0:
          print 'ZERO'
      else:
          print 'Average execution time:',str(wraper.total_time / wraper.count)
      return r
  wraper.count = wraper.total_time = 0
  return wraper

This is all for this time! But I still haven’t covered many decorators aspects, such as caching decorators, thread synchronization or timeout decorators.

To be continued, then…