diff --git a/CHANGELOG.asciidoc b/CHANGELOG.asciidoc index b266b3aaac..20d46a06de 100644 --- a/CHANGELOG.asciidoc +++ b/CHANGELOG.asciidoc @@ -101,6 +101,8 @@ specifying links during span creation (with the limitation that span link Lambda layers now that https://aws.amazon.com/blogs/compute/node-js-16-x-runtime-now-available-in-aws-lambda/[this runtime is available on AWS]. +- Adds [dropped span statistics](https://github.com/elastic/apm/blob/main/specs/agents/handling-huge-traces/tracing-spans-dropped-stats.md) to transaction payloads allowing APM Server to calculate more accurate throughput metrics. + [float] ===== Bug fixes diff --git a/lib/instrumentation/dropped-span-stats.js b/lib/instrumentation/dropped-span-stats.js new file mode 100644 index 0000000000..2c92d650c0 --- /dev/null +++ b/lib/instrumentation/dropped-span-stats.js @@ -0,0 +1,58 @@ +'use strict' +const LIMIT_STATS = 128 +class DroppedSpanStats { + constructor () { + this.statsMap = new Map() + } + + captureDroppedSpan (span) { + const resource = span && span._destination && span._destination.service && span._destination.service.resource + if (!resource || !span._exitSpan) { + return + } + + const stats = this.getOrCreateStats(resource, span.outcome) + if (!stats) { + return + } + stats.duration.count++ + stats.duration.sum.us += (span._duration * 1000) + return true + } + + getOrCreateStats (resource, outcome) { + const key = [resource, outcome].join('') + let stats = this.statsMap.get(key) + if (stats) { + return stats + } + + if (this.statsMap.size >= LIMIT_STATS) { + return + } + stats = { + duration: { + count: 0, + sum: { + us: 0 + } + }, + destination_service_resource: resource, + outcome: outcome + } + this.statsMap.set(key, stats) + return stats + } + + encode () { + return Array.from(this.statsMap.values()) + } + + size () { + return this.statsMap.size + } +} + +module.exports = { + DroppedSpanStats +} diff --git a/lib/instrumentation/index.js b/lib/instrumentation/index.js index d3475d9947..f581025cab 100644 --- a/lib/instrumentation/index.js +++ b/lib/instrumentation/index.js @@ -357,6 +357,7 @@ Instrumentation.prototype.addEndedSpan = function (span) { } if (!span.isRecorded()) { + span.transaction.captureDroppedSpan(span) return } diff --git a/lib/instrumentation/transaction.js b/lib/instrumentation/transaction.js index 3d341292f8..b9bea11441 100644 --- a/lib/instrumentation/transaction.js +++ b/lib/instrumentation/transaction.js @@ -5,6 +5,7 @@ var util = require('util') var ObjectIdentityMap = require('object-identity-map') const constants = require('../constants') +const { DroppedSpanStats } = require('./dropped-span-stats') var getPathFromRequest = require('./express-utils').getPathFromRequest var GenericSpan = require('./generic-span') var parsers = require('../parsers') @@ -87,6 +88,7 @@ function Transaction (agent, name, ...args) { this._service = undefined this._message = undefined this._cloud = undefined + this._droppedSpanStats = new DroppedSpanStats() this.outcome = constants.OUTCOME_UNKNOWN } @@ -280,6 +282,9 @@ Transaction.prototype.toJSON = function () { payload.links = this._links } + if (this._droppedSpanStats.size() > 0) { + payload.dropped_spans_stats = this._droppedSpanStats.encode() + } return payload } @@ -433,6 +438,10 @@ Transaction.prototype._captureBreakdown = function (span) { } } +Transaction.prototype.captureDroppedSpan = function (span) { + return this._droppedSpanStats.captureDroppedSpan(span) +} + function transactionBreakdownDetails ({ name, type } = {}) { return { name, diff --git a/test/instrumentation/dropped-span-stats.test.js b/test/instrumentation/dropped-span-stats.test.js new file mode 100644 index 0000000000..f14ea19ab6 --- /dev/null +++ b/test/instrumentation/dropped-span-stats.test.js @@ -0,0 +1,141 @@ +'use strict' +const agent = require('../..').start({ + serviceName: 'test-span-stats', + captureExceptions: false, + metricsInterval: 0, + centralConfig: false, + cloudProvider: 'none', + spanCompressionEnabled: true, + spanCompressionExactMatchMaxDuration: '60ms', + spanCompressionSameKindMaxDuration: '50ms' +}) + +const tape = require('tape') +const { OUTCOME_FAILURE, OUTCOME_SUCCESS } = require('../../lib/constants') + +const destinationContext = { + service: { + resource: 'foo' + } +} +tape.test(function (suite) { + suite.test('test DroppedSpanStats invalid cases', function (test) { + const transaction = agent.startTransaction('trans') + const span = agent.startSpan('foo', 'baz', 'bar', { exitSpan: true }) + span.setDestinationContext(destinationContext) + span.setOutcome(OUTCOME_SUCCESS) + span.end() + + test.ok(transaction.captureDroppedSpan(span)) + + test.ok(!transaction.captureDroppedSpan(null)) + + span.setOutcome(OUTCOME_SUCCESS) + span.setDestinationContext({ + service: {} + }) + test.ok(!transaction.captureDroppedSpan(span)) + + transaction.end() + test.end() + }) + + suite.test('test DroppedSpanStats objects', function (test) { + const transaction = agent.startTransaction('trans') + for (let i = 0; i < 2; i++) { + const span = agent.startSpan('foo', 'baz', 'bar', { exitSpan: true }) + span.setDestinationContext(destinationContext) + span.setOutcome(OUTCOME_SUCCESS) + span.end() + test.ok( + transaction.captureDroppedSpan(span) + ) + } + + for (let i = 0; i < 3; i++) { + const span = agent.startSpan('foo', 'baz', 'bar', { exitSpan: true }) + span.setDestinationContext(destinationContext) + span.setOutcome(OUTCOME_FAILURE) + span.end() + test.ok( + transaction.captureDroppedSpan(span) + ) + } + + for (let i = 0; i < 4; i++) { + const span = agent.startSpan('foo', 'baz', 'bar', { exitSpan: true }) + span.setDestinationContext({ + service: { + resource: 'bar' + } + }) + span.setOutcome(OUTCOME_SUCCESS) + span.end() + span._duration = 1000 // override duration so we can test the sum + test.ok( + transaction.captureDroppedSpan(span) + ) + } + transaction.end() + + // three distinct resource/outcome pairs captured + test.equals(transaction._droppedSpanStats.statsMap.size, 3) + + const payload = transaction._encode() + const stats = payload.dropped_spans_stats + test.equals(stats[0].duration.count, 2) + test.equals(stats[0].destination_service_resource, 'foo') + test.equals(stats[0].outcome, OUTCOME_SUCCESS) + + test.equals(stats[1].duration.count, 3) + test.equals(stats[1].destination_service_resource, 'foo') + test.equals(stats[1].outcome, OUTCOME_FAILURE) + + test.equals(stats[2].duration.count, 4) + test.equals(stats[2].destination_service_resource, 'bar') + test.equals(stats[2].duration.sum.us, 4000000) + test.equals(stats[2].outcome, OUTCOME_SUCCESS) + + test.end() + }) + + suite.test('test DroppedSpanStats max items', function (test) { + const transaction = agent.startTransaction('trans') + for (let i = 0; i < 128; i++) { + const destinationContext = { + service: { + resource: 'foo' + i + } + } + const span = agent.startSpan('foo', 'baz', 'bar', { exitSpan: true }) + span.setDestinationContext(destinationContext) + span.setOutcome(OUTCOME_FAILURE) + span.end() + test.ok(transaction.captureDroppedSpan(span)) + } + + // one too many + const span = agent.startSpan('foo', 'baz', 'bar', { exitSpan: true }) + span.setDestinationContext(destinationContext) + span.setOutcome(OUTCOME_FAILURE) + span.end() + test.ok(!transaction.captureDroppedSpan(span)) + + // and we're still able to increment spans that fit the previous profile + const span2 = agent.startSpan('foo', 'baz', 'bar', { exitSpan: true }) + span2.setDestinationContext({ + service: { + resource: 'foo0' + } + }) + span2.setOutcome(OUTCOME_FAILURE) + span2.end() + test.ok(transaction.captureDroppedSpan(span2)) + + transaction.end() + test.equals(transaction._droppedSpanStats.statsMap.size, 128) + test.end() + }) + + suite.end() +}) diff --git a/test/instrumentation/transaction.test.js b/test/instrumentation/transaction.test.js index 8b1c608c2d..00cd263d7c 100644 --- a/test/instrumentation/transaction.test.js +++ b/test/instrumentation/transaction.test.js @@ -499,11 +499,17 @@ test('#_encode() - dropped spans', function (t) { trans.result = 'result' var span0 = trans.startSpan('s0', 'type0') trans.startSpan('s1', 'type1') - var span2 = trans.startSpan() + var span2 = trans.startSpan('s2', { exitSpan: true }) + span2.setDestinationContext({ + service: { + resource: 'foo' + } + }) if (span2.isRecorded()) { t.fail('should have dropped the span') } span0.end() + span2.end() trans.end() agent.flush(function () { @@ -527,7 +533,7 @@ test('#_encode() - dropped spans', function (t) { started: 2, dropped: 1 }) - + t.equals(payload.dropped_spans_stats.length, 1) agent._conf.transactionMaxSpans = oldTransactionMaxSpans t.end() })