Wrap event listeners to delay evaluation of config.registry.metrics a…

…fter setup

kinto/core/initialization.py

@@ -547,11 +547,9 @@ def setup_listeners(config):
             listener_mod = config.maybe_dotted(module_value)
             listener = listener_mod.load_from_config(config, prefix)
 
-        # If StatsD is enabled, monitor execution time of listeners.
-        if getattr(config.registry, "metrics", None):
-            metrics = config.registry.metrics
-            key = f"listeners.{name}"
-            listener = metrics.timer(key)(listener.__call__)
+        wrapped_listener = metrics.listener_with_timer(
+            config, f"listeners.{name}", listener.__call__
+        )
 
         # Optional filter by event action.
         actions_setting = prefix + "actions"
@@ -577,11 +575,11 @@ def setup_listeners(config):
         options = dict(for_actions=actions, for_resources=resource_names)
 
         if ACTIONS.READ in actions:
-            config.add_subscriber(listener, ResourceRead, **options)
+            config.add_subscriber(wrapped_listener, ResourceRead, **options)
             actions = [a for a in actions if a != ACTIONS.READ]
 
         if len(actions) > 0:
-            config.add_subscriber(listener, ResourceChanged, **options)
+            config.add_subscriber(wrapped_listener, ResourceChanged, **options)
 
 
 def load_default_settings(config, default_settings):

kinto/core/metrics.py

@@ -37,3 +37,21 @@ def watch_execution_time(metrics_service, obj, prefix="", classname=None):
             statsd_key = f"{prefix}.{classname}.{name}"
             decorated_method = metrics_service.timer(statsd_key)(value)
             setattr(obj, name, decorated_method)
+
+
+def listener_with_timer(config, key, func):
+    """
+    Add a timer with the specified `key` on the specified `func`.
+    This is used to avoid evaluating `config.registry.metrics` during setup time
+    to avoid having to deal with initialization order and configuration committing.
+    """
+
+    def wrapped(*args, **kwargs):
+        metrics_service = config.registry.metrics
+        if not metrics_service:
+            return func(*args, **kwargs)
+        # If metrics are enabled, monitor execution time of listeners.
+        with metrics_service.timer(key):
+            return func(*args, **kwargs)
+
+    return wrapped

kinto/plugins/history/__init__.py

@@ -1,4 +1,5 @@
 from kinto.authorization import PERMISSIONS_INHERITANCE_TREE
+from kinto.core import metrics
 from kinto.core.events import ResourceChanged
 
 from .listener import on_resource_changed
@@ -14,15 +15,13 @@ def includeme(config):
     # Activate end-points.
     config.scan("kinto.plugins.history.views")
 
-    # If metrics are enabled, monitor execution time of listener.
-    listener = on_resource_changed
-    if config.registry.metrics:
-        key = "plugins.history"
-        listener = config.registry.metrics.timer(key)(on_resource_changed)
+    wrapped_listener = metrics.listener_with_timer(config, "plugins.history", on_resource_changed)
 
     # Listen to every resources (except history)
     config.add_subscriber(
-        listener, ResourceChanged, for_resources=("bucket", "group", "collection", "record")
+        wrapped_listener,
+        ResourceChanged,
+        for_resources=("bucket", "group", "collection", "record"),
     )
 
     # Register the permission inheritance for history entries.

kinto/plugins/quotas/__init__.py

@@ -1,3 +1,4 @@
+from kinto.core import metrics
 from kinto.core.events import ResourceChanged
 
 from .listener import on_resource_changed
@@ -10,13 +11,11 @@ def includeme(config):
         url="https://kinto.readthedocs.io",
     )
 
-    # If metrics are enabled, monitor execution time of listener.
-    listener = on_resource_changed
-    if config.registry.metrics:
-        key = "plugins.quotas"
-        listener = config.registry.metrics.timer(key)(on_resource_changed)
+    wrapped_listener = metrics.listener_with_timer(config, "plugins.quotas", on_resource_changed)
 
     # Listen to every resources (except history)
     config.add_subscriber(
-        listener, ResourceChanged, for_resources=("bucket", "group", "collection", "record")
+        wrapped_listener,
+        ResourceChanged,
+        for_resources=("bucket", "group", "collection", "record"),
     )

