Skip to content

Commit

Permalink
feat: add timerify util
Browse files Browse the repository at this point in the history
  • Loading branch information
dnlup committed Dec 13, 2021
1 parent 119fdc3 commit 9be54b2
Show file tree
Hide file tree
Showing 9 changed files with 395 additions and 26 deletions.
71 changes: 64 additions & 7 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,15 @@ It supports Fastify versions `>=3.0.0`.
- [Notes](#notes)
- [Metrics collected](#metrics-collected)
- [Decorators](#decorators)
- [`fastify.stats`](#fastifystats)
- [`fastify.doc`:](#fastifydoc)
- [`fastify.hrtime2ns(time)`](#fastifyhrtime2nstime)
- [`fastify.hrtime2us(time)`](#fastifyhrtime2ustime)
- [`fastify.hrtime2ms(time)`](#fastifyhrtime2mstime)
- [`fastify.hrtime2s(time)`](#fastifyhrtime2stime)
- [`fastify.timerify(fn[, options])`](#fastifytimerifyfn-options)
- [Caveats](#caveats)
- [onSend(name, value)](#onsendname-value)
- [Hooks](#hooks)
- [API](#api)
- [Configuration `options`](#configuration-options)
Expand Down Expand Up @@ -107,13 +116,61 @@ These are the metrics that are collected automatically.

## Decorators

The plugin adds the following decorators:
The plugin adds the following decorators.

- `fastify.stats`: A [dats](https://github.com/immobiliare/dats) instance
- `fastify.doc`: A [doc](https://github.com/dnlup/doc) instance used to sample process metrics, if `options.collect.health` is `true
- `fastify.hrtime2ns`: A utility function to convert the legacy `process.hrtime([time])` value to nanoseconds
- `fastify.hrtime2ms`: A utility function to convert the legacy `process.hrtime([time])` value to milliseconds
- `fastify.hrtime2s`: A utility function to convert the legacy `process.hrtime([time])` value to seconds
### `fastify.stats`

- [`<Client>`](https://github.com/immobiliare/dats#client)

A [dats](https://github.com/immobiliare/dats) instance.

### `fastify.doc`:

- [`<Sampler>`](https://github.com/dnlup/doc#class-docsampler)

A [doc](https://github.com/dnlup/doc) sampler instance used to sample process metrics, if `options.collect.health` is `true`.

### `fastify.hrtime2ns(time)`

A [utility function](https://github.com/dnlup/hrtime-utils#hrtime2nstime) to convert the legacy `process.hrtime([time])` value to nanoseconds.

### `fastify.hrtime2us(time)`

A [utility function](https://github.com/dnlup/hrtime-utils#hrtime2ustime) to convert the legacy `process.hrtime([time])` value to microseconds.

### `fastify.hrtime2ms(time)`

A [utility function](https://github.com/dnlup/hrtime-utils#hrtime2mstime) to convert the legacy `process.hrtime([time])` value to milliseconds.

### `fastify.hrtime2s(time)`

A [utility function](https://github.com/dnlup/hrtime-utils#hrtime2stime) to convert the legacy `process.hrtime([time])` value to seconds.

### `fastify.timerify(fn[, options])`

- `fn` [`<Function>`](https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Function): the function to time. It can be a sync function, an async function, a function returning a promise, or a constructor. Functions with the callback pattern are not supported.
- `options` [`<Object>`](https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Object): optional configuration options.
- `label` [`<string>`](https://developer.mozilla.org/en-US/docs/Web/JavaScript/Data_structures#String_type): the label of the metric, by default is the function name.
- `onSend` [`<Function>`](https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Function): a custom function to send the timing metric. By default it is a function that send the execution time in millisencods with the passed `name` as label. See the [`onSend`](#onsendname-value) definition.
- `timerifyOptions` [`<Object>`](https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Object): the same options object used to configure the Node core [`timerify`](https://nodejs.org/dist/latest-v16.x/docs/api/perf_hooks.html#performancetimerifyfn-options) function.

It creates a new function that automatically tracks its execution time and sends the corresponding metric.

TODO: add examples

#### Caveats

This decorator uses the core [`timerify`](https://nodejs.org/dist/latest-v16.x/docs/api/perf_hooks.html#performancetimerifyfn-options) api in conjunction with a [`PerformanceObserver`](https://nodejs.org/dist/latest-v16.x/docs/api/perf_hooks.html#class-perf_hooksperformanceobserver) to time the execution of a function.
Since the `name` property of the original function is used to create a [`PerfomanceEntry`](https://nodejs.org/dist/latest-v16.x/docs/api/perf_hooks.html#class-performanceentry) in the timeline, passing anonymous functions or using the same name for multiple functions will result in conflicts when the `PerformanceObserver` callback of this decorator function tries to understand which execution time has been tracked. So, avoid using conflicting names when creating timerified functions whenever possible.

#### onSend(name, value)

- `name` [`<string>`](https://developer.mozilla.org/en-US/docs/Web/JavaScript/Data_structures#String_type): the label of the metric.
- `value` [`<PerfomanceEntry>`](https://nodejs.org/dist/latest-v16.x/docs/api/perf_hooks.html#class-performanceentry): the performance entry of the function.

A syncronous function to send the function execution time. The function context is bound to the `fastify` instance that registered the plugin.

TODO: add examples

## Hooks

Expand All @@ -137,7 +194,7 @@ This module exports a [plugin registration function](https://github.com/fastify/
- `bufferSize`: Number. Metrics buffer size. See [dats](https://github.com/immobiliare/dats#new-clientoptions).
- `bufferFlushTimeout`: Number. Metrics buffer flush timeout. See [dats](https://github.com/immobiliare/dats#new-clientoptions).
- `sampleInterval`: Number. Optional. Sample interval in `ms` used to gather process stats. Defaults to `1000`.
- `onError`: Function: `(err) => void`. Optional. This function to handle possible Dats errors. See [dats](https://github.com/immobiliare/dats#new-clientoptions). Default: `(err) => log(err)`
- `onError`: Function: `(err) => void`. Optional. This function to handle possible Dats errors. See [dats](https://github.com/immobiliare/dats#new-clientoptions). Default: `(err) => fastify.log.error(err)`
- `udpDnsCache`: Boolean. Optional. Activate udpDnsCache. Default `true`.
- `udpDnsCacheTTL`: Number. Optional. DNS cache Time to live of an entry in seconds. Default `120`.
- `collect`: Object. Optional. Which metrics the plugin should track.
Expand Down
25 changes: 23 additions & 2 deletions index.d.ts
Original file line number Diff line number Diff line change
@@ -1,8 +1,24 @@
import { FastifyPluginCallback, FastifyPluginAsync } from 'fastify';

import {
FastifyInstance,
FastifyPluginCallback,
FastifyPluginAsync,
} from 'fastify';
import { TimerifyOptions, PerformanceEntry } from 'perf_hooks';
import Client, { Options } from '@immobiliarelabs/dats';
import { Sampler } from '@dnlup/doc';

export type OnSendHook = (
this: FastifyInstance,
name: string,
value: PerformanceEntry
) => void;

export type MetricsTimerifyOptions = {
label?: string;
onSend?: OnSendHook;
timerifyOptions?: TimerifyOptions;
};

export interface MetricsPluginOptions extends Options {
sampleInterval?: number;
collect?: {
Expand All @@ -23,7 +39,12 @@ declare module 'fastify' {
stats: Client;
doc?: Sampler;
hrtime2ns: (time: [number, number]) => number;
hrtime2us: (time: [number, number]) => number;
hrtime2ms: (time: [number, number]) => number;
hrtime2s: (time: [number, number]) => number;
timerify<T extends (...params: any[]) => any>(
fn: T,
options?: MetricsTimerifyOptions
): T;
}
}
19 changes: 17 additions & 2 deletions index.js
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,20 @@
const fp = require('fastify-plugin');
const { default: Client } = require('@immobiliarelabs/dats');
const doc = require('@dnlup/doc');
const { hrtime2ns, hrtime2ms, hrtime2s } = require('@dnlup/hrtime-utils');
const {
hrtime2ns,
hrtime2us,
hrtime2ms,
hrtime2s,
} = require('@dnlup/hrtime-utils');
const { gte16 } = require('./lib/utils');

const timerifyNotSupported = () => {
throw new Error('Timerify is supported only on Node version 16 and newer.');
};
const timerifyWrap = gte16
? require('./lib/timerifyWrap').timerifyWrap
: () => timerifyNotSupported;

function clientMock() {
const mock = {
Expand Down Expand Up @@ -109,12 +122,14 @@ module.exports = fp(
bufferFlushTimeout,
udpDnsCache,
udpDnsCacheTTL,
onError: onError,
onError,
})
: clientMock();

fastify.decorate('stats', stats);
fastify.decorate('timerify', timerifyWrap(fastify));
fastify.decorate('hrtime2ns', hrtime2ns);
fastify.decorate('hrtime2us', hrtime2us);
fastify.decorate('hrtime2ms', hrtime2ms);
fastify.decorate('hrtime2s', hrtime2s);

Expand Down
41 changes: 37 additions & 4 deletions index.test-d.ts
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
import { expectType } from 'tsd';

import { PerformanceEntry } from 'perf_hooks';
import { expectType, expectError } from 'tsd';
import Fastify, { FastifyPluginCallback, FastifyPluginAsync } from 'fastify';
import Client from '@immobiliarelabs/dats';
import { Sampler } from '@dnlup/doc';
Expand All @@ -17,9 +17,42 @@ const fastify = Fastify();

fastify.register(plugin).after((err) => {
if (err) throw err;
expectType<(time: [number, number]) => number>(fastify.hrtime2ns);
expectType<(time: [number, number]) => number>(fastify.hrtime2us);
expectType<(time: [number, number]) => number>(fastify.hrtime2ms);
expectType<(time: [number, number]) => number>(fastify.hrtime2ms);
expectType<(time: [number, number]) => number>(fastify.hrtime2ms);
expectType<(time: [number, number]) => number>(fastify.hrtime2s);
expectType<Client>(fastify.stats);
expectType<Sampler | undefined>(fastify.doc);

// These should work
const sendPerfEntry = (name: string, value: PerformanceEntry) => {
console.log(name, value.duration);
};
let timerified = fastify.timerify(function test1() {}, { label: 'test1' });
expectType<() => void>(timerified);
fastify.timerify(function test2() {}, {
label: 'test2',
onSend: sendPerfEntry,
});
fastify.timerify(function test3() {}, { label: 'test3' });

// These should not
expectError(fastify.timerify());
expectError(fastify.timerify('test'));
expectError(fastify.timerify('test', {}));
expectError(fastify.timerify(function test5() {}, { label: 3 }));
expectError(
fastify.timerify(function test6() {}, {
label: 'test',
onSend: 'string',
})
);
expectError(
fastify.timerify(function test6() {}, {
label: 'test',
onSend: (label: number, value: number) => {
console.log(label, value);
},
})
);
});
86 changes: 86 additions & 0 deletions lib/timerifyWrap.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,86 @@
'use strict';

const { performance, PerformanceObserver } = require('perf_hooks');

/**
* A map that associates metrics labels to timerified
* functions and send hooks.
*/
const map = new Map();
let obs = null;

const registry = new FinalizationRegistry((label) => {
map.delete(label);
if (map.size === 0 && obs) {
obs.disconnect();
obs = null;
}
});

function wrap(fn, opts) {
// TODO: throw an error if a function woth the same name is already
// present?
const wrapped = performance.timerify(fn, opts.timerifyOptions);
if (!obs) {
obs = new PerformanceObserver((list) => {
for (const entry of list.getEntries()) {
const i = map.get(entry.name);
const name = i[0];
const onSend = i[1];
/* istanbul ignore else */
if (name) {
onSend(name, entry);
}
}
});
obs.observe({ entryTypes: ['function'] });
}
map.set(fn.name, [opts.label, opts.onSend, wrapped]);
registry.register(wrapped, opts.label);
return wrapped;
}

function sendPerfEntry(name, entry) {
this.stats.timing(name, entry.duration);
}

// This is here just to simplify testing.
exports.clear = function () {
for (const [k, v] of map.entries()) {
registry.unregister(v[2]);
map.delete(k);
}
obs && obs.disconnect();
obs = null;
};

// Bind a timerify wrap factory to a specific fastify instance.
exports.timerifyWrap = function (fastify) {
const _onSend = sendPerfEntry.bind(fastify);
return function timerify(fn, opts) {
if (typeof fn !== 'function') {
throw new Error('You have to pass a function to timerify');
}
const defaults = {
label: fn.name,
onSend: _onSend,
timerifyOptions: undefined,
};
const options = Object.assign({}, defaults, opts);
if (typeof options.label !== 'string') {
throw new Error(
'You have to pass a string to label the timerified function metric'
);
}
if (typeof options.onSend !== 'function') {
throw new Error(
'You have to pass a function to the custom onSend hook'
);
}
if (options.onSend !== _onSend) {
// `this` refers to the fastify instance decorated with the timerify util.
options.onSend = options.onSend.bind(this);
}
return wrap(fn, options);
};
};
3 changes: 3 additions & 0 deletions lib/utils.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,3 @@
'use strict';

exports.gte16 = Number(process.version.split('.')[0].replace('v', '')) >= 16;
7 changes: 6 additions & 1 deletion nyc.config.js
Original file line number Diff line number Diff line change
@@ -1,5 +1,10 @@
'use strict';

const defaultExclude = require('@istanbuljs/schema/default-exclude');
const { gte16 } = require('./lib/utils');

const onLt16 = ['lib/timerifyWrap.js', 'lib/sendPerfEntry.js'];

module.exports = {
exclude: ['*tests*'],
exclude: defaultExclude.concat(gte16 ? [] : onLt16),
};
8 changes: 2 additions & 6 deletions package.json
Original file line number Diff line number Diff line change
Expand Up @@ -22,11 +22,11 @@
"files": [
"index.js",
"index.d.ts",
"util.js"
"lib"
],
"scripts": {
"lint": "eslint --fix --ignore-path .gitignore .",
"test": "tsd && nyc --reporter=lcov --reporter=text-summary ava && nyc check-coverage --lines 100 --branches 100 --functions 100",
"test": "tsd && nyc --reporter=lcov --reporter=text-summary ava",
"bench:base": "concurrently -k -s first \"node benchmarks/fixtures/base.js\" \"node -e 'setTimeout(() => {}, 1000)' && npx autocannon -c 100 -d 30 http://localhost:3000\"",
"bench": "concurrently -k -s first \"node benchmarks/fixtures/withMetrics.js\" \"node benchmarks/fixtures/statsd.js\" \"node -e 'setTimeout(() => {}, 1000)' && npx autocannon -c 100 -d 30 http://localhost:3001\"",
"toc": "markdown-toc -i README.md",
Expand Down Expand Up @@ -80,9 +80,5 @@
"@dnlup/hrtime-utils": "^1.0.1",
"@immobiliarelabs/dats": "^1.0.0",
"fastify-plugin": "^3.0.0"
},
"volta": {
"node": "16.12.0",
"npm": "8.1.1"
}
}
Loading

0 comments on commit 9be54b2

Please sign in to comment.