buildbucket: add monitoring using ts_mon

buildbucket: add monitoring using ts_mon

Monitor the following metrics per bucket:
* per builder and user_agent:
  * # of pending and running builds
  * rate of build starts
  * rate of heartbeat failures
  * rate of lease expirations
  * per build result, failure reason, cancelation reason:
    * rate of build completions
* distribution of durations of first build lease
* distribution of durations of build remaining in SCHEDULED state

Send metrics and log only after a transaction succeeds.

Leave Cloud Monitoring for now.

R=sergeyberezin@chromium.org
BUG=559500
Committed: https://chromium.googlesource.com/infra/infra/+/2322647e9b17e2025a5af0e6ffe1a6b475f2e6ff

[nodir, 2015-12-16 20:43:58]

Description was changed from

==========
buildbucket: add monitoring using ts_mon

Monitor the following metrics per bucket:
* per build tags:
  * # of pending and running builds
  * rate of build starts
  * rate of heartbeat failures
  * rate of lease expirations
  * per build result, failure reason, cancelation reason:
    * rate of build completions
* distribution of durations of first build lease
* distribution of durations of build remaining in SCHEDULED state

Note that build tags include builder and user-agent (cq, git-cl-try,
rietveld).

R=sergeyberezin@chromium.org
BUG=559500
==========

to

==========
buildbucket: add monitoring using ts_mon

Monitor the following metrics per bucket:
* per build tags:
  * # of pending and running builds
  * rate of build starts
  * rate of heartbeat failures
  * rate of lease expirations
  * per build result, failure reason, cancelation reason:
    * rate of build completions
* distribution of durations of first build lease
* distribution of durations of build remaining in SCHEDULED state

Note that build tags include builder and user-agent (cq, git-cl-try,
rietveld).

Leave Cloud Monitoring for now.

R=sergeyberezin@chromium.org
BUG=559500
==========

[nodir, 2015-12-16 22:30:07]

Description was changed from

==========
buildbucket: add monitoring using ts_mon

Monitor the following metrics per bucket:
* per build tags:
  * # of pending and running builds
  * rate of build starts
  * rate of heartbeat failures
  * rate of lease expirations
  * per build result, failure reason, cancelation reason:
    * rate of build completions
* distribution of durations of first build lease
* distribution of durations of build remaining in SCHEDULED state

Note that build tags include builder and user-agent (cq, git-cl-try,
rietveld).

Leave Cloud Monitoring for now.

R=sergeyberezin@chromium.org
BUG=559500
==========

to

==========
buildbucket: add monitoring using ts_mon

Monitor the following metrics per bucket:
* per build tags:
  * # of pending and running builds
  * rate of build starts
  * rate of heartbeat failures
  * rate of lease expirations
  * per build result, failure reason, cancelation reason:
    * rate of build completions
* distribution of durations of first build lease
* distribution of durations of build remaining in SCHEDULED state

Note that build tags include builder and user-agent (cq, git-cl-try,
rietveld).

Leave Cloud Monitoring for now.

Send metrics and log only after a transaction succeeds.

R=sergeyberezin@chromium.org
BUG=559500
==========

[nodir, 2015-12-16 22:36:47]

Patchset #2 (id:20001) has been deleted

[nodir, 2015-12-16 22:36:53]

Patchset #1 (id:1) has been deleted

[nodir, 2015-12-16 22:37:02]

PTAL

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

Overall it's mostly good, just a few comments.

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
File appengine/cr-buildbucket/metrics.py (right):

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/metrics.py:61: '/buildbucket/%s' % name,
Remove the leading slash: just 'buildbucket/%s'.

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/metrics.py:68: 'created',
nit: I'd make the metric name more descriptive, e.g. 'builds/created'. Similarly
below.

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/metrics.py:107:
gae_ts_mon.NonCumulativeDistributionMetric,
I think this should be CumulativeDistributionMetric, since you want to measure
it at the moment the build is leased, so it becomes an event.

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/metrics.py:132: if v is not None
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.

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/metrics.py:138: fields.setdefault('tag_%s' % k, v)
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.

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
File appengine/cr-buildbucket/service.py (right):

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/service.py:479: def txn():
nit: spell out (transaction?)

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/service.py:538:
metrics.increment(metrics.HEARTBEAT_FAILURE_COUNT, build)
nit: as an option, you might consider counting all heartbeats, distinguishing
them by a 'status' field ('failed' or 'succeeded'). As a bonus, you'd be able to
track heartbeat failure rate, not just the raw count.

[nodir, 2015-12-17 01:28:55]

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
File appengine/cr-buildbucket/metrics.py (right):

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/metrics.py:61: '/buildbucket/%s' % name,
On 2015/12/17 00:08:01, Sergey Berezin wrote:
> Remove the leading slash: just 'buildbucket/%s'.

