Add StatsReporter for reporting of runtime monitoring stats

Summary:
For monitoring/alerting/debugging, we should be able to report runtime stats
cheaply; this adds a simple Stats class for reporting to statsd, along with
StatsReporter for app-specific setup.
I've also included a few sample uses; not necessarily high value, but illustrative.
Happy to remove those if we think they should be added later or not at all.

Test Plan: Manual; open to suggestions.

Reviewers: ar, vishal

Reviewed By: ar, vishal

Subscribers: cf, wwu

Projects: #changes, #changes-stability

Differential Revision: https://tails.corp.dropbox.com/D84470

changes/api/build_index.py

@@ -11,7 +11,7 @@
 
 from changes.api.base import APIView, error
 from changes.api.validators.author import AuthorValidator
-from changes.config import db
+from changes.config import db, statsreporter
 from changes.constants import Result, Status, ProjectStatus
 from changes.db.utils import get_or_create
 from changes.jobs.create_job import create_job
@@ -123,6 +123,8 @@ def create_build(project, collection_id, label, target, message, author,
                 'data': source_data or {},
             })
 
+    statsreporter.stats().incr('new_api_build')
+
     build = Build(
         project=project,
         project_id=project.id,

changes/config.py

@@ -20,6 +20,7 @@
 from changes.api.controller import APIController, APICatchall
 from changes.ext.celery import Celery
 from changes.ext.redis import Redis
+from changes.ext.statsreporter import StatsReporter
 from changes.url_converters.uuid import UUIDConverter
 
 # because foo.in_([]) ever executing is a bad idea
@@ -55,6 +56,7 @@ def process_response(self, response):
 mail = Mail()
 queue = Celery()
 redis = Redis()
+statsreporter = StatsReporter()
 sentry = Sentry(logging=True, level=logging.WARN)
 
 
@@ -250,6 +252,8 @@ def capture_user(*args, **kwargs):
     mail.init_app(app)
     queue.init_app(app)
     redis.init_app(app)
+    statsreporter.init_app(app)
+
     configure_debug_toolbar(app)
 
     from raven.contrib.celery import register_signal, register_logger_signal

changes/ext/statsreporter.py

@@ -0,0 +1,103 @@
+import statsd
+import re
+import logging
+
+logger = logging.getLogger('statsreporter')
+
+
+def swallow_exceptions(exn_logger):
+    """Decorator to catch, log, and discard any Exceptions raised in a method.
+    :param exn_logger: logging.Logger to use for logging any exceptions.
+    """
+    def decor(func):
+        def wrapper(*args, **kwargs):
+            try:
+                return func(*args, **kwargs)
+            except Exception as e:
+                exn_logger.exception(e)
+        return wrapper
+    return decor
+
+
+class StatsReporter(object):
+    """StatsReporter is responsible for maintaining an app-specific Stats instance.
+    The app config should specify:
+       STATSD_HOST (address of statsd host as a string)
+       STATSD_PORT (port statsd is listening on as an int)
+       STATSD_PREFIX (string to be automatically prepended to all reported stats for namespacing)
+
+    If STATSD_HOST isn't specified, none of the others will be used and this app will
+    get a no-op Stats instance.
+    """
+    def __init__(self, app=None):
+        self.app = app
+        self._stats = None
+        if app:
+            self.init_app(app)
+
+    def init_app(self, app):
+        if not self._stats and app.config.get('STATSD_HOST'):
+            sd = statsd.StatsClient(host=app.config['STATSD_HOST'],
+                                    prefix=app.config['STATSD_PREFIX'],
+                                    port=app.config['STATSD_PORT'])
+            self._stats = Stats(client=sd)
+
+    def stats(self):
+        """Returns a Stats object.
+        If no statsd config has been provided,
+        the Stats won't do anything but validate."""
+        if self._stats:
+            return self._stats
+        return Stats(client=None)
+
+
+class Stats(object):
+    """ Minimalistic class for sending stats/monitoring values."""
+
+    def __init__(self, client):
+        """
+        @param client - A statsd.StatsClient instance, or None for a no-op Stats.
+        """
+        # A thin wrapper around Statsd rather than just Statsd so we
+        # can pick which features to support and how to encode the data.
+        self._client = client
+
+    @swallow_exceptions(logger)
+    def set_gauge(self, key, value):
+        """ Set a gauge, typically a sampled instantaneous value.
+            @param key - the name of the gauge.
+            @param value - current value of the gauge.
+        """
+        assert isinstance(value, (int, float, long))
+        Stats._check_key(key)
+        if self._client:
+            self._client.gauge(key, value)
+
+    @swallow_exceptions(logger)
+    def incr(self, key, delta=1):
+        """ Increment a count.
+            @param key - the name of the stat.
+            @param delta - amount to increment the stat by. Must be positive.
+        """
+        assert isinstance(delta, (int, float, long))
+        assert delta >= 0
+        Stats._check_key(key)
+        if self._client:
+            self._client.incr(key, delta)
+
+    @swallow_exceptions(logger)
+    def log_timing(self, key, duration_ms):
+        """ Record a millisecond timing. """
+        assert isinstance(duration_ms, (int, float, long))
+        Stats._check_key(key)
+        if self._client:
+            self._client.timing(key, duration_ms)
+
+    _KEY_RE = re.compile(r'^[A-Za-z0-9_-]+$')
+
+    @classmethod
+    def _check_key(cls, key):
+        """ This is probably overly strict, but we have little use for
+        interestingly named keys and this avoids unintentionally using them."""
+        if not cls._KEY_RE.match(key):
+            raise Exception("Invalid key: {}".format(repr(key)))

changes/jobs/sync_build.py

@@ -2,7 +2,7 @@
 from flask import current_app
 from sqlalchemy.sql import func
 
-from changes.config import db, queue
+from changes.config import db, queue, statsreporter
 from changes.constants import Result, Status
 from changes.db.utils import try_create
 from changes.jobs.signals import fire_signal
@@ -40,6 +40,10 @@ def abort_build(task):
     current_app.logger.exception('Unrecoverable exception syncing build %s', build.id)
 
 
+def _timedelta_to_millis(td):
+    return int(td.total_seconds() * 1000)
+
+
 @tracked_task(on_abort=abort_build)
 def sync_build(build_id):
     """
@@ -66,17 +70,24 @@ def sync_build(build_id):
     if any(p.status != Status.finished for p in all_jobs):
         is_finished = False
 
+    prev_started = build.date_started
     build.date_started = safe_agg(
         min, (j.date_started for j in all_jobs if j.date_started))
 
+    # We want to report how long we waited for the build to start once and only once,
+    # so we do it at the transition from not started to started.
+    if not prev_started and build.date_started:
+        queued_time = build.date_started - build.date_created
+        statsreporter.stats().log_timing('build_start_latency', _timedelta_to_millis(queued_time))
+
     if is_finished:
         build.date_finished = safe_agg(
             max, (j.date_finished for j in all_jobs if j.date_finished))
     else:
         build.date_finished = None
 
     if build.date_started and build.date_finished:
-        build.duration = int((build.date_finished - build.date_started).total_seconds() * 1000)
+        build.duration = _timedelta_to_millis(build.date_finished - build.date_started)
     else:
         build.duration = None
 

changes/web/index.py

@@ -1,12 +1,14 @@
 import changes
 import urlparse
 
+from changes.config import statsreporter
 from flask import render_template, current_app
 from flask.views import MethodView
 
 
 class IndexView(MethodView):
     def get(self, path=''):
+        statsreporter.stats().incr('homepage_view')
         if current_app.config['SENTRY_DSN'] and False:
             parsed = urlparse.urlparse(current_app.config['SENTRY_DSN'])
             dsn = '%s://%s@%s/%s' % (

setup.py

@@ -53,6 +53,7 @@
     'simplejson>=3.3.0,<3.4.0',
     'sqlalchemy==0.9.4',
     'statprof',
+    'statsd==3.0.1',
     'toronado==0.0.4',
     'uwsgi>=2.0.4,<2.1.0',
 ]