Although logs and metrics are useful to understand the behavior of individual services, they are not enough to provide a complete overview of the lifetime of a request in a distributed system.
In a distributed system, a request can span multiple services and each service can make multiple requests to other services to fulfill the request. In such a scenario, we need to have a way to track the lifetime of a request across multiple services to diagnose what services are the bottlenecks and where the request is spending most of its time.
Spans
A span represents a single unit of work or operation within a request. It provides a detailed view of what happened during the execution of that specific operation.
Each span typically contains the following information:
Span Component
Description
Name
Describes the specific operation being tracked.
Timing Data
Timestamps indicating when the operation started and its duration.
Log Messages
Structured logs capturing important events during the operation.
Attributes
Metadata providing additional context about the operation.
Spans are key building blocks in tracing, helping you visualize and understand the flow of requests through various services.
Traces
A trace records the paths taken by requests (made by an application or end-user) as they propagate through multi-service architectures, like microservice and serverless applications.
Without tracing, it is challenging to pinpoint the cause of performance problems in a distributed system.
A trace is made of one or more spans. The first span represents the root span. Each root span represents a request from start to finish. The spans underneath the parent provide a more in-depth context of what occurs during a request (or what steps make up a request).
Many Observability back-ends visualize traces as waterfall diagrams that may look something like this:
Waterfall diagrams show the parent-child relationship between a root span and its child spans. When a span encapsulates another span, this also represents a nested relationship.
Creating Spans
You can add tracing to an effect by creating a span using the Effect.withSpan API. This helps you track specific operations within the effect.
Example (Adding a Span to an Effect)
Instrumenting an effect with a span does not change its type. If you start with an Effect<A, E, R>, the result remains an Effect<A, E, R>.
Printing Spans
To print spans for debugging or analysis, you’ll need to install the required tracing tools. Here’s how to set them up for your project.
Installing Dependencies
Choose your package manager and install the necessary libraries:
constwithSpan: (name:string, options?:SpanOptions|undefined) => <A, E, R>(self:Effect.Effect<A, E, R>) =>Effect.Effect<A, E, Exclude<R, ParentSpan>> (+1overload)
Executes an effect and returns a Promise that resolves with the result.
Use runPromise when working with asynchronous effects and you need to integrate with code that uses Promises.
If the effect fails, the returned Promise will be rejected with the error.
@example
import { Effect } from "effect"
// Execute an effect and handle the result with a Promise
Effect.runPromise(Effect.succeed(1)).then(console.log) // Output: 1
// Execute a failing effect and handle the rejection
Effect.runPromise(Effect.fail("my error")).catch((error) => {
console.error("Effect failed with error:", error)
})
constprovide: <Resource, never, never>(layer:Layer<Resource, never, never>) => <A, E, R>(self:Effect.Effect<A, E, R>) =>Effect.Effect<A, E, Exclude<R, Resource>> (+9overloads)
Splits the context into two parts, providing one part using the
specified layer/context/runtime and leaving the remainder R0
@since ― 2.0.0
provide(
constNodeSdkLive:Layer<Resource, never, never>
NodeSdkLive)))
23
/*
24
Example Output:
25
{
26
traceId: 'd0f730abfc366205806469596092b239',
27
parentId: undefined,
28
traceState: undefined,
29
name: 'myspan',
30
id: 'ab4e42592e7f1f7c',
31
kind: 0,
32
timestamp: 1697040012664380.5,
33
duration: 2895.769,
34
attributes: {},
35
status: { code: 1 },
36
events: [],
37
links: []
38
}
39
*/
Understanding the Span Output
The output provides detailed information about the span:
Field
Description
traceId
A unique identifier for the entire trace, helping trace requests or operations as they move through an application.
parentId
Identifies the parent span of the current span, marked as undefined in the output when there is no parent span, making it a root span.
name
Describes the name of the span, indicating the operation being tracked (e.g., “myspan”).
id
A unique identifier for the current span, distinguishing it from other spans within a trace.
timestamp
A timestamp representing when the span started, measured in microseconds since the Unix epoch.
duration
Specifies the duration of the span, representing the time taken to complete the operation (e.g., 2895.769 microseconds).
attributes
Spans may contain attributes, which are key-value pairs providing additional context or information about the operation. In this output, it’s an empty object, indicating no specific attributes in this span.
status
The status field provides information about the span’s status. In this case, it has a code of 1, which typically indicates an OK status (whereas a code of 2 signifies an ERROR status)
events
Spans can include events, which are records of specific moments during the span’s lifecycle. In this output, it’s an empty array, suggesting no specific events recorded.
links
Links can be used to associate this span with other spans in different traces. In the output, it’s an empty array, indicating no specific links for this span.
Span Capturing an Error
Here’s how a span looks when the effect encounters an error:
Example (Span for an Effect that Fails)
1
import {
import Effect
@since ― 2.0.0
@since ― 2.0.0
@since ― 2.0.0
Effect } from"effect"
2
import {
import NodeSdk
NodeSdk } from"@effect/opentelemetry"
3
import {
4
classConsoleSpanExporter
This is implementation of
SpanExporter
that prints spans to the
console. This class can be used for diagnostic purposes.
NOTE: This
SpanExporter
is intended for diagnostics use only, output rendered to the console may change at any time.
Creates an Effect that represents a recoverable error.
This Effect does not succeed but instead fails with the provided error. The
failure can be of any type, and will propagate through the effect pipeline
unless handled.
Use this function when you want to explicitly signal an error in an Effect
computation. The failed effect can later be handled with functions like
catchAll
or
catchTag
.
@example
import { Effect } from "effect"
// Example of creating a failed effect
const failedEffect = Effect.fail("Something went wrong")
// Handle the failure
failedEffect.pipe(
Effect.catchAll((error) => Effect.succeed(Recovered from: ${error})),
Effect.runPromise
).then(console.log)
// Output: "Recovered from: Something went wrong"
constdelay: (duration:DurationInput) => <A, E, R>(self:Effect.Effect<A, E, R>) =>Effect.Effect<A, E, R> (+1overload)
Returns an effect that is delayed from this effect by the specified
Duration.
@since ― 2.0.0
delay("100 millis"),
10
import Effect
@since ― 2.0.0
@since ― 2.0.0
@since ― 2.0.0
Effect.
constwithSpan: (name:string, options?:SpanOptions|undefined) => <A, E, R>(self:Effect.Effect<A, E, R>) =>Effect.Effect<A, E, Exclude<R, ParentSpan>> (+1overload)
Executes an effect and returns a Promise that resolves with an Exit describing the result.
Use runPromiseExit when you need detailed information about the outcome of the effect, including success or failure,
and you want to work with Promises.
@example
import { Effect } from "effect"
// Execute a successful effect and get the Exit result as a Promise
Effect.runPromiseExit(Effect.succeed(1)).then(console.log)
// Output:
// {
// _id: "Exit",
// _tag: "Success",
// value: 1
// }
// Execute a failing effect and get the Exit result as a Promise
Effect.runPromiseExit(Effect.fail("my error")).then(console.log)
// Output:
// {
// _id: "Exit",
// _tag: "Failure",
// cause: {
// _id: "Cause",
// _tag: "Fail",
// failure: "my error"
// }
// }
Attaches callbacks for the resolution and/or rejection of the Promise.
@param ― onfulfilled The callback to execute when the Promise is resolved.
@param ― onrejected The callback to execute when the Promise is rejected.
@returns ― A Promise for the completion of which ever callback is executed.
then(
19
var console:Console
The console module provides a simple debugging console that is similar to the
JavaScript console mechanism provided by web browsers.
The module exports two specific components:
A Console class with methods such as console.log(), console.error() and console.warn() that can be used to write to any Node.js stream.
A global console instance configured to write to process.stdout and
process.stderr. The global console can be used without importing the node:console module.
Warning: The global console object's methods are neither consistently
synchronous like the browser APIs they resemble, nor are they consistently
asynchronous like all other Node.js streams. See the note on process I/O for
more information.
Example using the global console:
console.log('hello world');
// Prints: hello world, to stdout
console.log('hello %s', 'world');
// Prints: hello world, to stdout
console.error(newError('Whoops, something bad happened'));
// Prints error message and stack trace to stderr:
// Error: Whoops, something bad happened
// at [eval]:5:15
// at Script.runInThisContext (node:vm:132:18)
// at Object.runInThisContext (node:vm:309:38)
// at node:internal/process/execution:77:19
// at [eval]-wrapper:6:22
// at evalScript (node:internal/process/execution:76:60)
// at node:internal/main/eval_string:23:3
constname='Will Robinson';
console.warn(`Danger ${name}! Danger!`);
// Prints: Danger Will Robinson! Danger!, to stderr
Example using the Console class:
constout=getStreamSomehow();
consterr=getStreamSomehow();
constmyConsole=new console.Console(out, err);
myConsole.log('hello world');
// Prints: hello world, to out
myConsole.log('hello %s', 'world');
// Prints: hello world, to out
myConsole.error(newError('Whoops, something bad happened'));
// Prints: [Error: Whoops, something bad happened], to err
Prints to stdout with newline. Multiple arguments can be passed, with the
first used as the primary message and all additional used as substitution
values similar to printf(3)
(the arguments are all passed to util.format()).
In this example, the span’s status code is 2, indicating an error. The message in the status provides more details about the failure.
Adding Annotations
You can provide extra information to a span by utilizing the Effect.annotateCurrentSpan function.
This function allows you to attach key-value pairs, offering more context about the execution of the span.
Example (Annotating a Span)
1
import {
import Effect
@since ― 2.0.0
@since ― 2.0.0
@since ― 2.0.0
Effect } from"effect"
2
import {
import NodeSdk
NodeSdk } from"@effect/opentelemetry"
3
import {
4
classConsoleSpanExporter
This is implementation of
SpanExporter
that prints spans to the
console. This class can be used for diagnostic purposes.
NOTE: This
SpanExporter
is intended for diagnostics use only, output rendered to the console may change at any time.
Adds an annotation to the current span if available
@since ― 2.0.0
annotateCurrentSpan("key", "value")),
12
// Wrap the effect in a span named 'myspan'
13
import Effect
@since ― 2.0.0
@since ― 2.0.0
@since ― 2.0.0
Effect.
constwithSpan: (name:string, options?:SpanOptions|undefined) => <A, E, R>(self:Effect.Effect<A, E, R>) =>Effect.Effect<A, E, Exclude<R, ParentSpan>> (+1overload)
Executes an effect and returns a Promise that resolves with the result.
Use runPromise when working with asynchronous effects and you need to integrate with code that uses Promises.
If the effect fails, the returned Promise will be rejected with the error.
@example
import { Effect } from "effect"
// Execute an effect and handle the result with a Promise
Effect.runPromise(Effect.succeed(1)).then(console.log) // Output: 1
// Execute a failing effect and handle the rejection
Effect.runPromise(Effect.fail("my error")).catch((error) => {
console.error("Effect failed with error:", error)
})
constprovide: <Resource, never, never>(layer:Layer<Resource, never, never>) => <A, E, R>(self:Effect.Effect<A, E, R>) =>Effect.Effect<A, E, Exclude<R, Resource>> (+9overloads)
Splits the context into two parts, providing one part using the
specified layer/context/runtime and leaving the remainder R0
@since ― 2.0.0
provide(
constNodeSdkLive:Layer<Resource, never, never>
NodeSdkLive)))
24
/*
25
Example Output:
26
{
27
traceId: '869c9d74d9db14a4ba4393ca8e0f61db',
28
parentId: undefined,
29
traceState: undefined,
30
name: 'myspan',
31
id: '31eb49570d197f8d',
32
kind: 0,
33
timestamp: 1697045981663321.5,
34
duration: 109563.353,
35
attributes: { key: 'value' },
36
status: { code: 1 },
37
events: [],
38
links: []
39
}
40
*/
Logs as events
In the context of tracing, logs are converted into “Span Events.” These events offer structured insights into your application’s activities and provide a timeline of when specific operations occurred.
1
import {
import Effect
@since ― 2.0.0
@since ― 2.0.0
@since ― 2.0.0
Effect } from"effect"
2
import {
import NodeSdk
NodeSdk } from"@effect/opentelemetry"
3
import {
4
classConsoleSpanExporter
This is implementation of
SpanExporter
that prints spans to the
console. This class can be used for diagnostic purposes.
NOTE: This
SpanExporter
is intended for diagnostics use only, output rendered to the console may change at any time.
ConsoleSpanExporter,
5
classBatchSpanProcessor
BatchSpanProcessor
6
} from"@opentelemetry/sdk-trace-base"
7
8
// Define a program that logs a message and delays for 100 milliseconds
Logs one or more messages or error causes at the current log level, which is INFO by default.
This function allows logging multiple items at once and can include detailed error information using Cause instances.
To adjust the log level, use the Logger.withMinimumLogLevel function.
constdelay: (duration:DurationInput) => <A, E, R>(self:Effect.Effect<A, E, R>) =>Effect.Effect<A, E, R> (+1overload)
Returns an effect that is delayed from this effect by the specified
Duration.
@since ― 2.0.0
delay("100 millis"),
11
import Effect
@since ― 2.0.0
@since ― 2.0.0
@since ― 2.0.0
Effect.
constwithSpan: (name:string, options?:SpanOptions|undefined) => <A, E, R>(self:Effect.Effect<A, E, R>) =>Effect.Effect<A, E, Exclude<R, ParentSpan>> (+1overload)
Executes an effect and returns a Promise that resolves with the result.
Use runPromise when working with asynchronous effects and you need to integrate with code that uses Promises.
If the effect fails, the returned Promise will be rejected with the error.
@example
import { Effect } from "effect"
// Execute an effect and handle the result with a Promise
Effect.runPromise(Effect.succeed(1)).then(console.log) // Output: 1
// Execute a failing effect and handle the rejection
Effect.runPromise(Effect.fail("my error")).catch((error) => {
console.error("Effect failed with error:", error)
})
Each span can include events, which capture specific moments during the execution of a span. In this example, a log message "Hello" is recorded as an event within the span. Key details of the event include:
Field
Description
name
The name of the event, which corresponds to the logged message (e.g., 'Hello').
attributes
Key-value pairs that provide additional context about the event, such as fiberId and log level.
time
The timestamp of when the event occurred, shown in a high-precision format.
droppedAttributesCount
Indicates how many attributes were discarded, if any. In this case, no attributes were dropped.
Nesting Spans
Spans can be nested to represent a hierarchy of operations. This allows you to track how different parts of your application relate to one another during execution. The following example demonstrates how to create and manage nested spans.
Example (Nesting Spans in a Trace)
1
import {
import Effect
@since ― 2.0.0
@since ― 2.0.0
@since ― 2.0.0
Effect } from"effect"
2
import {
import NodeSdk
NodeSdk } from"@effect/opentelemetry"
3
import {
4
classConsoleSpanExporter
This is implementation of
SpanExporter
that prints spans to the
console. This class can be used for diagnostic purposes.
NOTE: This
SpanExporter
is intended for diagnostics use only, output rendered to the console may change at any time.
constdelay: (duration:DurationInput) => <A, E, R>(self:Effect.Effect<A, E, R>) =>Effect.Effect<A, E, R> (+1overload)
Returns an effect that is delayed from this effect by the specified
Duration.
@since ― 2.0.0
delay("100 millis"),
10
import Effect
@since ― 2.0.0
@since ― 2.0.0
@since ― 2.0.0
Effect.
constwithSpan: (name:string, options?:SpanOptions|undefined) => <A, E, R>(self:Effect.Effect<A, E, R>) =>Effect.Effect<A, E, Exclude<R, ParentSpan>> (+1overload)
constwithSpan: (name:string, options?:SpanOptions|undefined) => <A, E, R>(self:Effect.Effect<A, E, R>) =>Effect.Effect<A, E, Exclude<R, ParentSpan>> (+1overload)
Executes an effect and returns a Promise that resolves with the result.
Use runPromise when working with asynchronous effects and you need to integrate with code that uses Promises.
If the effect fails, the returned Promise will be rejected with the error.
@example
import { Effect } from "effect"
// Execute an effect and handle the result with a Promise
Effect.runPromise(Effect.succeed(1)).then(console.log) // Output: 1
// Execute a failing effect and handle the rejection
Effect.runPromise(Effect.fail("my error")).catch((error) => {
console.error("Effect failed with error:", error)
})
constprovide: <Resource, never, never>(layer:Layer<Resource, never, never>) => <A, E, R>(self:Effect.Effect<A, E, R>) =>Effect.Effect<A, E, Exclude<R, Resource>> (+9overloads)
Splits the context into two parts, providing one part using the
specified layer/context/runtime and leaving the remainder R0
@since ― 2.0.0
provide(
constNodeSdkLive:Layer<Resource, never, never>
NodeSdkLive)))
27
/*
28
Example Output:
29
{
30
traceId: '92fe81f1454d9c099198568cf867dc59',
31
parentId: 'b953d6c7d37ad93d', // This indicates the span is a child of 'parent'
32
traceState: undefined,
33
name: 'child',
34
id: '2fd19c8c23ebc7e8', // Unique ID for the child span
35
kind: 0,
36
timestamp: 1697043815321888.2,
37
duration: 106536.264,
38
attributes: {},
39
status: { code: 1 },
40
events: [],
41
links: []
42
}
43
{
44
traceId: '92fe81f1454d9c099198568cf867dc59',
45
parentId: undefined, // Indicates this is the root span
46
traceState: undefined,
47
name: 'parent',
48
id: 'b953d6c7d37ad93d', // Unique ID for the parent span
49
kind: 0,
50
timestamp: 1697043815292133.2,
51
duration: 149724.295,
52
attributes: {},
53
status: { code: 1 },
54
events: [],
55
links: []
56
}
57
*/
The parent-child relationship is evident in the span output, where the parentId of the child span matches the id of the parent span. This structure helps track how operations are related within a single trace.
Tutorial: Visualizing Traces with Docker, Prometheus, Grafana, and Tempo
In this tutorial, we’ll guide you through simulating and visualizing traces using a sample instrumented Node.js application. We will use Docker, Prometheus, Grafana, and Tempo to create, collect, and visualize traces.
Tools Explained
Let’s understand the tools we’ll be using in simple terms:
Docker: Docker allows us to run applications in containers. Think of a container as a lightweight and isolated environment where your application can run consistently, regardless of the host system. It’s a bit like a virtual machine but more efficient.
Prometheus: Prometheus is a monitoring and alerting toolkit. It collects metrics and data about your applications and stores them for further analysis. This helps in identifying performance issues and understanding the behavior of your applications.
Grafana: Grafana is a visualization and analytics platform. It helps in creating beautiful and interactive dashboards to visualize your application’s data. You can use it to graphically represent metrics collected by Prometheus.
Tempo: Tempo is a distributed tracing system that allows you to trace the journey of a request as it flows through your application. It provides insights into how requests are processed and helps in debugging and optimizing your applications.
Download Docker Desktop for your operating system (Windows or macOS) and install it.
After installation, open Docker Desktop, and it will run in the background.
Simulating Traces
Now, let’s simulate traces using a sample Node.js application. We’ll provide you with the code and guide you on setting up the necessary components.
Download Docker Files. Download the required Docker files: docker.zip
Set Up docker. Unzip the downloaded file, navigate to the /docker/local directory in your terminal or command prompt and run the following command to start the necessary services:
Terminal window
docker-composeup
Simulate Traces. Run the following example code in your Node.js environment.
This code simulates a set of tasks and generates traces.
Before proceeding, you’ll need to install additional libraries in addition to the latest version of effect. Here are the required libraries:
The Effect interface defines a value that lazily describes a workflow or job.
The workflow requires some context R, and may fail with an error of type E,
or succeed with a value of type A.
Effect values model resourceful interaction with the outside world, including
synchronous, asynchronous, concurrent, and parallel interaction. They use a
fiber-based concurrency model, with built-in support for scheduling, fine-grained
interruption, structured concurrency, and high scalability.
To run an Effect value, you need a Runtime, which is a type that is capable
of executing Effect values.
Logs one or more messages or error causes at the current log level, which is INFO by default.
This function allows logging multiple items at once and can include detailed error information using Cause instances.
To adjust the log level, use the Logger.withMinimumLogLevel function.
constwithSpan: (name:string, options?:SpanOptions|undefined) => <A, E, R>(self:Effect.Effect<A, E, R>) =>Effect.Effect<A, E, Exclude<R, ParentSpan>> (+1overload)
Executes an effect and returns a Promise that resolves with the result.
Use runPromise when working with asynchronous effects and you need to integrate with code that uses Promises.
If the effect fails, the returned Promise will be rejected with the error.
@example
import { Effect } from "effect"
// Execute an effect and handle the result with a Promise
Effect.runPromise(Effect.succeed(1)).then(console.log) // Output: 1
// Execute a failing effect and handle the rejection
Effect.runPromise(Effect.fail("my error")).catch((error) => {
console.error("Effect failed with error:", error)
})
Visualize Traces. Now, open your web browser and go to http://localhost:3000/explore. You will see a generated Trace ID on the web page. Click on it to see the details of the trace.