Get Timestamp with process.hrtime and Date.now (#261)

* Replace process.hrtime with Date.now

Although process.hrtime() provides a high-resolution timer, it is from an unknown relative time, not epoch i.e. The time is relative to an arbitrary time in the past (not related to the time of day) and therefore not subject to clock drifts. The whole purpose of hrtime is to gather information on intervals or durations. That's why it doesn't really matter what the point in time was. Also, it is impossible to construct the ISO timestamp from hrtime, which is required when we export metrics data using stackdriver exporter. I am proposing to use Date.now function, as it returns the number of milliseconds elapsed since 1 January 1970 00:00:00 UTC. I have written timestampFromMillis function to construct Timestamp object from the given milliseconds.

* Construct Timestamp from Date.now and Process.hrtime

* mock time for tests

Author: mayurkale22

packages/opencensus-core/src/common/time-util.ts

@@ -0,0 +1,67 @@
+/**
+ * Copyright 2019, OpenCensus Authors
+ *
+ * Licensed under the Apache License, Version 2.0 the "License";
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+import {Timestamp} from '../metrics/export/types';
+
+const MILLIS_PER_SECOND = 1e3;
+const NANOS_PER_MILLI = 1e3 * 1e3;
+const NANOS_PER_SECOND = 1e3 * 1e3 * 1e3;
+
+let hrtime = process.hrtime;
+let hrtimeOrigin: [number, number] = [0, 0];
+let hrtimeRefSeconds = 0;
+let hrtimeRefNanos = 0;
+
+function setHrtimeReference() {
+  resetHrtimeFunctionCache();
+  hrtimeOrigin = hrtime();
+  const refTime = Date.now();
+  hrtimeRefSeconds = Math.floor(refTime / MILLIS_PER_SECOND);
+  hrtimeRefNanos = (refTime % MILLIS_PER_SECOND) * NANOS_PER_MILLI;
+}
+
+/**
+ * This is used to enable tests to mock process.hrtime while still allow us to
+ * cache it.
+ */
+function resetHrtimeFunctionCache() {
+  hrtime = process.hrtime;
+}
+
+/**
+ * Gets the current timestamp with seconds and nanoseconds.
+ *
+ * @returns {Timestamp} The Timestamp.
+ */
+export function getTimestampWithProcessHRTime(): Timestamp {
+  const [offsetSecs, offsetNanos] = hrtime(hrtimeOrigin);
+
+  // determine drift in seconds and nanoseconds
+  const seconds = hrtimeRefSeconds + offsetSecs;
+  const nanos = hrtimeRefNanos + offsetNanos;
+
+  if (nanos >= NANOS_PER_SECOND) {
+    return {seconds: seconds + 1, nanos: nanos % NANOS_PER_SECOND};
+  }
+  return {seconds, nanos};
+}
+
+setHrtimeReference();
+
+export const TEST_ONLY = {
+  setHrtimeReference,
+  resetHrtimeFunctionCache
+};

packages/opencensus-core/src/metrics/gauges/derived-gauge.ts

@@ -14,8 +14,9 @@
  * limitations under the License.
  */
 
+import {getTimestampWithProcessHRTime} from '../../common/time-util';
 import {validateArrayElementsNotNull, validateNotNull} from '../../common/validations';
-import {LabelKey, LabelValue, Metric, MetricDescriptor, MetricDescriptorType, TimeSeries} from '../export/types';
+import {LabelKey, LabelValue, Metric, MetricDescriptor, MetricDescriptorType, TimeSeries, Timestamp} from '../export/types';
 import * as types from '../gauges/types';
 import {hashLabelValues} from '../utils';
 
@@ -204,16 +205,14 @@ export class DerivedGauge implements types.Meter {
     if (this.registeredPoints.size === 0) {
       return null;
     }
-    const [seconds, nanos] = process.hrtime();
+    const timestamp: Timestamp = getTimestampWithProcessHRTime();
     return {
       descriptor: this.metricDescriptor,
       timeseries: Array.from(
           this.registeredPoints,
           ([_, gaugeEntry]) => ({
             labelValues: gaugeEntry.labelValues,
-            points: [
-              {value: gaugeEntry.extractor(), timestamp: {seconds, nanos}}
-            ]
+            points: [{value: gaugeEntry.extractor(), timestamp}]
           } as TimeSeries))
     };
   }

packages/opencensus-core/src/metrics/gauges/gauge.ts

@@ -14,6 +14,7 @@
  * limitations under the License.
  */
 
+import {getTimestampWithProcessHRTime} from '../../common/time-util';
 import {validateArrayElementsNotNull, validateNotNull} from '../../common/validations';
 import {LabelKey, LabelValue, Metric, MetricDescriptor, MetricDescriptorType, TimeSeries, Timestamp} from '../export/types';
 import * as types from '../gauges/types';
@@ -129,12 +130,11 @@ export class Gauge implements types.Meter {
     if (this.registeredPoints.size === 0) {
       return null;
     }
-    const [seconds, nanos] = process.hrtime();
+    const timestamp: Timestamp = getTimestampWithProcessHRTime();
     return {
       descriptor: this.metricDescriptor,
       timeseries: Array.from(
-          this.registeredPoints,
-          ([_, point]) => point.getTimeSeries({seconds, nanos}))
+          this.registeredPoints, ([_, point]) => point.getTimeSeries(timestamp))
     };
   }
 }

