OpenTelemetry tracing integrated with logr/zap logging #4

Open
kacerr wants to merge 13 commits from feat/otel-tracing into main
3 changed files with 29 additions and 6 deletions
Showing only changes of commit ec7267b8de - Show all commits

View File

@@ -7,7 +7,7 @@ Plan: `docs/plans/2026-08-24-1025-otel-tracing.md`
- [x] Step 3 — `provider.WithTracing` decorator - [x] Step 3 — `provider.WithTracing` decorator
- [x] Step 4 — `cmd/main.go` wiring - [x] Step 4 — `cmd/main.go` wiring
- [x] Step 5 — Reconciler spans - [x] Step 5 — Reconciler spans
- [ ] Step 6 — Discovery server - [x] Step 6 — Discovery server
- [ ] Step 7 — GC + health - [ ] Step 7 — GC + health
- [ ] Step 8 — GCP wire-log enrichment - [ ] Step 8 — GCP wire-log enrichment
- [ ] Step 9 — Manifests + docs - [ ] Step 9 — Manifests + docs
@@ -118,3 +118,18 @@ span's content — a real PATCH shows up as its k8s HTTP child). Tests that
call `r.Reconcile` directly bypass the wrapper; with no global tracer set call `r.Reconcile` directly bypass the wrapper; with no global tracer set
they see no-op spans, so the existing fake-client and envtest suites run they see no-op spans, so the existing fake-client and envtest suites run
unchanged. unchanged.
## Step 6 — Discovery server
Middleware chain is now recover → tracing (server span + request logger) →
request-log → body cap → auth; the request-log middleware and the three
handler error sites log via `logf.FromContext(r.Context())` — which is
`s.log` enriched with the request's traceID/spanID by the tracing
middleware, not a different logger (logr sinks can't read ctx at log time,
so per-request values must ride on the logger instance in the ctx; user
asked, answered in-session).
Deviation from the plan's letter: `recoverMiddleware` keeps `s.log`. It sits
*outside* the tracing layer, so its request ctx never has the enriched
logger — switching it to `FromContext` would silently drop the `"discovery"`
name and gain nothing.

View File

@@ -11,6 +11,7 @@ import (
apimeta "k8s.io/apimachinery/pkg/api/meta" apimeta "k8s.io/apimachinery/pkg/api/meta"
"sigs.k8s.io/controller-runtime/pkg/client" "sigs.k8s.io/controller-runtime/pkg/client"
logf "sigs.k8s.io/controller-runtime/pkg/log"
crawlv1alpha1 "gitea.home.hrajfrisbee.cz/kacerr/egress-proxies-operator/api/v1alpha1" crawlv1alpha1 "gitea.home.hrajfrisbee.cz/kacerr/egress-proxies-operator/api/v1alpha1"
"gitea.home.hrajfrisbee.cz/kacerr/egress-proxies-operator/internal/lease" "gitea.home.hrajfrisbee.cz/kacerr/egress-proxies-operator/internal/lease"
@@ -82,7 +83,10 @@ func (s *Server) handleListProxies(w http.ResponseWriter, r *http.Request) {
var list crawlv1alpha1.ProxyList var list crawlv1alpha1.ProxyList
if err := s.Reader.List(r.Context(), &list); err != nil { if err := s.Reader.List(r.Context(), &list); err != nil {
s.log.Error(err, "listing proxies") // The ctx logger is s.log enriched with this request's
// traceID/spanID by the tracing middleware (logr sinks can't read
// ctx at log time, so per-request values ride on the logger).
logf.FromContext(r.Context()).Error(err, "listing proxies")
writeError(w, http.StatusInternalServerError, "internal", "listing proxies failed") writeError(w, http.StatusInternalServerError, "internal", "listing proxies failed")
return return
} }
@@ -138,7 +142,7 @@ func (s *Server) handleAcquireLease(w http.ResponseWriter, r *http.Request) {
var list crawlv1alpha1.ProxyList var list crawlv1alpha1.ProxyList
if err := s.Reader.List(r.Context(), &list); err != nil { if err := s.Reader.List(r.Context(), &list); err != nil {
s.log.Error(err, "listing proxies for lease") logf.FromContext(r.Context()).Error(err, "listing proxies for lease")
writeError(w, http.StatusInternalServerError, "internal", "listing proxies failed") writeError(w, http.StatusInternalServerError, "internal", "listing proxies failed")
return return
} }
@@ -231,7 +235,7 @@ func (s *Server) handleReportLease(w http.ResponseWriter, r *http.Request) {
writeError(w, http.StatusNotFound, "unknown_lease", "no such lease") writeError(w, http.StatusNotFound, "unknown_lease", "no such lease")
return return
} }
s.log.Error(err, "reporting lease", "leaseID", r.PathValue("id")) logf.FromContext(r.Context()).Error(err, "reporting lease", "leaseID", r.PathValue("id"))
writeError(w, http.StatusInternalServerError, "internal", "report failed") writeError(w, http.StatusInternalServerError, "internal", "report failed")
return return
} }

View File

@@ -20,6 +20,7 @@ import (
logf "sigs.k8s.io/controller-runtime/pkg/log" logf "sigs.k8s.io/controller-runtime/pkg/log"
"gitea.home.hrajfrisbee.cz/kacerr/egress-proxies-operator/internal/lease" "gitea.home.hrajfrisbee.cz/kacerr/egress-proxies-operator/internal/lease"
"gitea.home.hrajfrisbee.cz/kacerr/egress-proxies-operator/internal/tracing"
) )
// LeaseStore is what the handlers need from a lease backend. Defined here, // LeaseStore is what the handlers need from a lease backend. Defined here,
@@ -136,7 +137,9 @@ func (s *Server) Start(ctx context.Context) error {
} }
// handler assembles the mux and the middleware chain, outermost first: // handler assembles the mux and the middleware chain, outermost first:
// recover → request-log → body-size cap → bearer auth. // recover → tracing (server span + request logger) → request-log →
// body-size cap → bearer auth. Everything inside the tracing layer logs via
// logf.FromContext(r.Context()) and so carries traceID/spanID.
func (s *Server) handler() http.Handler { func (s *Server) handler() http.Handler {
mux := http.NewServeMux() mux := http.NewServeMux()
mux.HandleFunc("GET /healthz", func(w http.ResponseWriter, _ *http.Request) { mux.HandleFunc("GET /healthz", func(w http.ResponseWriter, _ *http.Request) {
@@ -152,6 +155,7 @@ func (s *Server) handler() http.Handler {
h = s.authMiddleware(h) h = s.authMiddleware(h)
h = maxBytesMiddleware(h) h = maxBytesMiddleware(h)
h = s.logMiddleware(h) h = s.logMiddleware(h)
h = tracing.HTTPMiddleware("discovery", s.log)(h)
h = s.recoverMiddleware(h) h = s.recoverMiddleware(h)
return h return h
} }
@@ -188,7 +192,7 @@ func (s *Server) logMiddleware(next http.Handler) http.Handler {
rec := &statusRecorder{ResponseWriter: w, status: http.StatusOK} rec := &statusRecorder{ResponseWriter: w, status: http.StatusOK}
start := time.Now() start := time.Now()
next.ServeHTTP(rec, r) next.ServeHTTP(rec, r)
s.log.Info("request", logf.FromContext(r.Context()).Info("request",
"method", r.Method, "path", r.URL.Path, "method", r.Method, "path", r.URL.Path,
"status", rec.status, "duration", time.Since(start).String()) "status", rec.status, "duration", time.Since(start).String())
}) })