Ghi log là một phần không thể thiếu trong bất kỳ ứng dụng sản phẩm nào. Nó cho phép chúng ta theo dõi hoạt động của ứng dụng, phát hiện lỗi, và hiểu được hành vi của hệ thống trong môi trường sản xuất. Trong bài viết này, chúng ta sẽ tìm hiểu về structured logging trong Go - một phương pháp ghi log hiệu quả và mạnh mẽ.
Tại sao cần Structured Logging?
Trước khi đi vào chi tiết, hãy hiểu tại sao chúng ta cần structured logging:
- Dễ dàng tìm kiếm và lọc: Log có cấu trúc dưới dạng JSON cho phép tìm kiếm nhanh chóng theo nhiều tiêu chí
- Phân tích tự động: Có thể xử lý và phân tích bởi các công cụ tự động
- Theo dõi request: Có thể theo dõi toàn bộ vòng đời của một request qua các service
- Context phong phú: Chứa nhiều thông tin hơn về ngữ cảnh của sự kiện
Thiết kế Logger Interface
Chúng ta sẽ bắt đầu với việc thiết kế một interface đơn giản nhưng linh hoạt:
// Logger định nghĩa interface chung cho các logger
type Logger interface {
Debug(msg string, fields map[string]interface{})
Info(msg string, fields map[string]interface{})
Warn(msg string, fields map[string]interface{})
Error(msg string, fields map[string]interface{})
WithField(key string, value interface{}) Logger
WithFields(fields map[string]interface{}) Logger
WithTraceID(traceID string) Logger
GetTraceID() string
}
Interface này cung cấp:
- Các phương thức ghi log theo cấp độ (
Debug
,Info
,Warn
,Error
) - Khả năng thêm thông tin bổ sung vào logger (
WithField
,WithFields
) - Hỗ trợ trace ID để theo dõi request (
WithTraceID
,GetTraceID
)
Cấu trúc của Logger
Bây giờ, chúng ta sẽ triển khai interface của mình sử dụng thư viện logrus - một thư viện logging phổ biến trong Go:
import (
"github.com/sirupsen/logrus"
"github.com/google/uuid"
)
// Các cấp độ log
type LogLevel string
const (
DEBUG LogLevel = "debug"
INFO LogLevel = "info"
WARN LogLevel = "warn"
ERROR LogLevel = "error"
)
// TraceIDKey là key để lưu trace ID trong log
const TraceIDKey = "trace_id"
// Config chứa các thiết lập cho logger
type Config struct {
LogLevel string
LogDirectory string
EnableConsole bool
}
// loggerImpl là triển khai của Logger interface
type loggerImpl struct {
logger *logrus.Logger
traceID string
extraFields map[string]interface{}
fileMutex sync.Mutex
}
Cấu trúc này bao gồm:
- Underlying logger (logrus)
- Trace ID để theo dõi request
- Extra fields để lưu trữ thông tin bổ sung
- Mutex để xử lý đồng thời khi ghi file
Khởi tạo Logger
// NewLogger tạo một instance logger mới
func NewLogger(config *Config) Logger {
logger := logrus.New()
// Thiết lập cấp độ log
level, err := logrus.ParseLevel(config.LogLevel)
if err != nil {
level = logrus.InfoLevel // Mặc định Info nếu cấp độ không hợp lệ
}
logger.SetLevel(level)
// Đảm bảo thư mục log tồn tại
if err := os.MkdirAll(config.LogDirectory, 0755); err != nil {
fmt.Fprintf(os.Stderr, "Failed to create log directory: %v\n", err)
}
// Cấu hình JSON formatter cho structured logging
logger.SetFormatter(&logrus.JSONFormatter{
TimestampFormat: time.RFC3339,
})
// Thiết lập output
if config.EnableConsole {
logger.SetOutput(os.Stdout)
} else {
logger.SetOutput(io.Discard) // Discard mặc định vì chúng ta sẽ ghi vào file riêng
}
return &loggerImpl{
logger: logger,
traceID: GenerateTraceID(),
extraFields: make(map[string]interface{}),
}
}
// GenerateTraceID tạo trace ID mới
func GenerateTraceID() string {
return uuid.New().String()
}
Khởi tạo logger bao gồm:
- Thiết lập cấp độ log
- Tạo thư mục log nếu chưa tồn tại
- Cấu hình JSON formatter cho structured logging
- Thiết lập output (console hoặc file)
- Tạo trace ID mặc định
Các phương thức bổ trợ
Chúng ta sẽ triển khai các phương thức hỗ trợ để thêm thông tin vào logger:
// WithTraceID tạo một logger mới với trace ID được chỉ định
func (l *loggerImpl) WithTraceID(traceID string) Logger {
newLogger := &loggerImpl{
logger: l.logger,
traceID: traceID,
extraFields: make(map[string]interface{}),
}
// Copy existing extra fields
for k, v := range l.extraFields {
newLogger.extraFields[k] = v
}
return newLogger
}
// WithField thêm một field vào logger
func (l *loggerImpl) WithField(key string, value interface{}) Logger {
newLogger := &loggerImpl{
logger: l.logger,
traceID: l.traceID,
extraFields: make(map[string]interface{}),
}
// Copy existing extra fields
for k, v := range l.extraFields {
newLogger.extraFields[k] = v
}
// Add new field
newLogger.extraFields[key] = value
return newLogger
}
// WithFields thêm nhiều fields vào logger
func (l *loggerImpl) WithFields(fields map[string]interface{}) Logger {
newLogger := &loggerImpl{
logger: l.logger,
traceID: l.traceID,
extraFields: make(map[string]interface{}),
}
// Copy existing extra fields
for k, v := range l.extraFields {
newLogger.extraFields[k] = v
}
// Add new fields
for k, v := range fields {
newLogger.extraFields[k] = v
}
return newLogger
}
// GetTraceID trả về trace ID hiện tại
func (l *loggerImpl) GetTraceID() string {
return l.traceID
}
Điểm quan trọng cần lưu ý:
- Mỗi phương thức trả về một logger mới, không thay đổi logger gốc (immutable)
- Các fields hiện tại được sao chép sang logger mới
- Fields mới được thêm vào logger mới
Chuẩn bị Log Entry
Trước khi ghi log, chúng ta cần chuẩn bị log entry với các fields chuẩn:
// makeFields thêm các fields chung vào log entry
func (l *loggerImpl) makeFields(fields map[string]interface{}) logrus.Fields {
if fields == nil {
fields = make(map[string]interface{})
}
// Thêm trace ID và timestamp
fields[TraceIDKey] = l.traceID
fields["timestamp"] = time.Now().UTC().Format(time.RFC3339)
// Thêm các extra fields
for k, v := range l.extraFields {
fields[k] = v
}
return logrus.Fields(fields)
}
Hàm này:
- Đảm bảo có một map fields (tạo mới nếu null)
- Thêm trace ID và timestamp
- Thêm các fields từ logger context
Ghi Log vào File
Bây giờ, chúng ta sẽ triển khai ghi log vào file theo cấp độ:
// getLogFile trả về file log thích hợp cho cấp độ
func (l *loggerImpl) getLogFile(level logrus.Level) *os.File {
// Lock cho các hoạt động file
l.fileMutex.Lock()
defer l.fileMutex.Unlock()
var logPath string
logDir := l.logger.Out.(*os.File).Name()
if logDir == os.Stdout.Name() || logDir == os.Stderr.Name() {
logDir = "./logs" // Mặc định nếu output là stdout/stderr
} else {
logDir = filepath.Dir(logDir)
}
// Xác định tên file dựa trên cấp độ
switch level {
case logrus.DebugLevel:
logPath = filepath.Join(logDir, "debug.log")
case logrus.InfoLevel:
logPath = filepath.Join(logDir, "info.log")
case logrus.WarnLevel:
logPath = filepath.Join(logDir, "warning.log")
case logrus.ErrorLevel:
logPath = filepath.Join(logDir, "error.log")
default:
logPath = filepath.Join(logDir, "app.log")
}
// Mở file log
file, err := os.OpenFile(logPath, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666)
if err != nil {
fmt.Fprintf(os.Stderr, "Failed to open log file %s: %v\n", logPath, err)
return os.Stderr // Fallback to stderr nếu không mở được file
}
return file
}
// logToFile ghi log vào file theo cấp độ
func (l *loggerImpl) logToFile(level logrus.Level, entry *logrus.Entry) {
if !l.logger.IsLevelEnabled(level) {
return
}
// Lấy file phù hợp
file := l.getLogFile(level)
defer file.Close()
// Tạo logger mới cho file cụ thể
fileLogger := logrus.New()
fileLogger.SetOutput(file)
fileLogger.SetFormatter(&logrus.JSONFormatter{
TimestampFormat: time.RFC3339,
})
fileLogger.SetLevel(level)
// Ghi log theo cấp độ
switch level {
case logrus.DebugLevel:
fileLogger.WithFields(entry.Data).Debug(entry.Message)
case logrus.InfoLevel:
fileLogger.WithFields(entry.Data).Info(entry.Message)
case logrus.WarnLevel:
fileLogger.WithFields(entry.Data).Warn(entry.Message)
case logrus.ErrorLevel:
fileLogger.WithFields(entry.Data).Error(entry.Message)
}
}
Những điểm quan trọng:
- Mỗi cấp độ log có file riêng
- Sử dụng mutex để tránh xung đột khi ghi file
- Fallback sang stderr nếu không thể mở file
- Tạo logger mới cho mỗi lần ghi để tránh vấn đề với output
Triển khai các phương thức log
Cuối cùng, chúng ta triển khai các phương thức ghi log:
// Debug ghi log ở cấp độ DEBUG
func (l *loggerImpl) Debug(msg string, fields map[string]interface{}) {
if l.logger.IsLevelEnabled(logrus.DebugLevel) {
entry := &logrus.Entry{
Logger: l.logger,
Data: l.makeFields(fields),
Time: time.Now(),
Level: logrus.DebugLevel,
Message: msg,
}
// Ghi ra console nếu được bật
l.logger.WithFields(entry.Data).Debug(msg)
// Ghi vào file
l.logToFile(logrus.DebugLevel, entry)
}
}
// Info ghi log ở cấp độ INFO
func (l *loggerImpl) Info(msg string, fields map[string]interface{}) {
if l.logger.IsLevelEnabled(logrus.InfoLevel) {
entry := &logrus.Entry{
Logger: l.logger,
Data: l.makeFields(fields),
Time: time.Now(),
Level: logrus.InfoLevel,
Message: msg,
}
// Ghi ra console nếu được bật
l.logger.WithFields(entry.Data).Info(msg)
// Ghi vào file
l.logToFile(logrus.InfoLevel, entry)
}
}
// Warn ghi log ở cấp độ WARN
func (l *loggerImpl) Warn(msg string, fields map[string]interface{}) {
if l.logger.IsLevelEnabled(logrus.WarnLevel) {
entry := &logrus.Entry{
Logger: l.logger,
Data: l.makeFields(fields),
Time: time.Now(),
Level: logrus.WarnLevel,
Message: msg,
}
// Ghi ra console nếu được bật
l.logger.WithFields(entry.Data).Warn(msg)
// Ghi vào file
l.logToFile(logrus.WarnLevel, entry)
}
}
// Error ghi log ở cấp độ ERROR
func (l *loggerImpl) Error(msg string, fields map[string]interface{}) {
if l.logger.IsLevelEnabled(logrus.ErrorLevel) {
entry := &logrus.Entry{
Logger: l.logger,
Data: l.makeFields(fields),
Time: time.Now(),
Level: logrus.ErrorLevel,
Message: msg,
}
// Ghi ra console nếu được bật
l.logger.WithFields(entry.Data).Error(msg)
// Ghi vào file
l.logToFile(logrus.ErrorLevel, entry)
}
}
Mỗi phương thức:
- Kiểm tra xem cấp độ log có được bật không
- Tạo entry với fields và timestamp
- Ghi ra console nếu được bật
- Ghi vào file tương ứng với cấp độ
Tích hợp với HTTP Middleware
Một trong những ứng dụng chính của structured logging là trong HTTP middleware để tự động ghi log cho mỗi request:
// RequestLoggerMiddleware tạo middleware cho Gin để ghi log HTTP requests
func RequestLoggerMiddleware(logger Logger) gin.HandlerFunc {
return func(c *gin.Context) {
// Bắt đầu timer
start := time.Now()
// Lấy hoặc tạo trace ID
traceID := c.GetHeader("X-Trace-ID")
if traceID == "" {
traceID = GenerateTraceID()
}
// Tạo logger với trace ID
requestLogger := logger.WithTraceID(traceID)
// Lưu logger vào context
c.Set("logger", requestLogger)
// Thêm trace ID vào response header
c.Header("X-Trace-ID", traceID)
// Ghi log request
requestLogger.Info("Request started", map[string]interface{}{
"method": c.Request.Method,
"path": c.Request.URL.Path,
"query": c.Request.URL.RawQuery,
"client_ip": c.ClientIP(),
"user_agent": c.Request.UserAgent(),
})
// Xử lý request
c.Next()
// Ghi log response
statusCode := c.Writer.Status()
elapsed := time.Since(start)
logFields := map[string]interface{}{
"status_code": statusCode,
"duration_ms": elapsed.Milliseconds(),
}
if len(c.Errors) > 0 {
logFields["errors"] = c.Errors.Errors()
}
if statusCode >= 500 {
requestLogger.Error("Request failed", logFields)
} else if statusCode >= 400 {
requestLogger.Warn("Request error", logFields)
} else {
requestLogger.Info("Request completed", logFields)
}
}
}
Middleware này:
- Bắt đầu timer cho request
- Lấy hoặc tạo trace ID
- Tạo logger riêng cho mỗi request
- Ghi log khi request bắt đầu
- Ghi log khi request kết thúc, với thông tin về status code và thời gian xử lý
Cách sử dụng Logger
Sau khi đã thiết lập logger, đây là cách sử dụng nó trong ứng dụng:
func main() {
// Khởi tạo logger
logger := NewLogger(&Config{
LogLevel: "info",
LogDirectory: "./logs",
EnableConsole: true,
})
// Sử dụng logger trực tiếp
logger.Info("Application starting", map[string]interface{}{
"version": "1.0.0",
"env": "production",
})
// Tạo logger với context
userLogger := logger.WithField("user_id", "12345")
userLogger.Info("User logged in", map[string]interface{}{
"username": "john.doe",
"role": "admin",
})
// Ghi log lỗi
if err := someFunction(); err != nil {
logger.Error("Operation failed", map[string]interface{}{
"operation": "someFunction",
"error": err.Error(),
})
}
// Trong handler HTTP
http.HandleFunc("/api/users", func(w http.ResponseWriter, r *http.Request) {
// Retrieve logger from context (if using middleware)
ctx := r.Context()
reqLogger, ok := ctx.Value("logger").(Logger)
if !ok {
reqLogger = logger
}
reqLogger.Info("Processing users request", nil)
// ... xử lý request
})
}
Ví dụ về Log JSON
Đây là một số ví dụ về log JSON được tạo ra bởi logger của chúng ta:
Log INFO
{
"level": "info",
"msg": "Application starting",
"version": "1.0.0",
"env": "production",
"trace_id": "7b8f3da4-6149-4d4a-b3a2-65f0c568a563",
"timestamp": "2023-06-14T10:32:45Z"
}
Log Request
{
"level": "info",
"msg": "Request started",
"path": "/api/users",
"method": "GET",
"client_ip": "127.0.0.1",
"trace_id": "3a9f1d83-5b41-4918-a432-f61b3a4bd69c",
"timestamp": "2023-06-14T10:32:45Z",
"user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36..."
}
Log ERROR
{
"level": "error",
"msg": "Operation failed",
"operation": "someFunction",
"error": "connection refused",
"trace_id": "3a9f1d83-5b41-4918-a432-f61b3a4bd69c",
"timestamp": "2023-06-14T10:32:47Z"
}
Tìm kiếm và phân tích Log
Với log có cấu trúc, chúng ta có thể dễ dàng tìm kiếm và phân tích bằng các công cụ như jq. Đây là một số ví dụ:
Tìm tất cả log lỗi
cat logs/error.log | jq '.'
Tìm log theo trace_id
cat logs/*.log | jq 'select(.trace_id == "3a9f1d83-5b41-4918-a432-f61b3a4bd69c")'
Thống kê lỗi theo loại
cat logs/error.log | jq -r '.operation' | sort | uniq -c | sort -nr
Phân tích thời gian phản hồi trung bình
cat logs/info.log | jq 'select(.duration_ms != null) | .duration_ms' | awk '{ sum += $1; n++ } END { if (n > 0) print sum / n; }'
Thực tiễn tốt nhất
1. Sử dụng cấp độ log phù hợp
- DEBUG: Thông tin chi tiết cho phát triển
- INFO: Thông tin về hoạt động bình thường
- WARN: Cảnh báo về vấn đề tiềm ẩn
- ERROR: Lỗi ảnh hưởng đến chức năng
2. Cung cấp context đầy đủ
// Không tốt
logger.Error("Database connection failed")
// Tốt hơn
logger.Error("Database connection failed", map[string]interface{}{
"database": "users",
"host": dbHost,
"port": dbPort,
"retry_count": retryCount,
"error": err.Error(),
})
3. Dùng trace ID để theo dõi request
// Ở service đầu tiên
traceID := GenerateTraceID()
requestLogger := logger.WithTraceID(traceID)
// Truyền trace ID đến service tiếp theo
nextServiceRequest.Header.Set("X-Trace-ID", traceID)
4. Không log thông tin nhạy cảm
// KHÔNG NÊN
logger.Info("User authenticated", map[string]interface{}{
"email": user.Email,
"password": password, // ĐỪNG làm điều này!
})
// NÊN LÀM
logger.Info("User authenticated", map[string]interface{}{
"user_id": user.ID,
"email": user.Email,
})
5. Sử dụng log sampling cho traffic cao
Đối với endpoints có traffic cao, bạn có thể cân nhắc chỉ log một phần nhỏ các requests:
func shouldSampleLog() bool {
return rand.Float64() < 0.01 // Log 1% requests
}
if shouldSampleLog() {
logger.Info("High traffic endpoint accessed", map[string]interface{}{
"path": "/api/status",
})
}
Kết luận
Structured logging là một công cụ mạnh mẽ trong bộ công cụ của nhà phát triển Go. Bằng cách sử dụng các kỹ thuật được mô tả trong bài viết này, bạn có thể xây dựng một hệ thống logging mạnh mẽ, giúp dễ dàng theo dõi, gỡ lỗi và phân tích ứng dụng của mình trong môi trường sản xuất.
Nhớ rằng, một hệ thống logging tốt không chỉ giúp bạn phát hiện và giải quyết vấn đề nhanh hơn, mà còn cung cấp insights quý giá về hành vi và hiệu suất của ứng dụng. Hãy đầu tư thời gian vào việc thiết kế hệ thống logging của bạn, và nó sẽ đền đáp bạn nhiều lần khi ứng dụng phát triển.