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
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
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
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
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
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
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
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
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
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
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
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