metrics: use new statsd client logic, and start gathering new metrics

vcsserver/lib/statsd_client.py

@@ -0,0 +1,49 b''
+from vcsserver.lib._vendor.statsd import client_from_config
+
+
+class StatsdClientNotInitialised(Exception):
+    pass
+
+
+class _Singleton(type):
+    """A metaclass that creates a Singleton base class when called."""
+
+    _instances = {}
+
+    def __call__(cls, *args, **kwargs):
+        if cls not in cls._instances:
+            cls._instances[cls] = super(_Singleton, cls).__call__(*args, **kwargs)
+        return cls._instances[cls]
+
+
+class Singleton(_Singleton("SingletonMeta", (object,), {})):
+    pass
+
+
+class StatsdClientClass(Singleton):
+    setup_run = False
+    statsd_client = None
+    statsd = None
+
+    def __getattribute__(self, name):
+
+        if name.startswith("statsd"):
+            if self.setup_run:
+                return super(StatsdClientClass, self).__getattribute__(name)
+            else:
+                return None
+                #raise StatsdClientNotInitialised("requested key was %s" % name)
+
+        return super(StatsdClientClass, self).__getattribute__(name)
+
+    def setup(self, settings):
+        """
+        Initialize the client
+        """
+        statsd = client_from_config(settings)
+        self.statsd = statsd
+        self.statsd_client = statsd
+        self.setup_run = True
+
+
+StatsdClient = StatsdClientClass()

vcsserver/http_main.py

@@ -37,6 +37,7 b' from pyramid.compat import configparser'
 from pyramid.response import Response
 
 from vcsserver.utils import safe_int
+from vcsserver.lib.statsd_client import StatsdClient
 
 log = logging.getLogger(__name__)
 
@@ -243,6 +244,9 b' class HTTPApplication(object):'
         self._sanitize_settings_and_apply_defaults(settings)
 
         self.config = Configurator(settings=settings)
+        # Init our statsd at very start
+        self.config.registry.statsd = StatsdClient.statsd
+
         self.global_config = global_config
         self.config.include('vcsserver.lib.rc_cache')
 
@@ -359,10 +363,6 b' class HTTPApplication(object):'
             'vcsserver.lib.request_counter.get_request_counter',
             'request_count')
 
-        self.config.add_request_method(
-            'vcsserver.lib._vendor.statsd.get_statsd_client',
-            'statsd', reify=True)
-
     def wsgi_app(self):
         return self.config.make_wsgi_app()
 
@@ -397,6 +397,12 b' class HTTPApplication(object):'
             log.debug('Method requested:`%s` with args:%s kwargs:%s context_uid: %s, repo_state_uid:%s',
                       method, call_args, kwargs, context_uid, repo_state_uid)
 
+            statsd = request.registry.statsd
+            if statsd:
+                statsd.incr(
+                    'vcsserver_method_count', tags=[
+                        "method:{}".format(method),
+                    ])
         return payload, remote, method, args, kwargs
 
     def vcs_view(self, request):
@@ -681,6 +687,10 b' class HTTPApplication(object):'
         log.error(
             'error occurred handling this request for path: %s, \n tb: %s',
             request.path, traceback_info)
+
+        statsd = request.registry.statsd
+        if statsd:
+            statsd.incr('vcsserver_exception')
         raise exception
 
 
@@ -701,5 +711,8 b' def main(global_config, **settings):'
         hgpatches.patch_largefiles_capabilities()
         hgpatches.patch_subrepo_type_mapping()
 
+    # init and bootstrap StatsdClient
+    StatsdClient.setup(settings)
+
     app = HTTPApplication(settings=settings, global_config=global_config)
     return app.wsgi_app()

vcsserver/lib/_vendor/statsd/base.py

@@ -1,11 +1,27 b''
 from __future__ import absolute_import, division, unicode_literals
 
+import re
 import random
 from collections import deque
 from datetime import timedelta
+from repoze.lru import lru_cache
 
 from .timer import Timer
 
+TAG_INVALID_CHARS_RE = re.compile(r"[^\w\d_\-:/\.]", re.UNICODE)
+TAG_INVALID_CHARS_SUBS = "_"
+
+
+@lru_cache(maxsize=500)
+def _normalize_tags_with_cache(tag_list):
+    return [TAG_INVALID_CHARS_RE.sub(TAG_INVALID_CHARS_SUBS, tag) for tag in tag_list]
+
+
+def normalize_tags(tag_list):
+    # We have to turn our input tag list into a non-mutable tuple for it to
+    # be hashable (and thus usable) by the @lru_cache decorator.
+    return _normalize_tags_with_cache(tuple(tag_list))
+
 
 class StatsClientBase(object):
     """A Base class for various statsd clients."""
@@ -20,10 +36,10 b' class StatsClientBase(object):'
     def pipeline(self):
         raise NotImplementedError()
 
-    def timer(self, stat, rate=1):
-        return Timer(self, stat, rate)
+    def timer(self, stat, rate=1, tags=None):
+        return Timer(self, stat, rate, tags)
 