Done.

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/metrics.py:68: 'created',
On 2015/12/17 00:08:01, Sergey Berezin wrote:
> nit: I'd make the metric name more descriptive, e.g. 'builds/created'.
Similarly
> below.

Done

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/metrics.py:107:
gae_ts_mon.NonCumulativeDistributionMetric,
On 2015/12/17 00:08:01, Sergey Berezin wrote:
> I think this should be CumulativeDistributionMetric, since you want to measure
> it at the moment the build is leased, so it becomes an event.

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.

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/metrics.py:132: if v is not None
On 2015/12/17 00:08:01, Sergey Berezin wrote:
> 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.

Done.

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/metrics.py:138: fields.setdefault('tag_%s' % k, v)
On 2015/12/17 00:08:01, Sergey Berezin wrote:
> 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.

made them static

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
File appengine/cr-buildbucket/service.py (right):

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/service.py:479: def txn():
On 2015/12/17 00:08:01, Sergey Berezin wrote:
> nit: spell out (transaction?)

txn is kind of standard, I see it a lot in code by maruel and vadimsh

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/service.py:538:
metrics.increment(metrics.HEARTBEAT_FAILURE_COUNT, build)
On 2015/12/17 00:08:01, Sergey Berezin wrote:
> nit: as an option, you might consider counting all heartbeats, distinguishing
> them by a 'status' field ('failed' or 'succeeded'). As a bonus, you'd be able
to
> track heartbeat failure rate, not just the raw count.

hearbeats are sent in batches and heartbeat_async is called many times per
request. Are you sure metrics.increment won't try to persist state to memcache
(synchronously)? Reading gae_ts_mon code [1] it seems it will try to persist it
right away, so I hesitate.

[1]:
https://code.google.com/p/chromium/codesearch#chromium/infra/appengine_module...

[nodir, 2015-12-17 01:34:40]

Description was changed from

==========
buildbucket: add monitoring using ts_mon

Monitor the following metrics per bucket:
* per build tags:
  * # of pending and running builds
  * rate of build starts
  * rate of heartbeat failures
  * rate of lease expirations
  * per build result, failure reason, cancelation reason:
    * rate of build completions
* distribution of durations of first build lease
* distribution of durations of build remaining in SCHEDULED state

Note that build tags include builder and user-agent (cq, git-cl-try,
rietveld).

Leave Cloud Monitoring for now.

Send metrics and log only after a transaction succeeds.

R=sergeyberezin@chromium.org
BUG=559500
==========

to

==========
buildbucket: add monitoring using ts_mon

Monitor the following metrics per bucket:
* per builder and user_agent:
  * # of pending and running builds
  * rate of build starts
  * rate of heartbeat failures
  * rate of lease expirations
  * per build result, failure reason, cancelation reason:
    * rate of build completions
* distribution of durations of first build lease
* distribution of durations of build remaining in SCHEDULED state

Send metrics and log only after a transaction succeeds.

Leave Cloud Monitoring for now.

R=sergeyberezin@chromium.org
BUG=559500
==========

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

LGTM to unblock the CL + some more responses. Even as is, this is better than no
monitoring, and we can polish it up later. Thanks!

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
File appengine/cr-buildbucket/metrics.py (right):

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/metrics.py:107:
gae_ts_mon.NonCumulativeDistributionMetric,
On 2015/12/17 01:28:54, nodir wrote:
> On 2015/12/17 00:08:01, Sergey Berezin wrote:
> > I think this should be CumulativeDistributionMetric, since you want to
measure
> > it at the moment the build is leased, so it becomes an event.
> 
> 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.

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.

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
File appengine/cr-buildbucket/service.py (right):

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/service.py:479: def txn():
On 2015/12/17 01:28:54, nodir wrote:
> On 2015/12/17 00:08:01, Sergey Berezin wrote:
> > nit: spell out (transaction?)
> 
> txn is kind of standard, I see it a lot in code by maruel and vadimsh

Acknowledged.

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/service.py:538:
metrics.increment(metrics.HEARTBEAT_FAILURE_COUNT, build)
On 2015/12/17 01:28:54, nodir wrote:
> On 2015/12/17 00:08:01, Sergey Berezin wrote:
> > nit: as an option, you might consider counting all heartbeats,
distinguishing
> > them by a 'status' field ('failed' or 'succeeded'). As a bonus, you'd be
able
> to
> > track heartbeat failure rate, not just the raw count.
> 
> hearbeats are sent in batches and heartbeat_async is called many times per
> request. Are you sure metrics.increment won't try to persist state to memcache
> (synchronously)? Reading gae_ts_mon code [1] it seems it will try to persist
it
> right away, so I hesitate.
> 
> [1]:
>
https://code.google.com/p/chromium/codesearch#chromium/infra/appengine_module...

