gRPC Observability With OpenTelemetry in Go Services

A request that crosses a gRPC boundary is the hardest kind to debug without tooling. The client says the call took 800 ms; the server's logs say the handler took 40. Somewhere in between, queueing, a slow dependency or a network hop ate the rest, and with plain logs you cannot tell which. Distributed tracing connects the two sides into one timeline, and metrics tell you how often it happens.

OpenTelemetry has first-class support for gRPC in Go through the otelgrpc package. This article wires it up on both sides of a service, runs two calls (one succeeding, one failing) and reads the spans and metrics that come out. It builds on HTTP tracing with OpenTelemetry, uses the metadata propagation described in gRPC metadata, and feeds the SLI calculations in SLOs. It ran on Go 1.25.6.

Stats handlers, not interceptors

grpc-go has two extension points: interceptors, which wrap calls and can change them, and stats handlers, which receive events about every RPC (started, headers sent, message received, ended) with timing and sizes and cannot change behaviour. otelgrpc uses stats handlers. That is deliberate: instrumentation should observe, not intervene, and a stats handler sees the whole life of a call including the transport, whatever interceptors are installed. There is also no order to maintain among observers and interceptors.

You install it once on each side:

srv := grpc.NewServer(grpc.StatsHandler(otelgrpc.NewServerHandler()))
conn, _ := grpc.NewClient(addr, grpc.WithStatsHandler(otelgrpc.NewClientHandler()))

The older UnaryServerInterceptor and StreamServerInterceptor functions in the package are deprecated in favour of the handlers.

What it needs from you

The handlers use the global tracer provider, meter provider and propagator unless you pass your own. The lab sets them: a tracer provider with an in-memory exporter, a meter provider with a manual reader (so the program can read the metrics synchronously), and the W3C TraceContext propagator that puts a traceparent entry into the gRPC metadata on the client and reads it on the server. In production, replace the exporter with OTLP to a collector, as shown in the HTTP article.

syntax = "proto3";

package greeter.v1;

option go_package = "example.test/lab/greeterpb";

// Greeter is the service. Each rpc becomes a method on the generated client and server interfaces.
service Greeter {
  rpc SayHello(HelloRequest) returns (HelloReply);
}

message HelloRequest {
  string name = 1;
}

message HelloReply {
  string message = 1;
}

//go:build tools

package main

import (
	_ "google.golang.org/grpc/cmd/protoc-gen-go-grpc"
	_ "google.golang.org/protobuf/cmd/protoc-gen-go"
)

package main

import (
	"context"
	"fmt"
	"log"
	"net"
	"sort"
	"strings"
	"time"

	"go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc"
	"go.opentelemetry.io/otel"
	"go.opentelemetry.io/otel/attribute"
	"go.opentelemetry.io/otel/propagation"
	sdkmetric "go.opentelemetry.io/otel/sdk/metric"
	"go.opentelemetry.io/otel/sdk/metric/metricdata"
	sdktrace "go.opentelemetry.io/otel/sdk/trace"
	"go.opentelemetry.io/otel/sdk/trace/tracetest"
	"google.golang.org/grpc"
	"google.golang.org/grpc/codes"
	"google.golang.org/grpc/credentials/insecure"
	"google.golang.org/grpc/status"

	pb "example.test/lab/greeterpb"
)

type server struct{ pb.UnimplementedGreeterServer }

func (server) SayHello(ctx context.Context, r *pb.HelloRequest) (*pb.HelloReply, error) {
	// A custom span inside the handler becomes a child of the RPC span the stats handler created.
	_, span := otel.Tracer("greeter").Start(ctx, "lookup-greeting")
	span.SetAttributes(attribute.String("greeting.name", r.GetName()))
	time.Sleep(2 * time.Millisecond)
	span.End()
	if r.GetName() == "" {
		return nil, status.Error(codes.InvalidArgument, "name is required")
	}
	return &pb.HelloReply{Message: "Hello, " + r.GetName()}, nil
}

