From 7b15838b6a6c4c535ce3b51c946a387bd3a677b9 Mon Sep 17 00:00:00 2001 From: Victor Date: Sun, 17 Nov 2024 02:34:04 +0100 Subject: [PATCH] feat(sdk-trace-base): improved logging mechanism for operations on ended spans, making it easier to trace issues in both Node.js and Browser environments Reviewer: pichlermarc Refs: #5113 feat(sdk-trace-base): improved logging mechanism for operations on ended spans, making it easier to trace issues in both Node.js and Browser environments Reviewer: pichlermarc Refs: #5113 feat(sdk-trace-base): improved logging mechanism for operations on ended spans, making it easier to trace issues in both Node.js and Browser environments Reviewer: pichlermarc Refs: #5113 --- package.json | 4 +-- .../opentelemetry-sdk-trace-base/src/Span.ts | 14 +++++++--- .../test/common/Span.test.ts | 26 +++++++++++++++++++ 3 files changed, 38 insertions(+), 6 deletions(-) diff --git a/package.json b/package.json index 8efce3d2656..449c5345159 100644 --- a/package.json +++ b/package.json @@ -105,8 +105,8 @@ "karma-webpack": "5.0.1", "lerna": "6.6.2", "linkinator": "6.1.2", - "markdownlint-cli2": "0.17.2", - "prettier": "3.4.2", + "markdownlint-cli2": "0.15.0", + "prettier": "3.0.3", "process": "0.11.10", "semver": "7.6.3", "ts-node": "10.9.2", diff --git a/packages/opentelemetry-sdk-trace-base/src/Span.ts b/packages/opentelemetry-sdk-trace-base/src/Span.ts index f28f74a3e1e..26ee7aeead5 100644 --- a/packages/opentelemetry-sdk-trace-base/src/Span.ts +++ b/packages/opentelemetry-sdk-trace-base/src/Span.ts @@ -369,12 +369,18 @@ export class SpanImpl implements Span { private _isSpanEnded(): boolean { if (this._ended) { - diag.warn( - `Can not execute the operation on ended Span {traceId: ${this._spanContext.traceId}, spanId: ${this._spanContext.spanId}}` - ); + const error = new Error(`Operation attempted on ended Span {traceId: ${this._spanContext.traceId}, spanId: ${this._spanContext.spanId}}`); + + diag.warn( + `Cannot execute the operation on ended Span {traceId: ${this._spanContext.traceId}, spanId: ${this._spanContext.spanId}}. Change log level to debug for stack trace.`, + error // Pass the error object as the second argument + ); + + // Optionally, you can still log the stack trace for additional context + diag.debug(`Stack trace for ended span operation: ${error.stack}`); } return this._ended; - } +} // Utility function to truncate given value within size // for value type of string, will truncate to given limit diff --git a/packages/opentelemetry-sdk-trace-base/test/common/Span.test.ts b/packages/opentelemetry-sdk-trace-base/test/common/Span.test.ts index cff451c43c2..e2a2beb39e8 100644 --- a/packages/opentelemetry-sdk-trace-base/test/common/Span.test.ts +++ b/packages/opentelemetry-sdk-trace-base/test/common/Span.test.ts @@ -280,6 +280,32 @@ describe('Span', () => { assert.ok(span.isRecording() === false); }); }); + it('should log a warning and a debug message when span is ended', () => { + const span = new Span( + tracer, + ROOT_CONTEXT, + name, + spanContext, + SpanKind.CLIENT + ); + span.end(); // End the span to set it to ended state + + const warnStub = sinon.spy(diag, 'warn'); + const debugStub = sinon.spy(diag, 'debug'); + + // Call the method that checks if the span is ended + span['_isSpanEnded'](); + + // Assert that the warning log was called with the expected message and an Error object + sinon.assert.calledOnce(warnStub); + sinon.assert.calledWith(warnStub, sinon.match(/Cannot execute the operation on ended Span/), sinon.match.instanceOf(Error)); + + // Assert that the debug log was called and contains a stack trace + sinon.assert.calledOnce(debugStub); + const debugMessage = debugStub.getCall(0).args[0]; + assert.ok(debugMessage.startsWith('Stack trace for ended span operation:')); + }); + }); describe('setAttribute', () => { describe('when default options set', () => {