From 1f1dee94f6025ce0a6e414cd6098cb766567bdd8 Mon Sep 17 00:00:00 2001
From: Erik Johnston <erik@matrix.org>
Date: Mon, 9 May 2016 10:13:25 +0100
Subject: [PATCH 1/3] Manually run GC on reactor tick.

This also adds a metric for amount of time spent in GC.
---
 synapse/metrics/__init__.py | 15 +++++++++++++++
 1 file changed, 15 insertions(+)

diff --git a/synapse/metrics/__init__.py b/synapse/metrics/__init__.py
index 5664d5a38..17be491b9 100644
--- a/synapse/metrics/__init__.py
+++ b/synapse/metrics/__init__.py
@@ -22,6 +22,7 @@ import functools
 import os
 import stat
 import time
+import gc
 
 from twisted.internet import reactor
 
@@ -155,6 +156,7 @@ get_metrics_for("process").register_callback("fds", _process_fds, labels=["type"
 reactor_metrics = get_metrics_for("reactor")
 tick_time = reactor_metrics.register_distribution("tick_time")
 pending_calls_metric = reactor_metrics.register_distribution("pending_calls")
+gc_time = reactor_metrics.register_distribution("gc_time")
 
 
 def runUntilCurrentTimer(func):
@@ -182,6 +184,18 @@ def runUntilCurrentTimer(func):
         end = time.time() * 1000
         tick_time.inc_by(end - start)
         pending_calls_metric.inc_by(num_pending)
+
+        threshold = gc.get_threshold()
+        counts = gc.get_count()
+
+        start = time.time() * 1000
+        for i in [2, 1, 0]:
+            if threshold[i] < counts[i]:
+                logger.info("Collecting gc %d", i)
+                gc.collect(i)
+        end = time.time() * 1000
+        gc_time.inc_by(end - start)
+
         return ret
 
     return f
@@ -196,5 +210,6 @@ try:
     # runUntilCurrent is called when we have pending calls. It is called once
     # per iteratation after fd polling.
     reactor.runUntilCurrent = runUntilCurrentTimer(reactor.runUntilCurrent)
+    gc.disable()
 except AttributeError:
     pass

From 7d6e89ed22aab4bae9ce033c2e4757a595257942 Mon Sep 17 00:00:00 2001
From: Erik Johnston <erik@matrix.org>
Date: Fri, 13 May 2016 16:31:08 +0100
Subject: [PATCH 2/3] Add a comment

---
 synapse/metrics/__init__.py | 5 +++++
 1 file changed, 5 insertions(+)

diff --git a/synapse/metrics/__init__.py b/synapse/metrics/__init__.py
index 17be491b9..c82685a52 100644
--- a/synapse/metrics/__init__.py
+++ b/synapse/metrics/__init__.py
@@ -185,6 +185,8 @@ def runUntilCurrentTimer(func):
         tick_time.inc_by(end - start)
         pending_calls_metric.inc_by(num_pending)
 
+        # Check if we need to do a manual GC (since its been disabled), and do
+        # one if necessary.
         threshold = gc.get_threshold()
         counts = gc.get_count()
 
@@ -210,6 +212,9 @@ try:
     # runUntilCurrent is called when we have pending calls. It is called once
     # per iteratation after fd polling.
     reactor.runUntilCurrent = runUntilCurrentTimer(reactor.runUntilCurrent)
+
+    # We manually run the GC each reactor tick so that we can get some metrics
+    # about time spent doing GC,
     gc.disable()
 except AttributeError:
     pass

From 60d53f9e9596520472954831ce8fea251a462d46 Mon Sep 17 00:00:00 2001
From: Erik Johnston <erik@matrix.org>
Date: Mon, 16 May 2016 09:32:29 +0100
Subject: [PATCH 3/3] Count number of GC collects

---
 synapse/metrics/__init__.py | 16 +++++++++++-----
 1 file changed, 11 insertions(+), 5 deletions(-)

diff --git a/synapse/metrics/__init__.py b/synapse/metrics/__init__.py
index c82685a52..bba265707 100644
--- a/synapse/metrics/__init__.py
+++ b/synapse/metrics/__init__.py
@@ -156,7 +156,12 @@ get_metrics_for("process").register_callback("fds", _process_fds, labels=["type"
 reactor_metrics = get_metrics_for("reactor")
 tick_time = reactor_metrics.register_distribution("tick_time")
 pending_calls_metric = reactor_metrics.register_distribution("pending_calls")
-gc_time = reactor_metrics.register_distribution("gc_time")
+
+gc_time = (
+    reactor_metrics.register_distribution("gc_time_gen0"),
+    reactor_metrics.register_distribution("gc_time_gen2"),
+    reactor_metrics.register_distribution("gc_time_gen2"),
+)
 
 
 def runUntilCurrentTimer(func):
@@ -189,14 +194,15 @@ def runUntilCurrentTimer(func):
         # one if necessary.
         threshold = gc.get_threshold()
         counts = gc.get_count()
-
-        start = time.time() * 1000
         for i in [2, 1, 0]:
             if threshold[i] < counts[i]:
                 logger.info("Collecting gc %d", i)
+
+                start = time.time() * 1000
                 gc.collect(i)
-        end = time.time() * 1000
-        gc_time.inc_by(end - start)
+                end = time.time() * 1000
+
+                gc_time[i].inc_by(end - start)
 
         return ret