From 93a4f31de2974c10b25ec317bfadd07aabcc9015 Mon Sep 17 00:00:00 2001 From: Carol Abadeer <60774943+carolabadeer@users.noreply.github.com> Date: Thu, 10 Nov 2022 09:36:19 -0800 Subject: [PATCH] Oversampling Mitigation (#541) * added implementation for oversampling mitigation * removed unnecessary comments and whitespaces * addressed feedback and fixed style issues * fixed sampling decision bug and updated unit tests * Make SqsMessageHelper static * Fixed trace headers and added unit tests * fixed style with eslint * renamed isSampled flag to notTraced and fixed styling with eslint * Revert "renamed isSampled flag to notTraced and fixed styling with eslint" This reverts commit f5ce869d876566742d990ed8a964fe35f70537ec. * Revert "fixed style with eslint" This reverts commit 7cde0b2b1158c62f5ac790f4a1430bf201d9bda0. * changed isSampled flag name to notTraced and fixed lint issues * fixed trace header bug --- packages/core/lib/env/aws_lambda.js | 2 +- packages/core/lib/env/sqs_message_helper.js | 12 + packages/core/lib/patchers/aws3_p.ts | 10 +- packages/core/lib/patchers/aws_p.js | 11 +- packages/core/lib/patchers/http_p.js | 10 +- .../lib/segments/attributes/subsegment.d.ts | 5 + .../lib/segments/attributes/subsegment.js | 21 +- packages/core/lib/segments/segment.d.ts | 4 + packages/core/lib/segments/segment.js | 17 + .../test/unit/env/sqs_message_helper.test.js | 84 ++++ .../core/test/unit/patchers/aws3_p.test.js | 91 ++++- .../core/test/unit/patchers/aws_p.test.js | 87 +++++ .../core/test/unit/patchers/http_p.test.js | 360 ++++++++++++++++++ .../segments/attributes/subsegment.test.js | 39 +- .../core/test/unit/segments/segment.test.js | 82 ++++ 15 files changed, 823 insertions(+), 12 deletions(-) create mode 100644 packages/core/lib/env/sqs_message_helper.js create mode 100644 packages/core/test/unit/env/sqs_message_helper.test.js diff --git a/packages/core/lib/env/aws_lambda.js b/packages/core/lib/env/aws_lambda.js index be3c6b4a..18ed0f12 100644 --- a/packages/core/lib/env/aws_lambda.js +++ b/packages/core/lib/env/aws_lambda.js @@ -41,7 +41,7 @@ module.exports.init = function init() { var facadeSegment = function facadeSegment() { var segment = new Segment('facade'); - var whitelistFcn = ['addNewSubsegment', 'addSubsegment', 'removeSubsegment', 'toString']; + var whitelistFcn = ['addNewSubsegment', 'addSubsegment', 'removeSubsegment', 'toString', 'addSubsegmentWithoutSampling', 'addNewSubsegmentWithoutSampling']; var silentFcn = ['incrementCounter', 'decrementCounter', 'isClosed', 'close', 'format', 'flush']; var xAmznTraceId = process.env._X_AMZN_TRACE_ID; diff --git a/packages/core/lib/env/sqs_message_helper.js b/packages/core/lib/env/sqs_message_helper.js new file mode 100644 index 00000000..33c72dfb --- /dev/null +++ b/packages/core/lib/env/sqs_message_helper.js @@ -0,0 +1,12 @@ +class SqsMessageHelper { + + static isSampled(message) { + const {attributes} = message; // extract attributes from message + if (!('AWSTraceHeader' in attributes)) { + return false; + } + return attributes['AWSTraceHeader'].includes('Sampled=1'); + } +} + +export default SqsMessageHelper; diff --git a/packages/core/lib/patchers/aws3_p.ts b/packages/core/lib/patchers/aws3_p.ts index 76bae9a8..98ef33fa 100644 --- a/packages/core/lib/patchers/aws3_p.ts +++ b/packages/core/lib/patchers/aws3_p.ts @@ -110,7 +110,13 @@ const getXRayMiddleware = (config: RegionResolvedConfig, manualSegment?: Segment return next(args); } - const subsegment: Subsegment = segment.addNewSubsegment(service); + let subsegment: Subsegment; + + if (segment.notTraced) { + subsegment = segment.addNewSubsegmentWithoutSampling(service); + } else { + subsegment = segment.addNewSubsegment(service); + } subsegment.addAttribute('namespace', 'aws'); const parent = (segment instanceof Subsegment ? segment.segment : segment); @@ -118,7 +124,7 @@ const getXRayMiddleware = (config: RegionResolvedConfig, manualSegment?: Segment { Root: parent.trace_id, Parent: subsegment.id, - Sampled: parent.notTraced ? '0' : '1', + Sampled: subsegment.notTraced ? '0' : '1', }, ';', ); diff --git a/packages/core/lib/patchers/aws_p.js b/packages/core/lib/patchers/aws_p.js index 87e78333..16eb4429 100644 --- a/packages/core/lib/patchers/aws_p.js +++ b/packages/core/lib/patchers/aws_p.js @@ -76,12 +76,19 @@ function captureAWSRequest(req) { var throttledError = this.throttledError || throttledErrorDefault; var stack = (new Error()).stack; - var subsegment = parent.addNewSubsegment(this.serviceIdentifier); + + let subsegment; + if (parent.notTraced) { + subsegment = parent.addNewSubsegmentWithoutSampling(this.serviceIdentifier); + } else { + subsegment = parent.addNewSubsegment(this.serviceIdentifier); + } + var traceId = parent.segment ? parent.segment.trace_id : parent.trace_id; var buildListener = function(req) { req.httpRequest.headers['X-Amzn-Trace-Id'] = 'Root=' + traceId + ';Parent=' + subsegment.id + - ';Sampled=' + (subsegment.segment.notTraced ? '0' : '1'); + ';Sampled=' + (subsegment.notTraced ? '0' : '1'); }; var completeListener = function(res) { diff --git a/packages/core/lib/patchers/http_p.js b/packages/core/lib/patchers/http_p.js index 1a335993..fcf2f16f 100644 --- a/packages/core/lib/patchers/http_p.js +++ b/packages/core/lib/patchers/http_p.js @@ -116,7 +116,13 @@ function enableCapture(module, downstreamXRayEnabled, subsegmentCallback) { return baseFunc(...args); } - const subsegment = parent.addNewSubsegment(hostname); + let subsegment; + if (parent.notTraced) { + subsegment = parent.addNewSubsegmentWithoutSampling(hostname); + } else { + subsegment = parent.addNewSubsegment(hostname); + } + const root = parent.segment ? parent.segment : parent; subsegment.namespace = 'remote'; @@ -125,7 +131,7 @@ function enableCapture(module, downstreamXRayEnabled, subsegmentCallback) { } options.headers['X-Amzn-Trace-Id'] = 'Root=' + root.trace_id + ';Parent=' + subsegment.id + - ';Sampled=' + (!root.notTraced ? '1' : '0'); + ';Sampled=' + (subsegment.notTraced ? '0' : '1'); const errorCapturer = function errorCapturer(e) { if (subsegmentCallback) { diff --git a/packages/core/lib/segments/attributes/subsegment.d.ts b/packages/core/lib/segments/attributes/subsegment.d.ts index ec649728..64db3433 100644 --- a/packages/core/lib/segments/attributes/subsegment.d.ts +++ b/packages/core/lib/segments/attributes/subsegment.d.ts @@ -10,6 +10,7 @@ declare class Subsegment { parent: SegmentLike; segment: Segment; namespace?: string; + notTraced: boolean; constructor(name: string); @@ -17,6 +18,10 @@ declare class Subsegment { addSubsegment(subsegment: Subsegment): void; + addNewSubsegmentWithoutSampling(name: String): Subsegment; + + addSubsegmentWithoutSampling(subsegment: Subsegment): void; + removeSubsegment(subsegment: Subsegment): void; addAttribute(name: string, data: any): void; diff --git a/packages/core/lib/segments/attributes/subsegment.js b/packages/core/lib/segments/attributes/subsegment.js index 09718d9e..a8644943 100644 --- a/packages/core/lib/segments/attributes/subsegment.js +++ b/packages/core/lib/segments/attributes/subsegment.js @@ -28,6 +28,7 @@ Subsegment.prototype.init = function init(name) { this.start_time = SegmentUtils.getCurrentTime(); this.in_progress = true; this.counter = 0; + this.notTraced = false; }; /** @@ -37,11 +38,23 @@ Subsegment.prototype.init = function init(name) { */ Subsegment.prototype.addNewSubsegment = function addNewSubsegment(name) { - var subsegment = new Subsegment(name); + const subsegment = new Subsegment(name); this.addSubsegment(subsegment); return subsegment; }; +Subsegment.prototype.addSubsegmentWithoutSampling = function addSubsegmentWithoutSampling(subsegment) { + this.addSubsegment(subsegment); + subsegment.notTraced = true; +}; + +Subsegment.prototype.addNewSubsegmentWithoutSampling = function addNewSubsegmentWithoutSampling(name) { + const subsegment = new Subsegment(name); + this.addSubsegment(subsegment); + subsegment.notTraced = true; + return subsegment; +}; + /** * Adds a subsegment to the array of subsegments. * @param {Subsegment} subsegment - The subsegment to append. @@ -60,11 +73,13 @@ Subsegment.prototype.addSubsegment = function(subsegment) { subsegment.segment = this.segment; subsegment.parent = this; + subsegment.notTraced = subsegment.parent.notTraced; + if (subsegment.end_time === undefined) { this.incrementCounter(subsegment.counter); } - this.subsegments.push(subsegment); + }; /** @@ -340,7 +355,7 @@ Subsegment.prototype.flush = function flush() { } if (this.segment.trace_id) { - if (this.segment.notTraced !== true) { + if (this.segment.notTraced !== true && !this.notTraced) { SegmentEmitter.send(this); } else { logger.getLogger().debug('Ignoring flush on subsegment ' + this.id + '. Associated segment is marked as not sampled.'); diff --git a/packages/core/lib/segments/segment.d.ts b/packages/core/lib/segments/segment.d.ts index f83de01e..f2d5ebf3 100644 --- a/packages/core/lib/segments/segment.d.ts +++ b/packages/core/lib/segments/segment.d.ts @@ -35,6 +35,10 @@ declare class Segment { addSubsegment(subsegment: Subsegment): void; + addSubsegmentWithoutSampling(subsegment: Subsegment): void; + + addNewSubsegmentWithoutSampling(name: string): Subsegment + removeSubsegment(subsegment: Subsegment): void; addError(err: Error | string, remote?: boolean): void; diff --git a/packages/core/lib/segments/segment.js b/packages/core/lib/segments/segment.js index 658bae80..92aae521 100644 --- a/packages/core/lib/segments/segment.js +++ b/packages/core/lib/segments/segment.js @@ -217,6 +217,19 @@ Segment.prototype.addNewSubsegment = function addNewSubsegment(name) { return subsegment; }; +Segment.prototype.addSubsegmentWithoutSampling = function addSubsegmentWithoutSampling(subsegment) { + this.addSubsegment(subsegment); + subsegment.notTraced = true; + +}; + +Segment.prototype.addNewSubsegmentWithoutSampling = function addNewSubsegmentWithoutSampling(name) { + const subsegment = new Subsegment(name); + this.addSubsegment(subsegment); + subsegment.notTraced = true; + return subsegment; +}; + /** * Adds a subsegment to the array of subsegments. * @param {Subsegment} subsegment - The subsegment to append. @@ -233,6 +246,8 @@ Segment.prototype.addSubsegment = function addSubsegment(subsegment) { subsegment.segment = this; subsegment.parent = this; + + subsegment.notTraced = subsegment.parent.notTraced; this.subsegments.push(subsegment); if (!subsegment.end_time) { @@ -240,6 +255,8 @@ Segment.prototype.addSubsegment = function addSubsegment(subsegment) { } }; + + /** * Removes the subsegment from the subsegments array, used in subsegment streaming. */ diff --git a/packages/core/test/unit/env/sqs_message_helper.test.js b/packages/core/test/unit/env/sqs_message_helper.test.js new file mode 100644 index 00000000..8ad8d6d7 --- /dev/null +++ b/packages/core/test/unit/env/sqs_message_helper.test.js @@ -0,0 +1,84 @@ +var assert = require('chai').assert; +var chai = require('chai'); +var sinonChai = require('sinon-chai'); + +import SqsMessageHelper from '../../../lib/env/sqs_message_helper'; + +chai.should(); +chai.use(sinonChai); + +describe('#SqsMessageHelper', function () { + + // sample records from https://docs.aws.amazon.com/lambda/latest/dg/with-sqs.html + const sampleSqsMessageEvent = { + 'Records': [ + { + 'messageId': '059f36b4-87a3-44ab-83d2-661975830a7d', + 'receiptHandle': 'AQEBwJnKyrHigUMZj6rYigCgxlaS3SLy0a...', + 'body': 'Test message.', + 'attributes': { + 'ApproximateReceiveCount': '1', + 'SentTimestamp': '1545082649183', + 'SenderId': 'AIDAIENQZJOLO23YVJ4VO', + 'ApproximateFirstReceiveTimestamp': '1545082649185', + 'AWSTraceHeader':'Root=1-632BB806-bd862e3fe1be46a994272793;Sampled=1' + }, + 'messageAttributes': {}, + 'md5OfBody': 'e4e68fb7bd0e697a0ae8f1bb342846b3', + 'eventSource': 'aws:sqs', + 'eventSourceARN': 'arn:aws:sqs:us-east-2:123456789012:my-queue', + 'awsRegion': 'us-east-2' + }, + { + 'messageId': '2e1424d4-f796-459a-8184-9c92662be6da', + 'receiptHandle': 'AQEBzWwaftRI0KuVm4tP+/7q1rGgNqicHq...', + 'body': 'Test message.', + 'attributes': { + 'ApproximateReceiveCount': '1', + 'SentTimestamp': '1545082650636', + 'SenderId': 'AIDAIENQZJOLO23YVJ4VO', + 'ApproximateFirstReceiveTimestamp': '1545082650649', + 'AWSTraceHeader':'Root=1-5759e988-bd862e3fe1be46a994272793;Parent=53995c3f42cd8ad8;Sampled=0' + }, + 'messageAttributes': {}, + 'md5OfBody': 'e4e68fb7bd0e697a0ae8f1bb342846b3', + 'eventSource': 'aws:sqs', + 'eventSourceARN': 'arn:aws:sqs:us-east-2:123456789012:my-queue', + 'awsRegion': 'us-east-2' + }, + { + 'messageId': '2e1424d4-f796-459a-8184-9c92662be6da', + 'receiptHandle': 'AQEBzWwaftRI0KuVm4tP+/7q1rGgNqicHq...', + 'body': 'Test message.', + 'attributes': { + 'ApproximateReceiveCount': '1', + 'SentTimestamp': '1545082650636', + 'SenderId': 'AIDAIENQZJOLO23YVJ4VO', + 'ApproximateFirstReceiveTimestamp': '1545082650649', + 'AWSTraceHeader':'Root=1-5759e988-bd862e3fe1be46a994272793;Parent=53995c3f42cd8ad8' + }, + 'messageAttributes': {}, + 'md5OfBody': 'e4e68fb7bd0e697a0ae8f1bb342846b3', + 'eventSource': 'aws:sqs', + 'eventSourceARN': 'arn:aws:sqs:us-east-2:123456789012:my-queue', + 'awsRegion': 'us-east-2' + } + ] + }; + + describe('SqsMessageHelper isSampled', function() { + + it('should return true when AWSTraceHeader has Sampled=1', function() { + assert.equal(SqsMessageHelper.isSampled(sampleSqsMessageEvent.Records[0]), true); + }); + + it('should return false when AWSTraceHeader has Sampled=0', function() { + assert.equal(SqsMessageHelper.isSampled(sampleSqsMessageEvent.Records[1]), false); + }); + + it('should return false when AWSTraceHeader has no Sampled flag', function() { + assert.equal(SqsMessageHelper.isSampled(sampleSqsMessageEvent.Records[2]), false); + }); + + }); +}); diff --git a/packages/core/test/unit/patchers/aws3_p.test.js b/packages/core/test/unit/patchers/aws3_p.test.js index cc1e798d..b15cafa1 100644 --- a/packages/core/test/unit/patchers/aws3_p.test.js +++ b/packages/core/test/unit/patchers/aws3_p.test.js @@ -132,9 +132,9 @@ describe('AWS v3 patcher', function() { it('should inject the tracing headers', async function() { await awsClient.send(awsRequest); - assert.isTrue(addNewSubsegmentStub.calledWith('S3')); + const expected = new RegExp('^Root=' + traceId + ';Parent=' + sub.id + ';Sampled=1$'); assert.match(awsRequest.request.headers['X-Amzn-Trace-Id'], expected); }); @@ -247,4 +247,93 @@ describe('AWS v3 patcher', function() { }); }); }); + + + describe('#captureAWSRequest-Unsampled', function() { + var awsClient, awsRequest, sandbox, segment, stubResolve, addNewSubsegmentStub, sub, service, addNewServiceSubsegmentStub; + + before(function() { + awsClient = { + send: async (req) => { + const context = { + clientName: 'S3Client', + commandName: 'ListBucketsCommand', + }; + const handler = awsClient.middlewareStack.resolve((args) => { + const error = req.response.error; + if (error) { + const err = new Error(error.message); + err.name = error.code; + err.$metadata = req.response.$metadata; + throw err; + } + return args; + }, context); + await handler(req); + return req.response; + }, + config: { + region: async () => 'us-east-1', + }, + middlewareStack: constructStack(), + }; + }); + + beforeEach(function() { + sandbox = sinon.createSandbox(); + + awsRequest = new (class ListBucketsCommand { + constructor() { + this.request = { + method: 'GET', + url: '/', + connection: { + remoteAddress: 'localhost' + }, + headers: {} + }; + this.response = {}; + this.output = { + $metadata: { + requestId: '123', + extendedRequestId: '456', + } + }; + } + })(); + + segment = new Segment('testSegment', traceId); + sub = segment.addNewSubsegmentWithoutSampling('subseg'); + service = sub.addNewSubsegmentWithoutSampling('service'); + + stubResolve = sandbox.stub(contextUtils, 'resolveSegment').returns(sub); + addNewSubsegmentStub = sandbox.stub(segment, 'addNewSubsegmentWithoutSampling').returns(sub); + addNewServiceSubsegmentStub = sandbox.stub(sub, 'addNewSubsegmentWithoutSampling').returns(service); + + }); + + afterEach(function() { + sandbox.restore(); + }); + + describe('#automaticMode', () => { + beforeEach(() => { + sandbox.stub(contextUtils, 'isAutomaticMode').returns(true); + }); + + before(() => { + awsClient = awsPatcher.captureAWSClient(awsClient); + }); + + + it('should inject the tracing headers', async function() { + await awsClient.send(awsRequest); + assert.isTrue(addNewServiceSubsegmentStub.calledWith('S3')); + + + const expected = new RegExp('^Root=' + traceId + ';Parent=' + service.id + ';Sampled=0$'); + assert.match(awsRequest.request.headers['X-Amzn-Trace-Id'], expected); + }); + }); + }); }); diff --git a/packages/core/test/unit/patchers/aws_p.test.js b/packages/core/test/unit/patchers/aws_p.test.js index 12ac727a..7b2865b4 100644 --- a/packages/core/test/unit/patchers/aws_p.test.js +++ b/packages/core/test/unit/patchers/aws_p.test.js @@ -259,4 +259,91 @@ describe('AWS patcher', function() { }, 50); }); }); + + + describe('#captureAWSRequest-Unsampled', function() { + var awsClient, awsRequest, MyEmitter, sandbox, segment, stubResolve, addNewSubsegmentStub, sub, addNewServiceSubsegmentStub, service; + + before(function() { + MyEmitter = function() { + EventEmitter.call(this); + }; + + awsClient = { + customizeRequests: function customizeRequests(captureAWSRequest) { + this.call = captureAWSRequest; + }, + throttledError: function throttledError() {} + }; + awsClient = awsPatcher.captureAWSClient(awsClient); + + util.inherits(MyEmitter, EventEmitter); + }); + + beforeEach(function() { + sandbox = sinon.createSandbox(); + + awsRequest = { + httpRequest: { + method: 'GET', + url: '/', + connection: { + remoteAddress: 'localhost' + }, + headers: {} + }, + response: {} + }; + + awsRequest.on = function(event, fcn) { + if (event === 'complete') { + this.emitter.on(event, fcn.bind(this, this.response)); + } else { + this.emitter.on(event, fcn.bind(this, this)); + } + return this; + }; + + awsRequest.emitter = new MyEmitter(); + + segment = new Segment('testSegment', traceId); + sub = segment.addNewSubsegmentWithoutSampling('subseg'); + service = sub.addNewSubsegmentWithoutSampling('service'); + + stubResolve = sandbox.stub(contextUtils, 'resolveSegment').returns(sub); + addNewSubsegmentStub = sandbox.stub(segment, 'addNewSubsegmentWithoutSampling').returns(sub); + addNewServiceSubsegmentStub = sandbox.stub(sub, 'addNewSubsegmentWithoutSampling').returns(service); + }); + + afterEach(function() { + sandbox.restore(); + }); + + it('should log an info statement and exit if parent is not found on the context or on the call params', function(done) { + stubResolve.returns(); + var logStub = sandbox.stub(logger, 'info'); + + awsClient.call(awsRequest); + + setTimeout(function() { + logStub.should.have.been.calledOnce; + done(); + }, 50); + }); + + it('should inject the tracing headers', function(done) { + sandbox.stub(contextUtils, 'isAutomaticMode').returns(true); + + awsClient.call(awsRequest); + + awsRequest.emitter.emit('build'); + + setTimeout(function() { + var expected = new RegExp('^Root=' + traceId + ';Parent=' + service.id + ';Sampled=0$'); + assert.match(awsRequest.httpRequest.headers['X-Amzn-Trace-Id'], expected); + done(); + }, 50); + }); + + }); }); diff --git a/packages/core/test/unit/patchers/http_p.test.js b/packages/core/test/unit/patchers/http_p.test.js index 09e035b1..37e28ad6 100644 --- a/packages/core/test/unit/patchers/http_p.test.js +++ b/packages/core/test/unit/patchers/http_p.test.js @@ -249,6 +249,8 @@ describe('HTTP/S', function() { }); }); + + describe('on the "end" event', function() { var capturedHttp, fakeRequest, fakeResponse, httpClient, sandbox; @@ -449,4 +451,362 @@ describe('HTTP/S', function() { }); }); }); + + + + + describe('#captureHTTPsRequest - Unsampled', function() { + var addRemoteDataStub, closeStub, httpOptions, newSubsegmentStub, resolveManualStub, sandbox, segment, subsegment, httpRequest, addNewRequestSubsegmentStub, stubResolve, addNewSubsegmentStub; + var traceId = '1-57fbe041-2c7ad569f5d6ff149137be86'; + + beforeEach(function() { + sandbox = sinon.createSandbox(); + segment = new Segment('testSegment', traceId); + subsegment = segment.addNewSubsegmentWithoutSampling('subseg'); + httpRequest = subsegment.addNewSubsegmentWithoutSampling('http-request'); + + // stubResolve = sandbox.stub(contextUtils, 'resolveSegment').returns(subsegment); + addNewSubsegmentStub = sandbox.stub(segment, 'addNewSubsegmentWithoutSampling').returns(subsegment); + addNewRequestSubsegmentStub = sandbox.stub(subsegment, 'addNewSubsegmentWithoutSampling').returns(httpRequest); + + resolveManualStub = sandbox.stub(contextUtils, 'resolveManualSegmentParams'); + sandbox.stub(contextUtils, 'isAutomaticMode').returns(true); + addRemoteDataStub = sandbox.stub(subsegment, 'addRemoteRequestData').returns(); + closeStub = sandbox.stub(httpRequest, 'close').returns(); + + httpOptions = { + host: 'myhost', + path: '/' + }; + }); + + afterEach(function() { + sandbox.restore(); + }); + + describe('#withContextAvailable', () => { + beforeEach(() => { + sandbox.stub(contextUtils, 'resolveSegment').returns(subsegment); + }); + afterEach(() => { + sandbox.restore(); + }); + + describe('on invocation', function() { + var capturedHttp, fakeRequest, fakeResponse, httpClient, requestSpy, resumeSpy, sandbox; + + beforeEach(function() { + sandbox = sinon.createSandbox(); + segment = new Segment('test', traceId); + + fakeRequest = buildFakeRequest(); + fakeResponse = buildFakeResponse(); + fakeResponse.req = fakeRequest; + + httpClient = { request: function(...args) { + const callback = args[typeof args[1] === 'object' ? 2 : 1]; + callback(fakeResponse); + return fakeRequest; + }}; + httpClient.get = httpClient.request; + + resumeSpy = sandbox.spy(fakeResponse, 'resume'); + requestSpy = sandbox.spy(httpClient, 'request'); + capturedHttp = captureHTTPs(httpClient, true); + }); + + afterEach(function() { + sandbox.restore(); + }); + + it('should call to resolve any manual params', function() { + var options = {hostname: 'hostname', path: '/'}; + capturedHttp.request(options); + + resolveManualStub.should.have.been.calledWith(options); + }); + + it('should consume the response if no callback is provided by user', function() { + capturedHttp.request(httpOptions); // no callback + resumeSpy.should.have.been.calledOnce; + }); + + it('should not consume the response if a callback is provided by user', function() { + capturedHttp.request(httpOptions, () => {}); + resumeSpy.should.not.have.been.called; + }); + + it('should not consume the response if a response listener is provided by user', function() { + fakeRequest.on('response', () => {}); + capturedHttp.request(httpOptions); + resumeSpy.should.not.have.been.called; + }); + + it('should create a new subsegment with name as hostname', function() { + var options = {hostname: 'hostname', path: '/'}; + capturedHttp.request(options); + addNewRequestSubsegmentStub.should.have.been.calledWith(options.hostname); + }); + + it('should create a new subsegment with name as host when hostname is missing', function() { + capturedHttp.request(httpOptions); + addNewRequestSubsegmentStub.should.have.been.calledWith(httpOptions.host); + }); + + it('should create a new subsegment with name as "Unknown host" when host and hostname is missing', function() { + capturedHttp.request({path: '/'}); + addNewRequestSubsegmentStub.should.have.been.calledWith('Unknown host'); + }); + + it('should pass when a string is passed', function() { + capturedHttp.request('http://hostname/api'); + addNewRequestSubsegmentStub.should.have.been.calledWith('hostname'); + capturedHttp.get('http://hostname/api'); + addNewRequestSubsegmentStub.should.have.been.calledWith('hostname'); + }); + + it('should pass when a URL is passed', function() { + var options = new url.URL('http://hostname/api'); + capturedHttp.request(options); + addNewRequestSubsegmentStub.should.have.been.calledWith('hostname'); + }); + + it('should call the base method', function() { + capturedHttp.request({'Segment': segment}); + assert(requestSpy.called); + }); + + it('should attach an event handler to the "end" event', function() { + capturedHttp.request(httpOptions); + assert.isFunction(fakeResponse._events.end); + }); + + it('should inject the tracing headers', function() { + capturedHttp.request(httpOptions); + + // example: 'Root=1-59138384-82ff54d5ba9282f0c680adb3;Parent=53af362e4e4efeb8;Sampled=1' + var xAmznTraceId = new RegExp('^Root=' + traceId + ';Parent=([a-f0-9]{16});Sampled=0$'); + var options = requestSpy.firstCall.args[0]; + assert.match(options.headers['X-Amzn-Trace-Id'], xAmznTraceId); + }); + + it('should inject the tracing headers into the options if a URL is also provided', function() { + capturedHttp.request(`http://${httpOptions.host}${httpOptions.path}`, httpOptions); + + // example: 'Root=1-59138384-82ff54d5ba9282f0c680adb3;Parent=53af362e4e4efeb8;Sampled=1' + var xAmznTraceId = new RegExp('^Root=' + traceId + ';Parent=([a-f0-9]{16});Sampled=0$'); + var options = requestSpy.firstCall.args[1]; + assert.match(options.headers['X-Amzn-Trace-Id'], xAmznTraceId); + }); + + it('should return the request object', function() { + var request = capturedHttp.request(httpOptions); + assert.equal(request, fakeRequest); + }); + }); + + + + describe('on the "end" event', function() { + var capturedHttp, fakeRequest, fakeResponse, httpClient, sandbox; + + beforeEach(function() { + sandbox = sinon.createSandbox(); + + fakeRequest = buildFakeRequest(); + fakeResponse = buildFakeResponse(); + // We need to manually link resume and end to mimic the real response + // per https://nodejs.org/api/http.html#http_class_http_clientrequest + fakeResponse.resume = function() { + fakeResponse.emit('end'); + }; + + httpClient = { request: function(options, callback) { + fakeResponse.req = fakeRequest; + callback(fakeResponse); + return fakeRequest; + }}; + + capturedHttp = captureHTTPs(httpClient); + }); + + afterEach(function() { + sandbox.restore(); + delete segment.notTraced; + }); + + it('should not set "http.traced" if the enableXRayDownstream flag is not set', function(done) { + fakeResponse.statusCode = 200; + capturedHttp.request(httpOptions); + + setTimeout(function() { + addRemoteDataStub.should.not.have.been.called; + done(); + }, 50); + }); + // }); + + it('should not set "http.traced" on the subsegment if the root is unsampled', function(done) { + capturedHttp = captureHTTPs(httpClient, true); + fakeResponse.statusCode = 200; + capturedHttp.request(httpOptions); + // }); + + setTimeout(function() { + addRemoteDataStub.should.not.have.been.called; + done(); + }, 50); + }); + + it('should call any custom subsegment callback', function(done) { + var subsegmentCallback = sandbox.spy(); + capturedHttp = captureHTTPs(httpClient, true, subsegmentCallback); + fakeResponse.statusCode = 200; + capturedHttp.request(httpOptions); + + setTimeout(function() { + subsegmentCallback.should.have.been.calledWithExactly(httpRequest, fakeRequest, fakeResponse); + done(); + }, 50); + }); + + it('should close the subsegment', function(done) { + fakeResponse.statusCode = 200; + capturedHttp.request(httpOptions); + + setTimeout(function() { + closeStub.should.have.been.calledWithExactly(); + done(); + }, 50); + }); + + it('should flag the subsegment as throttled if status code 429 is seen', function(done) { + var addThrottleStub = sandbox.stub(httpRequest, 'addThrottleFlag'); + + fakeResponse.statusCode = 429; + capturedHttp.request(httpOptions); + + setTimeout(function() { + addThrottleStub.should.have.been.calledOnce; + done(); + }, 50); + }); + + it('should check the cause of the http status code', function(done) { + var utilsCodeStub = sandbox.stub(Utils, 'getCauseTypeFromHttpStatus'); + + fakeResponse.statusCode = 500; + capturedHttp.request(httpOptions); + + setTimeout(function() { + utilsCodeStub.should.have.been.calledWith(fakeResponse.statusCode); + done(); + }, 50); + }); + }); + + describe('when the request "error" event fires', function() { + var capturedHttp, error, fakeRequest, httpClient, req, sandbox, subsegmentCallback; + + beforeEach(function() { + sandbox = sinon.createSandbox(); + + httpClient = { request: function() {} }; + + subsegmentCallback = sandbox.spy(); + capturedHttp = captureHTTPs(httpClient, null, subsegmentCallback); + + fakeRequest = buildFakeRequest(); + + sandbox.stub(capturedHttp, '__request').returns(fakeRequest); + error = {}; + + req = capturedHttp.request(httpOptions); + }); + + afterEach(function() { + sandbox.restore(); + }); + + // (request -> ECONNREFUSED -> error event). + // The way I verify if 'end' fired is if the subsegment.http.response was captured on the alternate code path. + // The only way to trigger this is a ECONNREFUSED error, as it is the only event which fires and has no response object. + + it('should capture the request ECONNREFUSED error', function(done) { + fakeRequest.on('error', function() {}); + fakeRequest.emit('error', error); + + setTimeout(function() { + addRemoteDataStub.should.not.have.been.called; + closeStub.should.have.been.calledWithExactly(error); + subsegmentCallback.should.have.been.calledWithExactly(httpRequest, fakeRequest, null, error); + done(); + }, 50); + }); + + // (request -> end event, then if error -> error event) + // sets subsegment.http = { response: { status: 500 }} to set the state that the 'end' event fired. + + it('should capture the request code error', function(done) { + subsegment.http = { response: { status: 500 }}; + fakeRequest.on('error', function() {}); + fakeRequest.emit('error', error); + + setTimeout(function() { + closeStub.should.have.been.calledWithExactly(error); + done(); + }, 50); + }); + + it('should re-emit the error if unhandled', function() { + assert.throws(function() { + fakeRequest.emitter.emit('error', error); + }); + }); + + it('should call any custom subsegment callback', function(done) { + fakeRequest.on('error', function() {}); + fakeRequest.emit('error', error); + + setTimeout(function() { + subsegmentCallback.should.have.been.calledWithExactly(httpRequest, fakeRequest, null, error); + done(); + }, 50); + }); + + if (process.version.startsWith('v') && process.version >= 'v12.17') { + it('should still re-emit if there are multiple errorMonitors attached', function() { + fakeRequest.on(events.errorMonitor, function() {}); + fakeRequest.on(events.errorMonitor, function() {}); + + assert.throws(function() { + fakeRequest.emitter.emit('error', error); + }); + }); + } + }); + }); + + describe('#withoutContextAvailable', function() { + let capturedHttp, httpClient, fakeRequest; + beforeEach(() => { + fakeRequest = {'foo': 'bar'}; + httpClient = { request: () => { + return fakeRequest; + }}; + capturedHttp = captureHTTPs(httpClient, true); + sandbox.stub(contextUtils, 'resolveSegment').returns(null); + }); + + afterEach(() => { + sandbox.restore(); + }); + + it('should return the original request without making a subsegment', () => { + const request = capturedHttp.request(new url.URL('http://amazon.com')); + assert.equal(request, fakeRequest); + expect(addNewRequestSubsegmentStub).not.to.be.called; + }); + }); + }); }); diff --git a/packages/core/test/unit/segments/attributes/subsegment.test.js b/packages/core/test/unit/segments/attributes/subsegment.test.js index 0d0bdf1a..f68cbe85 100644 --- a/packages/core/test/unit/segments/attributes/subsegment.test.js +++ b/packages/core/test/unit/segments/attributes/subsegment.test.js @@ -103,6 +103,36 @@ describe('Subsegment', function() { }); }); + describe('#addSubsegmentWithoutSampling', function () { + it('should have notTraced flag set to true', function() { + const subsegment = new Subsegment('test'); + const child = new Subsegment('child'); + subsegment.addSubsegmentWithoutSampling(child); + + assert.equal(subsegment.notTraced, false); + assert.equal(child.notTraced, true); + }); + + it('should have notTraced flag set to true for new unsampled subsegment', function() { + const subsegment = new Subsegment('test'); + const child = subsegment.addNewSubsegmentWithoutSampling('child'); + + assert.equal(subsegment.notTraced, false); + assert.equal(child.notTraced, true); + }); + + it('should respect the direct parent’s sampling decision', function() { + const subsegment = new Subsegment('test'); + const child = new Subsegment('child'); + subsegment.addSubsegmentWithoutSampling(child); + const child2 = child.addNewSubsegment('child2'); + + assert.equal(subsegment.notTraced, false); + assert.equal(child.notTraced, true); + assert.equal(child2.notTraced, true); + }); + }); + describe('#addError', function() { var err, exceptionStub, sandbox, subsegment; @@ -245,7 +275,7 @@ describe('Subsegment', function() { }); describe('#flush', function() { - var child, emitStub, parent, sandbox, segment; + var child, emitStub, parent, sandbox, segment, unsampledChild; // Since SegmentEmitter is reused across tests, we need the emitStub // to also persist across tests emitStub = sinon.stub(); @@ -262,7 +292,9 @@ describe('Subsegment', function() { }); child = parent.addNewSubsegment('child'); + unsampledChild = parent.addNewSubsegmentWithoutSampling('unsampled-child-segment'); child.segment = segment; + unsampledChild.segment = segment; }); afterEach(function() { @@ -291,6 +323,11 @@ describe('Subsegment', function() { emitStub.should.have.not.been.called; }); + it('should not send if the notTraced property evaluates to true', function() { + unsampledChild.flush(); + emitStub.should.have.not.been.called; + }); + it('should send if the notTraced property evaluates to false', function() { child.flush(); emitStub.should.have.been.called; diff --git a/packages/core/test/unit/segments/segment.test.js b/packages/core/test/unit/segments/segment.test.js index 71a76b71..fcf2e36a 100644 --- a/packages/core/test/unit/segments/segment.test.js +++ b/packages/core/test/unit/segments/segment.test.js @@ -9,6 +9,8 @@ var SegmentUtils = require('../../../lib/segments/segment_utils'); var Segment = require('../../../lib/segments/segment'); var Subsegment = require('../../../lib/segments/attributes/subsegment'); var logger = require('../../../lib/logger'); +var Lambda = require('../../../lib/env/aws_lambda'); +var Context = require('../../../lib/context_utils'); chai.should(); chai.use(sinonChai); @@ -262,6 +264,86 @@ describe('Segment', function() { }); }); + describe('#addSubsegmentWithoutSampling', function () { + let sandbox, setSegmentStub; + + beforeEach(function() { + sandbox = sinon.createSandbox(); + setSegmentStub = sandbox.stub(Context, 'setSegment'); + }); + + afterEach(function() { + sandbox.restore(); + }); + + it('should have notTraced flag set to true for unsampled subsegment of Lambda facade segment', function() { + process.env._X_AMZN_TRACE_ID = 'Root=1-57ff426a-80c11c39b0c928905eb0828d;Parent=1234abcd1234abcd;Sampled=1'; + + Lambda.init(); + + setSegmentStub.should.have.been.calledOnce; + + let facade = setSegmentStub.args[0][0]; + let unsampledSegment = facade.addNewSubsegmentWithoutSampling('unsampled-subsegment'); + assert.equal(unsampledSegment.notTraced, true); + }); + + it('should have notTraced flag set to undefined for subsegment of Lambda facade segment', function() { + process.env._X_AMZN_TRACE_ID = 'Root=1-57ff426a-80c11c39b0c928905eb0828d;Parent=1234abcd1234abcd;Sampled=1'; + Lambda.init(); + + setSegmentStub.should.have.been.calledOnce; + + let facade = setSegmentStub.args[0][0]; + let sampledSubsegment = facade.addNewSubsegment('sampled-subsegment'); + assert.equal(sampledSubsegment.notTraced, undefined); + }); + + it('should have notTraced flag set to true', function() { + var segment = new Segment('parent'); + var child = new Subsegment('child'); + segment.addSubsegmentWithoutSampling(child); + + assert.equal(child.notTraced, true); + }); + + it('should have notTraced flag set to true for new unsampled subsegment', function() { + var segment = new Segment('parent'); + var child = segment.addNewSubsegmentWithoutSampling('child'); + + assert.equal(child.notTraced, true); + }); + + + + it('should not sample subsegment or subsegment of subsegment', function() { + var segment = new Segment('parent'); + var child = new Subsegment('child'); + var child2 = new Subsegment('child-2'); + segment.addSubsegmentWithoutSampling(child); + child.addSubsegmentWithoutSampling(child2); + + assert.equal(child.notTraced, true); + assert.equal(child2.notTraced, true); + }); + + it('should not sample subsegment or subsegment of subsegment - mix', function() { + const segment = new Segment('parent'); + const child = new Subsegment('child'); + const child2 = new Subsegment('child-2'); + const child3 = new Subsegment('child-3'); + segment.addSubsegmentWithoutSampling(child); + child.addSubsegment(child2); + const child4 = child2.addNewSubsegment('child-4'); + child.addSubsegmentWithoutSampling(child3); + + assert.equal(child.notTraced, true); + assert.equal(child2.notTraced, true); + assert.equal(child3.notTraced, true); + assert.equal(child4.notTraced, true); + }); + }); + describe('#addError', function() { var err, exceptionStub, sandbox, segment;