packages/opencensus-core/src/stats/view.ts

@@ -15,6 +15,7 @@
  */
 
 import * as defaultLogger from '../common/console-logger';
+import {getTimestampWithProcessHRTime} from '../common/time-util';
 import * as loggerTypes from '../common/types';
 import {DistributionValue, LabelValue, Metric, MetricDescriptor, MetricDescriptorType, Point, TimeSeries, Timestamp} from '../metrics/export/types';
 
@@ -206,18 +207,16 @@ export class BaseView implements View {
     let startTimestamp: Timestamp;
 
     // The moment when this point was recorded.
-    const [currentSeconds, currentNanos] = process.hrtime();
-    const now: Timestamp = {seconds: currentSeconds, nanos: currentNanos};
+    const now: Timestamp = getTimestampWithProcessHRTime();
 
     switch (type) {
       case MetricDescriptorType.GAUGE_INT64:
       case MetricDescriptorType.GAUGE_DOUBLE:
         startTimestamp = null;
         break;
       default:
-        const [seconds, nanos] = process.hrtime();
         // TODO (mayurkale): This should be set when create Cumulative view.
-        startTimestamp = {seconds, nanos};
+        startTimestamp = getTimestampWithProcessHRTime();
     }
 
     const timeseries: TimeSeries[] = [];

packages/opencensus-core/test/test-derived-gauge.ts

@@ -15,7 +15,9 @@
  */
 
 import * as assert from 'assert';
-import {LabelKey, LabelValue, MetricDescriptorType} from '../src/metrics/export/types';
+
+import {TEST_ONLY} from '../src/common/time-util';
+import {LabelKey, LabelValue, MetricDescriptorType, Timestamp} from '../src/metrics/export/types';
 import {DerivedGauge} from '../src/metrics/gauges/derived-gauge';
 
 const METRIC_NAME = 'metric-name';
@@ -29,8 +31,10 @@ const LABEL_VALUES_400: LabelValue[] = [{value: '400'}];
 const LABEL_VALUES_EXRTA: LabelValue[] = [{value: '200'}, {value: '400'}];
 
 describe('DerivedGauge', () => {
-  const oldProcessHrtime = process.hrtime;
   let instance: DerivedGauge;
+  const realHrtimeFn = process.hrtime;
+  const realNowFn = Date.now;
+  const mockedTime: Timestamp = {seconds: 1450000100, nanos: 1e7};
   const expectedMetricDescriptor = {
     name: METRIC_NAME,
     description: METRIC_DESCRIPTION,
@@ -42,11 +46,18 @@ describe('DerivedGauge', () => {
   beforeEach(() => {
     instance = new DerivedGauge(
         METRIC_NAME, METRIC_DESCRIPTION, UNIT, GAUGE_INT64, LABEL_KEYS);
-    process.hrtime = () => [1000, 1e7];
+
+    process.hrtime = () => [100, 1e7];
+    Date.now = () => 1450000000000;
+    // Force the clock to recalibrate the time offset with the mocked time
+    TEST_ONLY.setHrtimeReference();
   });
 
   afterEach(() => {
-    process.hrtime = oldProcessHrtime;
+    process.hrtime = realHrtimeFn;
+    Date.now = realNowFn;
+    // Reset the hrtime reference so that it uses a real clock again.
+    TEST_ONLY.resetHrtimeFunctionCache();
   });
 
   describe('createTimeSeries()', () => {
@@ -73,14 +84,19 @@ describe('DerivedGauge', () => {
       map.set('key', 'value');
       instance.createTimeSeries(LABEL_VALUES_200, map);
       map.set('key1', 'value1');
+
       let metric = instance.getMetric();
       assert.notEqual(metric, null);
       assert.deepStrictEqual(metric.descriptor, expectedMetricDescriptor);
       assert.equal(metric.timeseries.length, 1);
       assert.deepStrictEqual(
           metric.timeseries, [{
             labelValues: LABEL_VALUES_200,
-            points: [{value: 2, timestamp: {nanos: 1e7, seconds: 1000}}]
+            points: [{
+              value: 2,
+              timestamp:
+                  {nanos: mockedTime.nanos, seconds: mockedTime.seconds}
+            }]
           }]);
       // add data in collection
       map.set('key2', 'value2');
@@ -98,11 +114,19 @@ describe('DerivedGauge', () => {
       assert.deepStrictEqual(metric.timeseries, [
         {
           labelValues: LABEL_VALUES_200,
-          points: [{value: 4, timestamp: {nanos: 1e7, seconds: 1000}}]
+          points: [{
+            value: 4,
+            timestamp:
+                {nanos: mockedTime.nanos, seconds: mockedTime.seconds}
+          }]
         },
         {
           labelValues: LABEL_VALUES_400,
-          points: [{value: 5, timestamp: {nanos: 1e7, seconds: 1000}}]
+          points: [{
+            value: 5,
+            timestamp:
+                {nanos: mockedTime.nanos, seconds: mockedTime.seconds}
+          }]
         }
       ]);
     });
@@ -121,7 +145,11 @@ describe('DerivedGauge', () => {
       assert.deepStrictEqual(
           metric.timeseries, [{
             labelValues: LABEL_VALUES_200,
-            points: [{value: 45, timestamp: {nanos: 1e7, seconds: 1000}}]
+            points: [{
+              value: 45,
+              timestamp:
+                  {nanos: mockedTime.nanos, seconds: mockedTime.seconds}
+            }]
           }]);
     });
     it('should return a Metric (Double) - custom object', () => {
@@ -147,7 +175,11 @@ describe('DerivedGauge', () => {
       assert.deepStrictEqual(
           metric.timeseries, [{
             labelValues: LABEL_VALUES_200,
-            points: [{value: 0.7, timestamp: {nanos: 1e7, seconds: 1000}}]
+            points: [{
+              value: 0.7,
+              timestamp:
+                  {nanos: mockedTime.nanos, seconds: mockedTime.seconds}
+            }]
           }]);
     });
     it('should throw an error when obj is null', () => {
@@ -166,7 +198,11 @@ describe('DerivedGauge', () => {
       assert.deepStrictEqual(
           metric.timeseries, [{
             labelValues: LABEL_VALUES_200,
-            points: [{value: 1, timestamp: {nanos: 1e7, seconds: 1000}}]
+            points: [{
+              value: 1,
+              timestamp:
+                  {nanos: mockedTime.nanos, seconds: mockedTime.seconds}
+            }]
           }]);
 
       // create timeseries with same labels.