veza/veza-backend-api/internal/database/performance_monitor.go

201 lines
5.7 KiB
Go

package database
import (
"context"
"time"
"veza-backend-api/internal/metrics"
"go.uber.org/zap"
"gorm.io/gorm"
)
// PerformanceMonitor monitors database query performance and logs slow queries
// BE-DB-018: Add database performance monitoring with slow query logging
type PerformanceMonitor struct {
logger *zap.Logger
slowQueryThreshold time.Duration // Threshold for slow query logging
enabled bool
}
// PerformanceMonitorConfig contains configuration for the performance monitor
type PerformanceMonitorConfig struct {
Logger *zap.Logger
SlowQueryThreshold time.Duration // Default: 1 second
Enabled bool // Default: true
}
// NewPerformanceMonitor creates a new performance monitor
func NewPerformanceMonitor(config PerformanceMonitorConfig) *PerformanceMonitor {
threshold := config.SlowQueryThreshold
if threshold == 0 {
threshold = 1 * time.Second // Default: 1 second
}
enabled := config.Enabled
if config.Logger == nil {
enabled = false // Disable if no logger
}
return &PerformanceMonitor{
logger: config.Logger,
slowQueryThreshold: threshold,
enabled: enabled,
}
}
// WrapGORM wraps a GORM DB instance with performance monitoring
func (pm *PerformanceMonitor) WrapGORM(db *gorm.DB) *gorm.DB {
if !pm.enabled {
return db
}
// Register GORM callback to monitor queries
db.Callback().Query().Before("gorm:query").Register("performance_monitor:before_query", pm.beforeQuery)
db.Callback().Query().After("gorm:query").Register("performance_monitor:after_query", pm.afterQuery)
db.Callback().Create().Before("gorm:create").Register("performance_monitor:before_create", pm.beforeQuery)
db.Callback().Create().After("gorm:create").Register("performance_monitor:after_create", pm.afterQuery)
db.Callback().Update().Before("gorm:update").Register("performance_monitor:before_update", pm.beforeQuery)
db.Callback().Update().After("gorm:update").Register("performance_monitor:after_update", pm.afterQuery)
db.Callback().Delete().Before("gorm:delete").Register("performance_monitor:before_delete", pm.beforeQuery)
db.Callback().Delete().After("gorm:delete").Register("performance_monitor:after_delete", pm.afterQuery)
return db
}
// beforeQuery is called before a query executes
func (pm *PerformanceMonitor) beforeQuery(db *gorm.DB) {
// Store start time in the statement context
ctx := context.WithValue(db.Statement.Context, "query_start_time", time.Now())
db.Statement.Context = ctx
}
// afterQuery is called after a query executes
func (pm *PerformanceMonitor) afterQuery(db *gorm.DB) {
// Get start time from context
startTime, ok := db.Statement.Context.Value("query_start_time").(time.Time)
if !ok {
return
}
duration := time.Since(startTime)
// Extract operation type and table name
operation := "UNKNOWN"
if db.Statement != nil {
// Try to determine operation from SQL
sqlStr := db.Statement.SQL.String()
if len(sqlStr) > 0 {
upperSQL := sqlStr[:min(10, len(sqlStr))]
switch {
case contains(upperSQL, "SELECT"):
operation = "SELECT"
case contains(upperSQL, "INSERT"):
operation = "INSERT"
case contains(upperSQL, "UPDATE"):
operation = "UPDATE"
case contains(upperSQL, "DELETE"):
operation = "DELETE"
}
}
table := "unknown"
if db.Statement.Table != "" {
table = db.Statement.Table
} else if db.Statement.Model != nil {
// Try to get table name from model
if stmt := db.Statement; stmt != nil {
table = stmt.Schema.Table
}
}
// Record metrics
metrics.RecordDBQuery(operation, table, duration)
// Log slow queries
if duration >= pm.slowQueryThreshold {
pm.logSlowQuery(operation, table, duration, db)
}
}
}
// logSlowQuery logs a slow query with details
func (pm *PerformanceMonitor) logSlowQuery(operation, table string, duration time.Duration, db *gorm.DB) {
fields := []zap.Field{
zap.String("operation", operation),
zap.String("table", table),
zap.Duration("duration", duration),
zap.Duration("threshold", pm.slowQueryThreshold),
}
// Add SQL if available (be careful with sensitive data)
if db.Statement != nil {
sqlStr := db.Statement.SQL.String()
if len(sqlStr) > 0 {
// Truncate SQL if too long
if len(sqlStr) > 500 {
sqlStr = sqlStr[:500] + "..."
}
fields = append(fields, zap.String("sql", sqlStr))
}
}
// Add error if query failed
if db.Error != nil {
fields = append(fields, zap.Error(db.Error))
pm.logger.Warn("Slow query with error", fields...)
} else {
pm.logger.Warn("Slow query detected", fields...)
}
// Record slow query metric
metrics.RecordSlowQuery(operation, table, duration)
}
// MeasureQuery measures a query execution time and logs if slow
// This is a helper function for manual query measurement
func (pm *PerformanceMonitor) MeasureQuery(operation, table string, fn func() error) error {
if !pm.enabled {
return fn()
}
start := time.Now()
err := fn()
duration := time.Since(start)
// Record metrics
metrics.RecordDBQuery(operation, table, duration)
// Log if slow
if duration >= pm.slowQueryThreshold {
fields := []zap.Field{
zap.String("operation", operation),
zap.String("table", table),
zap.Duration("duration", duration),
zap.Duration("threshold", pm.slowQueryThreshold),
}
if err != nil {
fields = append(fields, zap.Error(err))
pm.logger.Warn("Slow query with error", fields...)
} else {
pm.logger.Warn("Slow query detected", fields...)
}
// Record slow query metric
metrics.RecordSlowQuery(operation, table, duration)
}
return err
}
// Helper functions
func min(a, b int) int {
if a < b {
return a
}
return b
}
func contains(s, substr string) bool {
return len(s) >= len(substr) && (s == substr || len(s) > len(substr) && s[:len(substr)] == substr)
}