buildbucket: add monitoring using ts_mon

appengine/cr-buildbucket/metrics.py

Index: appengine/cr-buildbucket/metrics.py
diff --git a/appengine/cr-buildbucket/metrics.py b/appengine/cr-buildbucket/metrics.py
index 3473d984961b11b00f2ecb7f29d821a15570f834..5f63c359896b3c2e9f8d7020501d8ee8c3804dcf 100644
--- a/appengine/cr-buildbucket/metrics.py
+++ b/appengine/cr-buildbucket/metrics.py
@@ -3,14 +3,20 @@
 # found in the LICENSE file.
 
 import logging
+
+from google.appengine.api import app_identity
 from google.appengine.ext import ndb
 
 from components import metrics
 from components import utils
+import gae_ts_mon
 
 import config
 import model
 
+# TODO(nodir): remove Cloud Monitoring and refactor
+# when gae_ts_mon is stabilized
+
 LABEL_BUCKET = 'buildbucket/bucket'
 COMMON_LABELS = {
   LABEL_BUCKET: 'Bucket'
@@ -43,10 +49,102 @@ METRIC_SCHEDULING_LATENCY = metrics.Descriptor(
   labels=COMMON_LABELS,
 )
 
+# gae_ts_mon
+FIELD_BUCKET = 'bucket'
+COMMON_FIELDS = {
+  'buildbucket_hostname': app_identity.get_default_version_hostname(),
+}
+
+
+def _def_metric(metric_type, name, description):
+  return metric_type(
+    '/buildbucket/%s' % name,

[Sergey Berezin, 2015/12/17 00:08:01]

Remove the leading slash: just 'buildbucket/%s'.

[nodir, 2015/12/17 01:28:54]

Done.

+    fields=COMMON_FIELDS,
+    description=description)
+
+
+CREATE_COUNT = _def_metric(
+  gae_ts_mon.CounterMetric,
+  'created',

[Sergey Berezin, 2015/12/17 00:08:01]

nit: I'd make the metric name more descriptive, e.g. 'builds/created'. Similarly
below.

[nodir, 2015/12/17 01:28:54]

Done

+  'Build creation',
+)
+START_COUNT = _def_metric(
+  gae_ts_mon.CounterMetric,
+  'started',
+  'Build start',
+)
+COMPLETE_COUNT = _def_metric(
+  gae_ts_mon.CounterMetric,
+  'completed',
+  'Build completion, including success, failure and cancellation'
+)
+HEARTBEAT_FAILURE_COUNT = _def_metric(
+  gae_ts_mon.CounterMetric,
+  'heartbeat_failures',
+  'Failures to extend a build lease'
+)
+LEASE_COUNT = _def_metric(
+  gae_ts_mon.CounterMetric,
+  'leases',
+  'Successful build lease extension',
+)
+LEASE_EXPIRATION_COUNT = _def_metric(
+  gae_ts_mon.CounterMetric,
+  'lease_expired',
+  'Build lease expirations'
+)
+CURRENTLY_PENDING = _def_metric(
+  gae_ts_mon.GaugeMetric,
+  'pending',
+  'Number of pending builds',
+)
+CURRENTLY_RUNNING = _def_metric(
+  gae_ts_mon.GaugeMetric,
+  'running',
+  'Number of running builds'
+)
+LEASE_LATENCY = _def_metric(
+  gae_ts_mon.NonCumulativeDistributionMetric,

[Sergey Berezin, 2015/12/17 00:08:01]

I think this should be CumulativeDistributionMetric, since you want to measure
it at the moment the build is leased, so it becomes an event.

[nodir, 2015/12/17 01:28:54]

FWIU, you are suggesting to do

LEASE_LATENCY.add(now - created, {'bucket': 'master.x'})

the moment a build is leased.

However, imagine that something happened with buildbot and it stopped leasing
entirely. Events don't fire and thus graphs do not indicate a problem, until the
moment buildbot is back again. The moment leasing resumes we notice that it is
huge, but we want to notice it the moment leasing stopped.

[Sergey Berezin, 2015/12/17 02:30:18]

It's a valid point; e.g. CQ measures both completed attempt times (cumulative)
and time currently in CQ (non-cumulative), just for that reason.

In this case, the name and description of the metric suggests it's an actual
latency (time delta between two events), which is a cumulative measurement taken
at lease time. I'd add both builds/lease_latency (cumulative) and
builds/pending_time (or something like that - non-cumulative).

Similarly for builds/scheduling_latency - the word "latency" implies something
completed, not still waiting. The description also doesn't make it clear.

In CQ, these metrics are named pending_attempts/durations and
completed_attempts/durations, making it less ambiguous. 

[nodir, 2015/12/17 03:19:56]

Renamed to never_leased_duration and scheduling_duration

+  'lease_latency',
+  'Duration between a build is created and it is leased for the first time',
+)
+SCHEDULING_LATENCY = _def_metric(
+  gae_ts_mon.NonCumulativeDistributionMetric,
+  'scheduling_latency',
+  'Duration of a build being in SCHEDULED state',
+)
+
+
+GAUGE_OF_CLOUD_METRIC = {
+  METRIC_PENDING_BUILDS: CURRENTLY_PENDING,
+  METRIC_RUNNING_BUILDS: CURRENTLY_RUNNING,
+}
+DISTRIBUTION_OF_CLOUD_METRIC = {
+  METRIC_LEASE_BUILD_LATENCY: LEASE_LATENCY,
+  METRIC_SCHEDULING_LATENCY: SCHEDULING_LATENCY,
+}
+
+
+def increment(metric, build, **fields):
+  fields = {
+    k: str(v)
+    for k, v in fields.iteritems()
+    if v is not None

[Sergey Berezin, 2015/12/17 00:08:01]

Don't skip fields dynamically. ts_mon requires all fields to be present in the
metric for all points, globally. Otherwise inconsistent metrics will be
rejected. If needed, assign None, empty string or 0 to the field as appropriate.

[nodir, 2015/12/17 01:28:54]

Done.

+  }
+  fields.setdefault(FIELD_BUCKET, build.bucket if build else '<no bucket>')
+  if build:
+    for t in build.tags:
+      k, v = t.split(':', 1)
+      fields.setdefault('tag_%s' % k, v)

[Sergey Berezin, 2015/12/17 00:08:01]

How many different tags are there? Just checking that they are not dynamically
generated. If they are, we can't have them as a field, since they'll create too
many streams per metric.

[nodir, 2015/12/17 01:28:54]

made them static

+  metric.increment(fields)
+
 
 def set_gauge(buf, bucket, metric, value):
   logging.info('Bucket %s: %s = %d', bucket, metric.name, value)
   buf.set_gauge(metric, value, {LABEL_BUCKET: bucket})
+  gae_ts_mon_metric = GAUGE_OF_CLOUD_METRIC.get(metric)
+  if gae_ts_mon_metric:
+    gae_ts_mon_metric.set(value, {FIELD_BUCKET: bucket})
 
 
 @ndb.tasklet
@@ -73,12 +171,16 @@ def send_build_latency(buf, metric, bucket, must_be_never_leased):
   now = utils.utcnow()
   avg_latency = 0.0
   count = 0
+  dist = gae_ts_mon.Distribution(gae_ts_mon.GeometricBucketer())
   for e in q.iter(projection=[model.Build.create_time]):
-    avg_latency += (now - e.create_time).total_seconds()
+    latency = (now - e.create_time).total_seconds()
+    dist.add(latency)
+    avg_latency += latency
     count += 1
   if count > 0:
     avg_latency /= count
   set_gauge(buf, bucket, metric, avg_latency)
+  DISTRIBUTION_OF_CLOUD_METRIC[metric].set(dist, {FIELD_BUCKET: bucket})
 
 
 def send_all_metrics():