n4nAI
Open console →

API integration

How-to

Echo middleware for logging LLM request latency

Step-by-step guide to building Echo middleware for request latency logging of LLM API calls in Go, with runnable code, structured logs, and verification.

n4n Team4 min read875 words

Audio narration

Coming soon — every post will get a voice note here.

When you embed LLM calls inside a Go service, echo middleware request latency logging gives you immediate visibility into per-request cost and slow paths. This article walks through a complete implementation: a proxy route in Echo that forwards to an OpenAI-compatible inference endpoint, middleware that records latency and status, and log enrichment that captures model and token usage. You will end with runnable code and a way to verify it against real traffic.

Step 1: Scaffold an Echo server with an LLM proxy route

Start with a minimal Echo app that accepts POST /v1/chat/completions and forwards the body to an upstream LLM API. Use a standard http.Client with a timeout. Keep the upstream base URL configurable via environment variable so you can swap vendors without recompiling.

package main

import (
	"net/http"
	"net/http/httputil"
	"net/url"
	"os"

	"github.com/labstack/echo/v4"
)

func main() {
	e := echo.New()

	upstream := os.Getenv("LLM_UPSTREAM")
	if upstream == "" {
		upstream = "https://api.openai.com"
	}
	target, _ := url.Parse(upstream)
	proxy := httputil.NewSingleHostReverseProxy(target)

	e.POST("/v1/chat/completions", func(c echo.Context) error {
		req := c.Request()
		req.URL.Path = "/v1/chat/completions"
		req.Host = target.Host
		proxy.ServeHTTP(c.Response(), req)
		return nil
	})

	e.Start(":8080")
}

This is a dumb proxy. It does not log anything yet. The latency of the upstream call is hidden inside proxy.ServeHTTP. We will wrap that call with middleware so we can measure it without modifying the handler.

Reverse proxies in production should also handle header sanitation. At minimum, decide whether you terminate API keys at the edge or pass them through. For this guide we assume the upstream credential is injected by the proxy layer or supplied by the caller.

Step 2: Implement basic echo middleware request latency logging

Echo middleware has the signature func(echo.HandlerFunc) echo.HandlerFunc. Capture time.Now() before calling the next handler, then log after it returns. Use c.Response().Status for the HTTP status that the handler (or proxy) set.

func LatencyLogger() echo.MiddlewareFunc {
	return func(next echo.HandlerFunc) echo.HandlerFunc {
		return func(c echo.Context) error {
			start := time.Now()
			err := next(c)
			stop := time.Now()
			latency := stop.Sub(start)

			fmt.Printf("method=%s path=%s status=%d latency=%s\n",
				c.Request().Method,
				c.Request().URL.Path,
				c.Response().Status,
				latency,
			)
			return err
		}
	}
}

Register it before the route:

e.Use(LatencyLogger())

This already satisfies a basic echo middleware request latency logging requirement. The measurement includes Echo’s routing overhead and the full upstream round trip. For LLM calls, however, a 2-second latency on a 10-token reply is a different problem than a 2-second latency on a 4K-token completion. Plain latency is not enough to debug model-specific slowness.

Step 3: Enrich logs with LLM request context

We need the model from the request JSON and the usage from the response JSON. For non-streaming responses, the upstream returns {"usage": {"total_tokens": N}}. To read the body without breaking the proxy, use a custom io.Writer that tees the response.

First, define a response wrapper:

type bodyCapture struct {
	echo.Response
	buf *bytes.Buffer
}

func (w *bodyCapture) Write(b []byte) (int, error) {
	w.buf.Write(b)
	return w.Response.Write(b)
}

In the middleware, swap the response writer for non-streaming requests. Check the request body for stream:true to avoid buffering streams.

func LLMLogger() echo.MiddlewareFunc {
	return func(next echo.HandlerFunc) echo.HandlerFunc {
		return func(c echo.Context) error {
			start := time.Now()

			var reqBody map[string]interface{}
			if c.Request().Body != nil {
				b, _ := io.ReadAll(c.Request().Body)
				json.Unmarshal(b, &reqBody)
				c.Request().Body = io.NopCloser(bytes.NewReader(b))
			}
			model, _ := reqBody["model"].(string)

			var bc *bodyCapture
			if stream, ok := reqBody["stream"].(bool); !ok || !stream {
				bc = &bodyCapture{Response: *c.Response(), buf: &bytes.Buffer{}}
				c.SetResponse(echo.NewResponse(bc, c.Echo()))
			}

			err := next(c)
			latency := time.Since(start)
			status := c.Response().Status

			entry := fmt.Sprintf("model=%s status=%d latency=%s", model, status, latency)
			if bc != nil {
				var respBody map[string]interface{}
				json.Unmarshal(bc.buf.Bytes(), &respBody)
				if usage, ok := respBody["usage"].(map[string]interface{}); ok {
					entry += fmt.Sprintf(" total_tokens=%v", usage["total_tokens"])
				}
			}
			fmt.Println(entry)
			return err
		}
	}
}

This upgrades our echo middleware request latency logging to include model and token counts. Reading the request body consumes it; we restore it with NopCloser so the proxy sees the original bytes. The response capture only triggers for non-streaming calls.

