1*9c5db199SXin Li# -*- coding: utf-8 -*- 2*9c5db199SXin Li# Copyright 2016 The Chromium OS Authors. All rights reserved. 3*9c5db199SXin Li# Use of this source code is governed by a BSD-style license that can be 4*9c5db199SXin Li# found in the LICENSE file. 5*9c5db199SXin Li 6*9c5db199SXin Li"""Wrapper library around ts_mon. 7*9c5db199SXin Li 8*9c5db199SXin LiThis library provides some wrapper functionality around ts_mon, to make it more 9*9c5db199SXin Lifriendly to developers. It also provides import safety, in case ts_mon is not 10*9c5db199SXin Lideployed with your code. 11*9c5db199SXin Li""" 12*9c5db199SXin Li 13*9c5db199SXin Lifrom __future__ import division 14*9c5db199SXin Lifrom __future__ import print_function 15*9c5db199SXin Li 16*9c5db199SXin Liimport collections 17*9c5db199SXin Liimport contextlib 18*9c5db199SXin Liimport ssl 19*9c5db199SXin Liimport time 20*9c5db199SXin Lifrom functools import wraps 21*9c5db199SXin Li 22*9c5db199SXin Liimport six 23*9c5db199SXin Lifrom six.moves import queue as Queue 24*9c5db199SXin Li 25*9c5db199SXin Lifrom autotest_lib.utils.frozen_chromite.lib import cros_logging as logging 26*9c5db199SXin Li 27*9c5db199SXin Litry: 28*9c5db199SXin Li from infra_libs import ts_mon 29*9c5db199SXin Liexcept (ImportError, RuntimeError): 30*9c5db199SXin Li ts_mon = None 31*9c5db199SXin Li 32*9c5db199SXin Li 33*9c5db199SXin Li# This number is chosen because 1.16^100 seconds is about 34*9c5db199SXin Li# 32 days. This is a good compromise between bucket size 35*9c5db199SXin Li# and dynamic range. 36*9c5db199SXin Li_SECONDS_BUCKET_FACTOR = 1.16 37*9c5db199SXin Li 38*9c5db199SXin Li# If none, we create metrics in this process. Otherwise, we send metrics via 39*9c5db199SXin Li# this Queue to a dedicated flushing processes. 40*9c5db199SXin Li# These attributes are set by chromite.lib.ts_mon_config.SetupTsMonGlobalState. 41*9c5db199SXin LiFLUSHING_PROCESS = None 42*9c5db199SXin LiMESSAGE_QUEUE = None 43*9c5db199SXin Li 44*9c5db199SXin Li_MISSING = object() 45*9c5db199SXin Li 46*9c5db199SXin LiMetricCall = collections.namedtuple('MetricCall', [ 47*9c5db199SXin Li 'metric_name', 'metric_args', 'metric_kwargs', 48*9c5db199SXin Li 'method', 'method_args', 'method_kwargs', 49*9c5db199SXin Li 'reset_after' 50*9c5db199SXin Li]) 51*9c5db199SXin Li 52*9c5db199SXin Li 53*9c5db199SXin Lidef _FlushingProcessClosed(): 54*9c5db199SXin Li """Returns whether the metrics flushing process has been closed.""" 55*9c5db199SXin Li return (FLUSHING_PROCESS is not None and 56*9c5db199SXin Li FLUSHING_PROCESS.exitcode is not None) 57*9c5db199SXin Li 58*9c5db199SXin Li 59*9c5db199SXin Liclass ProxyMetric(object): 60*9c5db199SXin Li """Redirects any method calls to the message queue.""" 61*9c5db199SXin Li def __init__(self, metric, metric_args, metric_kwargs): 62*9c5db199SXin Li self.metric = metric 63*9c5db199SXin Li self.metric_args = metric_args 64*9c5db199SXin Li self.reset_after = metric_kwargs.pop('reset_after', False) 65*9c5db199SXin Li self.metric_kwargs = metric_kwargs 66*9c5db199SXin Li 67*9c5db199SXin Li def __getattr__(self, method_name): 68*9c5db199SXin Li """Redirects all method calls to the MESSAGE_QUEUE.""" 69*9c5db199SXin Li def enqueue(*args, **kwargs): 70*9c5db199SXin Li if not _FlushingProcessClosed(): 71*9c5db199SXin Li try: 72*9c5db199SXin Li MESSAGE_QUEUE.put_nowait( 73*9c5db199SXin Li MetricCall( 74*9c5db199SXin Li metric_name=self.metric, 75*9c5db199SXin Li metric_args=self.metric_args, 76*9c5db199SXin Li metric_kwargs=self.metric_kwargs, 77*9c5db199SXin Li method=method_name, 78*9c5db199SXin Li method_args=args, 79*9c5db199SXin Li method_kwargs=kwargs, 80*9c5db199SXin Li reset_after=self.reset_after)) 81*9c5db199SXin Li except Queue.Full: 82*9c5db199SXin Li logging.warning( 83*9c5db199SXin Li "Metrics queue is full; skipped sending metric '%s'", 84*9c5db199SXin Li self.metric) 85*9c5db199SXin Li else: 86*9c5db199SXin Li try: 87*9c5db199SXin Li exit_code = FLUSHING_PROCESS.exitcode 88*9c5db199SXin Li except AttributeError: 89*9c5db199SXin Li exit_code = None 90*9c5db199SXin Li logging.warning( 91*9c5db199SXin Li 'Flushing process has been closed (exit code %s),' 92*9c5db199SXin Li " skipped sending metric '%s'", 93*9c5db199SXin Li exit_code, 94*9c5db199SXin Li self.metric) 95*9c5db199SXin Li 96*9c5db199SXin Li return enqueue 97*9c5db199SXin Li 98*9c5db199SXin Li 99*9c5db199SXin Lidef _Indirect(fn): 100*9c5db199SXin Li """Decorates a function to be indirect If MESSAGE_QUEUE is set. 101*9c5db199SXin Li 102*9c5db199SXin Li If MESSAGE_QUEUE is set, the indirect function will return a proxy metrics 103*9c5db199SXin Li object; otherwise, it behaves normally. 104*9c5db199SXin Li """ 105*9c5db199SXin Li @wraps(fn) 106*9c5db199SXin Li def AddToQueueIfPresent(*args, **kwargs): 107*9c5db199SXin Li if MESSAGE_QUEUE: 108*9c5db199SXin Li return ProxyMetric(fn.__name__, args, kwargs) 109*9c5db199SXin Li else: 110*9c5db199SXin Li # Whether to reset the metric after the flush; this is only used by 111*9c5db199SXin Li # |ProxyMetric|, so remove this from the kwargs. 112*9c5db199SXin Li kwargs.pop('reset_after', None) 113*9c5db199SXin Li return fn(*args, **kwargs) 114*9c5db199SXin Li return AddToQueueIfPresent 115*9c5db199SXin Li 116*9c5db199SXin Li 117*9c5db199SXin Liclass MockMetric(object): 118*9c5db199SXin Li """Mock metric object, to be returned if ts_mon is not set up.""" 119*9c5db199SXin Li 120*9c5db199SXin Li def _mock_method(self, *args, **kwargs): 121*9c5db199SXin Li pass 122*9c5db199SXin Li 123*9c5db199SXin Li def __getattr__(self, _): 124*9c5db199SXin Li return self._mock_method 125*9c5db199SXin Li 126*9c5db199SXin Li 127*9c5db199SXin Lidef _ImportSafe(fn): 128*9c5db199SXin Li """Decorator which causes |fn| to return MockMetric if ts_mon not imported.""" 129*9c5db199SXin Li @wraps(fn) 130*9c5db199SXin Li def wrapper(*args, **kwargs): 131*9c5db199SXin Li if ts_mon: 132*9c5db199SXin Li return fn(*args, **kwargs) 133*9c5db199SXin Li else: 134*9c5db199SXin Li return MockMetric() 135*9c5db199SXin Li 136*9c5db199SXin Li return wrapper 137*9c5db199SXin Li 138*9c5db199SXin Li 139*9c5db199SXin Liclass FieldSpecAdapter(object): 140*9c5db199SXin Li """Infers the types of fields values to work around field_spec requirement. 141*9c5db199SXin Li 142*9c5db199SXin Li See: https://chromium-review.googlesource.com/c/432120/ for the change 143*9c5db199SXin Li which added a required field_spec argument. This class is a temporary 144*9c5db199SXin Li workaround to allow inferring the field_spec if is not provided. 145*9c5db199SXin Li """ 146*9c5db199SXin Li FIELD_CLASSES = {} if ts_mon is None else { 147*9c5db199SXin Li bool: ts_mon.BooleanField, 148*9c5db199SXin Li int: ts_mon.IntegerField, 149*9c5db199SXin Li str: ts_mon.StringField, 150*9c5db199SXin Li six.text_type: ts_mon.StringField, 151*9c5db199SXin Li } 152*9c5db199SXin Li 153*9c5db199SXin Li def __init__(self, metric_cls, *args, **kwargs): 154*9c5db199SXin Li self._metric_cls = metric_cls 155*9c5db199SXin Li self._args = args 156*9c5db199SXin Li self._kwargs = kwargs 157*9c5db199SXin Li self._instance = _MISSING 158*9c5db199SXin Li 159*9c5db199SXin Li def __getattr__(self, prop): 160*9c5db199SXin Li """Return a wrapper which constructs the metric object on demand. 161*9c5db199SXin Li 162*9c5db199SXin Li Args: 163*9c5db199SXin Li prop: The property name 164*9c5db199SXin Li 165*9c5db199SXin Li Returns: 166*9c5db199SXin Li If self._instance has been created, the instance's .|prop| property, 167*9c5db199SXin Li otherwise, a wrapper function which creates the ._instance and then 168*9c5db199SXin Li calls the |prop| method on the instance. 169*9c5db199SXin Li """ 170*9c5db199SXin Li if self._instance is not _MISSING: 171*9c5db199SXin Li return getattr(self._instance, prop) 172*9c5db199SXin Li 173*9c5db199SXin Li def func(*args, **kwargs): 174*9c5db199SXin Li if self._instance is not _MISSING: 175*9c5db199SXin Li return getattr(self._instance, prop)(*args, **kwargs) 176*9c5db199SXin Li fields = FieldSpecAdapter._InferFields(prop, args, kwargs) 177*9c5db199SXin Li self._kwargs['field_spec'] = FieldSpecAdapter._InferFieldSpec(fields) 178*9c5db199SXin Li self._instance = self._metric_cls(*self._args, **self._kwargs) 179*9c5db199SXin Li return getattr(self._instance, prop)(*args, **kwargs) 180*9c5db199SXin Li 181*9c5db199SXin Li func.__name__ = prop 182*9c5db199SXin Li return func 183*9c5db199SXin Li 184*9c5db199SXin Li @staticmethod 185*9c5db199SXin Li def _InferFields(method_name, args, kwargs): 186*9c5db199SXin Li """Infers the fields argument. 187*9c5db199SXin Li 188*9c5db199SXin Li Args: 189*9c5db199SXin Li method_name: The method called. 190*9c5db199SXin Li args: The args list 191*9c5db199SXin Li kwargs: The keyword args 192*9c5db199SXin Li """ 193*9c5db199SXin Li if 'fields' in kwargs: 194*9c5db199SXin Li return kwargs['fields'] 195*9c5db199SXin Li 196*9c5db199SXin Li if method_name == 'increment' and args: 197*9c5db199SXin Li return args[0] 198*9c5db199SXin Li 199*9c5db199SXin Li if len(args) >= 2: 200*9c5db199SXin Li return args[1] 201*9c5db199SXin Li 202*9c5db199SXin Li @staticmethod 203*9c5db199SXin Li def _InferFieldSpec(fields): 204*9c5db199SXin Li """Infers the fields types from the given fields. 205*9c5db199SXin Li 206*9c5db199SXin Li Args: 207*9c5db199SXin Li fields: A dictionary with metric fields. 208*9c5db199SXin Li """ 209*9c5db199SXin Li if not fields or not ts_mon: 210*9c5db199SXin Li return None 211*9c5db199SXin Li 212*9c5db199SXin Li return [FieldSpecAdapter.FIELD_CLASSES[type(v)](field) 213*9c5db199SXin Li for (field, v) in sorted(fields.items())] 214*9c5db199SXin Li 215*9c5db199SXin Li 216*9c5db199SXin Lidef _OptionalFieldSpec(fn): 217*9c5db199SXin Li """Decorates a function to allow an optional description and field_spec.""" 218*9c5db199SXin Li @wraps(fn) 219*9c5db199SXin Li def wrapper(*args, **kwargs): 220*9c5db199SXin Li kwargs = dict(**kwargs) # It's bad practice to mutate **kwargs 221*9c5db199SXin Li # Slightly different than .setdefault, this line sets a default even when 222*9c5db199SXin Li # the key is present (as long as the value is not truthy). Empty or None is 223*9c5db199SXin Li # not allowed for descriptions. 224*9c5db199SXin Li kwargs['description'] = kwargs.get('description') or 'No description.' 225*9c5db199SXin Li if 'field_spec' in kwargs and kwargs['field_spec'] is not _MISSING: 226*9c5db199SXin Li return fn(*args, **kwargs) 227*9c5db199SXin Li else: 228*9c5db199SXin Li return FieldSpecAdapter(fn, *args, **kwargs) 229*9c5db199SXin Li return wrapper 230*9c5db199SXin Li 231*9c5db199SXin Li 232*9c5db199SXin Lidef _Metric(fn): 233*9c5db199SXin Li """A pipeline of decorators to apply to our metric constructors.""" 234*9c5db199SXin Li return _OptionalFieldSpec(_ImportSafe(_Indirect(fn))) 235*9c5db199SXin Li 236*9c5db199SXin Li 237*9c5db199SXin Li# This is needed for the reset_after flag used by @Indirect. 238*9c5db199SXin Li# pylint: disable=unused-argument 239*9c5db199SXin Li 240*9c5db199SXin Li@_Metric 241*9c5db199SXin Lidef CounterMetric(name, reset_after=False, description=None, 242*9c5db199SXin Li field_spec=_MISSING, start_time=None): 243*9c5db199SXin Li """Returns a metric handle for a counter named |name|.""" 244*9c5db199SXin Li return ts_mon.CounterMetric(name, 245*9c5db199SXin Li description=description, field_spec=field_spec, 246*9c5db199SXin Li start_time=start_time) 247*9c5db199SXin LiCounter = CounterMetric 248*9c5db199SXin Li 249*9c5db199SXin Li 250*9c5db199SXin Li@_Metric 251*9c5db199SXin Lidef GaugeMetric(name, reset_after=False, description=None, field_spec=_MISSING): 252*9c5db199SXin Li """Returns a metric handle for a gauge named |name|.""" 253*9c5db199SXin Li return ts_mon.GaugeMetric(name, description=description, 254*9c5db199SXin Li field_spec=field_spec) 255*9c5db199SXin LiGauge = GaugeMetric 256*9c5db199SXin Li 257*9c5db199SXin Li 258*9c5db199SXin Li@_Metric 259*9c5db199SXin Lidef CumulativeMetric(name, reset_after=False, description=None, 260*9c5db199SXin Li field_spec=_MISSING): 261*9c5db199SXin Li """Returns a metric handle for a cumulative float named |name|.""" 262*9c5db199SXin Li return ts_mon.CumulativeMetric(name, description=description, 263*9c5db199SXin Li field_spec=field_spec) 264*9c5db199SXin Li 265*9c5db199SXin Li 266*9c5db199SXin Li@_Metric 267*9c5db199SXin Lidef StringMetric(name, reset_after=False, description=None, 268*9c5db199SXin Li field_spec=_MISSING): 269*9c5db199SXin Li """Returns a metric handle for a string named |name|.""" 270*9c5db199SXin Li return ts_mon.StringMetric(name, description=description, 271*9c5db199SXin Li field_spec=field_spec) 272*9c5db199SXin LiString = StringMetric 273*9c5db199SXin Li 274*9c5db199SXin Li 275*9c5db199SXin Li@_Metric 276*9c5db199SXin Lidef BooleanMetric(name, reset_after=False, description=None, 277*9c5db199SXin Li field_spec=_MISSING): 278*9c5db199SXin Li """Returns a metric handle for a boolean named |name|.""" 279*9c5db199SXin Li return ts_mon.BooleanMetric(name, description=description, 280*9c5db199SXin Li field_spec=field_spec) 281*9c5db199SXin LiBoolean = BooleanMetric 282*9c5db199SXin Li 283*9c5db199SXin Li 284*9c5db199SXin Li@_Metric 285*9c5db199SXin Lidef FloatMetric(name, reset_after=False, description=None, field_spec=_MISSING): 286*9c5db199SXin Li """Returns a metric handle for a float named |name|.""" 287*9c5db199SXin Li return ts_mon.FloatMetric(name, description=description, 288*9c5db199SXin Li field_spec=field_spec) 289*9c5db199SXin LiFloat = FloatMetric 290*9c5db199SXin Li 291*9c5db199SXin Li 292*9c5db199SXin Li@_Metric 293*9c5db199SXin Lidef CumulativeDistributionMetric(name, reset_after=False, description=None, 294*9c5db199SXin Li bucketer=None, field_spec=_MISSING): 295*9c5db199SXin Li """Returns a metric handle for a cumulative distribution named |name|.""" 296*9c5db199SXin Li return ts_mon.CumulativeDistributionMetric( 297*9c5db199SXin Li name, description=description, bucketer=bucketer, field_spec=field_spec) 298*9c5db199SXin LiCumulativeDistribution = CumulativeDistributionMetric 299*9c5db199SXin Li 300*9c5db199SXin Li 301*9c5db199SXin Li@_Metric 302*9c5db199SXin Lidef DistributionMetric(name, reset_after=False, description=None, 303*9c5db199SXin Li bucketer=None, field_spec=_MISSING): 304*9c5db199SXin Li """Returns a metric handle for a distribution named |name|.""" 305*9c5db199SXin Li return ts_mon.NonCumulativeDistributionMetric( 306*9c5db199SXin Li name, description=description, bucketer=bucketer, field_spec=field_spec) 307*9c5db199SXin LiDistribution = DistributionMetric 308*9c5db199SXin Li 309*9c5db199SXin Li 310*9c5db199SXin Li@_Metric 311*9c5db199SXin Lidef CumulativeSmallIntegerDistribution(name, reset_after=False, 312*9c5db199SXin Li description=None, field_spec=_MISSING): 313*9c5db199SXin Li """Returns a metric handle for a cumulative distribution named |name|. 314*9c5db199SXin Li 315*9c5db199SXin Li This differs slightly from CumulativeDistribution, in that the underlying 316*9c5db199SXin Li metric uses a uniform bucketer rather than a geometric one. 317*9c5db199SXin Li 318*9c5db199SXin Li This metric type is suitable for holding a distribution of numbers that are 319*9c5db199SXin Li nonnegative integers in the range of 0 to 100. 320*9c5db199SXin Li """ 321*9c5db199SXin Li return ts_mon.CumulativeDistributionMetric( 322*9c5db199SXin Li name, 323*9c5db199SXin Li bucketer=ts_mon.FixedWidthBucketer(1), 324*9c5db199SXin Li description=description, 325*9c5db199SXin Li field_spec=field_spec) 326*9c5db199SXin Li 327*9c5db199SXin Li 328*9c5db199SXin Li@_Metric 329*9c5db199SXin Lidef CumulativeSecondsDistribution(name, scale=1, reset_after=False, 330*9c5db199SXin Li description=None, field_spec=_MISSING): 331*9c5db199SXin Li """Returns a metric handle for a cumulative distribution named |name|. 332*9c5db199SXin Li 333*9c5db199SXin Li The distribution handle returned by this method is better suited than the 334*9c5db199SXin Li default one for recording handling times, in seconds. 335*9c5db199SXin Li 336*9c5db199SXin Li This metric handle has bucketing that is optimized for time intervals 337*9c5db199SXin Li (in seconds) in the range of 1 second to 32 days. Use |scale| to adjust this 338*9c5db199SXin Li (e.g. scale=0.1 covers a range from .1 seconds to 3.2 days). 339*9c5db199SXin Li 340*9c5db199SXin Li Args: 341*9c5db199SXin Li name: string name of metric 342*9c5db199SXin Li scale: scaling factor of buckets, and size of the first bucket. default: 1 343*9c5db199SXin Li reset_after: Should the metric be reset after reporting. 344*9c5db199SXin Li description: A string description of the metric. 345*9c5db199SXin Li field_spec: A sequence of ts_mon.Field objects to specify the field schema. 346*9c5db199SXin Li """ 347*9c5db199SXin Li b = ts_mon.GeometricBucketer(growth_factor=_SECONDS_BUCKET_FACTOR, 348*9c5db199SXin Li scale=scale) 349*9c5db199SXin Li return ts_mon.CumulativeDistributionMetric( 350*9c5db199SXin Li name, bucketer=b, units=ts_mon.MetricsDataUnits.SECONDS, 351*9c5db199SXin Li description=description, field_spec=field_spec) 352*9c5db199SXin Li 353*9c5db199SXin LiSecondsDistribution = CumulativeSecondsDistribution 354*9c5db199SXin Li 355*9c5db199SXin Li 356*9c5db199SXin Li@_Metric 357*9c5db199SXin Lidef PercentageDistribution( 358*9c5db199SXin Li name, num_buckets=1000, reset_after=False, 359*9c5db199SXin Li description=None, field_spec=_MISSING): 360*9c5db199SXin Li """Returns a metric handle for a cumulative distribution for percentage. 361*9c5db199SXin Li 362*9c5db199SXin Li The distribution handle returned by this method is better suited for reporting 363*9c5db199SXin Li percentage values than the default one. The bucketing is optimized for values 364*9c5db199SXin Li in [0,100]. 365*9c5db199SXin Li 366*9c5db199SXin Li Args: 367*9c5db199SXin Li name: The name of this metric. 368*9c5db199SXin Li num_buckets: This metric buckets the percentage values before 369*9c5db199SXin Li reporting. This argument controls the number of the bucket the range 370*9c5db199SXin Li [0,100] is divided in. The default gives you 0.1% resolution. 371*9c5db199SXin Li reset_after: Should the metric be reset after reporting. 372*9c5db199SXin Li description: A string description of the metric. 373*9c5db199SXin Li field_spec: A sequence of ts_mon.Field objects to specify the field schema. 374*9c5db199SXin Li """ 375*9c5db199SXin Li # The last bucket actually covers [100, 100 + 1.0/num_buckets), so it 376*9c5db199SXin Li # corresponds to values that exactly match 100%. 377*9c5db199SXin Li bucket_width = 100 / num_buckets 378*9c5db199SXin Li b = ts_mon.FixedWidthBucketer(bucket_width, num_buckets) 379*9c5db199SXin Li return ts_mon.CumulativeDistributionMetric( 380*9c5db199SXin Li name, bucketer=b, 381*9c5db199SXin Li description=description, field_spec=field_spec) 382*9c5db199SXin Li 383*9c5db199SXin Li 384*9c5db199SXin Li@contextlib.contextmanager 385*9c5db199SXin Lidef SecondsTimer(name, fields=None, description=None, field_spec=_MISSING, 386*9c5db199SXin Li scale=1, record_on_exception=True, add_exception_field=False): 387*9c5db199SXin Li """Record the time of an operation to a CumulativeSecondsDistributionMetric. 388*9c5db199SXin Li 389*9c5db199SXin Li Records the time taken inside of the context block, to the 390*9c5db199SXin Li CumulativeSecondsDistribution named |name|, with the given fields. 391*9c5db199SXin Li 392*9c5db199SXin Li Examples: 393*9c5db199SXin Li # Time the doSomething() call, with field values that are independent of the 394*9c5db199SXin Li # results of the operation. 395*9c5db199SXin Li with SecondsTimer('timer/name', fields={'foo': 'bar'}, 396*9c5db199SXin Li description='My timer', 397*9c5db199SXin Li field_spec=[ts_mon.StringField('foo'), 398*9c5db199SXin Li ts_mon.BooleanField('success')]): 399*9c5db199SXin Li doSomething() 400*9c5db199SXin Li 401*9c5db199SXin Li # Time the doSomethingElse call, with field values that depend on the 402*9c5db199SXin Li # results of that operation. Note that it is important that a default value 403*9c5db199SXin Li # is specified for these fields, in case an exception is thrown by 404*9c5db199SXin Li # doSomethingElse() 405*9c5db199SXin Li f = {'success': False, 'foo': 'bar'} 406*9c5db199SXin Li with SecondsTimer('timer/name', fields=f, description='My timer', 407*9c5db199SXin Li field_spec=[ts_mon.StringField('foo')]) as c: 408*9c5db199SXin Li doSomethingElse() 409*9c5db199SXin Li c['success'] = True 410*9c5db199SXin Li 411*9c5db199SXin Li # Incorrect Usage! 412*9c5db199SXin Li with SecondsTimer('timer/name', description='My timer') as c: 413*9c5db199SXin Li doSomething() 414*9c5db199SXin Li c['foo'] = bar # 'foo' is not a valid field, because no default 415*9c5db199SXin Li # value for it was specified in the context constructor. 416*9c5db199SXin Li # It will be silently ignored. 417*9c5db199SXin Li 418*9c5db199SXin Li Args: 419*9c5db199SXin Li name: The name of the metric to create 420*9c5db199SXin Li fields: The fields of the metric to create. 421*9c5db199SXin Li description: A string description of the metric. 422*9c5db199SXin Li field_spec: A sequence of ts_mon.Field objects to specify the field schema. 423*9c5db199SXin Li scale: A float to scale the CumulativeSecondsDistribution buckets by. 424*9c5db199SXin Li record_on_exception: Whether to record metrics if an exception is raised. 425*9c5db199SXin Li add_exception_field: Whether to add a BooleanField('encountered_exception') 426*9c5db199SXin Li to the FieldSpec provided, and set its value to True iff an exception 427*9c5db199SXin Li was raised in the context. 428*9c5db199SXin Li """ 429*9c5db199SXin Li if field_spec is not None and field_spec is not _MISSING: 430*9c5db199SXin Li field_spec.append(ts_mon.BooleanField('encountered_exception')) 431*9c5db199SXin Li 432*9c5db199SXin Li m = CumulativeSecondsDistribution( 433*9c5db199SXin Li name, scale=scale, description=description, field_spec=field_spec) 434*9c5db199SXin Li f = fields or {} 435*9c5db199SXin Li f = dict(f) 436*9c5db199SXin Li keys = list(f) 437*9c5db199SXin Li t0 = _GetSystemClock() 438*9c5db199SXin Li 439*9c5db199SXin Li error = True 440*9c5db199SXin Li try: 441*9c5db199SXin Li yield f 442*9c5db199SXin Li error = False 443*9c5db199SXin Li finally: 444*9c5db199SXin Li if record_on_exception and add_exception_field: 445*9c5db199SXin Li keys.append('encountered_exception') 446*9c5db199SXin Li f.setdefault('encountered_exception', error) 447*9c5db199SXin Li # Filter out keys that were not part of the initial key set. This is to 448*9c5db199SXin Li # avoid inconsistent fields. 449*9c5db199SXin Li # TODO(akeshet): Doing this filtering isn't super efficient. Would be better 450*9c5db199SXin Li # to implement some key-restricted subclass or wrapper around dict, and just 451*9c5db199SXin Li # yield that above rather than yielding a regular dict. 452*9c5db199SXin Li if record_on_exception or not error: 453*9c5db199SXin Li dt = _GetSystemClock() - t0 454*9c5db199SXin Li # TODO(ayatane): Handle backward clock jumps. See _GetSystemClock. 455*9c5db199SXin Li if dt >= 0: 456*9c5db199SXin Li m.add(dt, fields={k: f[k] for k in keys}) 457*9c5db199SXin Li 458*9c5db199SXin Li 459*9c5db199SXin Lidef SecondsTimerDecorator(name, fields=None, description=None, 460*9c5db199SXin Li field_spec=_MISSING, scale=1, 461*9c5db199SXin Li record_on_exception=True, add_exception_field=False): 462*9c5db199SXin Li """Decorator to time the duration of function calls. 463*9c5db199SXin Li 464*9c5db199SXin Li Examples: 465*9c5db199SXin Li @SecondsTimerDecorator('timer/name', fields={'foo': 'bar'}, 466*9c5db199SXin Li description='My timer', 467*9c5db199SXin Li field_spec=[ts_mon.StringField('foo')]) 468*9c5db199SXin Li def Foo(bar): 469*9c5db199SXin Li return doStuff() 470*9c5db199SXin Li 471*9c5db199SXin Li is equivalent to 472*9c5db199SXin Li 473*9c5db199SXin Li def Foo(bar): 474*9c5db199SXin Li with SecondsTimer('timer/name', fields={'foo': 'bar'}, 475*9c5db199SXin Li description='My timer', 476*9c5db199SXin Li field_spec=[ts_mon.StringField('foo')]) 477*9c5db199SXin Li return doStuff() 478*9c5db199SXin Li 479*9c5db199SXin Li Args: 480*9c5db199SXin Li name: The name of the metric to create 481*9c5db199SXin Li fields: The fields of the metric to create 482*9c5db199SXin Li description: A string description of the metric. 483*9c5db199SXin Li field_spec: A sequence of ts_mon.Field objects to specify the field schema. 484*9c5db199SXin Li scale: A float to scale the distrubtion by 485*9c5db199SXin Li record_on_exception: Whether to record metrics if an exception is raised. 486*9c5db199SXin Li add_exception_field: Whether to add a BooleanField('encountered_exception') 487*9c5db199SXin Li to the FieldSpec provided, and set its value to True iff an exception 488*9c5db199SXin Li was raised in the context. 489*9c5db199SXin Li """ 490*9c5db199SXin Li def decorator(fn): 491*9c5db199SXin Li @wraps(fn) 492*9c5db199SXin Li def wrapper(*args, **kwargs): 493*9c5db199SXin Li with SecondsTimer(name, fields=fields, description=description, 494*9c5db199SXin Li field_spec=field_spec, scale=scale, 495*9c5db199SXin Li record_on_exception=record_on_exception, 496*9c5db199SXin Li add_exception_field=add_exception_field): 497*9c5db199SXin Li return fn(*args, **kwargs) 498*9c5db199SXin Li 499*9c5db199SXin Li return wrapper 500*9c5db199SXin Li 501*9c5db199SXin Li return decorator 502*9c5db199SXin Li 503*9c5db199SXin Li 504*9c5db199SXin Li@contextlib.contextmanager 505*9c5db199SXin Lidef SecondsInstanceTimer(name, fields=None, description=None, 506*9c5db199SXin Li field_spec=_MISSING, record_on_exception=True, 507*9c5db199SXin Li add_exception_field=False): 508*9c5db199SXin Li """Record the time of an operation to a FloatMetric. 509*9c5db199SXin Li 510*9c5db199SXin Li Records the time taken inside of the context block, to the 511*9c5db199SXin Li Float metric named |name|, with the given fields. This is 512*9c5db199SXin Li a non-cumulative metric; this represents the absolute time 513*9c5db199SXin Li taken for a specific block. The duration is stored in a float 514*9c5db199SXin Li to provide flexibility in the future for higher accuracy. 515*9c5db199SXin Li 516*9c5db199SXin Li Examples: 517*9c5db199SXin Li # Time the doSomething() call, with field values that are independent of the 518*9c5db199SXin Li # results of the operation. 519*9c5db199SXin Li with SecondsInstanceTimer('timer/name', fields={'foo': 'bar'}, 520*9c5db199SXin Li description='My timer', 521*9c5db199SXin Li field_spec=[ts_mon.StringField('foo'), 522*9c5db199SXin Li ts_mon.BooleanField('success')]): 523*9c5db199SXin Li doSomething() 524*9c5db199SXin Li 525*9c5db199SXin Li # Time the doSomethingElse call, with field values that depend on the 526*9c5db199SXin Li # results of that operation. Note that it is important that a default value 527*9c5db199SXin Li # is specified for these fields, in case an exception is thrown by 528*9c5db199SXin Li # doSomethingElse() 529*9c5db199SXin Li f = {'success': False, 'foo': 'bar'} 530*9c5db199SXin Li with SecondsInstanceTimer('timer/name', fields=f, description='My timer', 531*9c5db199SXin Li field_spec=[ts_mon.StringField('foo')]) as c: 532*9c5db199SXin Li doSomethingElse() 533*9c5db199SXin Li c['success'] = True 534*9c5db199SXin Li 535*9c5db199SXin Li # Incorrect Usage! 536*9c5db199SXin Li with SecondsInstanceTimer('timer/name', description='My timer') as c: 537*9c5db199SXin Li doSomething() 538*9c5db199SXin Li c['foo'] = bar # 'foo' is not a valid field, because no default 539*9c5db199SXin Li # value for it was specified in the context constructor. 540*9c5db199SXin Li # It will be silently ignored. 541*9c5db199SXin Li 542*9c5db199SXin Li Args: 543*9c5db199SXin Li name: The name of the metric to create 544*9c5db199SXin Li fields: The fields of the metric to create. 545*9c5db199SXin Li description: A string description of the metric. 546*9c5db199SXin Li field_spec: A sequence of ts_mon.Field objects to specify the field schema. 547*9c5db199SXin Li record_on_exception: Whether to record metrics if an exception is raised. 548*9c5db199SXin Li add_exception_field: Whether to add a BooleanField('encountered_exception') 549*9c5db199SXin Li to the FieldSpec provided, and set its value to True iff an exception 550*9c5db199SXin Li was raised in the context. 551*9c5db199SXin Li 552*9c5db199SXin Li Yields: 553*9c5db199SXin Li Float based metric measing the duration of execution. 554*9c5db199SXin Li """ 555*9c5db199SXin Li if field_spec is not None and field_spec is not _MISSING: 556*9c5db199SXin Li field_spec.append(ts_mon.BooleanField('encountered_exception')) 557*9c5db199SXin Li 558*9c5db199SXin Li m = FloatMetric(name, description=description, field_spec=field_spec) 559*9c5db199SXin Li f = dict(fields or {}) 560*9c5db199SXin Li keys = list(f) 561*9c5db199SXin Li t0 = _GetSystemClock() 562*9c5db199SXin Li 563*9c5db199SXin Li error = True 564*9c5db199SXin Li try: 565*9c5db199SXin Li yield f 566*9c5db199SXin Li error = False 567*9c5db199SXin Li finally: 568*9c5db199SXin Li if record_on_exception and add_exception_field: 569*9c5db199SXin Li keys.append('encountered_exception') 570*9c5db199SXin Li f.setdefault('encountered_exception', error) 571*9c5db199SXin Li # Filter out keys that were not part of the initial key set. This is to 572*9c5db199SXin Li # avoid inconsistent fields. 573*9c5db199SXin Li # TODO(akeshet): Doing this filtering isn't super efficient. Would be better 574*9c5db199SXin Li # to implement some key-restricted subclass or wrapper around dict, and just 575*9c5db199SXin Li # yield that above rather than yielding a regular dict. 576*9c5db199SXin Li if record_on_exception or not error: 577*9c5db199SXin Li dt = _GetSystemClock() - t0 578*9c5db199SXin Li m.set(dt, fields={k: f[k] for k in keys}) 579*9c5db199SXin Li 580*9c5db199SXin Li 581*9c5db199SXin Lidef SecondsInstanceTimerDecorator(name, fields=None, description=None, 582*9c5db199SXin Li field_spec=_MISSING, 583*9c5db199SXin Li record_on_exception=True, 584*9c5db199SXin Li add_exception_field=False): 585*9c5db199SXin Li """Decorator to time the gauge duration of function calls. 586*9c5db199SXin Li 587*9c5db199SXin Li Examples: 588*9c5db199SXin Li @SecondsInstanceTimerDecorator('timer/name', fields={'foo': 'bar'}, 589*9c5db199SXin Li description='My timer', 590*9c5db199SXin Li field_spec=[ts_mon.StringField('foo'), 591*9c5db199SXin Li ts_mon.BooleanField('success')]): 592*9c5db199SXin Li 593*9c5db199SXin Li def Foo(bar): 594*9c5db199SXin Li return doStuff() 595*9c5db199SXin Li 596*9c5db199SXin Li is equivalent to 597*9c5db199SXin Li 598*9c5db199SXin Li def Foo(bar): 599*9c5db199SXin Li with SecondsInstanceTimer('timer/name', fields={'foo': 'bar'}, 600*9c5db199SXin Li description='My timer', 601*9c5db199SXin Li field_spec=[ts_mon.StringField('foo'), 602*9c5db199SXin Li ts_mon.BooleanField('success')]): 603*9c5db199SXin Li return doStuff() 604*9c5db199SXin Li 605*9c5db199SXin Li Args: 606*9c5db199SXin Li name: The name of the metric to create 607*9c5db199SXin Li fields: The fields of the metric to create 608*9c5db199SXin Li description: A string description of the metric. 609*9c5db199SXin Li field_spec: A sequence of ts_mon.Field objects to specify the field schema. 610*9c5db199SXin Li record_on_exception: Whether to record metrics if an exception is raised. 611*9c5db199SXin Li add_exception_field: Whether to add a BooleanField('encountered_exception') 612*9c5db199SXin Li to the FieldSpec provided, and set its value to True iff an exception 613*9c5db199SXin Li was raised in the context. 614*9c5db199SXin Li 615*9c5db199SXin Li Returns: 616*9c5db199SXin Li A SecondsInstanceTimer metric decorator. 617*9c5db199SXin Li """ 618*9c5db199SXin Li def decorator(fn): 619*9c5db199SXin Li @wraps(fn) 620*9c5db199SXin Li def wrapper(*args, **kwargs): 621*9c5db199SXin Li with SecondsInstanceTimer(name, fields=fields, description=description, 622*9c5db199SXin Li field_spec=field_spec, 623*9c5db199SXin Li record_on_exception=record_on_exception, 624*9c5db199SXin Li add_exception_field=add_exception_field): 625*9c5db199SXin Li return fn(*args, **kwargs) 626*9c5db199SXin Li 627*9c5db199SXin Li return wrapper 628*9c5db199SXin Li 629*9c5db199SXin Li return decorator 630*9c5db199SXin Li 631*9c5db199SXin Li 632*9c5db199SXin Li@contextlib.contextmanager 633*9c5db199SXin Lidef SuccessCounter(name, fields=None, description=None, field_spec=_MISSING): 634*9c5db199SXin Li """Create a counter that tracks if something succeeds. 635*9c5db199SXin Li 636*9c5db199SXin Li Args: 637*9c5db199SXin Li name: The name of the metric to create 638*9c5db199SXin Li fields: The fields of the metric 639*9c5db199SXin Li description: A string description of the metric. 640*9c5db199SXin Li field_spec: A sequence of ts_mon.Field objects to specify the field schema. 641*9c5db199SXin Li """ 642*9c5db199SXin Li c = Counter(name) 643*9c5db199SXin Li f = fields or {} 644*9c5db199SXin Li f = f.copy() 645*9c5db199SXin Li # We add in the additional field success. 646*9c5db199SXin Li keys = list(f) + ['success'] 647*9c5db199SXin Li success = False 648*9c5db199SXin Li try: 649*9c5db199SXin Li yield f 650*9c5db199SXin Li success = True 651*9c5db199SXin Li finally: 652*9c5db199SXin Li f.setdefault('success', success) 653*9c5db199SXin Li f = {k: f[k] for k in keys} 654*9c5db199SXin Li c.increment(fields=f) 655*9c5db199SXin Li 656*9c5db199SXin Li 657*9c5db199SXin Li@contextlib.contextmanager 658*9c5db199SXin Lidef Presence(name, fields=None, description=None, field_spec=_MISSING): 659*9c5db199SXin Li """A counter of 'active' things. 660*9c5db199SXin Li 661*9c5db199SXin Li This keeps track of how many name's are active at any given time. However, 662*9c5db199SXin Li it's only suitable for long running tasks, since the initial true value may 663*9c5db199SXin Li never be written out if the task doesn't run for at least a minute. 664*9c5db199SXin Li """ 665*9c5db199SXin Li b = Boolean(name, description=None, field_spec=field_spec) 666*9c5db199SXin Li b.set(True, fields=fields) 667*9c5db199SXin Li try: 668*9c5db199SXin Li yield 669*9c5db199SXin Li finally: 670*9c5db199SXin Li b.set(False, fields=fields) 671*9c5db199SXin Li 672*9c5db199SXin Li 673*9c5db199SXin Liclass RuntimeBreakdownTimer(object): 674*9c5db199SXin Li """Record the time of an operation and the breakdown into sub-steps. 675*9c5db199SXin Li 676*9c5db199SXin Li Examples: 677*9c5db199SXin Li with RuntimeBreakdownTimer('timer/name', fields={'foo':'bar'}, 678*9c5db199SXin Li description='My timer', 679*9c5db199SXin Li field_spec=[ts_mon.StringField('foo')]) as timer: 680*9c5db199SXin Li with timer.Step('first_step'): 681*9c5db199SXin Li doFirstStep() 682*9c5db199SXin Li with timer.Step('second_step'): 683*9c5db199SXin Li doSecondStep() 684*9c5db199SXin Li # The time spent next will show up under .../timer/name/breakdown_no_step 685*9c5db199SXin Li doSomeNonStepWork() 686*9c5db199SXin Li 687*9c5db199SXin Li This will emit the following metrics: 688*9c5db199SXin Li - .../timer/name/total_duration - A CumulativeSecondsDistribution metric for 689*9c5db199SXin Li the time spent inside the outer with block. 690*9c5db199SXin Li - .../timer/name/breakdown/first_step and 691*9c5db199SXin Li .../timer/name/breakdown/second_step - PercentageDistribution metrics for 692*9c5db199SXin Li the fraction of time devoted to each substep. 693*9c5db199SXin Li - .../timer/name/breakdown_unaccounted - PercentageDistribution metric for the 694*9c5db199SXin Li fraction of time that is not accounted for in any of the substeps. 695*9c5db199SXin Li - .../timer/name/bucketing_loss - PercentageDistribution metric buckets values 696*9c5db199SXin Li before reporting them as distributions. This causes small errors in the 697*9c5db199SXin Li reported values because they are rounded to the reported buckets lower 698*9c5db199SXin Li bound. This is a CumulativeMetric measuring the total rounding error 699*9c5db199SXin Li accrued in reporting all the percentages. The worst case bucketing loss 700*9c5db199SXin Li for x steps is (x+1)/10. So, if you time across 9 steps, you should 701*9c5db199SXin Li expect no more than 1% rounding error. 702*9c5db199SXin Li [experimental] 703*9c5db199SXin Li - .../timer/name/duration_breakdown - A Float metric, with one stream per Step 704*9c5db199SXin Li indicating the ratio of time spent in that step. The different steps are 705*9c5db199SXin Li differentiated via a field with key 'step_name'. Since some of the time 706*9c5db199SXin Li can be spent outside any steps, these ratios will sum to <= 1. 707*9c5db199SXin Li 708*9c5db199SXin Li NB: This helper can only be used if the field values are known at the 709*9c5db199SXin Li beginning of the outer context and do not change as a result of any of the 710*9c5db199SXin Li operations timed. 711*9c5db199SXin Li """ 712*9c5db199SXin Li 713*9c5db199SXin Li PERCENT_BUCKET_COUNT = 1000 714*9c5db199SXin Li 715*9c5db199SXin Li _StepMetrics = collections.namedtuple('_StepMetrics', ['name', 'time_s']) 716*9c5db199SXin Li 717*9c5db199SXin Li def __init__(self, name, fields=None, description=None, field_spec=_MISSING): 718*9c5db199SXin Li self._name = name 719*9c5db199SXin Li self._fields = fields 720*9c5db199SXin Li self._field_spec = field_spec 721*9c5db199SXin Li self._description = description 722*9c5db199SXin Li self._outer_t0 = None 723*9c5db199SXin Li self._total_time_s = 0 724*9c5db199SXin Li self._inside_step = False 725*9c5db199SXin Li self._step_metrics = [] 726*9c5db199SXin Li 727*9c5db199SXin Li def __enter__(self): 728*9c5db199SXin Li self._outer_t0 = _GetSystemClock() 729*9c5db199SXin Li return self 730*9c5db199SXin Li 731*9c5db199SXin Li def __exit__(self, _type, _value, _traceback): 732*9c5db199SXin Li self._RecordTotalTime() 733*9c5db199SXin Li 734*9c5db199SXin Li outer_timer = CumulativeSecondsDistribution( 735*9c5db199SXin Li '%s/total_duration' % (self._name,), 736*9c5db199SXin Li field_spec=self._field_spec, 737*9c5db199SXin Li description=self._description) 738*9c5db199SXin Li outer_timer.add(self._total_time_s, fields=self._fields) 739*9c5db199SXin Li 740*9c5db199SXin Li for name, percent in self._GetStepBreakdowns().items(): 741*9c5db199SXin Li step_metric = PercentageDistribution( 742*9c5db199SXin Li '%s/breakdown/%s' % (self._name, name), 743*9c5db199SXin Li num_buckets=self.PERCENT_BUCKET_COUNT, 744*9c5db199SXin Li field_spec=self._field_spec, 745*9c5db199SXin Li description=self._description) 746*9c5db199SXin Li step_metric.add(percent, fields=self._fields) 747*9c5db199SXin Li 748*9c5db199SXin Li fields = dict(self._fields) if self._fields is not None else dict() 749*9c5db199SXin Li fields['step_name'] = name 750*9c5db199SXin Li # TODO(pprabhu): Convert _GetStepBreakdowns() to return ratios instead of 751*9c5db199SXin Li # percentage when the old PercentageDistribution reporting is deleted. 752*9c5db199SXin Li Float('%s/duration_breakdown' % self._name).set(percent / 100, 753*9c5db199SXin Li fields=fields) 754*9c5db199SXin Li 755*9c5db199SXin Li unaccounted_metric = PercentageDistribution( 756*9c5db199SXin Li '%s/breakdown_unaccounted' % self._name, 757*9c5db199SXin Li num_buckets=self.PERCENT_BUCKET_COUNT, 758*9c5db199SXin Li field_spec=self._field_spec, 759*9c5db199SXin Li description=self._description) 760*9c5db199SXin Li unaccounted_metric.add(self._GetUnaccountedBreakdown(), fields=self._fields) 761*9c5db199SXin Li 762*9c5db199SXin Li bucketing_loss_metric = CumulativeMetric( 763*9c5db199SXin Li '%s/bucketing_loss' % self._name, 764*9c5db199SXin Li field_spec=self._field_spec, 765*9c5db199SXin Li description=self._description) 766*9c5db199SXin Li bucketing_loss_metric.increment_by(self._GetBucketingLoss(), 767*9c5db199SXin Li fields=self._fields) 768*9c5db199SXin Li 769*9c5db199SXin Li @contextlib.contextmanager 770*9c5db199SXin Li def Step(self, step_name): 771*9c5db199SXin Li """Start a new step named step_name in the timed operation. 772*9c5db199SXin Li 773*9c5db199SXin Li Note that it is not possible to start a step inside a step. i.e., 774*9c5db199SXin Li 775*9c5db199SXin Li with RuntimeBreakdownTimer('timer') as timer: 776*9c5db199SXin Li with timer.Step('outer_step'): 777*9c5db199SXin Li with timer.Step('inner_step'): 778*9c5db199SXin Li # will by design raise an exception. 779*9c5db199SXin Li 780*9c5db199SXin Li Args: 781*9c5db199SXin Li step_name: The name of the step being timed. 782*9c5db199SXin Li """ 783*9c5db199SXin Li if self._inside_step: 784*9c5db199SXin Li logging.error('RuntimeBreakdownTimer.Step is not reentrant. ' 785*9c5db199SXin Li 'Dropping step: %s', step_name) 786*9c5db199SXin Li yield 787*9c5db199SXin Li return 788*9c5db199SXin Li 789*9c5db199SXin Li self._inside_step = True 790*9c5db199SXin Li t0 = _GetSystemClock() 791*9c5db199SXin Li try: 792*9c5db199SXin Li yield 793*9c5db199SXin Li finally: 794*9c5db199SXin Li self._inside_step = False 795*9c5db199SXin Li step_time_s = _GetSystemClock() - t0 796*9c5db199SXin Li # TODO(ayatane): Handle backward clock jumps. See _GetSystemClock. 797*9c5db199SXin Li step_time_s = max(0, step_time_s) 798*9c5db199SXin Li self._step_metrics.append(self._StepMetrics(step_name, step_time_s)) 799*9c5db199SXin Li 800*9c5db199SXin Li def _GetStepBreakdowns(self): 801*9c5db199SXin Li """Returns percentage of time spent in each step. 802*9c5db199SXin Li 803*9c5db199SXin Li Must be called after |_RecordTotalTime|. 804*9c5db199SXin Li """ 805*9c5db199SXin Li if not self._total_time_s: 806*9c5db199SXin Li return {} 807*9c5db199SXin Li return {x.name: (x.time_s * 100) / self._total_time_s 808*9c5db199SXin Li for x in self._step_metrics} 809*9c5db199SXin Li 810*9c5db199SXin Li def _GetUnaccountedBreakdown(self): 811*9c5db199SXin Li """Returns the percentage time spent outside of all steps. 812*9c5db199SXin Li 813*9c5db199SXin Li Must be called after |_RecordTotalTime|. 814*9c5db199SXin Li """ 815*9c5db199SXin Li breakdown_percentages = sum(self._GetStepBreakdowns().values()) 816*9c5db199SXin Li return max(0, 100 - breakdown_percentages) 817*9c5db199SXin Li 818*9c5db199SXin Li def _GetBucketingLoss(self): 819*9c5db199SXin Li """Compute the actual loss in reported percentages due to bucketing. 820*9c5db199SXin Li 821*9c5db199SXin Li Must be called after |_RecordTotalTime|. 822*9c5db199SXin Li """ 823*9c5db199SXin Li reported = list(self._GetStepBreakdowns().values()) 824*9c5db199SXin Li reported.append(self._GetUnaccountedBreakdown()) 825*9c5db199SXin Li bucket_width = 100 / self.PERCENT_BUCKET_COUNT 826*9c5db199SXin Li return sum(x % bucket_width for x in reported) 827*9c5db199SXin Li 828*9c5db199SXin Li def _RecordTotalTime(self): 829*9c5db199SXin Li self._total_time_s = _GetSystemClock() - self._outer_t0 830*9c5db199SXin Li # TODO(ayatane): Handle backward clock jumps. See _GetSystemClock. 831*9c5db199SXin Li self._total_time_s = max(0, self._total_time_s) 832*9c5db199SXin Li 833*9c5db199SXin Li 834*9c5db199SXin Lidef _GetSystemClock(): 835*9c5db199SXin Li """Return a clock time. 836*9c5db199SXin Li 837*9c5db199SXin Li The only thing that the return value can be used for is to subtract from 838*9c5db199SXin Li other instances to determine time elapsed. 839*9c5db199SXin Li """ 840*9c5db199SXin Li # TODO(ayatane): We should use a monotonic clock to measure this, 841*9c5db199SXin Li # but Python 2 does not have one. 842*9c5db199SXin Li return time.time() 843*9c5db199SXin Li 844*9c5db199SXin Li 845*9c5db199SXin Lidef Flush(reset_after=()): 846*9c5db199SXin Li """Flushes metrics, but warns on transient errors. 847*9c5db199SXin Li 848*9c5db199SXin Li Args: 849*9c5db199SXin Li reset_after: A list of metrics to reset after flushing. 850*9c5db199SXin Li """ 851*9c5db199SXin Li if not ts_mon: 852*9c5db199SXin Li return 853*9c5db199SXin Li 854*9c5db199SXin Li try: 855*9c5db199SXin Li ts_mon.flush() 856*9c5db199SXin Li while reset_after: 857*9c5db199SXin Li reset_after.pop().reset() 858*9c5db199SXin Li except ssl.SSLError as e: 859*9c5db199SXin Li logging.warning('Caught transient network error while flushing: %s', e) 860*9c5db199SXin Li except Exception as e: 861*9c5db199SXin Li logging.error('Caught exception while flushing: %s', e) 862