From 1f1dee94f6025ce0a6e414cd6098cb766567bdd8 Mon Sep 17 00:00:00 2001 From: Erik Johnston Date: Mon, 9 May 2016 10:13:25 +0100 Subject: 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(+) (limited to 'synapse') diff --git a/synapse/metrics/__init__.py b/synapse/metrics/__init__.py index 5664d5a381..17be491b93 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 -- cgit 1.4.1 From 7d6e89ed22aab4bae9ce033c2e4757a595257942 Mon Sep 17 00:00:00 2001 From: Erik Johnston Date: Fri, 13 May 2016 16:31:08 +0100 Subject: Add a comment --- synapse/metrics/__init__.py | 5 +++++ 1 file changed, 5 insertions(+) (limited to 'synapse') diff --git a/synapse/metrics/__init__.py b/synapse/metrics/__init__.py index 17be491b93..c82685a524 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 -- cgit 1.4.1 From 60d53f9e9596520472954831ce8fea251a462d46 Mon Sep 17 00:00:00 2001 From: Erik Johnston Date: Mon, 16 May 2016 09:32:29 +0100 Subject: Count number of GC collects --- synapse/metrics/__init__.py | 16 +++++++++++----- 1 file changed, 11 insertions(+), 5 deletions(-) (limited to 'synapse') diff --git a/synapse/metrics/__init__.py b/synapse/metrics/__init__.py index c82685a524..bba2657075 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 -- cgit 1.4.1