Bài 6: Query Performance Metrics, Slow Query Logging & Tracing

Chúng ta đã đi qua một hành trình trọn vẹn: từ tư duy thiết kế Database Wrapper, quản lý Connection Pool, hiện thực hóa Unit of Work, kiểm soát Query Timeout đến chuẩn hóa lỗi và cơ chế Retry.

Tuy nhiên, trong bài học cuối cùng này, chúng ta sẽ giải quyết một bài toán tối quan trọng để vận hành hệ thống trên môi trường Production: Làm sao để biết câu lệnh SQL nào đang chạy chậm (Slow Query)? Làm sao để đo lường hiệu năng và tích hợp Distributed Tracing để quan sát toàn bộ luồng truy vấn từ HTTP Request xuống tận Database?

1. Vấn đề của "Hộp đen" Cơ sở dữ liệu

Khi ứng dụng gặp tình trạng tăng cao đột biến về độ trễ (Latency Spike), các lập trình viên thường rơi vào cảnh mù mờ: Liệu có phải tầng HTTP API chậm? Hay do Redis cache miss? Hay do một câu lệnh SQL nào đó đang bị thiếu Index và mất tới 3 giây để quét toàn bộ bảng?

Nếu không nhúng cơ chế đo lường hiệu năng (Metrics) và ghi log truy vấn chậm (Slow Query Logging) trực tiếp vào Database Wrapper, bạn sẽ mất hàng giờ đồng hồ để mò mẫm trong vô vọng.

2. Xây dựng Tracing & Metrics Wrapper (Decorator Pattern)

Thay vì gọi trực tiếp các hàm QueryContext hay ExecContext của sql.DB, chúng ta sẽ áp dụng Decorator Pattern để bọc mọi thao tác database qua một lớp đo lường thời gian thực thi.

Dưới đây là thiết kế của một Query Tracer Wrapper tích hợp với hệ thống Wrapper Logging mà chúng ta đã học ở series trước:

Tạo file pkg/database/tracer.go:

Go

package database

import (
	"context"
	"database/sql"
	"time"

	"your-project/pkg/logger" // Import wrapper logger từ series trước
)

// DBWrapper bọc sql.DB để tự động đo lường hiệu năng và ghi log slow query
type DBWrapper struct {
	db  *sql.DB
	log logger.Logger
	slowQueryThreshold time.Duration // Ngưỡng xác định slow query (ví dụ: 200ms)
}

func NewDBWrapper(db *sql.DB, log logger.Logger, threshold time.Duration) *DBWrapper {
	return &DBWrapper{
		db:                 db,
		log:                log,
		slowQueryThreshold: threshold,
	}
}

// ExecContext bọc câu lệnh thực thi ghi (INSERT, UPDATE, DELETE)
func (w *DBWrapper) ExecContext(ctx context.Context, queryName string, query string, args ...any) (sql.Result, error) {
	start := time.Now()
	
	result, err := w.db.ExecContext(ctx, query, args...)
	
	duration := time.Since(start)
	w.recordMetrics(ctx, "Exec", queryName, query, duration, err)
	
	return result, err
}

// QueryRowContext bọc câu lệnh truy vấn trả về một dòng
func (w *DBWrapper) QueryRowContext(ctx context.Context, queryName string, query string, args ...any) *sql.Row {
	// Lưu ý: QueryRow trả về *sql.Row, việc đo lường thời gian sẽ được tính khi Scan() thực tế, 
	// nhưng ta có thể ghi nhận tổng thời gian gửi request.
	start := time.Now()
	defer func() {
		duration := time.Since(start)
		w.recordMetrics(ctx, "QueryRow", queryName, query, duration, nil)
	}()

	return w.db.QueryRowContext(ctx, query, args...)
}

// recordMetrics xử lý logic ghi log và phát hiện Slow Query
func (w *DBWrapper) recordMetrics(ctx context.Context, opType, queryName, query string, duration time.Duration, err error) {
	fields := []logger.Field{
		{Key: "db_op", Value: opType},
		{Key: "query_name", Value: queryName},
		{Key: "duration_ms", Value: duration.Milliseconds()},
	}

	if err != nil {
		fields = append(fields, logger.Err(err))
		w.log.Ctx(ctx).Error("Database Operation Failed", fields...)
		return
	}

	// Kiểm tra ngưỡng Slow Query
	if duration > w.slowQueryThreshold {
		fields = append(fields, logger.Field{Key: "query_sql", Value: query})
		w.log.Ctx(ctx).Warn("⚠️ SLOW QUERY DETECTED", fields...)
	} else {
		w.log.Ctx(ctx).Debug("Database Operation Succeeded", fields...)
	}
}

3. Tích hợp Distributed Tracing (OpenTelemetry)

Trong các kiến trúc Microservices hiện đại, việc tích hợp OpenTelemetry (OTel) vào Database Wrapper giúp các công cụ như Jaeger hoặc Grafana Tempo vẽ ra biểu đồ cây (Span/Trace) thể hiện rõ ràng: Request này mất tổng cộng 500ms, trong đó tốn 20ms cho HTTP router, 30ms cho gọi service khác, và tận 450ms nằm ở câu lệnh SQL FindUser.

Mẫu tích hợp Span cho OTel trong Wrapper:

Go

import (
	"go.opentelemetry.io/otel"
	"go.opentelemetry.io/otel/trace"
)

func (w *DBWrapper) TraceAndExec(ctx context.Context, queryName string, query string, fn func(ctx context.Context) error) error {
	// Khởi tạo một OTel Span cho thao tác database
	tr := otel.Tracer("database-wrapper")
	ctx, span := tr.Start(ctx, "DB:"+queryName, trace.WithSpanKind(trace.SpanKindClient))
	defer span.End()

	start := time.Now()
	err := fn(ctx)
	duration := time.Since(start)

	// Ghi nhận trạng thái lỗi hoặc thành công vào Trace Span
	if err != nil {
		span.RecordError(err)
		return err
	}

	span.SetAttributes(
		attribute.String("db.statement", query),
		attribute.Int64("db.duration_ms", duration.Milliseconds()),
	)

	return nil
}

Tổng kết Series Database Wrapper

Chúc mừng bạn đã hoàn thành trọn vẹn chuỗi series chuyên sâu về Database Wrapper trong Golang:

1. Hiểu rõ hạn chế của truy vấn trực tiếp và áp dụng Repository Pattern để cô lập tầng dữ liệu.

2. Xây dựng kết nối tối ưu với Connection Pool an toàn.

3. Quản lý Transaction sạch sẽ không bám bẩn mã nguồn qua Unit of Work Pattern.

4. Bảo vệ hệ thống bằng Context Propagation & Query Timeout.

5. Chuẩn hóa lỗi chuyên nghiệp với Error Translation và tự động phục hồi qua Retry Mechanism.

6. Kiểm soát hiệu năng toàn diện bằng Slow Query Logging & Distributed Tracing.