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/metrics/__init__.py') 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/metrics/__init__.py') 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/metrics/__init__.py') 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 From 75331c5fca6d2207094b8cbf0b3bb34cc52a4ec4 Mon Sep 17 00:00:00 2001 From: Erik Johnston Date: Tue, 7 Jun 2016 13:33:13 +0100 Subject: Change the way we do stats --- synapse/metrics/__init__.py | 10 +++------- 1 file changed, 3 insertions(+), 7 deletions(-) (limited to 'synapse/metrics/__init__.py') diff --git a/synapse/metrics/__init__.py b/synapse/metrics/__init__.py index f317034b8f..ef14bcd840 100644 --- a/synapse/metrics/__init__.py +++ b/synapse/metrics/__init__.py @@ -153,11 +153,7 @@ 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_gen0"), - reactor_metrics.register_distribution("gc_time_gen2"), - reactor_metrics.register_distribution("gc_time_gen2"), -) +gc_time = reactor_metrics.register_distribution("gc_time", labels=["gen"]) def runUntilCurrentTimer(func): @@ -190,7 +186,7 @@ def runUntilCurrentTimer(func): # one if necessary. threshold = gc.get_threshold() counts = gc.get_count() - for i in [2, 1, 0]: + for i in (0, 1, 2): if threshold[i] < counts[i]: logger.info("Collecting gc %d", i) @@ -198,7 +194,7 @@ def runUntilCurrentTimer(func): gc.collect(i) end = time.time() * 1000 - gc_time[i].inc_by(end - start) + gc_time.inc_by(end - start, i) return ret -- cgit 1.4.1 From 48e65099b52383743a47844b6369e173b9a96f90 Mon Sep 17 00:00:00 2001 From: Erik Johnston Date: Tue, 7 Jun 2016 13:40:22 +0100 Subject: Also record number of unreachable objects --- synapse/metrics/__init__.py | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) (limited to 'synapse/metrics/__init__.py') diff --git a/synapse/metrics/__init__.py b/synapse/metrics/__init__.py index ef14bcd840..b29cec3de1 100644 --- a/synapse/metrics/__init__.py +++ b/synapse/metrics/__init__.py @@ -154,6 +154,7 @@ 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", labels=["gen"]) +gc_unreachable = reactor_metrics.register_counter("gc_unreachable", labels=["gen"]) def runUntilCurrentTimer(func): @@ -186,15 +187,16 @@ def runUntilCurrentTimer(func): # one if necessary. threshold = gc.get_threshold() counts = gc.get_count() - for i in (0, 1, 2): + for i in (2, 1, 0): if threshold[i] < counts[i]: logger.info("Collecting gc %d", i) start = time.time() * 1000 - gc.collect(i) + unreachable = gc.collect(i) end = time.time() * 1000 gc_time.inc_by(end - start, i) + gc_unreachable.inc_by(unreachable, i) return ret -- cgit 1.4.1 From 18f0cc7d993408a754e7ff26e9474a969adf762a Mon Sep 17 00:00:00 2001 From: Erik Johnston Date: Tue, 7 Jun 2016 16:51:01 +0100 Subject: Record some more GC metrics --- synapse/metrics/__init__.py | 5 +++++ 1 file changed, 5 insertions(+) (limited to 'synapse/metrics/__init__.py') diff --git a/synapse/metrics/__init__.py b/synapse/metrics/__init__.py index b29cec3de1..8f69aa1ff3 100644 --- a/synapse/metrics/__init__.py +++ b/synapse/metrics/__init__.py @@ -156,6 +156,11 @@ pending_calls_metric = reactor_metrics.register_distribution("pending_calls") gc_time = reactor_metrics.register_distribution("gc_time", labels=["gen"]) gc_unreachable = reactor_metrics.register_counter("gc_unreachable", labels=["gen"]) +reactor_metrics.register_callback("gc_total_objects", lambda: len(gc.get_objects())) +reactor_metrics.register_callback( + "gc_counts", lambda: {(i,): v for i, v in enumerate(gc.get_count())}, labels=["gen"] +) + def runUntilCurrentTimer(func): -- cgit 1.4.1 From 0f2165ccf4fd0ae6636018cea7e1b91141179e88 Mon Sep 17 00:00:00 2001 From: Erik Johnston Date: Tue, 7 Jun 2016 17:00:45 +0100 Subject: Don't track total objects as its too expensive to calculate --- synapse/metrics/__init__.py | 1 - 1 file changed, 1 deletion(-) (limited to 'synapse/metrics/__init__.py') diff --git a/synapse/metrics/__init__.py b/synapse/metrics/__init__.py index 8f69aa1ff3..bdd7292a30 100644 --- a/synapse/metrics/__init__.py +++ b/synapse/metrics/__init__.py @@ -156,7 +156,6 @@ pending_calls_metric = reactor_metrics.register_distribution("pending_calls") gc_time = reactor_metrics.register_distribution("gc_time", labels=["gen"]) gc_unreachable = reactor_metrics.register_counter("gc_unreachable", labels=["gen"]) -reactor_metrics.register_callback("gc_total_objects", lambda: len(gc.get_objects())) reactor_metrics.register_callback( "gc_counts", lambda: {(i,): v for i, v in enumerate(gc.get_count())}, labels=["gen"] ) -- cgit 1.4.1