Use cProfile. Hook into doIteration. Track utime.

This commit is contained in:
Erik Johnston 2015-05-29 10:37:41 +01:00
parent 06c4124f8e
commit c7fcb53b92

View file

@ -519,36 +519,40 @@ def run(hs):
PROFILE_SYNAPSE = True PROFILE_SYNAPSE = True
if PROFILE_SYNAPSE: if PROFILE_SYNAPSE:
def profile(func): def profile(func):
from pyinstrument import Profiler from cProfile import Profile
from threading import current_thread from threading import current_thread
import time import time
import resource
def profiled(*args, **kargs): def profiled(*args, **kargs):
profile = Profiler() profile = Profile()
rusage = resource.getrusage(resource.RUSAGE_SELF)
start_utime = rusage.ru_utime * 1000
start = int(time.time()*1000) start = int(time.time()*1000)
profile.start() profile.enable()
func(*args, **kargs) func(*args, **kargs)
profile.stop() profile.disable()
end = int(time.time()*1000) end = int(time.time()*1000)
rusage = resource.getrusage(resource.RUSAGE_SELF)
end_utime = rusage.ru_utime * 1000
if end - start > 100: if end_utime - start_utime > 50:
ident = current_thread().ident ident = current_thread().ident
name = "/tmp/%s.%s.%i.%d-%d.%d" % ( name = "/tmp/%s.%s.%i.%d-%d.%d-%d.pstat" % (
hs.hostname, func.__name__, ident, start, end, end-start hs.hostname, func.__name__, ident, start, end,
end-start, end_utime - start_utime,
) )
# profile.dump_stats(name + ".pstat") profile.dump_stats(name)
html = profile.output_html()
with open(name + ".html", "w") as f:
f.write(html)
return profiled return profiled
# from twisted.python.threadpool import ThreadPool # from twisted.python.threadpool import ThreadPool
# ThreadPool._worker = profile(ThreadPool._worker) # ThreadPool._worker = profile(ThreadPool._worker)
reactor.runUntilCurrent = profile(reactor.runUntilCurrent) reactor.runUntilCurrent = profile(reactor.runUntilCurrent)
reactor.doIteration = profile(reactor.doIteration)
def in_thread(): def in_thread():
with LoggingContext("run"): with LoggingContext("run"):