Improve request logging and make health check lightweight

- Log slow requests (>1s) at WARNING level with slow=true flag
- Log request timeouts at WARNING level in TimeoutMiddleware
- Replace heavy GetStatsContext with lightweight Ping in health check
- Add Ping method to database interface (SELECT 1)
This commit is contained in:
Jeffrey Paul 2026-01-01 06:06:20 -08:00
parent 8f524485f7
commit a163449a28
6 changed files with 37 additions and 6 deletions

View File

@ -1997,3 +1997,14 @@ func (d *Database) Checkpoint(ctx context.Context) error {
return nil return nil
} }
// Ping checks if the database connection is alive with a lightweight query.
func (d *Database) Ping(ctx context.Context) error {
var result int
err := d.db.QueryRowContext(ctx, "SELECT 1").Scan(&result)
if err != nil {
return fmt.Errorf("database ping failed: %w", err)
}
return nil
}

View File

@ -88,6 +88,7 @@ type Store interface {
Vacuum(ctx context.Context) error Vacuum(ctx context.Context) error
Analyze(ctx context.Context) error Analyze(ctx context.Context) error
Checkpoint(ctx context.Context) error Checkpoint(ctx context.Context) error
Ping(ctx context.Context) error
} }
// Ensure Database implements Store // Ensure Database implements Store

View File

@ -420,6 +420,11 @@ func (m *mockStore) Checkpoint(ctx context.Context) error {
return nil return nil
} }
// Ping mock implementation
func (m *mockStore) Ping(ctx context.Context) error {
return nil
}
func TestRouteWatchLiveFeed(t *testing.T) { func TestRouteWatchLiveFeed(t *testing.T) {
// Create mock database // Create mock database

View File

@ -37,6 +37,7 @@ type HealthCheckResponse struct {
// handleHealthCheck returns a handler that performs health checks. // handleHealthCheck returns a handler that performs health checks.
// Returns 200 if healthy, 503 if any check fails. // Returns 200 if healthy, 503 if any check fails.
// Uses lightweight checks to avoid timeout issues under load.
func (s *Server) handleHealthCheck() http.HandlerFunc { func (s *Server) handleHealthCheck() http.HandlerFunc {
return func(w http.ResponseWriter, r *http.Request) { return func(w http.ResponseWriter, r *http.Request) {
ctx, cancel := context.WithTimeout(r.Context(), healthCheckTimeout) ctx, cancel := context.WithTimeout(r.Context(), healthCheckTimeout)
@ -45,13 +46,11 @@ func (s *Server) handleHealthCheck() http.HandlerFunc {
checks := make(map[string]string) checks := make(map[string]string)
healthy := true healthy := true
// Check database connectivity // Check database connectivity with lightweight ping
dbStats, err := s.db.GetStatsContext(ctx) err := s.db.Ping(ctx)
if err != nil { if err != nil {
checks["database"] = "error: " + err.Error() checks["database"] = "error: " + err.Error()
healthy = false healthy = false
} else if dbStats.ASNs == 0 && dbStats.Prefixes == 0 {
checks["database"] = "warning: empty database"
} else { } else {
checks["database"] = "ok" checks["database"] = "ok"
} }

View File

@ -168,7 +168,7 @@ func (tw *timeoutWriter) markWritten() {
// The timeout parameter specifies the maximum duration allowed for request processing. // The timeout parameter specifies the maximum duration allowed for request processing.
// The returned middleware handles panics from the wrapped handler by re-panicking // The returned middleware handles panics from the wrapped handler by re-panicking
// after cleanup, and prevents concurrent writes to the response after timeout occurs. // after cleanup, and prevents concurrent writes to the response after timeout occurs.
func TimeoutMiddleware(timeout time.Duration) func(http.Handler) http.Handler { func TimeoutMiddleware(timeout time.Duration, logger *slog.Logger) func(http.Handler) http.Handler {
return func(next http.Handler) http.Handler { return func(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
startTime := time.Now() startTime := time.Now()
@ -204,6 +204,14 @@ func TimeoutMiddleware(timeout time.Duration) func(http.Handler) http.Handler {
tw.markWritten() // Prevent the handler from writing after timeout tw.markWritten() // Prevent the handler from writing after timeout
execTime := time.Since(startTime) execTime := time.Since(startTime)
// Log the timeout as a warning
logger.Warn("Request timeout",
"method", r.Method,
"path", r.URL.Path,
"duration_ms", execTime.Milliseconds(),
"remote_addr", r.RemoteAddr,
)
// Write directly to the underlying writer since we've marked tw as written // Write directly to the underlying writer since we've marked tw as written
// This is safe because markWritten() prevents the handler from writing // This is safe because markWritten() prevents the handler from writing
tw.mu.Lock() tw.mu.Lock()
@ -350,10 +358,16 @@ func RequestLoggerMiddleware(logger *slog.Logger) func(http.Handler) http.Handle
// Log request completion // Log request completion
duration := time.Since(start) duration := time.Since(start)
logLevel := slog.LevelInfo logLevel := slog.LevelInfo
// Slow query threshold (1 second)
const slowQueryThreshold = 1 * time.Second
if sw.statusCode >= http.StatusInternalServerError { if sw.statusCode >= http.StatusInternalServerError {
logLevel = slog.LevelError logLevel = slog.LevelError
} else if sw.statusCode >= http.StatusBadRequest { } else if sw.statusCode >= http.StatusBadRequest {
logLevel = slog.LevelWarn logLevel = slog.LevelWarn
} else if duration >= slowQueryThreshold {
logLevel = slog.LevelWarn
} }
logger.Log(r.Context(), logLevel, "HTTP request completed", logger.Log(r.Context(), logLevel, "HTTP request completed",
@ -362,6 +376,7 @@ func RequestLoggerMiddleware(logger *slog.Logger) func(http.Handler) http.Handle
"status", sw.statusCode, "status", sw.statusCode,
"duration_ms", duration.Milliseconds(), "duration_ms", duration.Milliseconds(),
"remote_addr", r.RemoteAddr, "remote_addr", r.RemoteAddr,
"slow", duration >= slowQueryThreshold,
) )
}) })
} }

View File

@ -17,7 +17,7 @@ func (s *Server) setupRoutes() {
r.Use(RequestLoggerMiddleware(s.logger.Logger)) // Structured request logging r.Use(RequestLoggerMiddleware(s.logger.Logger)) // Structured request logging
r.Use(middleware.Recoverer) r.Use(middleware.Recoverer)
const requestTimeout = 30 * time.Second // Increased from 8s for slow queries const requestTimeout = 30 * time.Second // Increased from 8s for slow queries
r.Use(TimeoutMiddleware(requestTimeout)) r.Use(TimeoutMiddleware(requestTimeout, s.logger.Logger))
r.Use(JSONResponseMiddleware) r.Use(JSONResponseMiddleware)
// Routes // Routes