14 Adding Simple Logging to a gRPC Server

When building modern backend applications, one of the most important yet frequently overlooked elements is logging. Logging isn’t just about writing errors to a log file—it’s a window into the life of our application: Is anything failing? Which endpoints are accessed most often? How long does each request take to execute? This matters even more when we use gRPC, whose communication is based on a binary, streaming protocol; good logs can be enormously helpful for debugging and monitoring.

In this article, we’ll discuss how to add simple logging to a gRPC server using the Go programming language. We’ll also cover when the right time to log is, what kind of information you should write out, and a complete code example with a simulation, flow diagrams, and tables.

Why Is Logging in gRPC Important?

Before we get to the code, let’s lay out a few reasons:

• gRPC uses a binary protocol, so request/response messages can’t be easily inspected with HTTP tools.
• With the interceptor pipeline in gRPC, developers can add logging without changing much of the business logic code.
• Logging makes troubleshooting and monitoring easier, especially in microservices that scale horizontally.

The Logging Scheme in a gRPC Server

gRPC provides interceptors that can be used to intercept (insert middleware logic into) every incoming request.

In simple terms, the flow looks like this:

flowchart LR
    A[Request dari Client] --> B[Interceptor Logging]
    B --> C[Method/Handler gRPC]
    C --> D[Response Kembali ke Client]

flowchart LR
    A[Request dari Client] --> B[Interceptor Logging]
    B --> C[Method/Handler gRPC]
    C --> D[Response Kembali ke Client]

So, logging happens before (or after) the gRPC handler runs.

Implementing gRPC Logging in Go

Let’s get to the meat of the article: a simple logging implementation on a gRPC server.

1. Setting Up a Simple Project

We’ll assume you already have a simple service, for example a HelloService.

 1// hello.proto
 2syntax = "proto3";
 3
 4package helloworld;
 5
 6service HelloService {
 7    rpc SayHello (HelloRequest) returns (HelloReply) {}
 8}
 9
10message HelloRequest {
11    string name = 1;
12}
13
14message HelloReply {
15    string message = 1;
16}

After generating the code from the proto file above (for example: protoc ...), let’s continue to the logging implementation.

2. Creating the Logging Interceptor

gRPC Interceptors

A gRPC interceptor in Go is a middleware function that follows a specific signature. The UnaryServerInterceptor is commonly used for regular (non-streaming) RPCs. Here’s an example of a simple logging interceptor:

 1// logging_interceptor.go
 2package main
 3
 4import (
 5	"context"
 6	"log"
 7	"time"
 8
 9	"google.golang.org/grpc"
10)
11
12// Unary interceptor for logging the request and response time
13func LoggingInterceptor(
14	ctx context.Context,
15	req interface{},
16	info *grpc.UnaryServerInfo,
17	handler grpc.UnaryHandler,
18) (resp interface{}, err error) {
19	start := time.Now()
20	log.Printf("Received request: %s at %s", info.FullMethod, start.Format(time.RFC3339))
21
22	// Execute the RPC handler (business logic)
23	resp, err = handler(ctx, req)
24
25	duration := time.Since(start)
26	if err != nil {
27		log.Printf("Error on %s: %v (duration: %s)", info.FullMethod, err, duration)
28	} else {
29		log.Printf("Completed %s (duration: %s)", info.FullMethod, duration)
30	}
31
32	return resp, err
33}

What does this code do?

• Before the handler runs, it records the start time and the name of the RPC endpoint being accessed.
• After the handler finishes, it records the elapsed time (duration) and whether it succeeded or failed.

3. Enabling the Interceptor on the Server

