From 079d802958b6421c58ecac934bc9715eace1b1df Mon Sep 17 00:00:00 2001 From: Trent Mick Date: Wed, 15 Sep 2021 12:07:38 -0700 Subject: [PATCH 1/8] fix: more reliable span.sync determination Current `span.sync` is tracked via: - the "before" async hook setting it false on the "active" span, and - Instrumentation#bindFunction's wrapper setting it false, on the fair assumption that all usages of bindFunction are for async callbacks. The former has issues when there are multiple active spans within a single async task -- as is the case with Elasticsearch instrumentation (issue #1996) and the aws-sdk instrumentations (which have manual workarounds). This changes to set sync=false if the executionAsyncId() at end-time is different than at start-time. This works for whatever `asyncHooks` config var value. Fixes: #1996 --- lib/instrumentation/async-hooks.js | 8 -------- lib/instrumentation/index.js | 8 +------- lib/instrumentation/modules/aws-sdk/dynamodb.js | 7 ------- lib/instrumentation/modules/aws-sdk/s3.js | 8 -------- lib/instrumentation/modules/aws-sdk/sqs.js | 3 --- lib/instrumentation/span.js | 5 +++++ lib/instrumentation/transaction.js | 5 +++++ 7 files changed, 11 insertions(+), 33 deletions(-) diff --git a/lib/instrumentation/async-hooks.js b/lib/instrumentation/async-hooks.js index 6f0c1f4e38..434d870b5d 100644 --- a/lib/instrumentation/async-hooks.js +++ b/lib/instrumentation/async-hooks.js @@ -92,14 +92,6 @@ module.exports = function (ins) { } function before (asyncId) { - const span = activeSpans.get(asyncId) - if (span && !span.ended) { - span.sync = false - } - const transaction = span ? span.transaction : activeTransactions.get(asyncId) - if (transaction && !transaction.ended) { - transaction.sync = false - } ins.bindingSpan = null } diff --git a/lib/instrumentation/index.js b/lib/instrumentation/index.js index 61c6a02cd5..dfb8551654 100644 --- a/lib/instrumentation/index.js +++ b/lib/instrumentation/index.js @@ -353,11 +353,7 @@ var wrapped = Symbol('elastic-apm-wrapped-function') // the callback function gets instrument on "the right" transaction and span. // // The instrumentation programmer is still responsible for starting a span, -// and ending a span. Additionally, this function will set a span's sync -// property to `false` -- it's up to the instrumentation programmer to ensure -// that the callback they're binding is really async. If bindFunction is -// passed a callback that the wrapped function executes synchronously, it will -// still mark the span's `async` property as `false`. +// and ending a span. // // @param {function} original Instrumentation.prototype.bindFunction = function (original) { @@ -379,8 +375,6 @@ Instrumentation.prototype.bindFunction = function (original) { ins.currentTransaction = trans ins.bindingSpan = null ins.activeSpan = span - if (trans) trans.sync = false - if (span) span.sync = false var result = original.apply(this, arguments) ins.currentTransaction = prevTrans return result diff --git a/lib/instrumentation/modules/aws-sdk/dynamodb.js b/lib/instrumentation/modules/aws-sdk/dynamodb.js index e4b7180cc3..e13ab5601f 100644 --- a/lib/instrumentation/modules/aws-sdk/dynamodb.js +++ b/lib/instrumentation/modules/aws-sdk/dynamodb.js @@ -100,13 +100,6 @@ function instrumentationDynamoDb (orig, origArguments, request, AWS, agent, { ve span._setOutcomeFromErrorCapture(constants.OUTCOME_FAILURE) } - // Workaround a bug in the agent's handling of `span.sync`. - // - // The bug: Currently this span.sync is not set `false` because there is - // an HTTP span created (for this S3 request) in the same async op. That - // HTTP span becomes the "active span" for this async op, and *it* gets - // marked as sync=false in `before()` in async-hooks.js. - span.sync = false span.end() }) diff --git a/lib/instrumentation/modules/aws-sdk/s3.js b/lib/instrumentation/modules/aws-sdk/s3.js index b305adcb16..5ffaac255b 100644 --- a/lib/instrumentation/modules/aws-sdk/s3.js +++ b/lib/instrumentation/modules/aws-sdk/s3.js @@ -109,14 +109,6 @@ function instrumentationS3 (orig, origArguments, request, AWS, agent, { version, } } - // Workaround a bug in the agent's handling of `span.sync`. - // - // The bug: Currently this span.sync is not set `false` because there is - // an HTTP span created (for this S3 request) in the same async op. That - // HTTP span becomes the "active span" for this async op, and *it* gets - // marked as sync=false in `before()` in async-hooks.js. - span.sync = false - span.end() }) } diff --git a/lib/instrumentation/modules/aws-sdk/sqs.js b/lib/instrumentation/modules/aws-sdk/sqs.js index 8058ae8874..84bf6f98b5 100644 --- a/lib/instrumentation/modules/aws-sdk/sqs.js +++ b/lib/instrumentation/modules/aws-sdk/sqs.js @@ -163,9 +163,6 @@ function instrumentationSqs (orig, origArguments, request, AWS, agent, { version span._setOutcomeFromErrorCapture(constants.OUTCOME_FAILURE) } - // we'll need to manually mark this span as async. The actual async hop - // is captured by the agent's async hooks instrumentation - span.sync = false span.end() if (request.operation === 'receiveMessage' && response && response.data) { diff --git a/lib/instrumentation/span.js b/lib/instrumentation/span.js index 2bad0162e1..b10e588836 100644 --- a/lib/instrumentation/span.js +++ b/lib/instrumentation/span.js @@ -1,5 +1,6 @@ 'use strict' +const { executionAsyncId } = require('async_hooks') var util = require('util') var Value = require('async-value-promise') @@ -34,6 +35,7 @@ function Span (transaction, name, ...args) { this._message = null this._stackObj = null this._capturedStackTrace = null + this._startXid = executionAsyncId() this.transaction = transaction this.name = name || 'unnamed' @@ -71,6 +73,9 @@ Span.prototype.end = function (endTime) { } this._timer.end(endTime) + if (executionAsyncId() !== this._startXid) { + this.sync = false + } this._setOutcomeFromSpanEnd() diff --git a/lib/instrumentation/transaction.js b/lib/instrumentation/transaction.js index 4a690b65d3..89d6ed28c4 100644 --- a/lib/instrumentation/transaction.js +++ b/lib/instrumentation/transaction.js @@ -1,5 +1,6 @@ 'use strict' +const { executionAsyncId } = require('async_hooks') var util = require('util') var ObjectIdentityMap = require('object-identity-map') @@ -35,6 +36,7 @@ function Transaction (agent, name, ...args) { this._contextLost = false // TODO: Send this up to the server some how this._abortTime = 0 this._breakdownTimings = new ObjectIdentityMap() + this._startXid = executionAsyncId() this.outcome = constants.OUTCOME_UNKNOWN } @@ -232,6 +234,9 @@ Transaction.prototype.end = function (result, endTime) { this._timer.end(endTime) this._captureBreakdown(this) this.ended = true + if (executionAsyncId() !== this._startXid) { + this.sync = false + } var trans = this._agent._instrumentation.currentTransaction From cf143cfd9f3557a5f6fdd72b38fe9e5311bd79c4 Mon Sep 17 00:00:00 2001 From: Trent Mick Date: Wed, 15 Sep 2021 12:39:01 -0700 Subject: [PATCH 2/8] test fix for only setting span.sync at span.end()-time --- test/instrumentation/async-hooks.test.js | 25 ++++++------------------ 1 file changed, 6 insertions(+), 19 deletions(-) diff --git a/test/instrumentation/async-hooks.test.js b/test/instrumentation/async-hooks.test.js index a5989b9d63..17fecd3328 100644 --- a/test/instrumentation/async-hooks.test.js +++ b/test/instrumentation/async-hooks.test.js @@ -121,20 +121,23 @@ test('post-defined, post-resolved promise', function (t) { }) }) -test('sync/async tracking: span ended in same function is sync', function (t) { +test('sync.sync', function (t) { var trans = agent.startTransaction() t.strictEqual(trans.sync, true) - var span1 = agent.startSpan() + var span1 = agent.startSpan('span1') t.strictEqual(span1.sync, true) // This span will be *ended* synchronously. It should stay `span.sync=true`. - var span2 = agent.startSpan() + var span2 = agent.startSpan('span2') t.strictEqual(span2.sync, true, 'span2.sync=true immediately after creation') span2.end() t.strictEqual(span2.sync, true, 'span2.sync=true immediately after end') setImmediate(() => { + span1.end() + t.strictEqual(span1.sync, false) + trans.end() t.strictEqual(trans.sync, false) t.strictEqual(span2.sync, true, 'span2.sync=true later after having ended sync') @@ -142,22 +145,6 @@ test('sync/async tracking: span ended in same function is sync', function (t) { }) }) -test('sync/async tracking: span ended across async boundary is not sync', function (t) { - var trans = agent.startTransaction() - t.strictEqual(trans.sync, true) - - var span1 = agent.startSpan() - t.strictEqual(span1.sync, true) - - setImmediate(() => { - span1.end() - t.strictEqual(trans.sync, false) - t.strictEqual(span1.sync, false, - 'span1.sync=true after having ended sync') - t.end() - }) -}) - function twice (fn) { setImmediate(fn) setImmediate(fn) From 4936dd865022b5f0af24372a41747299132936b3 Mon Sep 17 00:00:00 2001 From: Trent Mick Date: Wed, 15 Sep 2021 13:38:24 -0700 Subject: [PATCH 3/8] must now end a span/trans before using its .sync field val; also fix reliability of transaction.test.js usage of agent._transport (CapturingTransport) --- test/instrumentation/span.test.js | 1 + test/instrumentation/transaction.test.js | 24 +++++++++++++----------- 2 files changed, 14 insertions(+), 11 deletions(-) diff --git a/test/instrumentation/span.test.js b/test/instrumentation/span.test.js index e0dd65e72d..43afa8486e 100644 --- a/test/instrumentation/span.test.js +++ b/test/instrumentation/span.test.js @@ -166,6 +166,7 @@ test('sync/async tracking', function (t) { var span = new Span(trans) t.strictEqual(span.sync, true) setImmediate(() => { + span.end() t.strictEqual(span.sync, false) t.end() }) diff --git a/test/instrumentation/transaction.test.js b/test/instrumentation/transaction.test.js index c2fcd2b4de..a87cb63bbe 100644 --- a/test/instrumentation/transaction.test.js +++ b/test/instrumentation/transaction.test.js @@ -173,6 +173,8 @@ test('#startSpan()', function (t) { }) test('#end() - with result', function (t) { + agent._transport.clear() + var trans = new Transaction(agent) trans.end('test-result') t.strictEqual(trans.ended, true) @@ -182,11 +184,12 @@ test('#end() - with result', function (t) { t.strictEqual(added.id, trans.id) t.strictEqual(added.result, 'test-result') - agent._transport.clear() // clear the CapturingTransport for subsequent tests t.end() }) test('#duration()', function (t) { + agent._transport.clear() + var trans = new Transaction(agent) setTimeout(function () { trans.end() @@ -197,7 +200,6 @@ test('#duration()', function (t) { // TODO: Figure out why this fails on Jenkins... // t.ok(added.duration < 100) - agent._transport.clear() t.end() }, 50) }) @@ -217,7 +219,6 @@ test('custom start time', function (t) { t.ok(duration > 990, `duration should be circa more than 1s (was: ${duration})`) // we've seen 998.752 in the wild t.ok(duration < 1100, `duration should be less than 1.1s (was: ${duration})`) - agent._transport.clear() t.end() }) @@ -229,7 +230,6 @@ test('#end(time)', function (t) { t.strictEqual(trans.duration(), 2000.123) - agent._transport.clear() t.end() }) @@ -266,11 +266,12 @@ test('name - default first, then custom', function (t) { }) test('parallel transactions', function (t) { + agent._transport.clear() + function finish () { t.equal(agent._transport.transactions[0].name, 'second') t.equal(agent._transport.transactions[1].name, 'first') - agent._transport.clear() t.end() } @@ -294,6 +295,7 @@ test('sync/async tracking', function (t) { var trans = new Transaction(agent) t.strictEqual(trans.sync, true) setImmediate(() => { + trans.end() t.strictEqual(trans.sync, false) t.end() }) @@ -306,6 +308,8 @@ test('#_encode() - un-ended', function (t) { }) test('#_encode() - ended', function (t) { + agent._transport.clear() + var trans = new Transaction(agent) trans.end() @@ -323,11 +327,12 @@ test('#_encode() - ended', function (t) { t.strictEqual(payload.result, 'success') t.deepEqual(payload.context, { user: {}, tags: {}, custom: {} }) - agent._transport.clear() t.end() }) test('#_encode() - with meta data', function (t) { + agent._transport.clear() + var trans = new Transaction(agent, 'foo', 'bar') trans.result = 'baz' trans.setUserContext({ foo: 1 }) @@ -349,11 +354,12 @@ test('#_encode() - with meta data', function (t) { t.strictEqual(payload.result, 'baz') t.deepEqual(payload.context, { user: { foo: 1 }, tags: { bar: '1' }, custom: { baz: 1 } }) - agent._transport.clear() t.end() }) test('#_encode() - http request meta data', function (t) { + agent._transport.clear() + var trans = new Transaction(agent) trans.req = mockRequest() trans.end() @@ -401,7 +407,6 @@ test('#_encode() - http request meta data', function (t) { } }) - agent._transport.clear() t.end() }) @@ -430,7 +435,6 @@ test('#_encode() - with spans', function (t) { started: 1 }) - agent._transport.clear() t.end() }, 200) }) @@ -470,7 +474,6 @@ test('#_encode() - dropped spans', function (t) { }) agent._conf.transactionMaxSpans = oldTransactionMaxSpans - agent._transport.clear() t.end() }, 200) }) @@ -497,7 +500,6 @@ test('#_encode() - not sampled', function (t) { t.notOk(payload.context) agent._conf.transactionSampleRate = oldTransactionSampleRate - agent._transport.clear() t.end() }) From 39e385472b5c30f17d3d9af95b95c7bdf3d47a08 Mon Sep 17 00:00:00 2001 From: Trent Mick Date: Wed, 15 Sep 2021 13:47:11 -0700 Subject: [PATCH 4/8] fix: drop 'transaction.sync' field, it was never used by apm-server Also add a test for span.sync=false for ES and HTTP spans from @elastic/elasticsearch instrumentation for #1996. Move the span.sync test from async-hooks.test.js over to span.test.js because its impl no longer deps on lib/instrumentation/async-hooks.js. Fixes: #2292 --- lib/instrumentation/generic-span.js | 1 - lib/instrumentation/span.js | 1 + lib/instrumentation/transaction.js | 6 ----- test/instrumentation/async-hooks.test.js | 24 ------------------- .../modules/@elastic/elasticsearch.test.js | 2 ++ test/instrumentation/span.test.js | 23 +++++++++++++----- test/instrumentation/transaction.test.js | 10 -------- 7 files changed, 20 insertions(+), 47 deletions(-) diff --git a/lib/instrumentation/generic-span.js b/lib/instrumentation/generic-span.js index 1cf2ba130b..cf26d16dc8 100644 --- a/lib/instrumentation/generic-span.js +++ b/lib/instrumentation/generic-span.js @@ -23,7 +23,6 @@ function GenericSpan (agent, ...args) { this.timestamp = this._timer.start this.ended = false - this.sync = true this.outcome = constants.OUTCOME_UNKNOWN diff --git a/lib/instrumentation/span.js b/lib/instrumentation/span.js index b10e588836..1d5db4161a 100644 --- a/lib/instrumentation/span.js +++ b/lib/instrumentation/span.js @@ -35,6 +35,7 @@ function Span (transaction, name, ...args) { this._message = null this._stackObj = null this._capturedStackTrace = null + this.sync = true this._startXid = executionAsyncId() this.transaction = transaction diff --git a/lib/instrumentation/transaction.js b/lib/instrumentation/transaction.js index 89d6ed28c4..68520a75bd 100644 --- a/lib/instrumentation/transaction.js +++ b/lib/instrumentation/transaction.js @@ -1,6 +1,5 @@ 'use strict' -const { executionAsyncId } = require('async_hooks') var util = require('util') var ObjectIdentityMap = require('object-identity-map') @@ -36,7 +35,6 @@ function Transaction (agent, name, ...args) { this._contextLost = false // TODO: Send this up to the server some how this._abortTime = 0 this._breakdownTimings = new ObjectIdentityMap() - this._startXid = executionAsyncId() this.outcome = constants.OUTCOME_UNKNOWN } @@ -131,7 +129,6 @@ Transaction.prototype.toJSON = function () { result: String(this.result), sampled: this.sampled, context: undefined, - sync: this.sync, span_count: { started: this._builtSpans }, @@ -234,9 +231,6 @@ Transaction.prototype.end = function (result, endTime) { this._timer.end(endTime) this._captureBreakdown(this) this.ended = true - if (executionAsyncId() !== this._startXid) { - this.sync = false - } var trans = this._agent._instrumentation.currentTransaction diff --git a/test/instrumentation/async-hooks.test.js b/test/instrumentation/async-hooks.test.js index 17fecd3328..a77397e091 100644 --- a/test/instrumentation/async-hooks.test.js +++ b/test/instrumentation/async-hooks.test.js @@ -121,30 +121,6 @@ test('post-defined, post-resolved promise', function (t) { }) }) -test('sync.sync', function (t) { - var trans = agent.startTransaction() - t.strictEqual(trans.sync, true) - - var span1 = agent.startSpan('span1') - t.strictEqual(span1.sync, true) - - // This span will be *ended* synchronously. It should stay `span.sync=true`. - var span2 = agent.startSpan('span2') - t.strictEqual(span2.sync, true, 'span2.sync=true immediately after creation') - span2.end() - t.strictEqual(span2.sync, true, 'span2.sync=true immediately after end') - - setImmediate(() => { - span1.end() - t.strictEqual(span1.sync, false) - trans.end() - t.strictEqual(trans.sync, false) - t.strictEqual(span2.sync, true, - 'span2.sync=true later after having ended sync') - t.end() - }) -}) - function twice (fn) { setImmediate(fn) setImmediate(fn) diff --git a/test/instrumentation/modules/@elastic/elasticsearch.test.js b/test/instrumentation/modules/@elastic/elasticsearch.test.js index 802dfd9aa3..9b339e17f4 100644 --- a/test/instrumentation/modules/@elastic/elasticsearch.test.js +++ b/test/instrumentation/modules/@elastic/elasticsearch.test.js @@ -586,12 +586,14 @@ function checkDataAndEnd (t, method, path, dbStatement) { t.strictEqual(esSpan.type, 'db') t.strictEqual(esSpan.subtype, 'elasticsearch') t.strictEqual(esSpan.action, 'request') + t.strictEqual(esSpan.sync, false, 'span.sync=false') const httpSpan = findObjInArray(data.spans, 'subtype', 'http') t.ok(httpSpan, 'have an http span') t.strictEqual(httpSpan.type, 'external') t.strictEqual(httpSpan.subtype, 'http') t.strictEqual(httpSpan.action, method) + t.strictEqual(httpSpan.sync, false, 'span.sync=false') t.equal(httpSpan.name, method + ' ' + host, 'http span should have expected name') t.equal(esSpan.name, 'Elasticsearch: ' + method + ' ' + path, 'elasticsearch span should have expected name') diff --git a/test/instrumentation/span.test.js b/test/instrumentation/span.test.js index 43afa8486e..682523919b 100644 --- a/test/instrumentation/span.test.js +++ b/test/instrumentation/span.test.js @@ -161,13 +161,24 @@ test('#addLabels', function (t) { t.end() }) -test('sync/async tracking', function (t) { - var trans = new Transaction(agent) - var span = new Span(trans) - t.strictEqual(span.sync, true) +test('span.sync', function (t) { + var trans = agent.startTransaction() + + var span1 = agent.startSpan('span1') + t.strictEqual(span1.sync, true) + + // This span will be *ended* synchronously. It should stay `span.sync=true`. + var span2 = agent.startSpan('span2') + t.strictEqual(span2.sync, true, 'span2.sync=true immediately after creation') + span2.end() + t.strictEqual(span2.sync, true, 'span2.sync=true immediately after end') + setImmediate(() => { - span.end() - t.strictEqual(span.sync, false) + span1.end() + t.strictEqual(span1.sync, false, 'span1.sync=false immediately after end') + trans.end() + t.strictEqual(span2.sync, true, + 'span2.sync=true later after having ended sync') t.end() }) }) diff --git a/test/instrumentation/transaction.test.js b/test/instrumentation/transaction.test.js index a87cb63bbe..f79eb28e65 100644 --- a/test/instrumentation/transaction.test.js +++ b/test/instrumentation/transaction.test.js @@ -291,16 +291,6 @@ test('parallel transactions', function (t) { }, 25) }) -test('sync/async tracking', function (t) { - var trans = new Transaction(agent) - t.strictEqual(trans.sync, true) - setImmediate(() => { - trans.end() - t.strictEqual(trans.sync, false) - t.end() - }) -}) - test('#_encode() - un-ended', function (t) { var trans = new Transaction(agent) t.strictEqual(trans._encode(), null, 'cannot encode un-ended transaction') From a93c1989ecdeac796b7bd40d5b5bd5fa004a5e43 Mon Sep 17 00:00:00 2001 From: Trent Mick Date: Wed, 15 Sep 2021 13:51:46 -0700 Subject: [PATCH 5/8] fix up some test cases for having dropped transaction.sync --- test/instrumentation/transaction.test.js | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/test/instrumentation/transaction.test.js b/test/instrumentation/transaction.test.js index f79eb28e65..7eaaa5c46b 100644 --- a/test/instrumentation/transaction.test.js +++ b/test/instrumentation/transaction.test.js @@ -304,7 +304,7 @@ test('#_encode() - ended', function (t) { trans.end() const payload = agent._transport.transactions[0] - t.deepEqual(Object.keys(payload), ['id', 'trace_id', 'parent_id', 'name', 'type', 'subtype', 'action', 'duration', 'timestamp', 'result', 'sampled', 'context', 'sync', 'span_count', 'outcome', 'sample_rate']) + t.deepEqual(Object.keys(payload), ['id', 'trace_id', 'parent_id', 'name', 'type', 'subtype', 'action', 'duration', 'timestamp', 'result', 'sampled', 'context', 'span_count', 'outcome', 'sample_rate']) t.ok(/^[\da-f]{16}$/.test(payload.id)) t.ok(/^[\da-f]{32}$/.test(payload.trace_id)) t.strictEqual(payload.id, trans.id) @@ -331,7 +331,7 @@ test('#_encode() - with meta data', function (t) { trans.end() const payload = agent._transport.transactions[0] - t.deepEqual(Object.keys(payload), ['id', 'trace_id', 'parent_id', 'name', 'type', 'subtype', 'action', 'duration', 'timestamp', 'result', 'sampled', 'context', 'sync', 'span_count', 'outcome', 'sample_rate']) + t.deepEqual(Object.keys(payload), ['id', 'trace_id', 'parent_id', 'name', 'type', 'subtype', 'action', 'duration', 'timestamp', 'result', 'sampled', 'context', 'span_count', 'outcome', 'sample_rate']) t.ok(/^[\da-f]{16}$/.test(payload.id)) t.ok(/^[\da-f]{32}$/.test(payload.trace_id)) t.strictEqual(payload.id, trans.id) @@ -355,7 +355,7 @@ test('#_encode() - http request meta data', function (t) { trans.end() const payload = agent._transport.transactions[0] - t.deepEqual(Object.keys(payload), ['id', 'trace_id', 'parent_id', 'name', 'type', 'subtype', 'action', 'duration', 'timestamp', 'result', 'sampled', 'context', 'sync', 'span_count', 'outcome', 'sample_rate']) + t.deepEqual(Object.keys(payload), ['id', 'trace_id', 'parent_id', 'name', 'type', 'subtype', 'action', 'duration', 'timestamp', 'result', 'sampled', 'context', 'span_count', 'outcome', 'sample_rate']) t.ok(/^[\da-f]{16}$/.test(payload.id)) t.ok(/^[\da-f]{32}$/.test(payload.trace_id)) t.strictEqual(payload.id, trans.id) From c3736ca84199aff76d2630c434bcea4df71c6f16 Mon Sep 17 00:00:00 2001 From: Trent Mick Date: Mon, 20 Sep 2021 10:12:29 -0700 Subject: [PATCH 6/8] add changelog entry --- CHANGELOG.asciidoc | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/CHANGELOG.asciidoc b/CHANGELOG.asciidoc index 63cfcfc971..47526d0763 100644 --- a/CHANGELOG.asciidoc +++ b/CHANGELOG.asciidoc @@ -40,6 +40,12 @@ Notes: [float] ===== Bug fixes +* Improve `span.sync` determination (fixes {issue}1996[#1996]) and stop + reporting `transaction.sync` which was never used ({issue}2292[#2292]). + A minor semantic change is that `span.sync` is not set to a final value + until `span.end()` is called. Before `span.end()` the value will always + by `true`. + * Guard against a negative value of `metricsInterval`, which can lead to high CPU usage as metrics are collected as fast as possible. Also ensure no metrics collection can happen if `metricsInterval="0s"` as intended. From 60e3ed0e43dccc3c5c078cbc01733795bd000778 Mon Sep 17 00:00:00 2001 From: Trent Mick Date: Mon, 20 Sep 2021 10:12:59 -0700 Subject: [PATCH 7/8] remove the span.sync workaround from SNS instrumentation (I had missed this one earlier) --- lib/instrumentation/modules/aws-sdk/sns.js | 3 --- 1 file changed, 3 deletions(-) diff --git a/lib/instrumentation/modules/aws-sdk/sns.js b/lib/instrumentation/modules/aws-sdk/sns.js index 7389d16ffa..29f8eb5f05 100644 --- a/lib/instrumentation/modules/aws-sdk/sns.js +++ b/lib/instrumentation/modules/aws-sdk/sns.js @@ -131,9 +131,6 @@ function instrumentationSns (orig, origArguments, request, AWS, agent, { version span._setOutcomeFromErrorCapture(constants.OUTCOME_FAILURE) } - // we'll need to manually mark this span as async. The actual async hop - // is captured by the agent's async hooks instrumentation - span.sync = false span.end() }) From d512ebbec3b51f7eed8271cff184738c22decf32 Mon Sep 17 00:00:00 2001 From: Trent Mick Date: Mon, 20 Sep 2021 10:14:27 -0700 Subject: [PATCH 8/8] test span.sync in SNS instrumentation tests --- test/instrumentation/modules/aws-sdk/sns.test.js | 1 + 1 file changed, 1 insertion(+) diff --git a/test/instrumentation/modules/aws-sdk/sns.test.js b/test/instrumentation/modules/aws-sdk/sns.test.js index c42fd802cc..0da48f2509 100644 --- a/test/instrumentation/modules/aws-sdk/sns.test.js +++ b/test/instrumentation/modules/aws-sdk/sns.test.js @@ -243,6 +243,7 @@ tape.test('AWS SNS: End to End Test', function (test) { t.equals(span.type, 'messaging', 'span type correctly set') t.equals(span.subtype, 'sns', 'span subtype set correctly') t.equals(span.action, 'publish', 'span action set correctly') + t.equals(span.sync, false, 'span.sync is false') t.equals(span.context.message.queue.name, 'topic-name') t.equals(span.context.destination.service.resource, 'sns/topic-name') t.equals(span.context.destination.service.type, 'messaging')