Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improved logging mechanism for operations on ended spans, making it easier to trace issues in both Node.js and Browser environments #5113 #5184

Open
wants to merge 7 commits into
base: main
Choose a base branch
from

Conversation

Victorsesan
Copy link

No description provided.

…ded spans, making it easier to trace issues in both Node.js and Browser environments

Reviewer: pichlermarc
Refs: open-telemetry#5113
…ded spans, making it easier to trace issues in both Node.js and Browser environments

Reviewer: pichlermarc
Refs: open-telemetry#5113
@Victorsesan Victorsesan requested a review from a team as a code owner November 20, 2024 13:37
@Victorsesan
Copy link
Author

👋@pichlermarc this good?

);
// Adding a debug log to capture the stack trace
diag.debug(`Stack trace for ended span operation: ${new Error().stack}`);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Using just the stack trace string leads to dev tools not being able to apply custom formatting it does to error object - most notably the ability to jump to source code, which becomes inconsistent

// Test 1
console.log(`stack test - inline - ${new Error().stack}`);

// Test 2
console.log('stack test - arg2', new Error().stack);

// Test 3
console.log('stack test - error obj', new Error());

In chrome, the experience is okay as chrome auto-linkifys links
image

... as long as you don't expect to use sourcemaps - you just get lead into the built file instead of the source
image
image

(realistically at otel bundle size, yeah I'll take sourcemaps thanks)

while firefox doesn't touch non-error objects
image

But it's also an issue when debugging node over --inspect, chrome tries it's best to find some links but only the Error object version is correct:

node --inspect-brk .\logger_test.js

image

(at this point it's also worth considering if it's better to change issue requirements to just change into .warn(message, Error) as diag api allows 2nd+ argument to be unknown)

@pichlermarc
Copy link
Member

@Victorsesan thanks for working on this. I just read through @t2t2's comment here and I think he makes a good point.

(at this point it's also worth considering if it's better to change issue requirements to just change into .warn(message, Error) as diag api allows 2nd+ argument to be unknown)

I initially formulated the requirements in that way so that people would not think it's an actual unhandled Error and open bug issues everywhere. But the more I think about it, it actually should be addressed in instrumentation code that does this because it can lead to lost telemetry.

@Victorsesan would you mind changing your PR to put the error directly as the second argument in the warn message? Sorry for the churn 😞

@Victorsesan
Copy link
Author

👋 @pichlermarc

Copy link
Member

@pichlermarc pichlermarc left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for updating this - I think we can drop the debug log now since we just pass it to warn. There will be no extra info that end-user derive from enabling debug.

Once that's done and tests are updated we can merge this - sorry again for changing the requirements on you after you've already done the work. 😞

Comment on lines +373 to +374
// Optionally, you can still log the stack trace for additional context
diag.debug(`Stack trace for ended span operation: ${error.stack}`);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this one now does not provide extra value since the error is passed to the warn, we can safely remove it :)

Comment on lines +368 to +371
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
);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Since we remove the additional debug log, we can also remove the message telling people to enable it.

Suggested change
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
);
diag.warn(
`Cannot execute the operation on ended Span {traceId: ${this._spanContext.traceId}, spanId: ${this._spanContext.spanId}}.`,
error // Pass the error object as the second argument
);

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

[sdk-trace-base] add debug-level log with stack trace when modifying neded span
3 participants