-    def timing(self, stat, delta, rate=1):
+    def timing(self, stat, delta, rate=1, tags=None):
         """
         Send new timing information.
 
@@ -32,17 +48,17 b' class StatsClientBase(object):'
         if isinstance(delta, timedelta):
             # Convert timedelta to number of milliseconds.
             delta = delta.total_seconds() * 1000.
-        self._send_stat(stat, '%0.6f|ms' % delta, rate)
+        self._send_stat(stat, '%0.6f|ms' % delta, rate, tags)
 
-    def incr(self, stat, count=1, rate=1):
+    def incr(self, stat, count=1, rate=1, tags=None):
         """Increment a stat by `count`."""
-        self._send_stat(stat, '%s|c' % count, rate)
+        self._send_stat(stat, '%s|c' % count, rate, tags)
 
-    def decr(self, stat, count=1, rate=1):
+    def decr(self, stat, count=1, rate=1, tags=None):
         """Decrement a stat by `count`."""
-        self.incr(stat, -count, rate)
+        self.incr(stat, -count, rate, tags)
 
-    def gauge(self, stat, value, rate=1, delta=False):
+    def gauge(self, stat, value, rate=1, delta=False, tags=None):
         """Set a gauge value."""
         if value < 0 and not delta:
             if rate < 1:
@@ -53,16 +69,16 b' class StatsClientBase(object):'
                 pipe._send_stat(stat, '%s|g' % value, 1)
         else:
             prefix = '+' if delta and value >= 0 else ''
-            self._send_stat(stat, '%s%s|g' % (prefix, value), rate)
+            self._send_stat(stat, '%s%s|g' % (prefix, value), rate, tags)
 
     def set(self, stat, value, rate=1):
         """Set a set value."""
         self._send_stat(stat, '%s|s' % value, rate)
 
-    def _send_stat(self, stat, value, rate):
-        self._after(self._prepare(stat, value, rate))
+    def _send_stat(self, stat, value, rate, tags=None):
+        self._after(self._prepare(stat, value, rate, tags))
 
-    def _prepare(self, stat, value, rate):
+    def _prepare(self, stat, value, rate, tags=None):
         if rate < 1:
             if random.random() > rate:
                 return
@@ -71,7 +87,12 b' class StatsClientBase(object):'
         if self._prefix:
             stat = '%s.%s' % (self._prefix, stat)
 
-        return '%s:%s' % (stat, value)
+        res = '%s:%s%s' % (
+            stat,
+            value,
+            ("|#" + ",".join(normalize_tags(tags))) if tags else "",
+        )
+        return res
 
     def _after(self, data):
         if data:

vcsserver/lib/_vendor/statsd/timer.py

@@ -21,10 +21,11 b' def safe_wraps(wrapper, *args, **kwargs)'
 class Timer(object):
     """A context manager/decorator for statsd.timing()."""
 
-    def __init__(self, client, stat, rate=1):
+    def __init__(self, client, stat, rate=1, tags=None):
         self.client = client
         self.stat = stat
         self.rate = rate
+        self.tags = tags
         self.ms = None
         self._sent = False
         self._start_time = None
@@ -38,7 +39,7 b' class Timer(object):'
                 return f(*args, **kwargs)
             finally:
                 elapsed_time_ms = 1000.0 * (time_now() - start_time)
-                self.client.timing(self.stat, elapsed_time_ms, self.rate)
+                self.client.timing(self.stat, elapsed_time_ms, self.rate, self.tags)
         return _wrapped
 
     def __enter__(self):

vcsserver/tweens/request_wrapper.py

@@ -25,9 +25,9 b' from vcsserver.utils import safe_str'
 log = logging.getLogger(__name__)
 
 
-def get_access_path(request):
-    environ = request.environ
-    return environ.get('PATH_INFO')
+def get_access_path(environ):
+    path = environ.get('PATH_INFO')
+    return path
 
 
 def get_user_agent(environ):
@@ -49,18 +49,28 b' class RequestWrapperTween(object):'
         finally:
             count = request.request_count()
             _ver_ = vcsserver.__version__
-            statsd = request.statsd
+            _path = safe_str(get_access_path(request.environ))
+
             total = time.time() - start
-            if statsd:
-                statsd.timing('vcsserver.req.timing', total)
-                statsd.incr('vcsserver.req.count')
             log.info(
                 'Req[%4s] IP: %s %s Request to %s time: %.4fs [%s], VCSServer %s',
                 count, '127.0.0.1', request.environ.get('REQUEST_METHOD'),
-                safe_str(get_access_path(request)), total,
-                get_user_agent(request.environ), _ver_
+                _path, total, get_user_agent(request.environ), _ver_
             )
 
+            statsd = request.registry.statsd
+            if statsd:
+                elapsed_time_ms = 1000.0 * total
+                statsd.timing(
+                    'vcsserver_req_timing', elapsed_time_ms,
+                    tags=[
+                        "path:{}".format(_path),
+                    ]
+                )
+                statsd.incr(
+                    'vcsserver_req_count', tags=[
+                        "path:{}".format(_path),
+                    ])
         return response