feat(sdk-trace-base): add util.inspect support for SpanImpl, Tracer, BasicTracerProvider#6690
Conversation
Codecov Report❌ Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## main #6690 +/- ##
==========================================
+ Coverage 94.79% 94.86% +0.06%
==========================================
Files 374 377 +3
Lines 12445 12749 +304
Branches 2842 2887 +45
==========================================
+ Hits 11797 12094 +297
- Misses 648 655 +7
🚀 New features to boost your workflow:
|
…BasicTracerProvider
Implement Symbol.for('nodejs.util.inspect.custom') on the core trace SDK
classes so they render with class tags and key fields when logged via
console.log, util.inspect, or any logger that honors the symbol — including
DiagConsoleLogger used by diag.debug. SpanImpl's payload mirrors
ConsoleSpanExporter's _exportInfo plus internal state (ended flag, drop
counts, scope, resource); Tracer exposes scope, resource, and limits;
BasicTracerProvider exposes resource, registered tracer keys, and span
processor class names. A shared formatInspect helper centralizes depth
handling and the [ClassName] stub when the depth budget is exhausted, and
falls back to a plain payload object in environments that don't pass an
inspect callback (e.g. browsers).
024f911 to
72ffcf0
Compare
The karma browser harness loads tests from test/common, and the browser
shim of `util.inspect` does not honor `Symbol.for('nodejs.util.inspect.custom')`
the way Node does — assertions on the class-tagged prefix were failing.
Move the inspect tests under test/node so only the Node test runner picks
them up; the inspect symbol itself is a no-op in browsers, which is the
intended behaviour.
trentm
left a comment
There was a problem hiding this comment.
I think this will be super-useful for internal dev/debug.
I imagine we'll want to do the same for SDK implementation classes in sdk-metrics and sdk-logs eventually as well. We can feel out then if we want to share the inspect.ts functionality (perhaps in @opentelemetry/core).
| droppedEventsCount: this._droppedEventsCount, | ||
| droppedLinksCount: this._droppedLinksCount, | ||
| instrumentationScope: this.instrumentationScope, | ||
| resource: { attributes: this.resource.attributes }, |
There was a problem hiding this comment.
@pichlermarc noted (during the OTel JS SIG call earlier today) that accessing resource.attributes can emit other diag logs (at both error- and debug-level) if there are unsettled async attributes. E.g.:
const {NodeSDK} = require('@opentelemetry/sdk-node');
const {awsEc2Detector} = require('/Users/trentm/src/opentelemetry-js-contrib/packages/resource-detector-aws');
require('node:util').inspect.defaultOptions.depth = 10;
process.env.OTEL_LOG_LEVEL = 'debug';
const sdk = new NodeSDK({
resourceDetectors: [awsEc2Detector]
});
sdk.start();
process.once('beforeExit', async () => {
await sdk.shutdown();
})
const { diag, trace } = require('@opentelemetry/api');
const tracer = trace.getTracer('default')
tracer.startActiveSpan('a-span', {attributes: {anAttr:'aValue'}}, span => {
span.end();
diag.info('this is my span:', span);
});Running that:
...
Accessing resource attributes before async attributes settled <--- This one at "error" level
Unsettled resource attribute cloud.provider skipped
Unsettled resource attribute cloud.platform skipped
Unsettled resource attribute cloud.account.id skipped
Unsettled resource attribute cloud.region skipped
Unsettled resource attribute cloud.availability_zone skipped
Unsettled resource attribute host.id skipped
Unsettled resource attribute host.type skipped
Unsettled resource attribute host.name skipped
diag.info span: SpanImpl {
name: 'a-span',
kind: 0,
spanContext: {
traceId: '3ff9931075a6792d24eedadde6a19b6f',
spanId: '6b114a6edc91125d',
traceFlags: 1,
traceState: undefined
},
parentSpanContext: undefined,
status: { code: 0 },
startTime: [ 1778714142, 238000000 ],
endTime: [ 1778714142, 238157625 ],
duration: [ 0, 157625 ],
ended: true,
attributes: { anAttr: 'aValue' },
events: [],
links: [],
droppedAttributesCount: 0,
droppedEventsCount: 0,
droppedLinksCount: 0,
instrumentationScope: { name: 'default', version: undefined, schemaUrl: undefined },
resource: {
attributes: {
'service.name': 'unknown_service:node',
'telemetry.sdk.language': 'nodejs',
'telemetry.sdk.name': 'opentelemetry',
'telemetry.sdk.version': '2.7.1'
}
}
}
...
This is unfortunate. Possible improvements:
- Use
this.resource.getRawAttributes()and only include the settled ones, e.g.:
diff --git a/packages/opentelemetry-sdk-trace-base/src/Span.ts b/packages/opentelemetry-sdk-trace-base/src/Span.ts
index b3b9e3b8f..ed76ce745 100644
--- a/packages/opentelemetry-sdk-trace-base/src/Span.ts
+++ b/packages/opentelemetry-sdk-trace-base/src/Span.ts
@@ -532,6 +532,18 @@ export class SpanImpl implements Span {
options: InspectStylizeOptions | undefined,
inspect: InspectFn | undefined
): unknown {
+ // This reproduces ResourceImpl#attributes without any diag logging for
+ // unsettled attributes.
+ const settledAttrs: Attributes = {};
+ for (const [k, v] of this.resource.getRawAttributes()) {
+ if (typeof (v as Partial<PromiseLike<unknown>>)?.then === 'function') {
+ continue;
+ }
+ if (v != null) {
+ settledAttrs[k] ??= v as AttributeValue;
+ }
+ }
+
const payload = {
name: this.name,
kind: this.kind,
@@ -549,7 +561,7 @@ export class SpanImpl implements Span {
droppedEventsCount: this._droppedEventsCount,
droppedLinksCount: this._droppedLinksCount,
instrumentationScope: this.instrumentationScope,
- resource: { attributes: this.resource.attributes },
+ resource: { attributes: settledAttrs },
};
return formatInspect('SpanImpl', payload, depth, options, inspect);
}- Put a custom inspect method on ResourceImpl in the
resourcespackage and have it deal with it.
Though it could be misleading for those debugging early application behaviour (before all resource attributes are settled), I think it is fine to have the pretty-print representation just skip unsettled attributes -- for the common case.
There was a problem hiding this comment.
Good catch — addressed in 34539e6. I added a settledResourceAttributes() helper in inspect.ts that walks getRawAttributes() and silently skips promise-shaped entries, and applied it from all three classes (Span, Tracer, BasicTracerProvider) so none of them touch the attributes getter from inside an inspect call. There's also a regression test asserting no diag.error/diag.debug fires when inspecting a Span whose Resource has unsettled async attributes.
|
With a default depth of a measly 2, and somewhat obtuse type SdkDiagConsoleLoggerOptions = {
depth?: number;
};
class SdkDiagConsoleLogger implements DiagLogger {
private _logger: Console;
constructor(opts?: SdkDiagConsoleLoggerOptions) {
this._logger = new Console({
stdout: process.stdout,
stderr: process.stderr,
inspectOptions: { depth: opts?.depth ?? 2 },
});
}
// @ts-expect-error any
public error(...args) { return this._logger.error(...args); }
// @ts-expect-error any
public warn(...args) { return this._logger.warn(...args); }
// @ts-expect-error any
public info(...args) { return this._logger.info(...args); }
// @ts-expect-error any
public debug(...args) { return this._logger.debug(...args); }
// @ts-expect-error any
public verbose(...args) { return this._logger.trace(...args); }
}Update: To be clear, I'm just thinking out loud. Adding a SdkDiagConsoleLogger is obviously not something this PR needs to deal with. |
…ending async attributes
The custom util.inspect impls on SpanImpl, Tracer, and BasicTracerProvider
read this.resource.attributes, whose getter emits diag.error
("Accessing resource attributes before async attributes settled") plus a
diag.debug per pending key when async detectors haven't resolved. Logging
a span via diag.debug during startup would therefore trigger a cascade
of diag entries from inside the inspect call.
Replace the getter with a new settledResourceAttributes() helper that
walks Resource.getRawAttributes() directly and silently skips
promise-shaped (unsettled) entries — matching the approach @trentm
proposed in code review.
Which problem is this PR solving?
Debugging the trace SDK currently means logging spans that render as
SpanImpl {}(empty-looking) or as a wall of private fields. There is no way to askdiag.debugto pretty-print aSpanImpl,Tracer, orBasicTracerProvider— the only existing pretty-printer is buried insideConsoleSpanExporter._exportInfoand is exporter-only.Short description of the changes
Implements
Symbol.for('nodejs.util.inspect.custom')onSpanImpl,Tracer, andBasicTracerProviderin@opentelemetry/sdk-trace-base. Once the symbol is defined, the objects render cleanly viaconsole.log,util.inspect, or any logger that honors the symbol — most importantlyDiagConsoleLogger, so users can writediag.debug('span', span)and get useful output.SpanImpl's payload mirrorsConsoleSpanExporter._exportInfoplus internal state (ended, drop counters, scope, resource).TracerexposesinstrumentationScope,resource, and the active span/general limits.BasicTracerProviderexposesresource, registered tracer keys, and span-processor class names.formatInspecthelper centralizes the class-tag prefix, depth handling, and the[ClassName]stub when the depth budget is exhausted; it falls back to returning the raw payload when the runtime does not pass aninspectcallback (e.g. browsers), so the change stays cross-platform.Example output:
Type of change
How Has This Been Tested?
Span.test.tsandTracer.test.tscovering the class-tagged output and the depth-budget stub.DiagConsoleLoggeratDEBUGlevel and confirmeddiag.debug(...)rendersSpanImpl,Tracer, andBasicTracerProviderwith all key fields.Checklist