From 5522eefa6e9183982a11d85511404281b043be93 Mon Sep 17 00:00:00 2001 From: Thomas Watson Date: Wed, 11 Dec 2019 13:55:28 +0100 Subject: [PATCH 1/5] fix(elasticsearch): ensure requests can be aborted Fixes #1565 --- lib/instrumentation/modules/elasticsearch.js | 14 ++++- test/instrumentation/modules/elasticsearch.js | 60 ++++++++++++++++++- 2 files changed, 69 insertions(+), 5 deletions(-) diff --git a/lib/instrumentation/modules/elasticsearch.js b/lib/instrumentation/modules/elasticsearch.js index 1cf37fa28a..14ee08cef5 100644 --- a/lib/instrumentation/modules/elasticsearch.js +++ b/lib/instrumentation/modules/elasticsearch.js @@ -55,14 +55,22 @@ module.exports = function (elasticsearch, agent, { enabled }) { } return original.apply(this, args) } else { - return original.apply(this, arguments) - .then(function (originalP) { + const originalPromise = original.apply(this, arguments) + + const inspectedPromise = originalPromise + .then(function (value) { span.end() - return originalP + return value }, function (err) { span.end() throw err }) + + const descriptors = Object.getOwnPropertyDescriptors(originalPromise) + delete descriptors.domain + Object.defineProperties(inspectedPromise, descriptors) + + return inspectedPromise } } else { agent.logger.debug('could not instrument elasticsearch request %o', { id: id }) diff --git a/test/instrumentation/modules/elasticsearch.js b/test/instrumentation/modules/elasticsearch.js index 64e683f77f..329505a524 100644 --- a/test/instrumentation/modules/elasticsearch.js +++ b/test/instrumentation/modules/elasticsearch.js @@ -48,6 +48,32 @@ test('client.ping with promise', function userLandCode (t) { }) }) +test('client.ping with unhandled promise', function userLandCode (t) { + resetAgent(2, doneNoHTTP(t, 'HEAD', '/')) + + agent.startTransaction('foo') + + const client = new elasticsearch.Client({ + host: 'thiswillneverwork', + log: { + type: 'file', + level: 'error', + path: '/dev/null' + } + }) + + const unhandledPromise = client.ping() + + process.once('unhandledRejection', agent._instrumentation.bindFunction(unhandledRejection)) + + function unhandledRejection (reason, promise) { + t.equal(promise, unhandledPromise) + agent.endTransaction() + agent.flush() + client.close() + } +}) + test('client.search with callback', function userLandCode (t) { resetAgent(done(t, 'POST', '/_search', '{"q":"pants"}')) @@ -226,8 +252,38 @@ function done (t, method, path, query) { } } -function resetAgent (cb) { +function doneNoHTTP (t, method, path, query) { + return function (data, cb) { + t.equal(data.transactions.length, 1) + t.equal(data.spans.length, 1) + + var trans = data.transactions[0] + var span = data.spans[0] + + t.equal(trans.name, 'foo') + t.equal(trans.type, 'custom') + + t.equal(span.type, 'db') + t.equal(span.subtype, 'elasticsearch') + t.equal(span.action, 'request') + t.equal(span.name, 'Elasticsearch: ' + method + ' ' + path) + + t.ok(span.stacktrace.some(function (frame) { + return frame.function === 'userLandCode' + }), 'include user-land code frame') + + t.notOk(span.context) + + t.end() + } +} + +function resetAgent (expected, cb) { + if (typeof expected === 'function') { + cb = expected + expected = 3 + } agent._instrumentation.currentTransaction = null - agent._transport = mockClient(3, cb) + agent._transport = mockClient(expected, cb) agent.captureError = function (err) { throw err } } From 3ca033aa404f685fd9422e3b510137db8c564f37 Mon Sep 17 00:00:00 2001 From: vigneshshanmugam Date: Wed, 29 Jul 2020 15:43:47 +0200 Subject: [PATCH 2/5] chore: add abort as func testt --- test/instrumentation/modules/elasticsearch.js | 1 + 1 file changed, 1 insertion(+) diff --git a/test/instrumentation/modules/elasticsearch.js b/test/instrumentation/modules/elasticsearch.js index 329505a524..9395074560 100644 --- a/test/instrumentation/modules/elasticsearch.js +++ b/test/instrumentation/modules/elasticsearch.js @@ -68,6 +68,7 @@ test('client.ping with unhandled promise', function userLandCode (t) { function unhandledRejection (reason, promise) { t.equal(promise, unhandledPromise) + t.strictEqual(typeof promise.abort, 'function', 'promise.abort should be a function') agent.endTransaction() agent.flush() client.close() From 73fc86dad51ca806d883e8697ae4feb541c779fe Mon Sep 17 00:00:00 2001 From: vigneshshanmugam Date: Wed, 29 Jul 2020 17:17:17 +0200 Subject: [PATCH 3/5] fix: capture aborted spans --- lib/instrumentation/modules/elasticsearch.js | 10 +++ test/instrumentation/modules/elasticsearch.js | 70 +++++-------------- 2 files changed, 29 insertions(+), 51 deletions(-) diff --git a/lib/instrumentation/modules/elasticsearch.js b/lib/instrumentation/modules/elasticsearch.js index 14ee08cef5..937897e5b3 100644 --- a/lib/instrumentation/modules/elasticsearch.js +++ b/lib/instrumentation/modules/elasticsearch.js @@ -70,6 +70,16 @@ module.exports = function (elasticsearch, agent, { enabled }) { delete descriptors.domain Object.defineProperties(inspectedPromise, descriptors) + // we have to properly end the span when user aborts the request + shimmer.wrap(inspectedPromise, 'abort', function wrapAbort (originalAbort) { + return function wrappedAbort () { + if (span.ended) return + agent.logger.debug('intercepted call to elasticsearch.Transport.request.abort %o', { id: id, method: method, path: path }) + span.end() + return originalAbort.apply(this, args) + } + }) + return inspectedPromise } } else { diff --git a/test/instrumentation/modules/elasticsearch.js b/test/instrumentation/modules/elasticsearch.js index 9395074560..9b93d05af2 100644 --- a/test/instrumentation/modules/elasticsearch.js +++ b/test/instrumentation/modules/elasticsearch.js @@ -48,43 +48,33 @@ test('client.ping with promise', function userLandCode (t) { }) }) -test('client.ping with unhandled promise', function userLandCode (t) { - resetAgent(2, doneNoHTTP(t, 'HEAD', '/')) +test('client.search with callback', function userLandCode (t) { + resetAgent(done(t, 'POST', '/_search', '{"q":"pants"}')) agent.startTransaction('foo') - const client = new elasticsearch.Client({ - host: 'thiswillneverwork', - log: { - type: 'file', - level: 'error', - path: '/dev/null' - } - }) - - const unhandledPromise = client.ping() - - process.once('unhandledRejection', agent._instrumentation.bindFunction(unhandledRejection)) + var client = new elasticsearch.Client({ host: host }) + var query = { q: 'pants' } - function unhandledRejection (reason, promise) { - t.equal(promise, unhandledPromise) - t.strictEqual(typeof promise.abort, 'function', 'promise.abort should be a function') + client.search(query, function (err) { + t.error(err) agent.endTransaction() agent.flush() - client.close() - } + }) }) -test('client.search with callback', function userLandCode (t) { - resetAgent(done(t, 'POST', '/_search', '{"q":"pants"}')) +test('client.search with abort', function userLandCode (t) { + resetAgent(3, done(t, 'POST', '/_search', '{"q":"pants"}', true)) agent.startTransaction('foo') var client = new elasticsearch.Client({ host: host }) var query = { q: 'pants' } - client.search(query, function (err) { - t.error(err) + var req = client.search(query) + + setImmediate(() => { + req.abort() agent.endTransaction() agent.flush() }) @@ -194,7 +184,7 @@ test('client.count with callback', function userLandCode (t) { }) var queryRegexp = /_((search|msearch)(\/template)?|count)$/ -function done (t, method, path, query) { +function done (t, method, path, query, abort = false) { return function (data, cb) { t.strictEqual(data.transactions.length, 1) t.strictEqual(data.spans.length, 2) @@ -247,33 +237,11 @@ function done (t, method, path, query) { } t.ok(span1.timestamp > span2.timestamp, 'http span should start after elasticsearch span') - t.ok(span1.timestamp + span1.duration * 1000 < span2.timestamp + span2.duration * 1000, 'http span should end before elasticsearch span') - - t.end() - } -} - -function doneNoHTTP (t, method, path, query) { - return function (data, cb) { - t.equal(data.transactions.length, 1) - t.equal(data.spans.length, 1) - - var trans = data.transactions[0] - var span = data.spans[0] - - t.equal(trans.name, 'foo') - t.equal(trans.type, 'custom') - - t.equal(span.type, 'db') - t.equal(span.subtype, 'elasticsearch') - t.equal(span.action, 'request') - t.equal(span.name, 'Elasticsearch: ' + method + ' ' + path) - - t.ok(span.stacktrace.some(function (frame) { - return frame.function === 'userLandCode' - }), 'include user-land code frame') - - t.notOk(span.context) + if (abort) { + t.ok(span1.timestamp + span1.duration * 1000 > span2.timestamp + span2.duration * 1000, 'http span should end after elasticsearch span when req is aborted') + } else { + t.ok(span1.timestamp + span1.duration * 1000 < span2.timestamp + span2.duration * 1000, 'http span should end before elasticsearch span') + } t.end() } From f1bf177d0e8cf9fe9a0d2a915d88a726463b5edf Mon Sep 17 00:00:00 2001 From: vigneshshanmugam Date: Thu, 6 Aug 2020 12:43:55 +0200 Subject: [PATCH 4/5] chore: end span after calling abort --- lib/instrumentation/modules/elasticsearch.js | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/lib/instrumentation/modules/elasticsearch.js b/lib/instrumentation/modules/elasticsearch.js index 937897e5b3..70a0545274 100644 --- a/lib/instrumentation/modules/elasticsearch.js +++ b/lib/instrumentation/modules/elasticsearch.js @@ -75,8 +75,9 @@ module.exports = function (elasticsearch, agent, { enabled }) { return function wrappedAbort () { if (span.ended) return agent.logger.debug('intercepted call to elasticsearch.Transport.request.abort %o', { id: id, method: method, path: path }) + const originalReturn = originalAbort.apply(this, args) span.end() - return originalAbort.apply(this, args) + return originalReturn } }) From 7b3070665f9708809c324d1c858b6af9061cbf0d Mon Sep 17 00:00:00 2001 From: vigneshshanmugam Date: Thu, 6 Aug 2020 17:13:16 +0200 Subject: [PATCH 5/5] chore: obtain descriptors before promise tick --- lib/instrumentation/modules/elasticsearch.js | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/lib/instrumentation/modules/elasticsearch.js b/lib/instrumentation/modules/elasticsearch.js index 70a0545274..705e76c6d2 100644 --- a/lib/instrumentation/modules/elasticsearch.js +++ b/lib/instrumentation/modules/elasticsearch.js @@ -57,6 +57,9 @@ module.exports = function (elasticsearch, agent, { enabled }) { } else { const originalPromise = original.apply(this, arguments) + const descriptors = Object.getOwnPropertyDescriptors(originalPromise) + delete descriptors.domain + const inspectedPromise = originalPromise .then(function (value) { span.end() @@ -66,8 +69,6 @@ module.exports = function (elasticsearch, agent, { enabled }) { throw err }) - const descriptors = Object.getOwnPropertyDescriptors(originalPromise) - delete descriptors.domain Object.defineProperties(inspectedPromise, descriptors) // we have to properly end the span when user aborts the request