From c7fcb53b92ed1d10405e6210c81d92864cacd107 Mon Sep 17 00:00:00 2001 From: Erik Johnston Date: Fri, 29 May 2015 10:37:41 +0100 Subject: [PATCH] Use cProfile. Hook into doIteration. Track utime. --- synapse/app/homeserver.py | 26 +++++++++++++++----------- 1 file changed, 15 insertions(+), 11 deletions(-) diff --git a/synapse/app/homeserver.py b/synapse/app/homeserver.py index a41cd4f433..679c3b4d93 100755 --- a/synapse/app/homeserver.py +++ b/synapse/app/homeserver.py @@ -519,36 +519,40 @@ def run(hs): PROFILE_SYNAPSE = True if PROFILE_SYNAPSE: def profile(func): - from pyinstrument import Profiler + from cProfile import Profile from threading import current_thread import time + import resource 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) - profile.start() + profile.enable() func(*args, **kargs) - profile.stop() + profile.disable() 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 - name = "/tmp/%s.%s.%i.%d-%d.%d" % ( - hs.hostname, func.__name__, ident, start, end, end-start + name = "/tmp/%s.%s.%i.%d-%d.%d-%d.pstat" % ( + hs.hostname, func.__name__, ident, start, end, + end-start, end_utime - start_utime, ) - # profile.dump_stats(name + ".pstat") - html = profile.output_html() - with open(name + ".html", "w") as f: - f.write(html) + profile.dump_stats(name) return profiled # from twisted.python.threadpool import ThreadPool # ThreadPool._worker = profile(ThreadPool._worker) reactor.runUntilCurrent = profile(reactor.runUntilCurrent) + reactor.doIteration = profile(reactor.doIteration) def in_thread(): with LoggingContext("run"):