tests/plugins/test_history.py

@@ -3,9 +3,6 @@
 import unittest
 from unittest import mock
 
-from pyramid import testing
-
-from kinto import main as kinto_main
 from kinto.core.testing import get_user_headers, skip_if_no_statsd
 
 from .. import support
@@ -14,19 +11,6 @@
 DATETIME_REGEX = r"^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{6}\+\d{2}:\d{2}$"
 
 
-class PluginSetup(unittest.TestCase):
-    @skip_if_no_statsd
-    def test_a_statsd_timer_is_used_for_history_if_configured(self):
-        settings = {
-            "statsd_url": "udp://127.0.0.1:8125",
-            "includes": "kinto.plugins.history",
-        }
-        config = testing.setUp(settings=settings)
-        with mock.patch("kinto.plugins.statsd.Client.timer") as mocked:
-            kinto_main(None, config=config)
-            mocked.assert_called_with("plugins.history")
-
-
 class HistoryWebTest(support.BaseWebTest, unittest.TestCase):
     @classmethod
     def get_app_settings(cls, extras=None):
@@ -42,6 +26,24 @@ def test_history_capability_if_enabled(self):
         self.assertIn("history", capabilities)
 
 
+class MetricsTest(HistoryWebTest):
+    @classmethod
+    def get_app_settings(cls, extras=None):
+        settings = super().get_app_settings(extras)
+        settings.update(
+            **{
+                "statsd_url": "udp://127.0.0.1:8125",
+            }
+        )
+        return settings
+
+    @skip_if_no_statsd
+    def test_a_statsd_timer_is_used_for_history_if_configured(self):
+        with mock.patch("kinto.plugins.statsd.StatsDService.timer") as mocked:
+            self.app.put("/buckets/test", headers=self.headers)
+            mocked.assert_any_call("plugins.history")
+
+
 class HistoryViewTest(HistoryWebTest):
     def setUp(self):
         self.bucket_uri = "/buckets/test"

tests/plugins/test_quotas.py

@@ -3,9 +3,7 @@
 
 import pytest
 import transaction
-from pyramid import testing
 
-from kinto import main as kinto_main
 from kinto.core.errors import ERRORS
 from kinto.core.storage import Sort
 from kinto.core.storage.exceptions import ObjectNotFoundError
@@ -21,19 +19,6 @@
 from .. import support
 
 
-class PluginSetup(unittest.TestCase):
-    @skip_if_no_statsd
-    def test_a_statsd_timer_is_used_for_quotas_if_configured(self):
-        settings = {
-            "statsd_url": "udp://127.0.0.1:8125",
-            "includes": "kinto.plugins.quotas",
-        }
-        config = testing.setUp(settings=settings)
-        with mock.patch("kinto.plugins.statsd.Client.timer") as mocked:
-            kinto_main(None, config=config)
-            mocked.assert_called_with("plugins.quotas")
-
-
 class QuotaWebTest(support.BaseWebTest, unittest.TestCase):
     bucket_uri = "/buckets/test"
     collection_uri = "/buckets/test/collections/col"
@@ -91,6 +76,24 @@ def test_quota_capability_if_enabled(self):
         self.assertIn("quotas", capabilities)
 
 
+class MetricsTest(QuotaWebTest):
+    @classmethod
+    def get_app_settings(cls, extras=None):
+        settings = super().get_app_settings(extras)
+        settings.update(
+            **{
+                "statsd_url": "udp://127.0.0.1:8125",
+            }
+        )
+        return settings
+
+    @skip_if_no_statsd
+    def test_a_statsd_timer_is_used_for_quotas_if_configured(self):
+        with mock.patch("kinto.plugins.statsd.StatsDService.timer") as mocked:
+            self.app.put("/buckets/test", headers=self.headers)
+            mocked.assert_any_call("plugins.quotas")
+
+
 class QuotaListenerTest(QuotaWebTest):
     #
     # Bucket