# Performance & Observability Enhancement Plan ## Current State Analysis **Observability**: - Basic logging with logrus - No structured logging standards - No distributed tracing - No metrics collection - No health check endpoints **Performance**: - No caching layer - No connection pooling for upstream APIs - No circuit breakers - No request coalescing - No rate limiting per API key ## Phase 1: Structured Logging (Week 1) ### 1.1 Migrate to slog (Go 1.21+) **File**: `internal/infrastructure/logging/logger.go` ```go package logging import ( "context" "log/slog" "os" "github.com/google/uuid" ) // Logger wraps slog with application-specific methods type Logger struct { *slog.Logger } // Config for logger type Config struct { Level string `json:"level"` Format string `json:"format"` // json or text Output string `json:"output"` // stdout, stderr, or file path } func New(cfg Config) (*Logger, error) { level := parseLevel(cfg.Level) var handler slog.Handler opts := &slog.HandlerOptions{ Level: level, AddSource: true, } switch cfg.Format { case "json": handler = slog.NewJSONHandler(os.Stdout, opts) case "text": handler = slog.NewTextHandler(os.Stdout, opts) default: handler = slog.NewJSONHandler(os.Stdout, opts) } return &Logger{Logger: slog.New(handler)}, nil } // WithContext adds request context fields func (l *Logger) WithContext(ctx context.Context) *Logger { return &Logger{ Logger: l.Logger.With( "request_id", ctx.Value(RequestIDKey{}), "trace_id", ctx.Value(TraceIDKey{}), ), } } // WithError adds error field func (l *Logger) WithError(err error) *Logger { return &Logger{ Logger: l.Logger.With("error", err), } } // WithField adds a single field func (l *Logger) WithField(key string, value interface{}) *Logger { return &Logger{ Logger: l.Logger.With(key, value), } } // WithFields adds multiple fields func (l *Logger) WithFields(fields map[string]interface{}) *Logger { attrs := make([]slog.Attr, 0, len(fields)) for k, v := range fields { attrs = append(attrs, slog.Any(k, v)) } return &Logger{Logger: slog.New(l.Logger.Handler().WithAttrs(attrs))} } // Request logging helper func (l *Logger) LogRequest( ctx context.Context, method string, path string, status int, duration time.Duration, extra map[string]interface{}, ) { fields := map[string]interface{}{ "http.method": method, "http.path": path, "http.status": status, "duration_ms": duration.Milliseconds(), "duration_bucket": durationBucket(duration), } for k, v := range extra { fields[k] = v } logger := l.WithContext(ctx).WithFields(fields) switch { case status >= 500: logger.Error("HTTP request completed with server error") case status >= 400: logger.Warn("HTTP request completed with client error") case status >= 300: logger.Info("HTTP request redirected") default: logger.Info("HTTP request completed") } } func durationBucket(d time.Duration) string { switch { case d < 10*time.Millisecond: return "<10ms" case d < 50*time.Millisecond: return "10-50ms" case d < 100*time.Millisecond: return "50-100ms" case d < 500*time.Millisecond: return "100-500ms" case d < 1*time.Second: return "500ms-1s" default: return ">1s" } } ``` ### 1.2 Gin Middleware **File**: `internal/api/middleware/logging.go` ```go package middleware import ( "time" "github.com/gin-gonic/gin" "github.com/echyai/cliproxyapi/internal/infrastructure/logging" ) func RequestLogger(logger *logging.Logger) gin.HandlerFunc { return func(c *gin.Context) { start := time.Now() // Process request c.Next() // Log after request completes duration := time.Since(start) extra := map[string]interface{}{ "client_ip": c.ClientIP(), "user_agent": c.Request.UserAgent(), "errors": c.Errors.String(), } logger.LogRequest( c.Request.Context(), c.Request.Method, c.Request.URL.Path, c.Writer.Status(), duration, extra, ) } } ``` ## Phase 2: Distributed Tracing (Week 2) ### 2.1 OpenTelemetry Setup **File**: `internal/infrastructure/tracing/tracing.go` ```go package tracing import ( "context" "go.opentelemetry.io/otel" "go.opentelemetry.io/otel/exporters/jaeger" "go.opentelemetry.io/otel/sdk/resource" sdktrace "go.opentelemetry.io/otel/sdk/trace" semconv "go.opentelemetry.io/otel/semconv/v1.24.0" "go.opentelemetry.io/otel/trace" ) var Tracer trace.Tracer func Init(serviceName, jaegerEndpoint string) (*sdktrace.TracerProvider, error) { exp, err := jaeger.New(jaeger.WithCollectorEndpoint( jaeger.WithEndpoint(jaegerEndpoint), )) if err != nil { return nil, err } tp := sdktrace.NewTracerProvider( sdktrace.WithBatcher(exp), sdktrace.WithResource(resource.NewWithAttributes( semconv.SchemaURL, semconv.ServiceName(serviceName), semconv.ServiceVersion("1.0.0"), )), ) otel.SetTracerProvider(tp) Tracer = tp.Tracer(serviceName) return tp, nil } // SpanFromContext retrieves current span func SpanFromContext(ctx context.Context) trace.Span { return trace.SpanFromContext(ctx) } // StartSpan starts a new span func StartSpan(ctx context.Context, name string, opts ...trace.SpanStartOption) (context.Context, trace.Span) { return Tracer.Start(ctx, name, opts...) } ``` ### 2.2 Gin Tracing Middleware **File**: `internal/api/middleware/tracing.go` ```go package middleware import ( "github.com/gin-gonic/gin" "go.opentelemetry.io/otel/attribute" "go.opentelemetry.io/otel/propagation" semconv "go.opentelemetry.io/otel/semconv/v1.24.0" "go.opentelemetry.io/otel/trace" "github.com/echyai/cliproxyapi/internal/infrastructure/tracing" ) func Tracing() gin.HandlerFunc { return func(c *gin.Context) { // Extract trace context from headers ctx := propagation.TraceContext{}.Extract(c.Request.Context(), propagation.HeaderCarrier(c.Request.Header)) // Start span ctx, span := tracing.StartSpan(ctx, c.Request.Method+" "+c.FullPath(), trace.WithAttributes( semconv.HTTPMethod(c.Request.Method), semconv.HTTPURL(c.Request.URL.String()), semconv.HTTPUserAgent(c.Request.UserAgent()), semconv.HTTPClientIP(c.ClientIP()), ), ) defer span.End() // Add span to context c.Request = c.Request.WithContext(ctx) // Continue c.Next() // Record result span.SetAttributes( semconv.HTTPStatusCode(c.Writer.Status()), ) if c.Writer.Status() >= 400 { span.RecordError(c.Errors.Last()) } } } ``` ## Phase 3: Metrics Collection (Week 2-3) ### 3.1 Prometheus Metrics **File**: `internal/infrastructure/metrics/metrics.go` ```go package metrics import ( "github.com/prometheus/client_golang/prometheus" "github.com/prometheus/client_golang/prometheus/promauto" ) var ( // HTTP metrics HTTPRequestsTotal = promauto.NewCounterVec( prometheus.CounterOpts{ Name: "cliproxy_http_requests_total", Help: "Total HTTP requests", }, []string{"method", "path", "status"}, ) HTTPRequestDuration = promauto.NewHistogramVec( prometheus.HistogramOpts{ Name: "cliproxy_http_request_duration_seconds", Help: "HTTP request duration in seconds", Buckets: []float64{.005, .01, .025, .05, .1, .25, .5, 1, 2.5, 5, 10}, }, []string{"method", "path"}, ) // Provider metrics ProviderRequestsTotal = promauto.NewCounterVec( prometheus.CounterOpts{ Name: "cliproxy_provider_requests_total", Help: "Total requests to upstream providers", }, []string{"provider", "model", "status"}, ) ProviderRequestDuration = promauto.NewHistogramVec( prometheus.HistogramOpts{ Name: "cliproxy_provider_request_duration_seconds", Help: "Upstream provider request duration", Buckets: []float64{.1, .25, .5, 1, 2.5, 5, 10, 30, 60}, }, []string{"provider", "model"}, ) ProviderTokensTotal = promauto.NewCounterVec( prometheus.CounterOpts{ Name: "cliproxy_provider_tokens_total", Help: "Total tokens processed", }, []string{"provider", "model", "type"}, // type: input, output ) // Rate limiting metrics RateLimitHits = promauto.NewCounterVec( prometheus.CounterOpts{ Name: "cliproxy_rate_limit_hits_total", Help: "Total rate limit hits", }, []string{"key_type", "key_id"}, ) // Cache metrics CacheHits = promauto.NewCounterVec( prometheus.CounterOpts{ Name: "cliproxy_cache_hits_total", Help: "Total cache hits", }, []string{"cache_name"}, ) CacheMisses = promauto.NewCounterVec( prometheus.CounterOpts{ Name: "cliproxy_cache_misses_total", Help: "Total cache misses", }, []string{"cache_name"}, ) // Active connections ActiveConnections = promauto.NewGauge( prometheus.GaugeOpts{ Name: "cliproxy_active_connections", Help: "Number of active connections", }, ) // Auth metrics ActiveAuths = promauto.NewGaugeVec( prometheus.GaugeOpts{ Name: "cliproxy_active_auths", Help: "Number of active authentications", }, []string{"provider"}, ) ) ``` ### 3.2 Gin Metrics Middleware **File**: `internal/api/middleware/metrics.go` ```go package middleware import ( "strconv" "time" "github.com/gin-gonic/gin" "github.com/prometheus/client_golang/prometheus" "github.com/echyai/cliproxyapi/internal/infrastructure/metrics" ) func PrometheusMetrics() gin.HandlerFunc { return func(c *gin.Context) { start := time.Now() c.Next() duration := time.Since(start).Seconds() status := strconv.Itoa(c.Writer.Status()) path := c.FullPath() if path == "" { path = "unknown" } metrics.HTTPRequestsTotal.WithLabelValues( c.Request.Method, path, status, ).Inc() metrics.HTTPRequestDuration.WithLabelValues( c.Request.Method, path, ).Observe(duration) } } ``` ## Phase 4: Caching Layer (Week 3) ### 4.1 Cache Interface **File**: `internal/infrastructure/cache/cache.go` ```go package cache import ( "context" "time" ) // Cache interface for different backends type Cache interface { Get(ctx context.Context, key string) ([]byte, error) Set(ctx context.Context, key string, value []byte, ttl time.Duration) error Delete(ctx context.Context, key string) error GetSetMembers(ctx context.Context, key string) ([]string, error) AddToSet(ctx context.Context, key string, members ...string) error Close() error } // Config for cache type Config struct { Type string // redis, inmemory Redis *RedisConfig Memory *MemoryConfig } type RedisConfig struct { Addr string Password string DB int } type MemoryConfig struct { MaxSize int // Maximum number of items } ``` ### 4.2 Token Cache Implementation **File**: `internal/infrastructure/cache/token_cache.go` ```go package cache import ( "context" "encoding/json" "fmt" "time" "github.com/echyai/cliproxyapi/internal/domain/entities" ) // TokenCache provides caching for OAuth tokens type TokenCache struct { cache Cache ttl time.Duration } func NewTokenCache(cache Cache, ttl time.Duration) *TokenCache { return &TokenCache{ cache: cache, ttl: ttl, } } func (tc *TokenCache) Get(ctx context.Context, authID entities.AuthID) (*entities.TokenData, error) { key := fmt.Sprintf("token:%s", authID) data, err := tc.cache.Get(ctx, key) if err != nil { return nil, err } if data == nil { return nil, nil } var token entities.TokenData if err := json.Unmarshal(data, &token); err != nil { return nil, err } return &token, nil } func (tc *TokenCache) Set(ctx context.Context, authID entities.AuthID, token *entities.TokenData) error { key := fmt.Sprintf("token:%s", authID) data, err := json.Marshal(token) if err != nil { return err } return tc.cache.Set(ctx, key, data, tc.ttl) } func (tc *TokenCache) Invalidate(ctx context.Context, authID entities.AuthID) error { key := fmt.Sprintf("token:%s", authID) return tc.cache.Delete(ctx, key) } ``` ## Phase 5: Circuit Breaker (Week 4) ### 5.1 Circuit Breaker Implementation **File**: `internal/infrastructure/resilience/circuit_breaker.go` ```go package resilience import ( "context" "errors" "sync" "time" ) // State represents circuit breaker state type State int const ( StateClosed State = iota StateOpen StateHalfOpen ) func (s State) String() string { switch s { case StateClosed: return "closed" case StateOpen: return "open" case StateHalfOpen: return "half-open" default: return "unknown" } } // Config for circuit breaker type Config struct { FailureThreshold int // Number of failures before opening SuccessThreshold int // Number of successes to close from half-open Timeout time.Duration // Time before attempting half-open HalfOpenMaxCalls int // Max calls allowed in half-open state } // CircuitBreaker implements the circuit breaker pattern type CircuitBreaker struct { name string config Config state State failures int successes int lastFailure time.Time halfOpenCalls int mu sync.RWMutex onStateChange func(name string, from, to State) } func New(name string, config Config, onStateChange func(string, State, State)) *CircuitBreaker { return &CircuitBreaker{ name: name, config: config, state: StateClosed, onStateChange: onStateChange, } } func (cb *CircuitBreaker) Execute(ctx context.Context, fn func() error) error { cb.mu.Lock() state := cb.state switch state { case StateOpen: if time.Since(cb.lastFailure) > cb.config.Timeout { cb.transitionTo(StateHalfOpen) state = StateHalfOpen } else { cb.mu.Unlock() return errors.New("circuit breaker is open") } case StateHalfOpen: if cb.halfOpenCalls >= cb.config.HalfOpenMaxCalls { cb.mu.Unlock() return errors.New("circuit breaker half-open call limit reached") } cb.halfOpenCalls++ } cb.mu.Unlock() // Execute function err := fn() cb.recordResult(err) return err } func (cb *CircuitBreaker) recordResult(err error) { cb.mu.Lock() defer cb.mu.Unlock() if err == nil { cb.onSuccess() } else { cb.onFailure() } } func (cb *CircuitBreaker) onSuccess() { switch cb.state { case StateHalfOpen: cb.successes++ if cb.successes >= cb.config.SuccessThreshold { cb.transitionTo(StateClosed) } default: cb.failures = 0 } } func (cb *CircuitBreaker) onFailure() { cb.failures++ cb.lastFailure = time.Now() switch cb.state { case StateHalfOpen: cb.transitionTo(StateOpen) default: if cb.failures >= cb.config.FailureThreshold { cb.transitionTo(StateOpen) } } } func (cb *CircuitBreaker) transitionTo(newState State) { if cb.state != newState { oldState := cb.state cb.state = newState cb.failures = 0 cb.successes = 0 cb.halfOpenCalls = 0 if cb.onStateChange != nil { cb.onStateChange(cb.name, oldState, newState) } } } func (cb *CircuitBreaker) State() State { cb.mu.RLock() defer cb.mu.RUnlock() return cb.state } ``` ### 5.2 Provider Client with Circuit Breaker **File**: `internal/infrastructure/providers/gemini_client.go` ```go package providers import ( "context" "fmt" "time" "github.com/echyai/cliproxyapi/internal/infrastructure/metrics" "github.com/echyai/cliproxyapi/internal/infrastructure/resilience" ) type GeminiClient struct { baseURL string apiKey string httpClient *http.Client circuitBreaker *resilience.CircuitBreaker logger *logging.Logger } func NewGeminiClient(baseURL, apiKey string, logger *logging.Logger) *GeminiClient { cb := resilience.New("gemini", resilience.Config{ FailureThreshold: 5, SuccessThreshold: 2, Timeout: 30 * time.Second, HalfOpenMaxCalls: 3, }, func(name string, from, to resilience.State) { logger.WithFields(map[string]interface{}{ "circuit_breaker": name, "from_state": from.String(), "to_state": to.String(), }).Warn("Circuit breaker state changed") }) return &GeminiClient{ baseURL: baseURL, apiKey: apiKey, httpClient: &http.Client{ Timeout: 60 * time.Second, Transport: &http.Transport{ MaxIdleConns: 100, MaxIdleConnsPerHost: 10, IdleConnTimeout: 90 * time.Second, }, }, circuitBreaker: cb, logger: logger, } } func (c *GeminiClient) GenerateContent( ctx context.Context, req *GenerateContentRequest, ) (*GenerateContentResponse, error) { start := time.Now() model := req.Model var resp *GenerateContentResponse var err error cbErr := c.circuitBreaker.Execute(ctx, func() error { resp, err = c.doGenerateContent(ctx, req) return err }) if cbErr != nil { return nil, fmt.Errorf("circuit breaker: %w", cbErr) } // Record metrics duration := time.Since(start).Seconds() status := "success" if err != nil { status = "error" } metrics.ProviderRequestsTotal.WithLabelValues("gemini", model, status).Inc() metrics.ProviderRequestDuration.WithLabelValues("gemini", model).Observe(duration) if err != nil { return nil, err } // Record token metrics if resp.Usage != nil { metrics.ProviderTokensTotal.WithLabelValues("gemini", model, "input"). Add(float64(resp.Usage.InputTokens)) metrics.ProviderTokensTotal.WithLabelValues("gemini", model, "output"). Add(float64(resp.Usage.OutputTokens)) } return resp, nil } ``` ## Phase 6: Health Checks (Week 4) **File**: `internal/api/handlers/health_handler.go` ```go package handlers import ( "net/http" "github.com/gin-gonic/gin" "github.com/echyai/cliproxyapi/internal/infrastructure/health" ) type HealthHandler struct { checker *health.Checker } func NewHealthHandler(checker *health.Checker) *HealthHandler { return &HealthHandler{checker: checker} } func (h *HealthHandler) Register(r *gin.RouterGroup) { r.GET("/health", h.Liveness) r.GET("/ready", h.Readiness) r.GET("/metrics", gin.WrapH(promhttp.Handler())) } func (h *HealthHandler) Liveness(c *gin.Context) { c.JSON(http.StatusOK, gin.H{ "status": "alive", "time": time.Now().UTC(), }) } func (h *HealthHandler) Readiness(c *gin.Context) { checks := h.checker.RunAll(c.Request.Context()) status := http.StatusOK for _, check := range checks { if !check.Healthy { status = http.StatusServiceUnavailable break } } c.JSON(status, gin.H{ "status": map[bool]string{true: "ready", false: "not_ready"}[status == http.StatusOK], "checks": checks, "version": version.Get(), }) } ``` ## Success Metrics - [ ] < 50ms p99 latency for cached token lookups - [ ] 99.9% availability measured via health checks - [ ] < 1% request error rate - [ ] All requests have distributed trace IDs - [ ] Dashboard with key metrics in Grafana