DEV Community

Chethan
Chethan

Posted on

From log.Printf to Trace Context: What I Learned Debugging a Go Checkout Service with OpenTelemetry and SigNoz

I spent an hour staring at a 500 error in my terminal logs, only to realize the real culprit was hidden in a trace I wasn't looking at. Here is how I learned to stop relying on log.Printf and started using SigNoz and OpenTelemetry to map the full path of a failure.

While building a small checkout service simulator, I intentionally introduced database failures every few requests:

HTTP POST /checkout returned 500

The difficult question to answer was: Which request failed? and why did it fail?

For the agents of SigNoz hackathon, I have built a Go-based checkout simulator, which I have instrumented with OpenTelemetry to generate high-cardinality requests injected with controlled failures. I used SigNoz to understand which pieces of telemetry actually helped during debugging and how much context was needed to understand the root cause of a failed request.

What I Built

Find the link to repo here and follow README to reproduce: Checkout-Observability-Lab

These are the components of my experiment:

  • A Go checkout traffic generator
  • OpenTelemetry instrumentation
  • A local SigNoz deployment

The application simulated:

                   HTTP POST /checkout

                           |
                           |
                           v

                SQL SELECT clusters_meta
Enter fullscreen mode Exit fullscreen mode

Each request generated:

  • a unique user ID
  • a unique product ID
  • request metadata
  • simulated database latency

Every 15th request intentionally failed with:
database connection timeout on pool allocation

This was to simulate the situation that engineers would face during debugging.

## Environment

OS:
Ubuntu 24.04 LTS running inside WSL2

Container Runtime:
Docker Desktop 4.0.0
Docker Engine 27.5.1

Language:
Go 1.26.0

Telemetry:
OpenTelemetry Go SDK 1.44.0

Observability:
SigNoz self-hosted Docker deployment v0.133.0

Storage:
ClickHouse 25.12.5
Enter fullscreen mode Exit fullscreen mode

My local deployment included:

  • SigNoz frontend
  • OpenTelemetry collector
  • ClickHouse storage
  • PostgreSQL metadata store

The application exported telemetry through OTLP gRPC:
localhost:4317

The SigNoz interface was available at:
localhost:8080

Architecture

Experiment Architecture Diagram

The Go service was responsible for creating spans and attaching the context. The collector handled telemetry ingestion, while ClickHouse stored the data that SigNoz queried for trace exploration.

Simplified:

                         Go Checkout Service

                                |
                                |
                                | OTLP gRPC
                                |
                                v

                       OpenTelemetry Collector

                                |
                                |
                                v

                            ClickHouse

                                |
                                |
                                v

                             SigNoz UI
Enter fullscreen mode Exit fullscreen mode
  • The Go application created spans using the OpenTelemetry SDK.
  • The OTLP exporter sent those spans to the collector running with SigNoz.
  • The collector processed the telemetry and forwarded it to ClickHouse.
  • SigNoz then allowed me to explore the generated traces, errors, attributes, and service behavior from one interface.

Creating Realistic Traffic

The traffic generator created dynamic request data:

fakeUserID := fmt.Sprintf(
    "usr-%06d-%d",
    requestID,
    rand.IntN(1000),
)

fakeProductID := fmt.Sprintf(
    "prod-%016x",
    rand.Uint64(),
)
Enter fullscreen mode Exit fullscreen mode

I attached these values as span attributes:

rootSpan.SetAttributes(
    attribute.String(
        "user.id",
        fakeUserID,
    ),

    attribute.String(
        "product.id",
        fakeProductID,
    ),
)
Enter fullscreen mode Exit fullscreen mode

As, I wanted every request to carry enough information to investigate individually.

In the experiments, every request generated a different user ID. If I had attached these values as metric labels, each generated user could have created another unique time series. Instead, I kept this information in traces where it helped with individual request investigation.

Running the experiment

These are the commands I used to run the experiment:

# Start SigNoz locally
foundryctl cast -f deploy/casting.yaml

# Verify containers
docker ps

# Start traffic generator
go run main.go
Enter fullscreen mode Exit fullscreen mode

Running Traffic Generator

Traffic Generator

The Go simulator generated checkout traffic with injected failures while exporting OpenTelemetry telemetry.

SigNoz Service Overview

Service Overview

Before diving into individual trace failures, I started with the SigNoz Service Overview. Seeing the Apdex score and latency percentiles (p50, p90, p99) fluctuate in real-time helped me correlate the spikes in my 500 errors with the simulated database load.

The Unexpected Problem: My Logs Were Missing

Found No Events

I first thought because the application was already exporting OpenTelemetry traces, my existing application logs would somehow appear alongside those traces.

As the failure, path in my code looked:
log.Printf("[ERROR] Request failed",)

When I opened the failed checkout trace in SigNoz, and expected to find the matching log message.

