From 8e358ef35a8e2640176003cdb2396a9b4d71fbce Mon Sep 17 00:00:00 2001
From: Erik Johnston <erik@matrix.org>
Date: Tue, 28 Oct 2014 10:34:05 +0000
Subject: [PATCH] Add timer to LoggingTransaction

---
 synapse/storage/_base.py | 13 ++++++++++---
 1 file changed, 10 insertions(+), 3 deletions(-)

diff --git a/synapse/storage/_base.py b/synapse/storage/_base.py
index 65a86e9056..e839704a8c 100644
--- a/synapse/storage/_base.py
+++ b/synapse/storage/_base.py
@@ -23,6 +23,7 @@ from synapse.util.logutils import log_function
 import collections
 import copy
 import json
+import time
 
 
 logger = logging.getLogger(__name__)
@@ -61,9 +62,15 @@ class LoggingTransaction(object):
 
         # TODO(paul): Here would be an excellent place to put some timing
         #   measurements, and log (warning?) slow queries.
-        return object.__getattribute__(self, "txn").execute(
-            sql, *args, **kwargs
-        )
+
+        start = time.clock() * 1000
+        try:
+            return object.__getattribute__(self, "txn").execute(
+                sql, *args, **kwargs
+            )
+        finally:
+            end = time.clock() * 1000
+            sql_logger.debug("[SQL time] %f", end - start)
 
 
 class SQLBaseStore(object):