From 113da5e12ddfe7fab617c13d54f2252122770dac Mon Sep 17 00:00:00 2001 From: Andrew Zammit Date: Sat, 2 May 2020 13:27:07 -0700 Subject: [PATCH] feat: warn on too many concurrent requests --- package.json | 2 + src/TeenyStatistics.ts | 191 +++++++++++++++++++++++++ src/index.ts | 22 +++ test/TeenyStatistics.ts | 307 ++++++++++++++++++++++++++++++++++++++++ test/index.ts | 73 +++++++++- 5 files changed, 594 insertions(+), 1 deletion(-) create mode 100644 src/TeenyStatistics.ts create mode 100644 test/TeenyStatistics.ts diff --git a/package.json b/package.json index eed3f3d..094a7eb 100644 --- a/package.json +++ b/package.json @@ -47,6 +47,7 @@ "@compodoc/compodoc": "^1.1.9", "@types/mocha": "^7.0.0", "@types/node-fetch": "^2.1.2", + "@types/proxyquire": "^1.3.28", "@types/sinon": "^9.0.0", "@types/uuid": "^7.0.0", "c8": "^7.0.0", @@ -55,6 +56,7 @@ "linkinator": "^2.0.0", "mocha": "^7.0.0", "nock": "^12.0.0", + "proxyquire": "^2.1.3", "sinon": "^9.0.0", "typescript": "^3.8.3" }, diff --git a/src/TeenyStatistics.ts b/src/TeenyStatistics.ts new file mode 100644 index 0000000..f5cf42f --- /dev/null +++ b/src/TeenyStatistics.ts @@ -0,0 +1,191 @@ +/*! + * Copyright 2020 Google LLC + * + * 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. + */ + +export interface TeenyStatisticsOptions { + /** + * A positive number representing when to issue a warning about the number + * of concurrent requests using teeny-request. + * Set to 0 to disable this warning. + * Corresponds to the TEENY_REQUEST_WARN_CONCURRENT_REQUESTS environment + * variable. + */ + concurrentRequests?: number; +} + +type TeenyStatisticsConfig = Required; + +/** + * TeenyStatisticsCounters is distinct from TeenyStatisticsOptions: + * Used when dumping current counters and other internal metrics. + */ +export interface TeenyStatisticsCounters { + concurrentRequests: number; +} + +/** + * @class TeenyStatisticsWarning + * @extends Error + * @description While an error, is used for emitting warnings when + * meeting certain configured thresholds. + * @see process.emitWarning + */ +export class TeenyStatisticsWarning extends Error { + static readonly CONCURRENT_REQUESTS = 'ConcurrentRequestsExceededWarning'; + + public threshold = 0; + public type = ''; + public value = 0; + + /** + * @param {string} message + */ + constructor(message: string) { + super(message); + this.name = this.constructor.name; + Error.captureStackTrace(this, this.constructor); + } +} + +/** + * @class TeenyStatistics + * @description Maintain various statistics internal to teeny-request. Tracking + * is not automatic and must be instrumented within teeny-request. + */ +export class TeenyStatistics { + /** + * @description A default threshold representing when to warn about excessive + * in-flight/concurrent requests. + * @type {number} + * @static + * @readonly + * @default 5000 + */ + static readonly DEFAULT_WARN_CONCURRENT_REQUESTS = 5e3; + + /** + * @type {TeenyStatisticsConfig} + * @private + */ + private _options: TeenyStatisticsConfig; + + /** + * @type {number} + * @private + * @default 0 + */ + private _concurrentRequests = 0; + + /** + * @type {boolean} + * @private + * @default false + */ + private _didConcurrentRequestWarn = false; + + /** + * @param {TeenyStatisticsOptions} [opts] + */ + constructor(opts?: TeenyStatisticsOptions) { + this._options = TeenyStatistics._prepareOptions(opts); + } + + /** + * Change configured statistics options. This will not preserve unspecified + * options that were previously specified, i.e. this is a reset of options. + * @param {TeenyStatisticsOptions} [opts] + * @returns {TeenyStatisticsConfig} The previous options. + * @see _prepareOptions + */ + setOptions(opts?: TeenyStatisticsOptions): TeenyStatisticsConfig { + const oldOpts = this._options; + this._options = TeenyStatistics._prepareOptions(opts); + return oldOpts; + } + + /** + * @readonly + * @return {TeenyStatisticsCounters} + */ + get counters(): TeenyStatisticsCounters { + return { + concurrentRequests: this._concurrentRequests, + }; + } + + /** + * @description Should call this right before making a request. + */ + requestStarting(): void { + this._concurrentRequests++; + + if ( + this._options.concurrentRequests > 0 && + this._concurrentRequests >= this._options.concurrentRequests && + !this._didConcurrentRequestWarn + ) { + this._didConcurrentRequestWarn = true; + const warning = new TeenyStatisticsWarning( + 'Possible excessive concurrent requests detected. ' + + this._concurrentRequests + + ' requests in-flight, which exceeds the configured threshold of ' + + this._options.concurrentRequests + + '. Use the TEENY_REQUEST_WARN_CONCURRENT_REQUESTS environment ' + + 'variable or the concurrentRequests option of teeny-request to ' + + 'increase or disable (0) this warning.' + ); + warning.type = TeenyStatisticsWarning.CONCURRENT_REQUESTS; + warning.value = this._concurrentRequests; + warning.threshold = this._options.concurrentRequests; + process.emitWarning(warning); + } + } + + /** + * @description When using `requestStarting`, call this after the request + * has finished. + */ + requestFinished() { + // TODO negative? + this._concurrentRequests--; + } + + /** + * Configuration Precedence: + * 1. Dependency inversion via defined option. + * 2. Global numeric environment variable. + * 3. Built-in default. + * This will not preserve unspecified options previously specified. + * @param {TeenyStatisticsOptions} [opts] + * @returns {TeenyStatisticsOptions} + * @private + */ + private static _prepareOptions({ + concurrentRequests: diConcurrentRequests, + }: TeenyStatisticsOptions = {}): TeenyStatisticsConfig { + let concurrentRequests = this.DEFAULT_WARN_CONCURRENT_REQUESTS; + + const envConcurrentRequests = Number( + process.env.TEENY_REQUEST_WARN_CONCURRENT_REQUESTS + ); + if (diConcurrentRequests !== undefined) { + concurrentRequests = diConcurrentRequests; + } else if (!Number.isNaN(envConcurrentRequests)) { + concurrentRequests = envConcurrentRequests; + } + + return {concurrentRequests}; + } +} diff --git a/src/index.ts b/src/index.ts index 62a41cb..4533d94 100644 --- a/src/index.ts +++ b/src/index.ts @@ -20,6 +20,7 @@ import fetch, * as f from 'node-fetch'; import {PassThrough, Readable} from 'stream'; import * as uuid from 'uuid'; import {getAgent} from './agents'; +import {TeenyStatistics, TeenyStatisticsOptions} from './TeenyStatistics'; // eslint-disable-next-line @typescript-eslint/no-var-requires const streamEvents = require('stream-events'); @@ -83,6 +84,11 @@ interface Headers { [index: string]: any; } +/** + * Single instance of an interface for keeping track of things. + */ +const teenyStatistics: TeenyStatistics = new TeenyStatistics(); + /** * Convert options from Request to Fetch format * @private @@ -206,8 +212,10 @@ function teenyRequest( options.body = createMultipartStream(boundary, multipart); // Multipart upload + teenyStatistics.requestStarting(); fetch(uri, options).then( res => { + teenyStatistics.requestFinished(); const header = res.headers.get('content-type'); const response = fetchToRequestResponse(options, res); const body = response.body; @@ -259,8 +267,11 @@ function teenyRequest( } }); options.compress = false; + + teenyStatistics.requestStarting(); fetch(uri, options).then( res => { + teenyStatistics.requestFinished(); responseStream = res.body; responseStream.on('error', (err: Error) => { @@ -280,9 +291,12 @@ function teenyRequest( // stream. return requestStream as Request; } + // GET or POST with callback + teenyStatistics.requestStarting(); fetch(uri, options).then( res => { + teenyStatistics.requestFinished(); const header = res.headers.get('content-type'); const response = fetchToRequestResponse(options, res); const body = response.body; @@ -335,4 +349,12 @@ teenyRequest.defaults = (defaults: CoreOptions) => { }; }; +/** + * @see TeenyStatistics#setOptions + * @param {TeenyStatisticsOptions} opts + * @return {TeenyStatisticsConfig} + */ +teenyRequest.setStatOptions = (opts: TeenyStatisticsOptions) => + teenyStatistics.setOptions(opts); + export {teenyRequest}; diff --git a/test/TeenyStatistics.ts b/test/TeenyStatistics.ts new file mode 100644 index 0000000..738ec3e --- /dev/null +++ b/test/TeenyStatistics.ts @@ -0,0 +1,307 @@ +/*! + * Copyright 2020 Google LLC + * + * 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 * as assert from 'assert'; +import {afterEach, before, beforeEach, describe, it} from 'mocha'; +import * as sinon from 'sinon'; +import { + TeenyStatistics, + TeenyStatisticsOptions, + TeenyStatisticsWarning, +} from '../src/TeenyStatistics'; + +function hooksForEnvCleanupInThisContext() { + const prevEnvMap: Map = new Map([ + ['TEENY_REQUEST_WARN_CONCURRENT_REQUESTS', undefined], + ]); + + before(() => { + prevEnvMap.forEach((v, k, map) => { + map.set(k, process.env[k]); + }); + }); + + afterEach(() => { + prevEnvMap.forEach((v, k) => { + if (v === undefined) { + delete process.env[k]; + return; + } + + process.env[k] = v; + }); + }); +} + +describe('TeenyStatistics', () => { + const sandbox = sinon.createSandbox(); + let emitWarnStub: sinon.SinonStub; + + beforeEach(() => { + emitWarnStub = sandbox.stub(process, 'emitWarning'); + }); + + afterEach(() => { + sandbox.restore(); + }); + + describe('constructor', () => { + hooksForEnvCleanupInThisContext(); + + it('should have default concurrent requests', () => { + assert.strictEqual( + TeenyStatistics.DEFAULT_WARN_CONCURRENT_REQUESTS, + 5000 + ); + }); + + it('should use predefined options by default', () => { + const t = new TeenyStatistics(); + assert.deepStrictEqual(t['_options'], {concurrentRequests: 5e3}); + }); + + it('should allow constructor override', () => { + const opts: TeenyStatisticsOptions = {concurrentRequests: 99}; + const t = new TeenyStatistics(Object.assign({}, opts)); + assert.deepStrictEqual(t['_options'], opts); + }); + + it('should allow env var override', () => { + process.env.TEENY_REQUEST_WARN_CONCURRENT_REQUESTS = '42'; + const t = new TeenyStatistics(); + assert.deepStrictEqual(t['_options'], {concurrentRequests: 42}); + }); + + it('should prefer constructor over env var override', () => { + process.env.TEENY_REQUEST_WARN_CONCURRENT_REQUESTS = '123'; + const opts: TeenyStatisticsOptions = {concurrentRequests: 321}; + const t = new TeenyStatistics(Object.assign({}, opts)); + assert.deepStrictEqual(t['_options'], opts); + }); + }); + + describe('setOptions', () => { + hooksForEnvCleanupInThisContext(); + + it('should be optional and set to defaults', () => { + const opts1: TeenyStatisticsOptions = {concurrentRequests: 123}; + const t = new TeenyStatistics(Object.assign({}, opts1)); + t.setOptions(); + assert.deepStrictEqual(t['_options'], {concurrentRequests: 5e3}); + }); + + it('should override previously set using options', () => { + const opts1: TeenyStatisticsOptions = {concurrentRequests: 123}; + const opts2: TeenyStatisticsOptions = {concurrentRequests: 321}; + const t = new TeenyStatistics(Object.assign({}, opts1)); + t.setOptions(Object.assign({}, opts2)); + assert.deepStrictEqual(t['_options'], opts2); + }); + + it('should override previously set using env var', () => { + const opts1: TeenyStatisticsOptions = {concurrentRequests: 123}; + const t = new TeenyStatistics(Object.assign({}, opts1)); + assert.deepStrictEqual(t['_options'], {concurrentRequests: 123}); + process.env.TEENY_REQUEST_WARN_CONCURRENT_REQUESTS = '999'; + t.setOptions(); + assert.deepStrictEqual(t['_options'], {concurrentRequests: 999}); + }); + + it('should return old options', () => { + const opts1: TeenyStatisticsOptions = {concurrentRequests: 123}; + const opts2: TeenyStatisticsOptions = {concurrentRequests: 321}; + const t = new TeenyStatistics(Object.assign({}, opts1)); + const oldOpts = t.setOptions(Object.assign({}, opts2)); + assert.deepStrictEqual(oldOpts, opts1); + }); + }); + + describe('counters', () => { + it('should return counters', () => { + const t = new TeenyStatistics(); + assert.deepStrictEqual(t.counters, {concurrentRequests: 0}); + }); + + it('should be read-only', () => { + const t = new TeenyStatistics(); + assert.throws(() => { + // eslint-disable-next-line @typescript-eslint/ban-ts-ignore + // @ts-ignore + t.counters = {concurrentRequests: 99}; + }); + }); + }); + + describe('request concurrency', () => { + let t: TeenyStatistics; + beforeEach(() => { + t = new TeenyStatistics(); + }); + + it('should increment concurrency count', () => { + let numExpected = 0; + assert.strictEqual(t.counters.concurrentRequests, numExpected); + + t.requestStarting(); + numExpected++; + assert.strictEqual(t.counters.concurrentRequests, numExpected); + + t.requestStarting(); + numExpected++; + assert.strictEqual(t.counters.concurrentRequests, numExpected); + + t.requestStarting(); + numExpected++; + assert.strictEqual(t.counters.concurrentRequests, numExpected); + + for (let i = 0; i < 100; i++) { + t.requestStarting(); + numExpected++; + } + assert.strictEqual(t.counters.concurrentRequests, numExpected); + }); + + it('should decrement concurrency count', () => { + let numExpected = 0; + assert.strictEqual(t.counters.concurrentRequests, 0); + + for (let i = 0; i < 100; i++) { + t.requestStarting(); + numExpected++; + } + + t.requestFinished(); + numExpected--; + assert.strictEqual(t.counters.concurrentRequests, numExpected); + + t.requestFinished(); + numExpected--; + assert.strictEqual(t.counters.concurrentRequests, numExpected); + + t.requestFinished(); + numExpected--; + assert.strictEqual(t.counters.concurrentRequests, numExpected); + + for (let i = numExpected; i > 0; i--) { + t.requestFinished(); + numExpected--; + } + assert.strictEqual(t.counters.concurrentRequests, 0); + }); + + it('should emit a warning upon reaching threshold', () => { + for (let i = 0; i < 5e3 - 1; i++) { + t.requestStarting(); + } + assert(emitWarnStub.notCalled); + + t.requestStarting(); + assert( + emitWarnStub.calledOnceWith( + sinon.match.instanceOf(TeenyStatisticsWarning) + ) + ); + }); + + it('should not re-emit once emitted', () => { + for (let i = 0; i < 5e3 - 1; i++) { + t.requestStarting(); + } + assert(emitWarnStub.notCalled); + + // first time emitting + t.requestStarting(); + assert( + emitWarnStub.calledOnceWith( + sinon.match.instanceOf(TeenyStatisticsWarning) + ) + ); + + // shouldn't emit on the next call (i.e. still greater than threshold) + t.requestStarting(); + assert(emitWarnStub.calledOnce); + + // shouldn't emit after twice the threshold (possible bad math/logic) + for (let i = 0; i < 5e3; i++) { + t.requestStarting(); + } + assert(emitWarnStub.calledOnce); + }); + + it('should not re-emit when yoyoing threshold', () => { + for (let i = 0; i < 5e3 - 1; i++) { + t.requestStarting(); + } + assert(emitWarnStub.notCalled); + + // first time emitting + t.requestStarting(); + assert( + emitWarnStub.calledOnceWith( + sinon.match.instanceOf(TeenyStatisticsWarning) + ) + ); + + // let's bring the counter back down + for (let i = 5e3; i >= 0; i--) { + t.requestFinished(); + } + + // and bring it back again surpassing the threshold + for (let i = 0; i < 5e3 * 2; i++) { + t.requestStarting(); + } + assert(emitWarnStub.calledOnce); + }); + + it('should emit a TeenyStatisticsWarning', () => { + for (let i = 0; i < 5e3; i++) { + t.requestStarting(); + } + assert(emitWarnStub.calledOnce); + + const warning = emitWarnStub.firstCall.args[0] as TeenyStatisticsWarning; + assert.strictEqual(warning.threshold, 5e3); + assert.strictEqual(warning.value, 5e3); + assert.strictEqual( + warning.type, + TeenyStatisticsWarning.CONCURRENT_REQUESTS + ); + }); + + it('should emit a helpful message', () => { + for (let i = 0; i < 5e3; i++) { + t.requestStarting(); + } + assert(emitWarnStub.calledOnce); + + const errStr: string = emitWarnStub.firstCall.args[0].toString(); + assert( + errStr.includes('Possible excessive concurrent requests detected.'), + 'describes the nature of the warning' + ); + assert( + errStr.includes('TEENY_REQUEST_WARN_CONCURRENT_REQUESTS'), + 'mentions env var' + ); + assert( + errStr.includes('concurrentRequests'), + 'mentions concurrentRequests option' + ); + assert(errStr.search(/\b0\b/) !== -1, 'mentions 0'); + }); + }); +}); diff --git a/test/index.ts b/test/index.ts index bad2f46..57746c5 100644 --- a/test/index.ts +++ b/test/index.ts @@ -17,9 +17,10 @@ import * as assert from 'assert'; import {describe, it, afterEach} from 'mocha'; import * as nock from 'nock'; +import * as proxyquire from 'proxyquire'; import {Readable, PassThrough} from 'stream'; import * as sinon from 'sinon'; -import {teenyRequest} from '../src'; +import {teenyRequest as teenyRequestSrc} from '../src'; import {pool} from '../src/agents'; // eslint-disable-next-line @typescript-eslint/no-var-requires @@ -27,6 +28,7 @@ const HttpProxyAgent = require('http-proxy-agent'); // eslint-disable-next-line @typescript-eslint/no-var-requires const HttpsProxyAgent = require('https-proxy-agent'); +proxyquire.noPreserveCache(); nock.disableNetConnect(); const uri = 'https://example.com'; @@ -36,9 +38,25 @@ function mockJson() { describe('teeny', () => { const sandbox = sinon.createSandbox(); + + const statsSandbox = sinon.createSandbox(); + const statsInstanceStubs = { + requestFinished: statsSandbox.stub(), + requestStarting: statsSandbox.stub(), + setOptions: statsSandbox.stub(), + }; + + const teenyRequest = proxyquire('../src', { + './TeenyStatistics': { + TeenyStatistics: sinon.stub().returns(statsInstanceStubs), + '@noCallThru': true, + }, + }).teenyRequest as typeof teenyRequestSrc; + afterEach(() => { pool.clear(); sandbox.restore(); + statsSandbox.reset(); nock.cleanAll(); }); @@ -249,4 +267,57 @@ describe('teeny', () => { }); }); }); + + it('should track stats, callback mode', done => { + const scope = mockJson(); + teenyRequest({uri}, () => { + assert.ok(statsInstanceStubs.requestStarting.calledOnceWithExactly()); + assert.ok(statsInstanceStubs.requestFinished.calledOnceWithExactly()); + scope.done(); + done(); + }); + }); + + it('should track stats, stream mode', done => { + const scope = mockJson(); + const readable = teenyRequest({uri}); + assert.ok(statsInstanceStubs.requestStarting.calledOnceWithExactly()); + + readable.once('response', () => { + assert.ok(statsInstanceStubs.requestFinished.calledOnceWithExactly()); + scope.done(); + done(); + }); + }); + + // TODO multipart is broken with 2 strings + it.skip('should track stats, multipart mode', done => { + const scope = mockJson(); + teenyRequest( + { + headers: {}, + multipart: [{body: 'foo'}, {body: 'bar'}], + uri, + }, + () => { + assert.ok(statsInstanceStubs.requestStarting.calledOnceWithExactly()); + assert.ok(statsInstanceStubs.requestFinished.calledOnceWithExactly()); + scope.done(); + done(); + } + ); + }); + + it('should pass teeny statistics options', () => { + const opts = {concurrentRequests: 42}; + teenyRequest.setStatOptions(Object.assign({}, opts)); + assert(statsInstanceStubs.setOptions.calledOnceWithExactly(opts)); + }); + + it('should return teeny statistics options', () => { + const opts = {concurrentRequests: 42}; + statsInstanceStubs.setOptions.returns(Object.assign({}, opts)); + const optsDefault = teenyRequest.setStatOptions({}); + assert.deepStrictEqual(optsDefault, opts); + }); });