If DeferredMetricStore is not initialized (as is the case for Cloud Endpoints
handler), it may indeed send metrics to memcache synchronously. This will surely
be fixed once we add support for Cloud Endpoints. Meanwhile, I suppose we can
just report failures. But you can still define the metric with a status field,
and add all heartbeats later, assuming my initial comment actually makes sense
for it.

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

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
File appengine/cr-buildbucket/metrics.py (right):

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/metrics.py:107:
gae_ts_mon.NonCumulativeDistributionMetric,
On 2015/12/17 02:30:18, Sergey Berezin wrote:
> On 2015/12/17 01:28:54, nodir wrote:
> > On 2015/12/17 00:08:01, Sergey Berezin wrote:
> > > I think this should be CumulativeDistributionMetric, since you want to
> measure
> > > it at the moment the build is leased, so it becomes an event.
> > 
> > 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.
> 
> 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. 

Renamed to never_leased_duration and scheduling_duration

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
File appengine/cr-buildbucket/service.py (right):

https://codereview.chromium.org/1532713002/diff/40001/appengine/cr-buildbucke...
appengine/cr-buildbucket/service.py:538:
metrics.increment(metrics.HEARTBEAT_FAILURE_COUNT, build)
On 2015/12/17 02:30:18, Sergey Berezin wrote:
> On 2015/12/17 01:28:54, nodir wrote:
> > On 2015/12/17 00:08:01, Sergey Berezin wrote:
> > > nit: as an option, you might consider counting all heartbeats,
> distinguishing
> > > them by a 'status' field ('failed' or 'succeeded'). As a bonus, you'd be
> able
> > to
> > > track heartbeat failure rate, not just the raw count.
> > 
> > hearbeats are sent in batches and heartbeat_async is called many times per
> > request. Are you sure metrics.increment won't try to persist state to
memcache
> > (synchronously)? Reading gae_ts_mon code [1] it seems it will try to persist
> it
> > right away, so I hesitate.
> > 
> > [1]:
> >
>
https://code.google.com/p/chromium/codesearch#chromium/infra/appengine_module...
> 
> If DeferredMetricStore is not initialized (as is the case for Cloud Endpoints
> handler), it may indeed send metrics to memcache synchronously. This will
surely
> be fixed once we add support for Cloud Endpoints. Meanwhile, I suppose we can
> just report failures. But you can still define the metric with a status field,
> and add all heartbeats later, assuming my initial comment actually makes sense
> for it.

Done.

[nodir, 2015-12-17 03:20:01]

The CQ bit was checked by nodir@chromium.org

[nodir, 2015-12-17 03:20:01]

The patchset sent to the CQ was uploaded after l-g-t-m from
sergeyberezin@chromium.org
Link to the patchset: https://codereview.chromium.org/1532713002/#ps80001
(title: "duration")

[commit-bot: I haz the power, 2015-12-17 03:20:11]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1532713002/80001
View timeline at
 https://chromium-cq-status.appspot.com/patch-timeline/1532713002/80001

[commit-bot: I haz the power, 2015-12-17 03:22:51]

Description was changed from

==========
buildbucket: add monitoring using ts_mon

Monitor the following metrics per bucket:
* per builder and user_agent:
  * # of pending and running builds
  * rate of build starts
  * rate of heartbeat failures
  * rate of lease expirations
  * per build result, failure reason, cancelation reason:
    * rate of build completions
* distribution of durations of first build lease
* distribution of durations of build remaining in SCHEDULED state

Send metrics and log only after a transaction succeeds.

Leave Cloud Monitoring for now.

R=sergeyberezin@chromium.org
BUG=559500
==========

to

==========
buildbucket: add monitoring using ts_mon

Monitor the following metrics per bucket:
* per builder and user_agent:
  * # of pending and running builds
  * rate of build starts
  * rate of heartbeat failures
  * rate of lease expirations
  * per build result, failure reason, cancelation reason:
    * rate of build completions
* distribution of durations of first build lease
* distribution of durations of build remaining in SCHEDULED state

Send metrics and log only after a transaction succeeds.

Leave Cloud Monitoring for now.

R=sergeyberezin@chromium.org
BUG=559500

Committed:
https://chromium.googlesource.com/infra/infra/+/2322647e9b17e2025a5af0e6ffe1a...
==========

[commit-bot: I haz the power, 2015-12-17 03:22:52]

Committed patchset #3 (id:80001) as
https://chromium.googlesource.com/infra/infra/+/2322647e9b17e2025a5af0e6ffe1a...