Instead, I found:

  • the failed trace
  • the error status
  • the failed database span

but no application log entry. This created more confusion as the application clearly printed the error, and the trace clearly showed the failure.

That is when I found that both logs and traces are separate telemetry signals, and I had to explicitly instrument the application to connect them.

Fixing the Missing Context With Span Events

Instead of relying on my existing console logs, I attached structured failure information directly to the trace using span events.

For the database failure:

err := fmt.Errorf(
"database connection timeout on pool allocation",
)

dbSpan.RecordError(err)

dbSpan.SetStatus(
codes.Error,
err.Error(),
)
Enter fullscreen mode Exit fullscreen mode

This recorded the technical failure on the database span. Then I added a checkout request to get the information about:

  • what failed
  • where it failed
  • which user was affected
  • which product was involved

Checkout Failure Event

Failed Event

The checkout span contained structured failure context using OpenTelemetry span events.

Database Exception Span

Exception Span

The database child span captured the underlying exception details separately.

Scaling from Traces to Dashboards

While diving straight into a single trace is incredibly powerful when you know which transaction broke, finding that is like finding a needle in a haystack during a massive production incident. In a live environment, instead of manually sift through thousands of successful events to find a handful of failures, you need an aggregate macro-view that rings the alarm bells first.

This is where building an Error Dashboard changes the game. It perfectly bridges the gap between seeing that a system is bleeding and knowing exactly who or what is causing it.

Using SigNoz's flexible query builder, I set up a custom time-series monitoring panel fueled directly by our ingested Traces data:

Error Dashboard

  1. Navigate to the Dashboards tab on the left sidebar and select + New Dashboard.
  2. Click + Add Panel and choose Time Series.
  3. In the query panel dropdown, switch from all Spans to Root Spans (ensuring you only track the entry point of the failure).
  4. Configure the Query Builder options precisely: Filter (Where): http.status_code == 500 AND isRoot == 'true' Aggregation: count() Group By: service.name, product.id
  5. Click Run Query, name your panel Checkout Service - 500 Error Distribution, and hit Save Changes.

Using SigNoz to Investigate the Failure

After adding structured context, the debugging workflow changed.

Before:

                         Find error metric

                               ↓

                       Search application logs

                               ↓

                          Find request ID

                               ↓

                           Locate trace

                               ↓

                    Connect information manually
Enter fullscreen mode Exit fullscreen mode

After:

                    Find failed checkout trace

                               ↓

                      Inspect checkout span

                               ↓

                       View failure event

                               ↓

                       Open database span

                               ↓

                      Understand root cause
Enter fullscreen mode Exit fullscreen mode

I also used SigNoz features such as:

  • service overview for request rate, latency, and errors
  • trace filtering for failed requests
  • span attributes for investigating generated identifiers

Experiment Results

Experiment Results

During my completed run, the simulator generated 1698 requests and injected 113 controlled failures.

What I Learned

1. Instrumentation is only the beginning

What didn't work:

  • My first implementation focused on successfully exporting traces.
  • I verified that SigNoz received spans from my Go service, but I assumed my existing log.Printf() messages would automatically become visible during trace investigation. That assumption was wrong.

What worked:

Adding structured information directly to spans changed the workflow. By attaching error details, user identifiers, product identifiers, and failure events to the trace, the transaction carried the context needed for investigation.

What I would tell my past self:

Before generating traffic, decide what information you would need during an incident, and attach that context to spans instead of expecting the observability platform to construct it later after the failure occurs.

2. A good observability workflow is about reducing investigation time

What didn't work:

Before this experiment, I viewed observability mostly as collecting more data and creating more dashboards.

The first debugging approach still required several manual steps:

Find the latency or error signal.
Search application logs separately.
Identify the request involved.
Locate the corresponding trace.
Reconstruct the failure path manually.

The problem was not that the data did not exist. The problem was that the connection between the data sources was missing.

What worked:

After moving the failure context into trace events and span attributes, the investigation path became shorter:

Open failed checkout trace.
Inspect checkout span.
View failure event.
Open database child span.
Identify root cause.

The biggest improvement was not adding another dashboard. It was reducing the number of places I needed to check.

What I would tell my past self:

I spent time thinking observability was mainly about having more dashboards and more data. This experiment changed that view. The goal is not collecting every possible field; the goal is shortening the path from "something failed" to "I know why it failed." Add the context you will need during debugging while you are writing the application, not after an incident has already started.

Conclusion

Moving from log.Printf messages to structured OpenTelemetry events changed the debugging workflow from searching across disconnected information to investigating one connected trace.

With OpenTelemetry instrumentation and SigNoz running on ClickHouse, I was able to move from manually stitching together logs and traces to investigating failures directly from a single transaction view.

For readers interested in trying this workflow, these resources are useful starting points:

Top comments (0)