Skip to content

Commit

Permalink
feat: add metrics framework
Browse files Browse the repository at this point in the history
  • Loading branch information
maxjeffos committed Nov 2, 2020
1 parent 210a2c4 commit 1db5492
Show file tree
Hide file tree
Showing 2 changed files with 291 additions and 0 deletions.
144 changes: 144 additions & 0 deletions src/lib/metrics.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,144 @@
const debug = require('debug')('snyk-metrics');

type MetricType = 'timer' | 'synthetic';
export type MetricValue = number | undefined;
export const METRIC_TYPE_TIMER = 'timer';
export const METRIC_TYPE_SYNTHETIC = 'synthetic';

export abstract class MetricInstance {
abstract getValue(): MetricValue;
}

export class TimerMetricInstance extends MetricInstance {
startTimeMs = 0;
endTimeMs = 0;
metricTag: string;

/**
* Creates a new TimerMetricInstance
* @param metricTag used for logging to identify the metric
*/
public constructor(metricTag: string) {
super();
this.metricTag = metricTag;
}

public getValue(): MetricValue {
if (this.startTimeMs !== 0 && this.endTimeMs !== 0) {
return this.endTimeMs - this.startTimeMs;
} else {
return undefined;
}
}

public start() {
if (this.startTimeMs === 0) {
this.startTimeMs = Date.now();
debug(`Timer ${this.metricTag} started at ${this.startTimeMs}.`);
} else {
debug('Invalid Timer use: start() called when timer already stopped');
}
}

public stop() {
if (this.endTimeMs === 0) {
this.endTimeMs = Date.now();
debug(
`Timer ${this.metricTag} stopped at ${
this.endTimeMs
}. Elapsed time is ${this.getValue()}`,
);
} else {
debug('Invalid Timer use: stop() called when timer already stopped');
}
}
}

export class SyntheticMetricInstance extends MetricInstance {
private value = 0;

public setValue(value: number) {
this.value = value;
}

public getValue(): number {
return this.value;
}
}

export abstract class Metric {
public name: string;
public context: string;
public metricType: MetricType;
protected instances: Array<MetricInstance> = [];

public clear() {
this.instances = [];
}

public getValues(): number[] {
return this.instances.map((mi) => mi.getValue() || 0);
}

public getTotal(): number {
const sumMetricValues = (accum: number, current: MetricInstance) => {
const currentTimerMs = current.getValue() || 0;
return (accum = accum + currentTimerMs);
};

const total = this.instances.reduce(sumMetricValues, 0);
return total;
}

public constructor(name: string, metricType: MetricType, context: string) {
this.name = name;
this.metricType = metricType;
this.context = context;
}
}

export class TimerMetric extends Metric {
public createInstance(): TimerMetricInstance {
const t = new TimerMetricInstance(`${this.metricType}/${this.name}`);
this.instances.push(t);
return t;
}
}

export class SyntheticMetric extends Metric {
public createInstance(): SyntheticMetricInstance {
const sm = new SyntheticMetricInstance();
this.instances.push(sm);
return sm;
}
}

export class MetricsCollector {
public static NETWORK_TIME: TimerMetric = new TimerMetric(
'network_time',
'timer',
'Total time spent making and waiting on network requests',
);
public static CPU_TIME: SyntheticMetric = new SyntheticMetric(
'cpu_time',
'synthetic',
'Time spent on things other than network requests',
);

public static getAllMetrics(): any[] {
const metrics: Metric[] = [
MetricsCollector.NETWORK_TIME,
MetricsCollector.CPU_TIME,
];

const res: any = {};
for (const m of metrics) {
res[m.name] = {
type: m.metricType,
values: m.getValues(),
total: m.getTotal(),
};
}
return res;
}
}
147 changes: 147 additions & 0 deletions test/metrics.spec.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,147 @@
const debugMock: string[][] = [];
jest.mock('debug', () => {
const factory = (key) => (...args) => {
debugMock.push([key, ...args]);
};
factory.default = factory;
return factory;
});

import {
TimerMetricInstance,
SyntheticMetricInstance,
MetricsCollector,
} from '../src/lib/metrics';

