metrics: create framework for metric event gathering

Here I introduce some scaffolding for recording metrics events. This
data is aggregated and plumbed back through the Build API interface's
response protobufs. Currently only InstallPackagesResponse is hooked up.

The plan is to begin exploring this data via Analysis service, then
pivot as necessary towards finding ways to analyze, monitor and alert on
it.

BUG=chromium:989179
TEST=manual testing with api/contrib/call_scripts/sysroot__install_packages

Change-Id: I69fcd43112ffb5c6ab34eb584ec28ccd655914ce
Reviewed-on: https://chromium-review.googlesource.com/c/chromiumos/chromite/+/1727269
Tested-by: Will Bradley <wbbradley@chromium.org>
Reviewed-by: Alex Klein <saklein@chromium.org>
Commit-Queue: Will Bradley <wbbradley@chromium.org>
diff --git a/api/metrics.py b/api/metrics.py
new file mode 100644
index 0000000..b092949
--- /dev/null
+++ b/api/metrics.py
@@ -0,0 +1,60 @@
+# -*- coding: utf-8 -*-
+# Copyright 2019 The Chromium OS Authors. All rights reserved.
+# Use of this source code is governed by a BSD-style license that can be
+# found in the LICENSE file.
+
+"""Metrics for general consumption.
+
+See infra/proto/metrics.proto for a description of the type of record that this
+module will be creating.
+"""
+
+from __future__ import print_function
+
+from chromite.utils import metrics
+
+
+def deserialize_metrics_log(output_events, prefix=None):
+  """Read the current metrics events, adding to output_events.
+
+  This layer facilitates converting between the internal
+  chromite.utils.metrics representation of metric events and the
+  infra/proto/src/chromiumos/metrics.proto output type.
+
+  Args:
+    output_events: A chromiumos.MetricEvent protobuf message.
+    prefix: A string to prepend to all metric event names.
+  """
+  timers = {}
+
+  def make_name(name):
+    """Prepend a closed-over prefix to the given name."""
+    if prefix:
+      return '%s.%s' % (prefix, name)
+    else:
+      return name
+
+  # Reduce over the input events to append output_events.
+  for input_event in metrics.read_metrics_events():
+    if input_event.op == metrics.OP_START_TIMER:
+      timers[input_event.key] = (input_event.name,
+                                 input_event.timestamp_epoch_millis)
+    elif input_event.op == metrics.OP_STOP_TIMER:
+      timer = timers.pop(input_event.key)
+      if timer:
+        assert input_event.name == timer[0]
+        output_event = output_events.add()
+        output_event.name = make_name(timer[0])
+        output_event.timestamp_milliseconds = input_event.timestamp_epoch_millis
+        output_event.duration_milliseconds = (
+            output_event.timestamp_milliseconds - timer[1])
+    elif input_event.op == metrics.OP_NAMED_EVENT:
+      output_event = output_events.add()
+      output_event.name = make_name(input_event.name)
+      output_event.timestamp_milliseconds = input_event.timestamp_epoch_millis
+    else:
+      raise ValueError('unexpected op "%s" found in metric event: %s' % (
+          input_event.op, input_event))
+
+  # This is a sanity-check for unclosed timers.
+  assert len(timers.values()) == 0