Profiler une fonction facilement

Lorsque l'on cherche à optimiser son code, on a souvent besoin de
trouver quels blocs d'instructions posent problème. Le plus souvent, on
va chercher à trouver les morceaux de code qui prennent le plus de temps
à s'executer. Voyons quelles solutions s'offrent à nous.

Dans un premier temps, et de manière tout à fait intuitive, on peut
printer des time{.sourceCode} avant et après le bloc d'instruction à
bencher :

import time

t = time.time()
# mes instructions ...
print time.time() - t

On aura le résultat en secondes. Ca peut suffire, mais pas toujours.
Lorsque les instructions font appel à des méthodes de bibliothèques
tierces, on ne va pas s'amuser à mettre des print dans les sources de
là-dite bibliothèque. Il existe un profileur dans la lib standart de
python qui est bien pratique, j'ai nommé
cProfile. Attention
cependant, il va au bout des choses. Si votre fonction est grosse, cela
risque de devenir vite illisible.

L'utilisation est relativement simple. Essentiellement 2 cas de figures
:

• Soit vous voulez un benchmark d'une fonction de la lib standart et
  vous utilisez cProfile.runc("<mon appel>"){.sourceCode}
• Soit vous voulez un benchmark d'un truc bien à vous :
  cProfile.runctx("<mon appel>", None, locals()){.sourceCode}

Si la seconde solution vous revient en pleine face avec une
NameError{.sourceCode}, remplacez None{.sourceCode} par
globals(){.sourceCode}. Attention cependant, le dict
globals(){.sourceCode} est très consistant.

Du coup on aurait par exemple ça :

import cProfile

def my_func(arg1, arg2):
    print(arg1, arg2)

cProfile.runctx("my_func('Mulder', 'Scully')", None, locals()
# ou, si locals() est pas suffisant,
# cProfile.runctx("my_func('Mulder', 'Scully')", globals(), locals())
Mulder Scully
         5 function calls in 0.000 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.000    0.000 <stdin>:1(my_func)
        1    0.000    0.000    0.000    0.000 <string>:1(<module>)
        1    0.000    0.000    0.000    0.000 {built-in method exec}
        1    0.000    0.000    0.000    0.000 {built-in method print}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

Ici on vois que notre fonction prend un temps tellement négligeable que
cProfile le considère comme nul.

Ce qui est surtout intéressant de noter, c'est que cProfile affiche le
temps d'exécution, ainsi que le nombre d'exécutions des fonctions
built-in appelées. C'est ça qui nous intéresse lorsque l'on veut un
benchmark d'une fonction à nous utilisant une bibliothèque tierce.

Bon, ça, c'était pour l'utilisation dans un shell Python. Vous pouvez
aussi l'utiliser dans vos sources, mais ça va vite devenir pénible si
votre fonction prend pléthore d'arguments. Du coup, voilà un petit
décorateur pour vous faciliter le profilage.

import cProfile

def profiler(sort=-1, use_globals=False, use_locals=True):
    def decr(func):
        def wrp(*args, **kwargs):
            g = globals() if use_globals else None
            l = locals() if use_locals else None
            cProfile.runctx("func(*args, **kwargs)", g, l, sort=sort)
            return func(*args, **kwargs)
        return wrp
    return decr

Rien de bien magique ici, il est sous la forme d'un générateur de
décorateur, pour pouvoir lui passer l'index par lequel cProfile va trier
les résultats. Si vous voulez en savoir plus sur les décorateurs, un
petit tour sur le formidable article de
Sam&Max
vous fera le plus grand bien !

À vous de jouer !