Step 4: Use structured logging and request IDs

fmt.Println does not scale. Swap to log/slog (Go 1.21+) with JSON output. Also add a request ID so you can correlate logs with upstream traces.

import (
	"log/slog"
	"github.com/google/uuid"
)

func LLMSlogLogger() echo.MiddlewareFunc {
	return func(next echo.HandlerFunc) echo.HandlerFunc {
		return func(c echo.Context) error {
			start := time.Now()
			reqID := c.Request().Header.Get("X-Request-ID")
			if reqID == "" {
				reqID = uuid.NewString()
			}
			c.Response().Header().Set("X-Request-ID", reqID)

			// body capture omitted for brevity (same as Step 3)

			err := next(c)
			latency := time.Since(start)

			slog.Info("llm_request",
				slog.String("req_id", reqID),
				slog.String("model", model),
				slog.Int("status", c.Response().Status),
				slog.Duration("latency", latency),
			)
			return err
		}
	}
}

If you meter per-token usage downstream, those numbers appear in the response and get logged automatically. Structured logs let you pipe to Loki, Datadog, or stdout collectors without custom parsing.

Step 5: Handle streaming responses without buffering

LLM streaming uses text/event-stream. Buffering the whole response blocks the client and defeats the purpose of streaming. For streaming, do not wrap the writer with bodyCapture. Instead, log time-to-first-byte (TTFB) by hooking WriteHeader.

type ttfbWriter struct {
	echo.Response
	firstByte time.Time
	once      sync.Once
}

func (w *ttfbWriter) Write(b []byte) (int, error) {
	w.once.Do(func() { w.firstByte = time.Now() })
	return w.Response.Write(b)
}

In middleware, if stream is true, swap with ttfbWriter and record firstByte after next. Latency logging for streams should report TTFB separately from total duration, because a long completion can have a sub-second first token.

Step 6: Verify the middleware end to end

Run the server, then send a request with curl:

curl -X POST localhost:8080/v1/chat/completions \
  -H "Content-Type: application/json" \
  -d '{"model":"gpt-4o-mini","messages":[{"role":"user","content":"ping"}]}'

Check the server stdout. You should see a structured log line with model=gpt-4o-mini status=200 latency=... total_tokens=.... For streaming, add "stream":true and confirm TTFB logs appear without delaying responses.

Write a small Go test using httptest to assert the middleware records latency:

func TestLLMLogger(t *testing.T) {
	e := echo.New()
	e.Use(LLMLogger())
	e.POST("/v1/chat/completions", func(c echo.Context) error {
		return c.JSON(http.StatusOK, map[string]interface{}{
			"usage": map[string]interface{}{"total_tokens": 10},
		})
	})
	// send request, capture log output, assert model and latency present.
}

Verification succeeds when the log line is emitted on every request, the model field matches the request, and streaming calls do not block.

Step 7: Point the proxy at a multi-model gateway

If your deployment targets multiple providers, you can set LLM_UPSTREAM to a single OpenAI-compatible endpoint that fronts 240+ models and applies automatic fallback when a provider is rate-limited. n4n.ai operates such a gateway; using it means your echo middleware request latency logging will capture the extra hop only when fallback triggers, and the logged model string reflects the actually served model. This avoids per-provider middleware branches.

Keep the middleware provider-agnostic: it only reads model and usage. That decoupling is what makes the same logging code work whether you call a single vendor or a routing gateway.

Step 8: Export latency as Prometheus metrics

Logging is for humans; metrics are for alerts. Add a prometheus.Client and increment a histogram in the middleware:

var latencyHist = prometheus.NewHistogramVec(
	prometheus.HistogramOpts{Name: "llm_request_latency_seconds", Buckets: []float64{0.1, 0.5, 1, 2, 5}},
	[]string{"model", "status"},
)

func MetricsMiddleware() echo.MiddlewareFunc {
	return func(next echo.HandlerFunc) echo.HandlerFunc {
		return func(c echo.Context) error {
			start := time.Now()
			err := next(c)
			latencyHist.WithLabelValues(model, strconv.Itoa(c.Response().Status)).
				Observe(time.Since(start).Seconds())
			return err
		}
	}
}

Register the histogram with prometheus.MustRegister and expose /metrics. Now you can alert on p95 latency per model, not just watch logs.

Caveats and production notes

  • Reverse proxying with httputil does not forward all headers safely; sanitize Authorization if you terminate keys at the edge.
  • Body capture in middleware increases memory per request. For large responses, stream-parse usage instead of buffering the whole payload.
  • Latency measured in middleware includes Echo overhead and network to upstream; subtract proxy overhead if you need upstream-only numbers.
  • Use slog with a level filter; debug logs of full bodies violate privacy and bloat storage.

Following these steps gives you a working Echo middleware for request latency logging that surfaces LLM-specific signals. The code is minimal, testable, and ready to extend with metrics exporters or trace propagation.

Tagsgolangechomiddlewareobservability

Written by

n4n Team

The team building n4n — a single OpenAI-compatible API in front of 240+ models, with automatic fallback, load balancing and pay-per-token metering.

More from n4n Team →