Matrix-Mirrors/forked-synapse
1
0
Fork 0
mirror of https://mau.dev/maunium/synapse.git synced 2024-10-01 01:36:05 -04:00
Code Issues Packages Projects Releases Wiki Activity

Performance counters for database transaction names

Browse Source
This commit is contained in:
Mark Haines 2015-02-09 17:55:56 +00:00
parent 76c5a5c2f6
commit 3a5ad7dbd5
1 changed files with 31 additions and 1 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

32
synapse/storage/_base.py
View File

@ -39,6 +39,7 @@ class LoggingTransaction(object):
passed to the constructor. Adds logging to the .execute() method.""" passed to the constructor. Adds logging to the .execute() method."""
__slots__ = ["txn", "name"] __slots__ = ["txn", "name"]
def __init__(self, txn, name): def __init__(self, txn, name):
object.__setattr__(self, "txn", txn) object.__setattr__(self, "txn", txn)
object.__setattr__(self, "name", name) object.__setattr__(self, "name", name)
@ -88,6 +89,8 @@ class SQLBaseStore(object):
self._previous_txn_total_time = 0 self._previous_txn_total_time = 0
self._current_txn_total_time = 0 self._current_txn_total_time = 0
self._previous_loop_ts = 0 self._previous_loop_ts = 0
self._txn_perf_counters = {}
self._previous_txn_perf_counters = {}
def start_profiling(self): def start_profiling(self):
self._previous_loop_ts = self._clock.time_msec() self._previous_loop_ts = self._clock.time_msec()
@ -103,7 +106,29 @@ class SQLBaseStore(object):
ratio = (curr - prev)/(time_now - time_then) ratio = (curr - prev)/(time_now - time_then)
logger.info("Total database time: %.3f%%", ratio * 100) txn_counters = []
for name, (count, cum_time) in self._txn_perf_counters.items():
prev_count, prev_time = self._previous_txn_perf_counters.get(
name, (0,0)
)
txn_counters.append((
(cum_time - prev_time) / (time_now - time_then),
count - prev_count,
name
))
self._previous_txn_perf_counters = dict(self._txn_perf_counters)
txn_counters.sort(reverse=True)
top_three_counters = ", ".join(
"%s(%d): %.3f%%" % (name, count, 100 * ratio)
for ratio, count, name in txn_counters[:3]
)
logger.info(
"Total database time: %.3f%% {%s}",
ratio * 100, top_three_counters
)
self._clock.looping_call(loop, 10000) self._clock.looping_call(loop, 10000)
@ -139,6 +164,11 @@ class SQLBaseStore(object):
self._current_txn_total_time += end - start self._current_txn_total_time += end - start
count, cum_time = self._txn_perf_counters.get(name, (0,0))
count += 1
cum_time += end - start
self._txn_perf_counters[name] = (count, cum_time)
with PreserveLoggingContext(): with PreserveLoggingContext():
result = yield self._db_pool.runInteraction( result = yield self._db_pool.runInteraction(
inner_func, *args, **kwargs inner_func, *args, **kwargs