Observability Series ตอนที่ 3 — Tracing เชื่อม Logger ด้วย OpenTelemetry + Tempo

[Fiber Middleware] -> [Fiber Handler] -> [Service] -> [Repo]

project-root/
│
├── cmd/
│   └── main.go               # จุดเริ่มโปรแกรม, bootstrap Fiber, DI, middleware
│
├── internal/
│   ├── handler/
│   │   └── user_handler.go   # HTTP Handlers (Fiber routes)
│   │
│   ├── service/
│   │   └── user_service.go   # Business Logic Layer
│   │
│   └── repository/
│       └── user_repo.go      # Data Access Layer
│
├── pkg/
│   ├── ctxkey/
│   │   └── ctxkey.go         # Shared Lib: เก็บ context key
│   │
│   ├── logger/
│   │   └── logger.go         # Shared Lib: Logger setup (Zap)
│   │
│   ├── middleware/           # Shared Lib: Middleware
│   │    └── observability_middleware.go
│   │
│   └── observability/
│       └── observability.go  # Shared Lib: Trace
│
├── go.mod
└── go.sum

go get go.opentelemetry.io/otel
go get go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc
go get go.opentelemetry.io/otel/sdk/trace
go get go.opentelemetry.io/otel/trace

package observability

import (
	"context"
	"log"
	"time"

	"go.opentelemetry.io/otel"
	"go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc"

	"go.opentelemetry.io/otel/sdk/resource"
	sdktrace "go.opentelemetry.io/otel/sdk/trace"
	semconv "go.opentelemetry.io/otel/semconv/v1.21.0"
)

type OTel struct {
	TracerProvider *sdktrace.TracerProvider
}

func (c *OTel) Shutdown(ctx context.Context) error{
	ctx, cancel := context.WithTimeout(ctx, 5*time.Second)
	defer cancel()

	if err := c.TracerProvider.Shutdown(ctx); err != nil {
		return fmt.Errorf("failed to shutdown tracer: %w", err)
	}

	return nil
}

func NewOTel(ctx context.Context, collectorAddr, serviceName string) (*OTel, error) {
	// ----- Resource -----
	res, err := resource.New(ctx,
		resource.WithAttributes(
			semconv.ServiceName(serviceName),
		),
	)
	if err != nil {
		return nil, err
	}

	// ----- Tracer -----
	traceExp, err := otlptracegrpc.New(ctx,
		otlptracegrpc.WithEndpoint(collectorAddr),
		otlptracegrpc.WithInsecure(),
	)
	if err != nil {
		return nil, err
	}

	tp := sdktrace.NewTracerProvider(
		sdktrace.WithBatcher(traceExp),
		sdktrace.WithResource(res),
	)
	otel.SetTracerProvider(tp)

	return &OTel{
		TracerProvider: tp,
	}, nil
}

package middleware

import (
	"context"
	"demo/pkg/ctxkey"
	"fmt"
	"runtime/debug"
	"strings"
	"time"

	"github.com/gofiber/fiber/v2"
	"github.com/google/uuid"
	"go.opentelemetry.io/otel/trace"
	"go.uber.org/zap"
)

func NewObservabilityMiddleware(
	baseLogger *zap.Logger,
	tracer trace.Tracer,
) fiber.Handler {

	// Skip Paths ที่ไม่ต้องการ trace
	skipPaths := map[string]bool{
		"/health": true,
	}
	// กรณีมีการ serve SPA
	staticPrefixes := []string{"/static", "/assets", "/public", "/favicon", "/robots.txt"}

	return func(c *fiber.Ctx) error {
		start := time.Now()
		method := c.Method()
		path := c.Path()

		// ตรวจสอบ path ที่เรียกมา
		skip := skipPaths[path]
		for _, prefix := range staticPrefixes {
			if strings.HasPrefix(path, prefix) {
				skip = true
				break
			}
		}

		requestID := c.Get("X-Request-ID")
		if requestID == "" {
			requestID = uuid.New().String()
		}

		// Bind Request ID ลง Response Header
		c.Set("X-Request-ID", requestID)

		var (
			ctx     context.Context
			span    trace.Span
			traceID string
			spanID  string
		)

		if skip {
			ctx = c.Context()
		} else {
			ctx, span = tracer.Start(c.Context(), "HTTP "+c.Method()+" "+path,
				trace.WithAttributes(attribute.String("http.request_id", requestID)),
				trace.WithAttributes(attribute.String("http.request.method", method)),
				trace.WithAttributes(attribute.String("url.path", path)),
			)
			defer span.End()
			traceID = span.SpanContext().TraceID().String()
			spanID = span.SpanContext().SpanID().String()
		}

		// สร้าง child logger
		reqLogger := baseLogger.With(
			zap.String("request_id", requestID),
			zap.String("http.request.method", method),
			zap.String("url.path", path),
		)

		// สร้าง Context ใหม่ที่มี logger
		ctx = context.WithValue(ctx, ctxkey.Logger{}, reqLogger)
		// แทน Context เดิม
		c.SetUserContext(ctx)

		err := c.Next()

		duration := time.Since(start).Milliseconds()
		status := c.Response().StatusCode()

		// log unhandle error
		if err != nil {
			reqLogger.Error("an error occurred",
				zap.Any("error", err),
				zap.ByteString("stack", debug.Stack()),
				zap.String("trace_id", traceID), // เพิ่ม trace_id เพื่อเชื่อมโยง log กับ trace
				zap.String("span_id", spanID),   // เพิ่ม span_id เพื่อเชื่อมโยง log กับ trace
			)
		}

		msg := fmt.Sprintf("%d - %s %s", status, method, path)
		reqLogger.Info(msg,
			zap.Int("http.response.status_code", status),
			zap.Int64("duration_ms", duration),
			zap.String("trace_id", traceID), // เพิ่ม trace_id เพื่อเชื่อมโยง log กับ trace
			zap.String("span_id", spanID),   // เพิ่ม span_id เพื่อเชื่อมโยง log กับ trace
		)

		span.SetAttributes(
			attribute.Int("http.response.status_code", status),
		)

		if status >= 400 {
			span.SetStatus(codes.Error, "")
		} else {
			span.SetStatus(codes.Ok, "")
		}

		return err
	}
}

