diff --git a/synapse/app/homeserver.py b/synapse/app/homeserver.py
index cd7a52ec0..58c679bbf 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 6d7a6c3e2..263320152 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