From f5d35ef6f3959a0f9d35d360a33e92a18cd61733 Mon Sep 17 00:00:00 2001 From: James Hageman Date: Fri, 25 Jan 2019 15:32:35 -0800 Subject: [PATCH 1/4] Add Stripe client telemetry to request headers --- lib/StripeResource.js | 19 ++++++++++++++- lib/stripe.js | 2 ++ test/telemetry.spec.js | 54 ++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 74 insertions(+), 1 deletion(-) create mode 100644 test/telemetry.spec.js diff --git a/lib/StripeResource.js b/lib/StripeResource.js index ebcec4e035..8613e77f13 100644 --- a/lib/StripeResource.js +++ b/lib/StripeResource.js @@ -125,6 +125,8 @@ StripeResource.prototype = { // lastResponse. res.requestId = headers['request-id']; + var requestDuration = Date.now() - req._requestStart; + var responseEvent = utils.removeEmpty({ api_version: headers['stripe-version'], account: headers['stripe-account'], @@ -133,7 +135,7 @@ StripeResource.prototype = { path: req._requestEvent.path, status: res.statusCode, request_id: res.requestId, - elapsed: Date.now() - req._requestStart, + elapsed: requestDuration, }); self._stripe._emitter.emit('response', responseEvent); @@ -171,6 +173,14 @@ StripeResource.prototype = { null ); } + + if (res.requestId) { + self._stripe._prevRequestMetrics.push({ + 'request_id': res.requestId, + 'request_duration_ms': requestDuration, + }); + } + // Expose res object Object.defineProperty(response, 'lastResponse', { enumerable: false, @@ -248,6 +258,13 @@ StripeResource.prototype = { Object.assign(headers, options.headers); } + if (self._stripe._prevRequestMetrics.length > 0) { + var metrics = self._stripe._prevRequestMetrics.pop(); + headers['X-Stripe-Client-Telemetry'] = JSON.stringify({ + 'last_request_metrics': metrics + }); + } + makeRequest(apiVersion, headers); }); } diff --git a/lib/stripe.js b/lib/stripe.js index 2569e69e6c..7c88f007b9 100644 --- a/lib/stripe.js +++ b/lib/stripe.js @@ -150,6 +150,8 @@ function Stripe(key, version) { this.errors = require('./Error'); this.webhooks = require('./Webhooks'); + + this._prevRequestMetrics = []; } Stripe.errors = require('./Error'); diff --git a/test/telemetry.spec.js b/test/telemetry.spec.js new file mode 100644 index 0000000000..9f0db6e4ce --- /dev/null +++ b/test/telemetry.spec.js @@ -0,0 +1,54 @@ +'use strict'; + +require('../testUtils'); +var http = require('http'); + +var expect = require('chai').expect; +var testServer = null; + +describe('Client Telemetry', function() { + afterEach(function() { + if (testServer) { + testServer.close(); + testServer = null; + } + }); + + it('Sends client telemetry on the second request', function(done) { + var numRequests = 0; + testServer = http.createServer(function (req, res) { + numRequests += 1; + + var telemetry = req.headers['x-stripe-client-telemetry']; + switch (numRequests) { + case 1: + expect(telemetry).to.not.exist; + break; + case 2: + expect(telemetry).to.exist; + expect(JSON.parse(telemetry).last_request_metrics.request_id) + .to.eql('req_1'); + break; + default: + expect.fail(`Should not have reached request ${numRequests}`); + } + + res.setHeader('Request-Id', `req_${numRequests}`); + res.writeHead(200, {'Content-Type': 'application/json'}); + res.end('{}'); + }); + + testServer.listen(0, '127.0.0.1', function() { + const stripe = require('../lib/stripe')('sk_test_FEiILxKZwnmmocJDUjUNO6pa') + + stripe.setHost('127.0.0.1', testServer.address().port, 'http'); + + stripe.balance.retrieve().then(function (res) { + return stripe.balance.retrieve(); + }).then(function (res) { + expect(numRequests).to.equal(2); + done(); + }).catch(done); + }); + }); +}); From 04f135c55fb32fc445207c763b3864c03941e2c7 Mon Sep 17 00:00:00 2001 From: James Hageman Date: Mon, 28 Jan 2019 10:09:48 -0800 Subject: [PATCH 2/4] Add stripe.setTelemetryEnabled(bool) with tests --- lib/StripeResource.js | 4 +- lib/stripe.js | 10 +++- test/telemetry.spec.js | 113 ++++++++++++++++++++++++++++++++++++++--- 3 files changed, 116 insertions(+), 11 deletions(-) diff --git a/lib/StripeResource.js b/lib/StripeResource.js index 8613e77f13..e1ba22d493 100644 --- a/lib/StripeResource.js +++ b/lib/StripeResource.js @@ -174,7 +174,7 @@ StripeResource.prototype = { ); } - if (res.requestId) { + if (self._stripe.telemetryEnabled() && res.requestId) { self._stripe._prevRequestMetrics.push({ 'request_id': res.requestId, 'request_duration_ms': requestDuration, @@ -258,7 +258,7 @@ StripeResource.prototype = { Object.assign(headers, options.headers); } - if (self._stripe._prevRequestMetrics.length > 0) { + if (self._stripe.telemetryEnabled() && self._stripe._prevRequestMetrics.length > 0) { var metrics = self._stripe._prevRequestMetrics.pop(); headers['X-Stripe-Client-Telemetry'] = JSON.stringify({ 'last_request_metrics': metrics diff --git a/lib/stripe.js b/lib/stripe.js index 7c88f007b9..50edf43c96 100644 --- a/lib/stripe.js +++ b/lib/stripe.js @@ -152,6 +152,7 @@ function Stripe(key, version) { this.webhooks = require('./Webhooks'); this._prevRequestMetrics = []; + this.setTelemetryEnabled(false); } Stripe.errors = require('./Error'); @@ -301,12 +302,19 @@ Stripe.prototype = { return formatted; }, + setTelemetryEnabled: function(enableTelemetry) { + this._enableTelemetry = enableTelemetry; + }, + + telemetryEnabled: function() { + return this._enableTelemetry; + }, + _prepResources: function() { for (var name in resources) { this[utils.pascalToCamelCase(name)] = new resources[name](this); } }, - }; module.exports = Stripe; diff --git a/test/telemetry.spec.js b/test/telemetry.spec.js index 9f0db6e4ce..845d51770a 100644 --- a/test/telemetry.spec.js +++ b/test/telemetry.spec.js @@ -6,6 +6,24 @@ var http = require('http'); var expect = require('chai').expect; var testServer = null; +function createTestServer(handlerFunc, cb) { + var host = '127.0.0.1'; + testServer = http.createServer(function(req, res) { + try { + handlerFunc(req, res); + } catch (e) { + res.writeHead(400, {'Content-Type': 'application/json'}); + res.end(JSON.stringify({ + error: {type: 'invalid_request_error', message: e.message} + })); + } + }); + testServer.listen(0, host, function() { + var port = testServer.address().port; + cb(host, port); + }); +} + describe('Client Telemetry', function() { afterEach(function() { if (testServer) { @@ -14,12 +32,47 @@ describe('Client Telemetry', function() { } }); - it('Sends client telemetry on the second request', function(done) { + it('Does not send telemetry when disabled', function(done) { + var numRequests = 0; + + createTestServer(function (req, res) { + numRequests += 1; + + var telemetry = req.headers['x-stripe-client-telemetry']; + + switch (numRequests) { + case 1: + case 2: + expect(telemetry).to.not.exist; + break; + default: + expect.fail(`Should not have reached request ${numRequests}`); + } + + res.setHeader('Request-Id', `req_${numRequests}`); + res.writeHead(200, {'Content-Type': 'application/json'}); + res.end('{}'); + }, function(host, port) { + const stripe = require('../lib/stripe')('sk_test_FEiILxKZwnmmocJDUjUNO6pa') + stripe.setHost(host, port, 'http'); + + stripe.balance.retrieve().then(function (res) { + return stripe.balance.retrieve(); + }).then(function (res) { + expect(numRequests).to.equal(2); + done(); + }).catch(done); + }); + }); + + it('Sends client telemetry on the second request when enabled', function(done) { var numRequests = 0; - testServer = http.createServer(function (req, res) { + + createTestServer(function (req, res) { numRequests += 1; var telemetry = req.headers['x-stripe-client-telemetry']; + switch (numRequests) { case 1: expect(telemetry).to.not.exist; @@ -27,7 +80,7 @@ describe('Client Telemetry', function() { case 2: expect(telemetry).to.exist; expect(JSON.parse(telemetry).last_request_metrics.request_id) - .to.eql('req_1'); + .to.equal('req_1'); break; default: expect.fail(`Should not have reached request ${numRequests}`); @@ -36,12 +89,10 @@ describe('Client Telemetry', function() { res.setHeader('Request-Id', `req_${numRequests}`); res.writeHead(200, {'Content-Type': 'application/json'}); res.end('{}'); - }); - - testServer.listen(0, '127.0.0.1', function() { + }, function(host, port) { const stripe = require('../lib/stripe')('sk_test_FEiILxKZwnmmocJDUjUNO6pa') - - stripe.setHost('127.0.0.1', testServer.address().port, 'http'); + stripe.setTelemetryEnabled(true); + stripe.setHost(host, port, 'http'); stripe.balance.retrieve().then(function (res) { return stripe.balance.retrieve(); @@ -51,4 +102,50 @@ describe('Client Telemetry', function() { }).catch(done); }); }); + + it('Buffers metrics on concurrent requests', function(done) { + var numRequests = 0; + + createTestServer(function (req, res) { + numRequests += 1; + + var telemetry = req.headers['x-stripe-client-telemetry']; + + switch (numRequests) { + case 1: + case 2: + expect(telemetry).to.not.exist; + break; + case 3: + case 4: + expect(telemetry).to.exist; + expect(JSON.parse(telemetry).last_request_metrics.request_id) + .to.be.oneOf(['req_1', 'req_2']); + break; + default: + expect.fail(`Should not have reached request ${numRequests}`); + } + + res.setHeader('Request-Id', `req_${numRequests}`); + res.writeHead(200, {'Content-Type': 'application/json'}); + res.end('{}'); + }, function(host, port) { + const stripe = require('../lib/stripe')('sk_test_FEiILxKZwnmmocJDUjUNO6pa') + stripe.setTelemetryEnabled(true); + stripe.setHost(host, port, 'http'); + + Promise.all([ + stripe.balance.retrieve(), + stripe.balance.retrieve() + ]).then(function() { + return Promise.all([ + stripe.balance.retrieve(), + stripe.balance.retrieve() + ]); + }).then(function() { + expect(numRequests).to.equal(4); + done(); + }).catch(done); + }); + }); }); From ef449f4c7aeb8ed8ec65ac66c87765d99135704d Mon Sep 17 00:00:00 2001 From: James Hageman Date: Mon, 28 Jan 2019 12:48:57 -0800 Subject: [PATCH 3/4] Address dcarney's comments --- lib/StripeResource.js | 10 +++++----- lib/stripe.js | 2 +- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/lib/StripeResource.js b/lib/StripeResource.js index e1ba22d493..0ad526081f 100644 --- a/lib/StripeResource.js +++ b/lib/StripeResource.js @@ -125,7 +125,7 @@ StripeResource.prototype = { // lastResponse. res.requestId = headers['request-id']; - var requestDuration = Date.now() - req._requestStart; + var requestDurationMs = Date.now() - req._requestStart; var responseEvent = utils.removeEmpty({ api_version: headers['stripe-version'], @@ -135,7 +135,7 @@ StripeResource.prototype = { path: req._requestEvent.path, status: res.statusCode, request_id: res.requestId, - elapsed: requestDuration, + elapsed: requestDurationMs, }); self._stripe._emitter.emit('response', responseEvent); @@ -174,10 +174,10 @@ StripeResource.prototype = { ); } - if (self._stripe.telemetryEnabled() && res.requestId) { + if (self._stripe.getTelemetryEnabled() && res.requestId) { self._stripe._prevRequestMetrics.push({ 'request_id': res.requestId, - 'request_duration_ms': requestDuration, + 'request_duration_ms': requestDurationMs, }); } @@ -258,7 +258,7 @@ StripeResource.prototype = { Object.assign(headers, options.headers); } - if (self._stripe.telemetryEnabled() && self._stripe._prevRequestMetrics.length > 0) { + if (self._stripe.getTelemetryEnabled() && self._stripe._prevRequestMetrics.length > 0) { var metrics = self._stripe._prevRequestMetrics.pop(); headers['X-Stripe-Client-Telemetry'] = JSON.stringify({ 'last_request_metrics': metrics diff --git a/lib/stripe.js b/lib/stripe.js index 50edf43c96..8943a6ae53 100644 --- a/lib/stripe.js +++ b/lib/stripe.js @@ -306,7 +306,7 @@ Stripe.prototype = { this._enableTelemetry = enableTelemetry; }, - telemetryEnabled: function() { + getTelemetryEnabled: function() { return this._enableTelemetry; }, From b36eedc1b9da45243d7b1bb0ae1ba8d76e6db29e Mon Sep 17 00:00:00 2001 From: James Hageman Date: Wed, 30 Jan 2019 15:25:43 -0800 Subject: [PATCH 4/4] Extract telemetry-related functions, bound the buffer. --- lib/StripeResource.js | 38 ++++++++++++++++++++++++++------------ lib/utils.js | 2 ++ 2 files changed, 28 insertions(+), 12 deletions(-) diff --git a/lib/StripeResource.js b/lib/StripeResource.js index 0ad526081f..b2bddbac53 100644 --- a/lib/StripeResource.js +++ b/lib/StripeResource.js @@ -16,6 +16,8 @@ StripeResource.extend = utils.protoExtend; StripeResource.method = require('./StripeMethod'); StripeResource.BASIC_METHODS = require('./StripeMethod.basic'); +StripeResource.MAX_BUFFERED_REQUEST_METRICS = 100; + /** * Encapsulates request logic for a Stripe Resource */ @@ -174,12 +176,7 @@ StripeResource.prototype = { ); } - if (self._stripe.getTelemetryEnabled() && res.requestId) { - self._stripe._prevRequestMetrics.push({ - 'request_id': res.requestId, - 'request_duration_ms': requestDurationMs, - }); - } + self._recordRequestMetrics(res.requestId, requestDurationMs); // Expose res object Object.defineProperty(response, 'lastResponse', { @@ -235,6 +232,28 @@ StripeResource.prototype = { return headers; }, + _addTelemetryHeader: function(headers) { + if (this._stripe.getTelemetryEnabled() && this._stripe._prevRequestMetrics.length > 0) { + var metrics = this._stripe._prevRequestMetrics.shift(); + headers['X-Stripe-Client-Telemetry'] = JSON.stringify({ + 'last_request_metrics': metrics + }); + } + }, + + _recordRequestMetrics: function(requestId, requestDurationMs) { + if (this._stripe.getTelemetryEnabled() && requestId) { + if (this._stripe._prevRequestMetrics.length > StripeResource.MAX_BUFFERED_REQUEST_METRICS) { + utils.emitWarning('Request metrics buffer is full, dropping telemetry message.'); + } else { + this._stripe._prevRequestMetrics.push({ + 'request_id': requestId, + 'request_duration_ms': requestDurationMs, + }); + } + } + }, + _request: function(method, host, path, data, auth, options, callback) { var self = this; var requestData; @@ -258,12 +277,7 @@ StripeResource.prototype = { Object.assign(headers, options.headers); } - if (self._stripe.getTelemetryEnabled() && self._stripe._prevRequestMetrics.length > 0) { - var metrics = self._stripe._prevRequestMetrics.pop(); - headers['X-Stripe-Client-Telemetry'] = JSON.stringify({ - 'last_request_metrics': metrics - }); - } + self._addTelemetryHeader(headers); makeRequest(apiVersion, headers); }); diff --git a/lib/utils.js b/lib/utils.js index 0750965130..0c7b7766ae 100644 --- a/lib/utils.js +++ b/lib/utils.js @@ -252,6 +252,8 @@ var utils = module.exports = { return name[0].toLowerCase() + name.substring(1); } }, + + emitWarning: emitWarning, }; function emitWarning(warning) {