func main() {
	spans := tracetest.NewInMemoryExporter()
	tp := sdktrace.NewTracerProvider(sdktrace.WithSyncer(spans))
	reader := sdkmetric.NewManualReader()
	mp := sdkmetric.NewMeterProvider(sdkmetric.WithReader(reader))
	otel.SetTracerProvider(tp)
	otel.SetMeterProvider(mp)
	otel.SetTextMapPropagator(propagation.TraceContext{})

	lis, err := net.Listen("tcp", "127.0.0.1:0")
	if err != nil {
		log.Fatal(err)
	}
	// Instrumentation is a stats handler on each side: no interceptor code to write or order.
	srv := grpc.NewServer(grpc.StatsHandler(otelgrpc.NewServerHandler()))
	pb.RegisterGreeterServer(srv, server{})
	go srv.Serve(lis)
	defer srv.Stop()
	conn, err := grpc.NewClient(lis.Addr().String(),
		grpc.WithTransportCredentials(insecure.NewCredentials()), grpc.WithStatsHandler(otelgrpc.NewClientHandler()))
	if err != nil {
		log.Fatal(err)
	}
	defer conn.Close()
	c := pb.NewGreeterClient(conn)

	// An application span on the caller's side starts the trace.
	ctx, root := otel.Tracer("app").Start(context.Background(), "handle-request")
	c.SayHello(ctx, &pb.HelloRequest{Name: "Ada"})
	c.SayHello(ctx, &pb.HelloRequest{Name: ""})
	root.End()
	tp.ForceFlush(ctx)

	byID := map[string]string{}
	all := spans.GetSpans()
	for _, s := range all {
		byID[s.SpanContext.SpanID().String()] = s.Name
	}
	sort.SliceStable(all, func(i, j int) bool { return all[i].StartTime.Before(all[j].StartTime) })
	traceIDs := map[string]bool{}
	fmt.Println("spans (one trace, parent in brackets):")
	for _, s := range all {
		traceIDs[s.SpanContext.TraceID().String()] = true
		parent := "none"
		if s.Parent.IsValid() {
			parent = byID[s.Parent.SpanID().String()]
		}
		var attrs []string
		for _, a := range s.Attributes {
			switch string(a.Key) {
			case "rpc.system", "rpc.service", "rpc.method", "rpc.grpc.status_code", "greeting.name":
				attrs = append(attrs, fmt.Sprintf("%s=%v", a.Key, a.Value.Emit()))
			}
		}
		sort.Strings(attrs)
		fmt.Printf("  %-34s %-8s [%s] %s\n", s.Name, s.SpanKind, parent, strings.Join(attrs, " "))
	}
	fmt.Println("distinct trace ids:", len(traceIDs))

	var rm metricdata.ResourceMetrics
	reader.Collect(ctx, &rm)
	fmt.Println("metrics:")
	var names []string
	for _, sm := range rm.ScopeMetrics {
		for _, m := range sm.Metrics {
			if h, ok := m.Data.(metricdata.Histogram[float64]); ok {
				for _, dp := range h.DataPoints {
					names = append(names, fmt.Sprintf("  %-26s count=%d", m.Name, dp.Count))
				}
			}
		}
	}
	sort.Strings(names)
	for _, n := range names {
		fmt.Println(n)
	}
}

