diff options
| -rwxr-xr-x | synapse/app/homeserver.py | 12 | ||||
| -rw-r--r-- | synapse/util/logcontext.py | 4 |
2 files changed, 13 insertions, 3 deletions
diff --git a/synapse/app/homeserver.py b/synapse/app/homeserver.py index cd7a52ec07..58c679bbfd 100755 --- a/synapse/app/homeserver.py +++ b/synapse/app/homeserver.py @@ -499,13 +499,23 @@ class SynapseRequest(Request): self.start_time = int(time.time() * 1000) def finished_processing(self): + + try: + context = LoggingContext.current_context() + ru_utime, ru_stime = context.get_resource_usage() + except: + ru_utime, ru_stime = (0, 0) + self.site.access_logger.info( "%s - %s - {%s}" - " Processed request: %dms %sB %s \"%s %s %s\" \"%s\"", + " Processed request: %dms (%dms, %dms)" + " %sB %s \"%s %s %s\" \"%s\"", self.getClientIP(), self.site.site_tag, self.authenticated_entity, int(time.time() * 1000) - self.start_time, + int(ru_utime * 1000), + int(ru_stime * 1000), self.sentLength, self.code, self.method, diff --git a/synapse/util/logcontext.py b/synapse/util/logcontext.py index 6d7a6c3e2b..2633201528 100644 --- a/synapse/util/logcontext.py +++ b/synapse/util/logcontext.py @@ -23,6 +23,7 @@ try: import resource RUSAGE_THREAD = 1 resource.getrusage(RUSAGE_THREAD) + def get_thread_resource_usage(): return resource.getrusage(RUSAGE_THREAD) except: @@ -137,13 +138,12 @@ class LoggingContext(object): return if self.usage_start: - self.usage_end = get_thread_resource_usage() + self.usage_end = get_thread_resource_usage() def get_resource_usage(self): ru_utime = self.ru_utime ru_stime = self.ru_stime - start = self.usage_start if self.usage_start and threading.current_thread() is self.main_thread: current = get_thread_resource_usage() ru_utime += current.ru_utime - self.usage_start.ru_utime |