From 14d7acfad48ea7807b032b3fd99649b500e651f7 Mon Sep 17 00:00:00 2001 From: Daniel Wagner-Hall Date: Tue, 1 Dec 2015 17:34:32 +0000 Subject: Host /unstable and /r0 versions of r0 APIs --- synapse/http/server.py | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) (limited to 'synapse/http/server.py') diff --git a/synapse/http/server.py b/synapse/http/server.py index 50feea6f1c..ef75be742c 100644 --- a/synapse/http/server.py +++ b/synapse/http/server.py @@ -120,7 +120,7 @@ class HttpServer(object): """ Interface for registering callbacks on a HTTP server """ - def register_path(self, method, path_pattern, callback): + def register_paths(self, method, path_patterns, callback): """ Register a callback that gets fired if we receive a http request with the given method for a path that matches the given regex. @@ -129,7 +129,7 @@ class HttpServer(object): Args: method (str): The method to listen to. - path_pattern (str): The regex used to match requests. + path_patterns (list): The regex used to match requests. callback (function): The function to fire if we receive a matched request. The first argument will be the request object and subsequent arguments will be any matched groups from the regex. @@ -165,10 +165,11 @@ class JsonResource(HttpServer, resource.Resource): self.version_string = hs.version_string self.hs = hs - def register_path(self, method, path_pattern, callback): - self.path_regexs.setdefault(method, []).append( - self._PathEntry(path_pattern, callback) - ) + def register_paths(self, method, path_patterns, callback): + for path_pattern in path_patterns: + self.path_regexs.setdefault(method, []).append( + self._PathEntry(path_pattern, callback) + ) def render(self, request): """ This gets called by twisted every time someone sends us a request. -- cgit 1.4.1 From 99e1d6777f0a27340554379cd5348ed870380457 Mon Sep 17 00:00:00 2001 From: Mark Haines Date: Fri, 4 Dec 2015 14:42:24 +0000 Subject: Add metrics to track the cpu on the main thread consumed by each type of request --- synapse/http/server.py | 17 +++++++++++++++++ 1 file changed, 17 insertions(+) (limited to 'synapse/http/server.py') diff --git a/synapse/http/server.py b/synapse/http/server.py index ef75be742c..06fb53707b 100644 --- a/synapse/http/server.py +++ b/synapse/http/server.py @@ -53,6 +53,14 @@ response_timer = metrics.register_distribution( labels=["method", "servlet"] ) +response_ru_utime = metrics.register_distribution( + "response_ru_utime", labels=["method", "servlet"] +) + +response_ru_stime = metrics.register_distribution( + "response_ru_stime", labels=["method", "servlet"] +) + _next_request_id = 0 @@ -221,6 +229,15 @@ class JsonResource(HttpServer, resource.Resource): self.clock.time_msec() - start, request.method, servlet_classname ) + try: + context = LoggingContext.current_context() + ru_utime, ru_stime = context.get_resource_usage() + + response_ru_utime.inc_by(ru_utime, request.method, servlet_classname) + response_ru_stime.inc_by(ru_stime, request.method, servlet_classname) + except: + pass + return # Huh. No one wanted to handle that? Fiiiiiine. Send 400. -- cgit 1.4.1 From 6a5ff5f223c1b4311aa63574663c0335d0c6bd79 Mon Sep 17 00:00:00 2001 From: Mark Haines Date: Mon, 7 Dec 2015 17:56:11 +0000 Subject: Track the time spent in the database per request. and track the number of transactions that request started. --- synapse/app/homeserver.py | 7 ++++++- synapse/http/server.py | 15 +++++++++++++++ synapse/storage/_base.py | 9 +++++++-- synapse/storage/events.py | 2 +- synapse/util/logcontext.py | 9 +++++++++ 5 files changed, 38 insertions(+), 4 deletions(-) (limited to 'synapse/http/server.py') diff --git a/synapse/app/homeserver.py b/synapse/app/homeserver.py index 58c679bbfd..56bc52e9ca 100755 --- a/synapse/app/homeserver.py +++ b/synapse/app/homeserver.py @@ -503,12 +503,15 @@ class SynapseRequest(Request): try: context = LoggingContext.current_context() ru_utime, ru_stime = context.get_resource_usage() + db_txn_count = context.db_txn_count + db_txn_duration = context.db_txn_duration except: ru_utime, ru_stime = (0, 0) + db_txn_count, db_txn_duration = (0, 0) self.site.access_logger.info( "%s - %s - {%s}" - " Processed request: %dms (%dms, %dms)" + " Processed request: %dms (%dms, %dms) (%dms/%d)" " %sB %s \"%s %s %s\" \"%s\"", self.getClientIP(), self.site.site_tag, @@ -516,6 +519,8 @@ class SynapseRequest(Request): int(time.time() * 1000) - self.start_time, int(ru_utime * 1000), int(ru_stime * 1000), + int(db_txn_duration * 1000), + int(db_txn_count), self.sentLength, self.code, self.method, diff --git a/synapse/http/server.py b/synapse/http/server.py index 06fb53707b..c44bdfc888 100644 --- a/synapse/http/server.py +++ b/synapse/http/server.py @@ -61,6 +61,15 @@ response_ru_stime = metrics.register_distribution( "response_ru_stime", labels=["method", "servlet"] ) +response_db_txn_count = metrics.register_distribution( + "response_db_txn_count", labels=["method", "servlet"] +) + +response_db_txn_duration = metrics.register_distribution( + "response_db_txn_duration", labels=["method", "servlet"] +) + + _next_request_id = 0 @@ -235,6 +244,12 @@ class JsonResource(HttpServer, resource.Resource): response_ru_utime.inc_by(ru_utime, request.method, servlet_classname) response_ru_stime.inc_by(ru_stime, request.method, servlet_classname) + response_db_txn_count.inc_by( + context.db_txn_count, request.method, servlet_classname + ) + response_db_txn_duration.inc_by( + context.db_txn_duration, request.method, servlet_classname + ) except: pass 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 = { diff --git a/synapse/util/logcontext.py b/synapse/util/logcontext.py index c20c89aa8f..d528ced55a 100644 --- a/synapse/util/logcontext.py +++ b/synapse/util/logcontext.py @@ -69,6 +69,9 @@ class LoggingContext(object): def stop(self): pass + def add_database_transaction(self, duration_ms): + pass + sentinel = Sentinel() def __init__(self, name=None): @@ -76,6 +79,8 @@ class LoggingContext(object): self.name = name self.ru_stime = 0. self.ru_utime = 0. + self.db_txn_count = 0 + self.db_txn_duration = 0. self.usage_start = None self.main_thread = threading.current_thread() @@ -171,6 +176,10 @@ class LoggingContext(object): return ru_utime, ru_stime + def add_database_transaction(self, duration_ms): + self.db_txn_count += 1 + self.db_txn_duration += duration_ms / 1000. + class LoggingContextFilter(logging.Filter): """Logging filter that adds values from the current logging context to each -- cgit 1.4.1