diff --git a/packages/collector/test/tracing/misc/stack_trace/test.js b/packages/collector/test/tracing/misc/stack_trace/test.js index 26ca4db039..9714f5220e 100644 --- a/packages/collector/test/tracing/misc/stack_trace/test.js +++ b/packages/collector/test/tracing/misc/stack_trace/test.js @@ -89,6 +89,10 @@ const mochaSuiteFn = supportedVersion(process.versions.node) ? describe : descri await expressProxyControls.stop(); }); + beforeEach(async () => { + await agentControls.clearReceivedTraceData(); + }); + beforeEach(async () => { await agentControls.waitUntilAppIsCompletelyInitialized(expressControls.getPid()); }); @@ -107,7 +111,7 @@ const mochaSuiteFn = supportedVersion(process.versions.node) ? describe : descri .then(() => testUtils.retry(() => agentControls.getSpans().then(spans => { - expect(spans.length).to.equal(6); + expect(spans.length).to.equal(3); testUtils.expectAtLeastOneMatching(spans, [ span => expect(span.n).to.equal('node.http.server'), span => expect(span.stack).to.have.lengthOf(0) @@ -124,17 +128,16 @@ const mochaSuiteFn = supportedVersion(process.versions.node) ? describe : descri responseStatus: 201 }) .then(() => - testUtils.retry(() => - agentControls.getSpans().then(spans => { - expect(spans.length).to.equal(9); - testUtils.expectAtLeastOneMatching(spans, [ - span => expect(span.n).to.equal('node.http.client'), - span => expect(span.k).to.equal(constants.EXIT), - span => expect(span.stack[2].m).to.equal('fetch'), - span => expect(span.stack[2].c).to.contains('node-fetch') - ]); - }) - ) + agentControls.getSpans().then(spans => { + expect(spans.length).to.equal(3); + testUtils.expectAtLeastOneMatching(spans, [ + span => expect(span.n).to.equal('node.http.client'), + span => expect(span.k).to.equal(constants.EXIT), + // since we remove internal code, only customer code is present in stack trace from now on + span => expect(span.stack[1].m).to.equal('fetch'), + span => expect(span.stack[1].c).to.contains('node-fetch') + ]); + }) )); }); }); diff --git a/packages/core/src/tracing/instrumentation/databases/mysql.js b/packages/core/src/tracing/instrumentation/databases/mysql.js index afee7877bc..23c59dba72 100644 --- a/packages/core/src/tracing/instrumentation/databases/mysql.js +++ b/packages/core/src/tracing/instrumentation/databases/mysql.js @@ -168,7 +168,7 @@ function instrumentedAccessFunction( kind: constants.EXIT }); span.b = { s: 1 }; - span.stack = tracingUtil.getStackTrace(instrumentedAccessFunction); + span.data.mysql = { stmt: tracingUtil.shortenDatabaseStatement( typeof statementOrOpts === 'string' ? statementOrOpts : statementOrOpts.sql @@ -184,16 +184,12 @@ function instrumentedAccessFunction( resultPromise .then(result => { - span.d = Date.now() - span.ts; - span.transmit(); + tracingUtil.completeSpan({ span, referenceFunction: instrumentedAccessFunction }); return result; }) .catch(error => { - span.ec = 1; span.data.mysql.error = tracingUtil.getErrorDetails(error); - - span.d = Date.now() - span.ts; - span.transmit(); + tracingUtil.completeSpan({ span, referenceFunction: instrumentedAccessFunction, error }); return error; }); return resultPromise; @@ -204,12 +200,10 @@ function instrumentedAccessFunction( function onResult(error) { if (error) { - span.ec = 1; span.data.mysql.error = tracingUtil.getErrorDetails(error); } - span.d = Date.now() - span.ts; - span.transmit(); + tracingUtil.completeSpan({ span, referenceFunction: instrumentedAccessFunction, error }); if (originalCallback) { return originalCallback.apply(this, arguments); diff --git a/packages/core/src/tracing/instrumentation/databases/redis.js b/packages/core/src/tracing/instrumentation/databases/redis.js index ddacf5ad57..a49fc27bc5 100644 --- a/packages/core/src/tracing/instrumentation/databases/redis.js +++ b/packages/core/src/tracing/instrumentation/databases/redis.js @@ -319,7 +319,6 @@ function instrumentCommand(original, command, address, cbStyle) { kind: constants.EXIT, spanData }); - span.stack = tracingUtil.getStackTrace(instrumentCommand); let userProvidedCallback; @@ -361,14 +360,11 @@ function instrumentCommand(original, command, address, cbStyle) { } function onResult(error) { - span.d = Date.now() - span.ts; - if (error) { - span.ec = 1; span.data.redis.error = tracingUtil.getErrorDetails(error); } - span.transmit(); + tracingUtil.completeSpan({ span, referenceFunction: instrumentCommand, error }); if (typeof userProvidedCallback === 'function') { return userProvidedCallback.apply(this, arguments); diff --git a/packages/core/src/tracing/instrumentation/protocols/graphql.js b/packages/core/src/tracing/instrumentation/protocols/graphql.js index 5fcbcef99c..4f5dbd4a96 100644 --- a/packages/core/src/tracing/instrumentation/protocols/graphql.js +++ b/packages/core/src/tracing/instrumentation/protocols/graphql.js @@ -142,7 +142,7 @@ function traceQueryOrMutation( kind: constants.ENTRY }); } - span.stack = tracingUtil.getStackTrace(stackTraceRef); + span.data.graphql = { operationType: operationDefinition.operation, operationName: operationDefinition.name ? operationDefinition.name.value : operationName, @@ -151,7 +151,7 @@ function traceQueryOrMutation( }; addFieldsAndArguments(span, operationDefinition); - return runOriginalAndFinish(originalFunction, originalThis, originalArgs, span); + return runOriginalAndFinish(originalFunction, originalThis, originalArgs, span, stackTraceRef); }); } @@ -187,7 +187,6 @@ function traceSubscriptionUpdate( parentSpanId: parentSpan.s }); span.ts = Date.now(); - span.stack = tracingUtil.getStackTrace(stackTraceRef); span.data.graphql = { operationType: subscriptionUpdate, operationName: operationDefinition.name ? operationDefinition.name.value : operationName, @@ -195,7 +194,7 @@ function traceSubscriptionUpdate( args: {} }; addFieldsAndArguments(span, operationDefinition); - return runOriginalAndFinish(originalFunction, originalThis, originalArgs, span); + return runOriginalAndFinish(originalFunction, originalThis, originalArgs, span, stackTraceRef); }); } else { return originalFunction.apply(originalThis, originalArgs); @@ -250,13 +249,13 @@ function traverseSelections(definition, selectionPostProcessor) { return selectionPostProcessor(candidates); } -function runOriginalAndFinish(originalFunction, originalThis, originalArgs, span) { +function runOriginalAndFinish(originalFunction, originalThis, originalArgs, span, stackTraceRef) { let result; try { result = originalFunction.apply(originalThis, originalArgs); } catch (e) { // A synchronous exception happened when resolving the GraphQL query, finish immediately. - finishWithException(span, e); + finishWithException(span, e, stackTraceRef); return result; } @@ -266,43 +265,55 @@ function runOriginalAndFinish(originalFunction, originalThis, originalArgs, span if (result && typeof result.then === 'function') { return result.then( promiseResult => { - finishSpan(span, promiseResult); + finishSpan(span, promiseResult, stackTraceRef); return promiseResult; }, err => { - finishWithException(span, err); + finishWithException(span, err, stackTraceRef); throw err; } ); } else { // The GraphQL operation returned a value instead of a promise - that means, the resolver finished synchronously. We // can finish the span immediately. - finishSpan(span, result); + finishSpan(span, result, stackTraceRef); return result; } } -function finishSpan(span, result) { - span.ec = result.errors && result.errors.length >= 1 ? 1 : 0; - span.d = Date.now() - span.ts; +function finishSpan(span, result, stackTraceRef) { + const hasErrors = result.errors && result.errors.length >= 1; + if (Array.isArray(result.errors)) { span.data.graphql.errors = result.errors .map(singleError => (typeof singleError.message === 'string' ? singleError.message : null)) .filter(msg => !!msg) .join(', '); } - if (!span.postponeTransmit && !span.postponeTransmitApolloGateway) { - span.transmit(); - } + + // call completeSpan with conditional transmission based on postpone flags + const shouldSkipTransmit = span.postponeTransmit || span.postponeTransmitApolloGateway; + const error = hasErrors ? new Error(span.data.graphql.errors || 'GraphQL errors') : null; + + tracingUtil.completeSpan({ + span, + referenceFunction: stackTraceRef || finishSpan, + error, + skipTransmit: shouldSkipTransmit + }); } -function finishWithException(span, err) { - span.ec = 1; - span.d = Date.now() - span.ts; +function finishWithException(span, err, stackTraceRef) { span.data.graphql.errors = err.message; - if (!span.postponeTransmit) { - span.transmit(); - } + + const shouldSkipTransmit = span.postponeTransmit; + + tracingUtil.completeSpan({ + span, + referenceFunction: stackTraceRef || finishWithException, + error: err, + skipTransmit: shouldSkipTransmit + }); } function instrumentApolloGatewayExecuteQueryPlan(apolloGatewayExecuteQueryPlanModule) { diff --git a/packages/core/src/tracing/instrumentation/protocols/http2Client.js b/packages/core/src/tracing/instrumentation/protocols/http2Client.js index af5fd11ad5..f4814dc99a 100644 --- a/packages/core/src/tracing/instrumentation/protocols/http2Client.js +++ b/packages/core/src/tracing/instrumentation/protocols/http2Client.js @@ -120,7 +120,7 @@ function instrumentClientHttp2Session(clientHttp2Session) { const pathWithoutQuery = sanitizeUrl(path); const params = splitAndFilter(path); - span.stack = tracingUtil.getStackTrace(request); + const spanStackRefFn = originalRequest; span.data.http = { method, @@ -138,13 +138,12 @@ function instrumentClientHttp2Session(clientHttp2Session) { }); stream.on('end', () => { - span.d = Date.now() - span.ts; span.ec = status >= 500 ? 1 : 0; span.data.http.status = status; if (capturedHeaders) { span.data.http.header = capturedHeaders; } - span.transmit(); + tracingUtil.completeSpan({ span, referenceFunction: spanStackRefFn, error: null }); }); return stream; diff --git a/packages/core/src/tracing/instrumentation/protocols/httpClient.js b/packages/core/src/tracing/instrumentation/protocols/httpClient.js index 831b62133b..9e7857f239 100644 --- a/packages/core/src/tracing/instrumentation/protocols/httpClient.js +++ b/packages/core/src/tracing/instrumentation/protocols/httpClient.js @@ -225,8 +225,12 @@ function instrument(coreModule, forceHttps) { params = urlAndQuery[1]; } + // This needs to be revisited and removed span.stack = tracingUtil.getStackTrace(request); + // Store original request for span stack collection + const spanStackRefFn = originalRequest; + const boundCallback = cls.ns.bind(function boundCallback(res) { span.data.http = { method: clientRequest.method, @@ -240,9 +244,8 @@ function instrument(coreModule, forceHttps) { span.data.http.header = headers; } - span.d = Date.now() - span.ts; - span.ec = res.statusCode >= 500 ? 1 : 0; - span.transmit(); + const error = res.statusCode >= 500 ? new Error(`HTTP ${res.statusCode}`) : null; + tracingUtil.completeSpan({ span, referenceFunction: spanStackRefFn, error }); if (callback) { callback(res); @@ -266,9 +269,8 @@ function instrument(coreModule, forceHttps) { url: completeCallUrl, error: e ? e.message : '' }; - span.d = Date.now() - span.ts; - span.ec = 1; - span.transmit(); + + tracingUtil.completeSpan({ span, referenceFunction: spanStackRefFn, error: e }); throw e; } @@ -314,9 +316,8 @@ function instrument(coreModule, forceHttps) { url: completeCallUrl, error: errorMessage }; - span.d = Date.now() - span.ts; - span.ec = 1; - span.transmit(); + + tracingUtil.completeSpan({ span, referenceFunction: spanStackRefFn, error: err }); }); }); return clientRequest; @@ -336,10 +337,10 @@ function constructFromUrlOpts(options, self, forceHttps) { try { const agent = options.agent || self.agent; - const isHttps = forceHttps || options.protocol === 'https:' || (agent?.protocol === 'https:'); + const isHttps = forceHttps || options.protocol === 'https:' || agent?.protocol === 'https:'; // Use protocol-aware default port, 443 for HTTPS, 80 for HTTP - const port = options.port || options.defaultPort || (agent?.defaultPort) || (isHttps ? 443 : 80); + const port = options.port || options.defaultPort || agent?.defaultPort || (isHttps ? 443 : 80); const protocol = (port === 443 && 'https:') || diff --git a/packages/core/src/tracing/instrumentation/protocols/nativeFetch.js b/packages/core/src/tracing/instrumentation/protocols/nativeFetch.js index 342c217921..a7ce191580 100644 --- a/packages/core/src/tracing/instrumentation/protocols/nativeFetch.js +++ b/packages/core/src/tracing/instrumentation/protocols/nativeFetch.js @@ -167,7 +167,9 @@ function instrument() { params }; - span.stack = tracingUtil.getStackTrace(instanaFetch); + // span.stack = tracingUtil.getStackTrace(instanaFetch); + + tracingUtil.completeSpan({ span, referenceFunction: instanaFetch }); injectTraceCorrelationHeaders(originalArgs, span, w3cTraceContext); @@ -183,15 +185,16 @@ function instrument() { ); }) .catch(err => { - span.ec = 1; span.data.http.error = err.message; + + tracingUtil.completeSpan({ span, referenceFunction: instanaFetch, skipTransmit: true, error: err }); }) .finally(() => { - span.d = Date.now() - span.ts; if (capturedHeaders != null && Object.keys(capturedHeaders).length > 0) { span.data.http.header = capturedHeaders; } - span.transmit(); + + tracingUtil.completeSpan({ span, referenceFunction: instanaFetch }); }); return fetchPromise; diff --git a/packages/core/src/tracing/tracingUtil.js b/packages/core/src/tracing/tracingUtil.js index 9e0768130b..519e9a8cfc 100644 --- a/packages/core/src/tracing/tracingUtil.js +++ b/packages/core/src/tracing/tracingUtil.js @@ -25,12 +25,28 @@ exports.init = function (config) { }; /** + * Captures and filters stack trace to show only customer application code. + * + * Strategy: Capture more frames than needed (5x the configured length), filter out + * internal frames, then limit to the configured stackTraceLength. This ensures we + * get enough customer code frames even after filtering. + * * @param {Function} referenceFunction * @param {number} [drop] * @returns {Array.<*>} */ exports.getStackTrace = function getStackTrace(referenceFunction, drop) { - return stackTrace.captureStackTrace(stackTraceLength, referenceFunction, drop); + if (stackTraceLength <= 0) { + return []; + } + + // Currently this seems enough for capturing and discarding unwanted calls, may need to revisit + const captureLength = stackTraceLength * 5; + const rawStack = stackTrace.captureStackTrace(captureLength, referenceFunction, drop); + + const filteredStack = stackTrace.filterCustomerCode(rawStack); + + return filteredStack.slice(0, stackTraceLength); }; exports.generateRandomTraceId = function generateRandomTraceId() { @@ -276,3 +292,45 @@ exports.findCallback = (/** @type {string | any[]} */ originalArgs) => { callbackIndex }; }; + +/** + * Ensures span has a stack trace before transmission. + * + * @param {import('../core').InstanaBaseSpan} span - The span to update + * @param {Function} referenceFunction - The function to use as reference for stack trace + * @param {number} [drop] - Number of stack frames to drop + */ +exports.ensureStackTrace = function ensureStackTrace(span, referenceFunction, drop) { + if (!span.stack || span.stack.length === 0) { + span.stack = exports.getStackTrace(referenceFunction, drop); + } +}; + +/** + * Completes a span with lazy stack trace generation. + * This is a convenience wrapper that: + * 1. Sets span.d (duration) + * 2. Handles error case (sets ec=1 and captures stack trace) + * 3. Handles success case (captures stack trace if not already set) + * 4. Conditionally transmits the span (unless skipTransmit is true) + * + * @param {Object} options - Configuration object + * @param {import('../core').InstanaBaseSpan} options.span - The span to complete + * @param {Function} options.referenceFunction - The function to use as reference for stack trace + * @param {Error} [options.error] - Optional error object + * @param {number} [options.drop] - Number of stack frames to drop + * @param {boolean} [options.skipTransmit] - If true, skip calling span.transmit() (for special cases like GraphQL) + */ +exports.completeSpan = function completeSpan({ span, referenceFunction, error, drop, skipTransmit = false }) { + span.d = Date.now() - span.ts; + + if (error) { + span.ec = 1; + } + + exports.ensureStackTrace(span, referenceFunction, drop); + + if (!skipTransmit) { + span.transmit(); + } +}; diff --git a/packages/core/src/util/stackTrace.js b/packages/core/src/util/stackTrace.js index 218735856f..d5f792a1bc 100644 --- a/packages/core/src/util/stackTrace.js +++ b/packages/core/src/util/stackTrace.js @@ -159,6 +159,51 @@ exports.buildFunctionIdentifier = function buildFunctionIdentifier(callSite) { return label; }; +/** + * Filters stack trace to show only customer application code by removing: + * - Node.js internal calls (node:*) + * - Instana instrumentation code + * - CLS/async context tracking code + * + * @param {Array.} stack - The stack trace array + * @returns {Array.} Filtered stack trace containing only customer code + */ +exports.filterCustomerCode = function filterCustomerCode(stack) { + if (!Array.isArray(stack) || stack.length === 0) { + return stack; + } + + const filtered = stack.filter(frame => { + const filePath = frame.c || ''; + + if (!filePath) return false; + + // Filter Node.js internals (node:*, internal/*) + if (filePath.startsWith('node:') || filePath.startsWith('internal/')) { + return false; + } + + // Filter Instana packages in monorepo structure + if (filePath.includes('/packages/core/') || filePath.includes('/packages/collector/')) { + return false; + } + + // Filter CLS/async context tracking + if (filePath.includes('/cls-hooked/') || filePath.includes('/clsHooked/') || filePath.includes('async_hooks')) { + return false; + } + + // Filter shimmer/instrumentation utilities + if (filePath.includes('/shimmer.js') || filePath.includes('/hook.js')) { + return false; + } + + return true; + }); + + return filtered; +}; + /** * @param {Error} error * @param {Array<*>} frames