mkdir -p bin
go build -o bin/protoc-gen-go google.golang.org/protobuf/cmd/protoc-gen-go
go build -o bin/protoc-gen-go-grpc google.golang.org/grpc/cmd/protoc-gen-go-grpc
PATH="$PWD/bin:$PATH" protoc --go_out=. --go_opt=module=example.test/lab --go-grpc_out=. --go-grpc_opt=module=example.test/lab proto/*.proto
go run .

spans (one trace, parent in brackets):
  handle-request                     internal [none] 
  greeter.v1.Greeter/SayHello        client   [handle-request] rpc.grpc.status_code=0 rpc.method=SayHello rpc.service=greeter.v1.Greeter rpc.system=grpc
  greeter.v1.Greeter/SayHello        server   [greeter.v1.Greeter/SayHello] rpc.grpc.status_code=0 rpc.method=SayHello rpc.service=greeter.v1.Greeter rpc.system=grpc
  lookup-greeting                    internal [greeter.v1.Greeter/SayHello] greeting.name=Ada
  greeter.v1.Greeter/SayHello        client   [handle-request] rpc.grpc.status_code=3 rpc.method=SayHello rpc.service=greeter.v1.Greeter rpc.system=grpc
  greeter.v1.Greeter/SayHello        server   [greeter.v1.Greeter/SayHello] rpc.grpc.status_code=3 rpc.method=SayHello rpc.service=greeter.v1.Greeter rpc.system=grpc
  lookup-greeting                    internal [greeter.v1.Greeter/SayHello] greeting.name=
distinct trace ids: 1
metrics:
  rpc.client.duration        count=1
  rpc.client.duration        count=1
  rpc.server.duration        count=1
  rpc.server.duration        count=1

Reading the trace

The program starts an application span, handle-request, calls SayHello with a valid name and then with an empty name (which the handler rejects), and ends the span. All seven spans share one trace id (the line "distinct trace ids: 1"):

• handle-request is the root: kind internal, no parent.
• greeter.v1.Greeter/SayHello with kind client is created by the client handler. Its parent is handle-request, because the call used the context that carried that span.
• greeter.v1.Greeter/SayHello with kind server is created by the server handler. Its parent is the client span. This is the cross-process link, and it exists only because the client injected traceparent into the metadata and the server extracted it.
• lookup-greeting is a custom span the handler starts with otel.Tracer(...).Start(ctx, ...). Its parent is the server span, since the handler's context carries it. This is how you add detail inside a handler: start spans from the context the handler received.

The span name is package.Service/Method, a low-cardinality name that groups well in any tracing backend.

Attributes

Each RPC span carries the semantic-convention attributes: rpc.system=grpc, rpc.service=greeter.v1.Greeter, rpc.method=SayHello and rpc.grpc.status_code. The first call has status code 0 (OK), the second has 3, InvalidArgument, on both the client and the server span. That attribute is what lets you filter the traces for failures, count them, and alert on them. Note that the attribute names follow the OpenTelemetry semantic conventions of the instrumentation version in use, and the conventions are changing (a newer set is rolling out under an opt-in environment variable). Check the names before building dashboards on them, and pin the instrumentation version so they do not change under you.

Reading the metrics

The handlers also record histograms: rpc.server.duration and rpc.client.duration, with attributes for service, method and status code. The lab's output lists two data points for each, with a count of 1 each: one for the successful call and one for the failed one, because the status code is an attribute and different values make different series.

From these you derive the usual indicators. Request rate is the sum of counts. Error rate is the count with non-OK codes (be selective: InvalidArgument and NotFound are usually the caller's doing, Internal and Unavailable are yours) divided by the total. Latency percentiles come from the histogram buckets. That is the input for the burn-rate alerting in SLOs, computed from the server-side metric, per method.

Be careful with labels. Service and method are bounded and safe. Do not add user ids or request ids as metric attributes; they are for traces and logs. The histogram bucket boundaries are set by a view in the meter provider if the defaults do not match your latencies.

Things that commonly go wrong

The trace breaks between services. The propagator is not set, or the call was made with a context that lost the span (a fresh context.Background() in the handler, the same bug that loses deadlines, see deadlines). Check that the global propagator is registered and that handlers pass their context down.

Client spans without server spans. Only one side is instrumented. Both need a handler.

Missing spans in short-lived programs. Batch exporters flush periodically; a CLI that exits right after the call loses the last spans. Call tp.Shutdown(ctx) or ForceFlush. The lab uses a synchronous exporter and flushes explicitly.

Too much volume. Every RPC makes at least two spans. Sample: ParentBased(TraceIDRatioBased(0.1)) keeps whole traces or none (sampling). Health checks and other chatty calls can be filtered out of tracing with the handler's filter option so they do not drown real traffic.

Sensitive data in attributes. The handlers record method names, not message contents, by default. Keep it so. If you add events for request payloads, they become part of your trace storage and need the same care as logs (logging without leaking secrets).

Streaming calls produce one span for the whole stream, with events for each message sent and received if enabled. A stream that lasts an hour is a span that lasts an hour. That is correct and sometimes surprising in a UI.

Correlating with logs

Tracing works best when logs carry the trace id. In a handler, trace.SpanContextFromContext(ctx) gives the trace and span ids; add them to your structured log fields (a slog handler can do it for every record from the context). Then a log line found in one service leads to the full trace, and a slow trace leads to the log lines of each hop.

Testing it

The in-memory exporter is the test tool, as in the lab. Start the server and client with handlers, make a call, flush, and assert on the spans: that the server span's parent is the client span, that the status code attribute is right for failures and that your custom spans exist with the attributes you expect. It is a few lines, and it catches the common regression of someone replacing a context in the middle of a handler. The instrumentation package is documented at pkg.go.dev, and the RPC conventions at opentelemetry.io.