When initializing the gRPC server, add the interceptor:

 1// main.go
 2import (
 3	"google.golang.org/grpc"
 4	"log"
 5	"net"
 6)
 7
 8func main() {
 9	lis, err := net.Listen("tcp", ":50051")
10	if err != nil {
11		log.Fatalf("failed to listen: %v", err)
12	}
13
14	grpcServer := grpc.NewServer(
15		grpc.UnaryInterceptor(LoggingInterceptor),
16	)
17	// Register your service here
18	helloworld.RegisterHelloServiceServer(grpcServer, &HelloServiceImpl{})
19
20	log.Println("Server listening at :50051")
21	if err := grpcServer.Serve(lis); err != nil {
22		log.Fatalf("failed to serve: %v", err)
23	}
24}

With this setup, every request that comes into your gRPC server will pass through the LoggingInterceptor and be recorded in your logs.

Sample Log Output

If you run the server and make a request, the resulting logs might look like:

12024/07/01 10:15:23 Received request: /helloworld.HelloService/SayHello at 2024-07-01T10:15:23+07:00
22024/07/01 10:15:23 Completed /helloworld.HelloService/SayHello (duration: 102.324µs)

If an error occurs in the handler:

12024/07/01 10:15:25 Received request: /helloworld.HelloService/SayHello at 2024-07-01T10:15:25+07:00
22024/07/01 10:15:25 Error on /helloworld.HelloService/SayHello: rpc error: code = NotFound desc = name not found (duration: 98.202µs)

Simulation: Comparing a Server With and Without Logging

Adding Extra Information to the Log

For production, the following information should generally be recorded as well:

• Request/response ID (trace id, if available)
• User metadata (if authentication is implemented)
• The requester’s IP address
• Request/response size
• Custom tags

For this, you could extend it using a library like zap or logrus, which support structured logging and JSON output. For this article, however, we’ll focus on basic logging first.

Streaming RPC? Sure, But…

For gRPC streaming, you need to use a StreamServerInterceptor, which has a different signature. The concept is the same:

 1func LoggingStreamInterceptor(
 2    srv interface{},
 3    ss grpc.ServerStream,
 4    info *grpc.StreamServerInfo,
 5    handler grpc.StreamHandler,
 6) error {
 7    log.Printf("Streaming request: %s", info.FullMethod)
 8    start := time.Now()
 9
10    err := handler(srv, ss)
11
12    if err != nil {
13        log.Printf("Streaming error on %s: %v (in %s)", info.FullMethod, err, time.Since(start))
14    } else {
15        log.Printf("Finished streaming %s (in %s)", info.FullMethod, time.Since(start))
16    }
17    return err
18}

And it’s registered with:

1grpc.NewServer(
2	grpc.StreamInterceptor(LoggingStreamInterceptor),
3)

Logging Flow Diagram in a gRPC Server

sequenceDiagram
    participant C as gRPC Client
    participant I as Logging Interceptor
    participant S as Service Handler
    C->>I: Kirim request
    I->>I: Catat log permintaan (timestamp, method)
    I->>S: Teruskan ke handler service
    S-->>I: Jawab/Response dari handler
    I->>I: Catat log response/error (durasi eksekusi)
    I->>C: Kirim response

sequenceDiagram
    participant C as gRPC Client
    participant I as Logging Interceptor
    participant S as Service Handler
    C->>I: Kirim request
    I->>I: Catat log permintaan (timestamp, method)
    I->>S: Teruskan ke handler service
    S-->>I: Jawab/Response dari handler
    I->>I: Catat log response/error (durasi eksekusi)
    I->>C: Kirim response

Conclusion

Logging in a gRPC server is essential so that the application can be properly observed and debugged. By leveraging the interceptor mechanism, we can add logging at a low cost and with almost no modification to the business logic.

Of course, production requires more advanced logging—including trace IDs across services, contextual logs, and exporting to observability services (the ELK Stack, Grafana Loki, etc.). But starting with simple logging like this is already a great help.

We hope this article helps you improve the observability of your gRPC application!
Want to cover JSON logging, multi-level logging, or trace IDs in gRPC with Go? Drop a comment below! 🚀