StatsD execution timer by sub-policy

cliquet/initialization.py

@@ -33,7 +33,8 @@
 from pyramid.security import NO_PERMISSION_REQUIRED
 from pyramid.interfaces import IAuthenticationPolicy
 from pyramid.settings import asbool, aslist
-from pyramid_multiauth import MultiAuthPolicySelected
+from pyramid_multiauth import (MultiAuthenticationPolicy,
+                               MultiAuthPolicySelected)
 
 
 def setup_request_bound_data(config):
@@ -280,7 +281,13 @@ def setup_statsd(config):
         # Commit so that configured policy can be queried.
         config.commit()
         policy = config.registry.queryUtility(IAuthenticationPolicy)
-        client.watch_execution_time(policy, prefix='authentication')
+        if isinstance(policy, MultiAuthenticationPolicy):
+            for name, subpolicy in policy.get_policies():
+                client.watch_execution_time(subpolicy,
+                                            prefix='authentication',
+                                            classname=name)
+        else:
+            client.watch_execution_time(policy, prefix='authentication')
 
         def on_new_response(event):
             request = event.request

cliquet/statsd.py

@@ -1,4 +1,5 @@
 from __future__ import absolute_import
+import types
 
 try:
     import statsd as statsd_module
@@ -14,12 +15,13 @@ class Client(object):
     def __init__(self, host, port, prefix):
         self._client = statsd_module.StatsClient(host, port, prefix=prefix)
 
-    def watch_execution_time(self, obj, prefix=''):
-        classname = utils.classname(obj)
+    def watch_execution_time(self, obj, prefix='', classname=None):
+        classname = classname or utils.classname(obj)
         members = dir(obj)
         for name in members:
             value = getattr(obj, name)
-            if not name.startswith('_') and hasattr(value, '__call__'):
+            is_method = isinstance(value, types.MethodType)
+            if not name.startswith('_') and is_method:
                 statsd_key = "%s.%s.%s" % (prefix, classname, name)
                 decorated_method = self.timer(statsd_key)(value)
                 setattr(obj, name, decorated_method)

cliquet/tests/test_statsd.py

@@ -2,7 +2,7 @@
 
 from pyramid import testing
 
-from cliquet.tests.support import unittest
+from cliquet.tests.support import unittest, BaseWebTest
 from cliquet import statsd
 
 
@@ -80,3 +80,28 @@ def test_statsd_count_call_the_client_if_configured(self):
         request.registry.statsd = self.mocked_client
         statsd.statsd_count(request, 'toto')
         self.mocked_client.count.assert_called_with('toto')
+
+
+@unittest.skipIf(not statsd.statsd_module, "statsd is not installed.")
+class TimingTest(BaseWebTest, unittest.TestCase):
+    def get_app_settings(self, *args, **kwargs):
+        settings = super(TimingTest, self).get_app_settings(*args, **kwargs)
+        if not statsd.statsd_module:
+            return settings
+
+        settings['statsd_url'] = 'udp://localhost:8125'
+        return settings
+
+    def test_statds_tracks_listeners_execution_duration(self):
+        statsd_client = self.app.app.registry.statsd._client
+        with mock.patch.object(statsd_client, 'timing') as mocked:
+            self.app.get('/', headers=self.headers)
+            self.assertTrue(mocked.called)
+
+    def test_statds_tracks_authentication_policies(self):
+        statsd_client = self.app.app.registry.statsd._client
+        with mock.patch.object(statsd_client, 'timing') as mocked:
+            self.app.get('/', headers=self.headers)
+            timers = set(c[0][0] for c in mocked.call_args_list)
+            self.assertIn('authentication.basicauth.unauthenticated_userid',
+                          timers)

setup.py

@@ -21,7 +21,7 @@
     'colander',
     'cornice >= 1.1',  # Fix cache CORS
     'python-dateutil',
-    'pyramid_multiauth >= 0.6',  # Policy name in event.
+    'pyramid_multiauth >= 0.7',  # Contained policy names.
     'pyramid_tm',
     'redis',  # Default backend
     'requests',