Skip to content

Traces

Tracing plays a crucial role in modern application development by providing insights into the runtime behavior and performance characteristics of software systems. By instrumenting code execution and capturing relevant data points, traces enable developers to diagnose issues, optimize performance, and gain a deeper understanding of application dynamics.

Instrument

Access the traces instrument via the traces namespace:

inspector.instruments.traces

Configuration

Configure the traces instrument using the main Inspector configuration options:

const inspector = new Inspector({
instruments: {
traces: {
disabled: false,
},
},
});

Available configuration options:

  • disabled: boolean: Disables the instrument. When disabled, the instrument cannot be activated, and no data will be recorded (default false).

Tracing Your Application

The Inspector instance offers the traces instrument with the trace() function, providing a straightforward approach to trace execution for both synchronous and asynchronous functions.

type trace = (name: string, fn: (ctx: any) => any)

The fn function is executed immediately, and its return value is accessible through the trace() function. The execution duration of the fn function defines the span’s duration.

  • name: string: The name of the trace span.
  • fn: (ctx: any) => any: The function to be traced, can be asynchronous.
const { trace } = inspector.instruments.traces;
// synchronous function
const num = trace('getNumber', () => {
return 123;
});
// asynchronous function
const user = await trace('db:findUser', async () => {
return prisma.users.findUnique({
where: {
id: 123,
},
});
});

Alternatively, you can trace your code using startSpan() and endSpan() functions. However, note that these functions do not automatically detect the execution context, requiring you to provide the parent span manually, as seen in nested traces.

const { startSpan, endSpan } = inspector.instruments.traces;
const span = startSpan('db:findUser');
const user = await prisma.users.findUnique({
where: {
id: 123,
},
});
endSpan(span);

Nested Traces

The trace() function leverages Node’s AsyncLocalStorage to automatically detect the execution context, enabling you to trace nested calls seamlessly without the need to pass around context manually.

trace('parent', async () => {
trace('child_1', () => {
// ...
});
await trace('child_2', async () => {
await trace('sub_child', async () => {
// ...
});
});
});

The example above produces the following traces:

- parent [5.44ms]
- child_1 [0.2ms]
- child_2 [5.32ms]
- sub_child [5.11ms]

You can integrate the trace() function across your codebase in named functions, helpers, and classes. When executed inside another trace(), the parent span is automatically detected.

const { trace } = inspector.instruments.traces;
async function getUser(id: string) {
return trace('db:getUser', () => prisma.users.findUnique({
where: {
id,
},
}));
}
server.get('/user/:userId', () => {
return trace('router:getUser', async (req) => {
const user = await getUser(req.params.userId);
return {
user,
};
});
});

The example above yields the following traces:

- router:getUser [3.24ms]
- db:getUser [3.10ms]

When using the startSpan() function, provide the parent into the options:

const { startSpan, endSpan } = inspector.instruments.traces;
const parentSpan = startSpan('parent');
const childSpan = startSpan('child', {
parent: parentSpan,
});

For further details, visit the trace repository.

Preventing Leaked Async Traces

When utilizing the trace() function with asynchronous code, ensure proper awaiting of asynchronous function calls inside the trace. Failure to do so may lead to “leaked” traces where the automatic parent detection fails, resulting in a trace without a parent.

await trace('parent', async () => {
trace('child', async () => {});
await trace('child', async () => {});
})

In the application, you may observe the leaked trace “child” without a parent.

Span

A span encapsulates a function execution and always includes the name, start, and duration. “Root” spans (those without a parent) also feature a unique UUID, serving as a trace ID.

  • duration: number: Duration of the execution (in milliseconds).
  • name: string: Name of the span.
  • start: number: Start time of the span (in milliseconds).
  • uuid: string: Unique trace ID (UUID v4). Only present in spans without a parent.
{
"attributes": {},
"children": [
{
"attributes": {},
"children": [],
"duration": 6.110107421875,
"events": [],
"name": "prisma:getUser",
"start": 1707548525703.3647
}
],
"duration": 6.533447265625,
"events": [],
"name": "router:getUser",
"start": 1707548525703.1785,
"uuid": "12652d90-c01e-48c7-ae2a-7984033b515e"
}

Span Attributes

Span attributes provide key-value metadata containing additional information about the execution, such as HTTP method, server identifier, or user ID.

type addAttribute = (name: string, value: any) => void
  • name: string: Unique name of the attribute.
  • value: any: Value of the attribute, can be of any JSON-serializable type.

When using the trace() function, the first argument received into the handler is the span’s context containing the addAttribute() function bound to the current span.

const { trace } = inspector.instruments.traces;
server.get('/', (req) => {
return trace('request', (ctx) => {
ctx.addAttribute('method', req.method);
ctx.addAttribute('path', req.path);
return 'Hello';
});
});

Alternatively, you can use the addAttribute() function exported by the traces instrument, where the first argument must be the span to which the attribute will be set:

const { addAttribute, endSpan, startSpan } = inspector.instruments.traces;
server.get('/', (req) => {
const span = startSpan('request');
addAttribute(span, 'method', req.method);
addAttribute(span, 'path', req.path);
endSpan(span);
return 'Hello';
});

Span Events

Span events represent specific points in time during the execution of a span. They are useful for logging singular events during execution.

Similar to Span Attributes, you can track an event using the addEvent() function exported by the traces instrument or from the trace() context.

type addEvent = (text: string, attributes?: Record<string, any>) => void
  • text: string: The text (or name) of the event.
  • attributes?: Record<string, any>: Optional attributes associated with the event.
const { trace } = inspector.instruments.traces;
server.get('/', (req) => {
return trace('request', (ctx) => {
ctx.addEvent('event1');
return 'Hello';
});
});

Using the addEvent() function exported by the traces instrument, provide the span as the first argument:

const { addEvent, endSpan, startSpan } = inspector.instruments.traces;
server.get('/', (req) => {
const span = startSpan('request');
addEvent(span, 'event1');
endSpan(span);
return 'Hello';
});

Best Practices

To make the most out of tracing in your application, consider the following best practices:

  • Meaningful span names: Use descriptive names for spans that accurately reflect the operation being traced. Clear and concise span names facilitate easier interpretation of trace data and aid in identifying bottlenecks or areas for improvement.

  • Optimizing trace overhead: While tracing provides valuable insights, excessive instrumentation can introduce overhead. Strike a balance between granularity and performance impact by selectively tracing critical paths and optimizing instrumentation for minimal overhead.

  • Utilizing trace attributes: Leverage trace attributes not only for debugging and performance analysis but also for gaining insights into user behavior, service dependencies, and system interactions. Analyze trace data holistically to identify patterns, trends, and areas for optimization across your application stack.

Performance

The Exot tracing library is highly efficient and performant, suitable for use in production environments. When the traces instrument is deactivated, the performance penalty of the trace() function is negligible.

Refer to the trace repository for performance benchmarks.