Skip to content

Commit

Permalink
feat(sdk-trace-base): extra log operations on ended spans
Browse files Browse the repository at this point in the history
* Address PR feedback from #5184
* Fix tests and lint
  • Loading branch information
neilfordyce committed Jan 23, 2025
1 parent 97b1315 commit 9fe6cb8
Show file tree
Hide file tree
Showing 2 changed files with 28 additions and 30 deletions.
19 changes: 9 additions & 10 deletions packages/opentelemetry-sdk-trace-base/src/Span.ts
Original file line number Diff line number Diff line change
Expand Up @@ -369,18 +369,17 @@ export class SpanImpl implements Span {

private _isSpanEnded(): boolean {
if (this._ended) {
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}`);
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}}`,
error
);
}
return this._ended;
}
}

// Utility function to truncate given value within size
// for value type of string, will truncate to given limit
Expand Down
39 changes: 19 additions & 20 deletions packages/opentelemetry-sdk-trace-base/test/common/Span.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -280,31 +280,30 @@ 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

it('should log a warning attempting to add event to ended span', () => {
const span = new SpanImpl({
scope: tracer.instrumentationScope,
resource: tracer['_resource'],
context: ROOT_CONTEXT,
spanContext,
name,
kind: SpanKind.CLIENT,
spanLimits: tracer.getSpanLimits(),
spanProcessor: tracer['_spanProcessor'],
});
span.end();

const warnStub = sinon.spy(diag, 'warn');
const debugStub = sinon.spy(diag, 'debug');

// Call the method that checks if the span is ended
span['_isSpanEnded']();
span.addEvent('oops, too late');

// 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:'));
});
sinon.assert.calledWith(
warnStub,
sinon.match(/Cannot execute the operation on ended Span/),
sinon.match.instanceOf(Error)
);
});

describe('setAttribute', () => {
Expand Down

0 comments on commit 9fe6cb8

Please sign in to comment.