python twisted: récupérer un temps d'exécution différé

Question

Je voudrais savoir combien de temps un différé prend pour s'exécuter, à partir du moment où le premier rappel est déclenché au résultat final.

Des idées sur la façon de le faire, éventuellement de manière non-invasive (c'est-à-dire sans modification des fonctions de rappel afin de suivre le temps d'exécution)?

Answer 1

Si vous exécutez votre programme avec l'aide de "twistd", alors il a une option "--profile" qui peut vous aider à profiler le code tordu.

twistd "other options" --profile=statsfile --profiler=cProfile --savestats 

Et pour voir les statistiques:

import pstats 
stats = pstats.Stats('statsfile') 
stats.sort_stats('time').print_stats() 

sont exécutés immédiatement Callbacks après les deferreds sont tirés. Mais cela signifie immédiatement que chaque rappel dans la chaîne différée doit être exécuté et qu'ils auront leur propre temps d'exécution. De plus, divers morceaux de code auront leur propre tranche de temps pour l'exécution, y compris la boucle du réacteur. Donc, pour dire le mot - immédiatement, c'est dire le plus tôt possible.

Prenons l'exemple mauvais suivant:

from twisted.internet import reactor, defer 
import time 

def timeit(func): 
    def wrapper(*arg): 
     t1 = time.time() 
     res = func(*arg) 
     t2 = time.time() 
     print '%s took %0.3f ms' % (func.func_name, (t2-t1)*1000.0) 
     return res 
    return wrapper 

d = defer.Deferred() 

@timeit 
def callfunc1(result): 
    print 'XXXXX' 

@timeit 
def callfunc2(result): 
    print 'YYYYY' 

d.addCallback(callfunc1) 
d.addCallback(callfunc2) 
t1 = time.time() 
d.callback(True) 
t2 = time.time() 
print '%0.3f ms' % ((t2-t1)*1000.0) 

Sortie:

XXXXX 
callfunc1 took 0.039 ms 
YYYYY 
callfunc2 took 0.005 ms 
0.108 ms 

Maintenant, si nous modifions le code ci-dessus pour inclure un réacteur et callLater

Answer 2

Le profilage est un peu exagéré pour ce J'aimerais réussir.

J'ai fini avec une solution qui n'implique de lourdes modifications sur le code existant, mais est en aucune façon "universelle":

mon code d'origine était quelque chose comme:

def myfunc(*args): 
    d = Deferred() 
    d.addCallback(cb1) 
    ... 
    d.addCallback(lambda x: MyObject(x)) 

I maintenant ont:

def myfunc(*args): 
    init_time = time.time() 
    d = Deferred() 
    d.addCallback(cb1) 
    ... 
    d.addCallback(lambda x: MyObject(x, init_time)) 

class MyObject: 
    def __init__(self, *args): 
     ... 
     self.exec_time = time.time() - init_time 

Il fait exactement ce que je veux, mais j'espérais la structure différée exposerait la piste de quelque chose de tenue du temps d'exécution lui-même, au lieu d'avoir à bricoler avec mes objets. À partir du code source, je ne vois pas une telle chose est disponible: http://twistedmatrix.com/trac/browser/tags/releases/twisted-10.0.0/twisted/internet/defer.py#L137

Answer 3

Devinez vous devez profiler votre application, suivez la façon suivante:

installer cet outil http://kcachegrind.sourceforge.net/html/Home.html

feu votre application tordue et de recueillir des données brutes :

twistd --savestats -n --profile = myapp.hotshot monapp

que, vous convertissez 'hotshot' en 'calltree', exécutez:

hotshot2cg myapp.hotshot> myapp.calltree

maintenant nous pouvons voir calltree dans l'outil Kcachegrind.

kcachegrind myapp.calltree

avec cet outil, vous pouvez voir l'appel graphique de boucle d'événements torsadée, temps d'exécution, vous pouvez voir en pourcents. donc pas besoin de patcher le code, il suffit de lancer cet outil et de voir

P.S. pour vérifier la mémoire: How to use guppy/heapy for tracking down memory usage