Log some times to identify very slow parts

1 files changed, 39 insertions, 0 deletions

diff --git a/service/pixelated/support/__init__.py b/service/pixelated/support/__init__.py
index 2756a319..80ecaa2e 100644
--- a/service/pixelated/support/__init__.py
+++ b/service/pixelated/support/__init__.py
@@ -13,3 +13,42 @@
 #
 # You should have received a copy of the GNU Affero General Public License
 # along with Pixelated. If not, see <http://www.gnu.org/licenses/>.
+import time
+import logging
+from functools import wraps
+from twisted.internet import defer
+
+
+log = logging.getLogger(__name__)
+
+
+def log_time(f):
+
+    @wraps(f)
+    def wrapper(*args, **kwds):
+        start = time.clock()
+        result = f(*args, **kwds)
+        log.info('Needed %f ms to execute %s' % ((time.clock() - start), f))
+
+        return result
+
+    return wrapper
+
+
+def log_time_deferred(f):
+
+    def log_time(result, start):
+        log.info('after callback: Needed %f ms to execute %s' % ((time.clock() - start), f))
+        return result
+
+    @wraps(f)
+    def wrapper(*args, **kwds):
+        start = time.clock()
+        result = f(*args, **kwds)
+        if isinstance(result, defer.Deferred):
+            result.addCallback(log_time, start=start)
+        else:
+            log.warn('No Deferred returned, perhaps need to re-order annotations?')
+        return result
+
+    return wrapper