async function sleep(ms: number): Promise<void> {
return new Promise((resolve) => setTimeout(resolve, ms));
}

function getMetricsLogLines() {
return debugMock
.filter(([key]) => 'snyk-metrics' === key)
.map(([, logLine]) => logLine);
}

afterEach(() => {
MetricsCollector.NETWORK_TIME.clear();
MetricsCollector.CPU_TIME.clear();
jest.restoreAllMocks();
debugMock.length = 0;
});

describe('SyntheticMetricInstance', () => {
it('has a correct initial value', () => {
const smi = new SyntheticMetricInstance();
expect(smi.getValue()).toBe(0);
});

it('can be manually set', () => {
const smi = new SyntheticMetricInstance();
smi.setValue(5);
expect(smi.getValue()).toBe(5);
});
});

describe('TimerMetricInstance', () => {
it('has a correct initial value', () => {
const tmi = new TimerMetricInstance('timer/network_time');
expect(tmi.getValue()).toBeUndefined;
});

it('can time things', async () => {
const tmi = new TimerMetricInstance('timer/network_time');
tmi.start();
await sleep(10);
tmi.stop();
expect(tmi.getValue()).toBeGreaterThan(9);
});

it('.start() / .stop() logs start/top and improper use warnings if you try to start/stop it again after stopping it', async () => {
const t = new TimerMetricInstance('timer/network_time');
expect(t.getValue()).toBeUndefined();

t.start();
await sleep(2);
t.stop();
const t1 = t.getValue();

// if we try to start/stop it again then 1) we make logImproperUse call and 2) the Timer value does not change
t.start();
await sleep(2);
t.stop();

const logLines = getMetricsLogLines();
expect(logLines).toHaveLength(4);
expect(logLines[0]).toContain('Timer timer/network_time started at');
expect(logLines[1]).toContain('Timer timer/network_time stopped at');
expect(logLines[2]).toBe(
'Invalid Timer use: start() called when timer already stopped',
);
expect(logLines[3]).toBe(
'Invalid Timer use: stop() called when timer already stopped',
);

const t2 = t.getValue();
expect(t2).toBe(t1);
});
});

describe('MetricsCollector', () => {
it('can get values and compute total on timer through MetricsCollector', () => {
const t1 = MetricsCollector.NETWORK_TIME.createInstance();
t1.start();
t1.stop();
jest.spyOn(t1, 'getValue').mockReturnValue(100);
expect(t1.getValue()).toBe(100); // just to make sure the mock is actually working

const t2 = MetricsCollector.NETWORK_TIME.createInstance();
t2.start();
t2.stop();
jest.spyOn(t2, 'getValue').mockReturnValue(200);
expect(t2.getValue()).toBe(200); // just to make sure the mock is actually working

expect(MetricsCollector.NETWORK_TIME.getValues()).toEqual([100, 200]);
const total = MetricsCollector.NETWORK_TIME.getTotal();
expect(total).toBe(300);
});

it('can set and get cpu time through MetricsCollector', () => {
const s = MetricsCollector.CPU_TIME.createInstance();
s.setValue(5);
expect(MetricsCollector.CPU_TIME.getValues()).toEqual([5]);
expect(MetricsCollector.CPU_TIME.getTotal()).toBe(5);
});

it('returns all metrics in the way we need for analytics', () => {
const t1 = MetricsCollector.NETWORK_TIME.createInstance();
t1.start();
t1.stop();
jest.spyOn(t1, 'getValue').mockReturnValue(100);

const t2 = MetricsCollector.NETWORK_TIME.createInstance();
t2.start();
t2.stop();
jest.spyOn(t2, 'getValue').mockReturnValue(200);

MetricsCollector.CPU_TIME.createInstance().setValue(50);

const allMetrics = MetricsCollector.getAllMetrics();

const expected = {
// eslint-disable-next-line @typescript-eslint/camelcase
cpu_time: {
total: 50,
type: 'synthetic',
values: [50],
},
// eslint-disable-next-line @typescript-eslint/camelcase
network_time: {
total: 300,
type: 'timer',
values: [100, 200],
},
};
expect(allMetrics).toEqual(expected);
});
});

0 comments on commit 1db5492

Please sign in to comment.