From 7efd62e8775589efc068a8b9b06585d3cd3b4b2d Mon Sep 17 00:00:00 2001 From: Thais Siqueira Date: Mon, 22 Aug 2016 17:33:21 -0300 Subject: Adds a patch to measure function running in twisted The README explains how to apply the patch so you can get information about long running methods (longer than 100ms) on the main thread --- service/test/reactor/README.md | 7 ++++++ service/test/reactor/defer.patch | 47 ++++++++++++++++++++++++++++++++++++++++ 2 files changed, 54 insertions(+) create mode 100644 service/test/reactor/README.md create mode 100644 service/test/reactor/defer.patch diff --git a/service/test/reactor/README.md b/service/test/reactor/README.md new file mode 100644 index 00000000..8cbae687 --- /dev/null +++ b/service/test/reactor/README.md @@ -0,0 +1,7 @@ +To test the run times of functions in the main reactor thread: + +- Apply the patch defer.patch +``` +patch /local/lib/python2.7/twisted/internet/defer.py service/test/reactor/defer.patch +``` +- Run the user agent, preferrably out of debug mode, the timing of all the functions that take more than 100ms will be printed on the log diff --git a/service/test/reactor/defer.patch b/service/test/reactor/defer.patch new file mode 100644 index 00000000..de2f7d82 --- /dev/null +++ b/service/test/reactor/defer.patch @@ -0,0 +1,47 @@ +33a34,46 +> from datetime import datetime +> +> class Clock(): +> def __init__(self, label): +> self.start = datetime.now() +> self.label = label +> +> def stop(self): +> end = datetime.now() +> total = (end - self.start).total_seconds() +> if total > 0.1: +> print('EXECUTING {} {:.5f}'.format(self.label, total)) +> +195c208,221 +< +--- +> import threading +> import inspect +> def identifyItem(i): +> if i is None: +> return "(None)" +> else: +> if inspect.isbuiltin(i): +> return str(i) +> else: +> if 'gotResult' == i.__name__: +> return str(i.__closure__[1].cell_contents) +> f = inspect.getsourcefile(i) +> ln = inspect.getsourcelines(i)[1] +> return "%s (%s:%d)" % (str(i), f, ln) +300a327,329 +> +> # print "addCallbacks(%s, %s)" % (identifyItem(callback), identifyItem(errback)) +> +588c617,625 +< current.result = callback(current.result, *args, **kw) +--- +> currentItem = identifyItem(callback) +> currentThreadId = threading.current_thread().ident +> +> clock = Clock("%s in thread %d" % (currentItem, currentThreadId)) +> try: +> current.result = callback(current.result, *args, **kw) +> finally: +> clock.stop() +> -- cgit v1.2.3