func FromContext(ctx context.Context) *zap.Logger {
	log, ok := ctx.Value(ctxkey.Logger{}).(*zap.Logger)
	if !ok {
		log = baseLogger
	}

	// ดึง trace_id + span_id จาก OTel context
	span := trace.SpanContextFromContext(ctx)

	if span.IsValid() {
		return log.With(
			zap.String("trace_id", span.TraceID().String()), // เพิ่ม trace_id เพื่อเชื่อมโยง log กับ trace
			zap.String("span_id", span.SpanID().String()),   // เพิ่ม span_id เพื่อเชื่อมโยง log กับ trace
		)
	}

	return log
}

package main

import (
	"context"
	"os"

	"github.com/gofiber/fiber/v2"
	"github.com/gofiber/fiber/v2/middleware/cors"
	"github.com/gofiber/fiber/v2/middleware/recover"

	"demo/internal/handler"
	"demo/internal/repository"
	"demo/internal/service"
	"demo/pkg/logger"
	"demo/pkg/middleware"
	"demo/pkg/observability"
)

func main() {
	// Init Logger
	logger.Init()

	// Init Observability via Opentelmetry
	otel, err := observability.NewOTel(
		context.Background(),
		os.Getenv("OTEL_EXPORTER_OTLP_ENDPOINT"),
		"demo-app")
	if err != nil {
		logger.Default().Fatal(err.Error())
	}
	defer otel.Shutdown(context.Background())

	// Init Fiber
	app := fiber.New()

	// Middlewares
	app.Use(middleware.NewObservabilityMiddleware(
		logger.Default(),
		otel.TracerProvider.Tracer("demo-app"), // เพิ่มส่ง tracer
	))
	app.Use(cors.New())
	app.Use(recover.New())

	// Init DI
	repo := repository.NewUserRepository()
	svc := service.NewUserService(repo)
	h := handler.NewUserHandler(svc)

	// Routes
	app.Get("/users/:id", h.GetUser)

	// Start
	app.Listen(":8080")
}

package handler

import (
	"demo/internal/service"
	"demo/pkg/logger"

	"github.com/gofiber/fiber/v2"
	"go.opentelemetry.io/otel/trace"
	"go.uber.org/zap"
)

type UserHandler struct {
	svc *service.UserService
}

func NewUserHandler(svc *service.UserService) *UserHandler {
	return &UserHandler{svc: svc}
}

func (h *UserHandler) GetUser(c *fiber.Ctx) error {
	ctx := c.UserContext()
	logger := logger.FromContext(ctx)

	tracer := trace.SpanFromContext(ctx).TracerProvider().Tracer("handler")
	ctx, span := tracer.Start(ctx, "Handler:GetUser")
	defer span.End()

	logger.Info("Handler: GetUser called")

	id := c.Params("id")

	user, err := h.svc.GetUser(ctx, id)
	if err != nil {
		logger.Error("Handler: Failed to get user", zap.Error(err))
		return c.Status(500).SendString("Internal Server Error")
	}

	return c.JSON(user)
}

package service

import (
	"context"
	"demo/internal/repository"
	"demo/pkg/logger"

	"go.opentelemetry.io/otel/trace"
	"go.uber.org/zap"
)

type UserService struct {
	repo *repository.UserRepository
}

func NewUserService(repo *repository.UserRepository) *UserService {
	return &UserService{repo: repo}
}

func (s *UserService) GetUser(ctx context.Context, id string) (map[string]string, error) {
	logger := logger.FromContext(ctx)
	tracer := trace.SpanFromContext(ctx).TracerProvider().Tracer("service")
	ctx, span := tracer.Start(ctx, "Service:GetUser")
	defer span.End()

	logger.Info("Service: GetUser called", zap.String("id", id))

	return s.repo.FindUser(ctx, id)
}

package repository

import (
	"context"
	"demo/pkg/logger"

	"go.opentelemetry.io/otel/trace"
	"go.uber.org/zap"
)

type UserRepository struct{}

func NewUserRepository() *UserRepository {
	return &UserRepository{}
}

func (r *UserRepository) FindUser(ctx context.Context, id string) (map[string]string, error) {
	logger := logger.FromContext(ctx)
	tracer := trace.SpanFromContext(ctx).TracerProvider().Tracer("repository")
	ctx, span := tracer.Start(ctx, "Repository:FindUser")
	defer span.End()

	logger.Info("Repository: FindUser called", zap.String("id", id))

	// Mock DB
	user := map[string]string{
		"id":   id,
		"name": "John Doe",
	}
	return user, nil
}