Track the time spent in the database per request.

and track the number of transactions that request started.

2 files changed, 8 insertions, 3 deletions

diff --git a/synapse/storage/_base.py b/synapse/storage/_base.py
index 218e708054..17a14e001c 100644
--- a/synapse/storage/_base.py
+++ b/synapse/storage/_base.py
@@ -214,7 +214,8 @@ class SQLBaseStore(object):
 
         self._clock.looping_call(loop, 10000)
 
-    def _new_transaction(self, conn, desc, after_callbacks, func, *args, **kwargs):
+    def _new_transaction(self, conn, desc, after_callbacks, logging_context,
+                         func, *args, **kwargs):
         start = time.time() * 1000
         txn_id = self._TXN_ID
 
@@ -277,6 +278,9 @@ class SQLBaseStore(object):
             end = time.time() * 1000
             duration = end - start
 
+            if logging_context is not None:
+                logging_context.add_database_transaction(duration)
+
             transaction_logger.debug("[TXN END] {%s} %f", name, duration)
 
             self._current_txn_total_time += duration
@@ -302,7 +306,8 @@ class SQLBaseStore(object):
 
                 current_context.copy_to(context)
                 return self._new_transaction(
-                    conn, desc, after_callbacks, func, *args, **kwargs
+                    conn, desc, after_callbacks, current_context,
+                    func, *args, **kwargs
                 )
 
         result = yield preserve_context_over_fn(
diff --git a/synapse/storage/events.py b/synapse/storage/events.py
index 7088f2709b..fc5725097c 100644
--- a/synapse/storage/events.py
+++ b/synapse/storage/events.py
@@ -649,7 +649,7 @@ class EventsStore(SQLBaseStore):
                 ]
 
                 rows = self._new_transaction(
-                    conn, "do_fetch", [], self._fetch_event_rows, event_ids
+                    conn, "do_fetch", [], None, self._fetch_event_rows, event_ids
                 )
 
                 row_dict = {