cleanup(sidecar,logging): share the level encoder and use named verbosity constants

Dockerfile.builder

@@ -10,8 +10,8 @@ ARG KUBECTL_VERSION=v1.35.3
 ARG KUSTOMIZE_VERSION=v5.6.0
 ARG DOCKER_VERSION=29.3.0
 ARG DOCKER_BUILDX_VERSION=v0.32.1
-ARG ENVTEST_VERSION=release-0.19
-ARG ENVTEST_K8S_VERSION=1.31.0
+ARG ENVTEST_VERSION=release-0.23
+ARG ENVTEST_K8S_VERSION=1.35.0
 ARG GOVULNCHECK_VERSION=v1.3.0
 
 RUN apt-get update && apt-get install -y podman && apt-get clean all

pkg/common/observability/logging/logger.go

@@ -33,29 +33,33 @@ import (
 // level can be adjusted after the controller-runtime delegation is fulfilled.
 var atomicLevel = uberzap.NewAtomicLevelAt(zapcore.InfoLevel)
 
-func customLevelEncoder(l zapcore.Level, enc zapcore.PrimitiveArrayEncoder) {
+// LevelEncoder maps negative Zap levels to human-readable names that match
+// the project's verbosity constants (VERBOSE=3, DEBUG=4, TRACE=5). Without
+// this, controller-runtime's zap bridge emits all V(n) calls as "debug" in
+// JSON output, which is misleading for V(1)-V(3) (verbose info).
+func LevelEncoder(l zapcore.Level, enc zapcore.PrimitiveArrayEncoder) {
 	if l >= 0 {
 		zapcore.LowercaseLevelEncoder(l, enc)
 		return
 	}
 
 	switch l {
-	case zapcore.Level(-1 * DEBUG): // -4
+	case zapcore.Level(-1 * DEBUG): // V(4) -> "debug"
 		enc.AppendString("debug")
-	case zapcore.Level(-1 * TRACE): // -5
+	case zapcore.Level(-1 * TRACE): // V(5) -> "trace"
 		enc.AppendString("trace")
 	default:
-		if l >= zapcore.Level(-1*VERBOSE) { // >= -3 (i.e. V(1)-V(3))
+		if l >= zapcore.Level(-1*VERBOSE) { // V(1)-V(3) -> "info"
 			enc.AppendString("info")
-		} else {
+		} else { // V(6+) -> "trace"
 			enc.AppendString("trace")
 		}
 	}
 }
 
 func InitSetupLogging() {
 	config := uberzap.NewProductionEncoderConfig()
-	config.EncodeLevel = customLevelEncoder
+	config.EncodeLevel = LevelEncoder
 
 	logger := zap.New(
 		zap.Level(atomicLevel),

pkg/common/observability/logging/logger_test.go

@@ -87,7 +87,7 @@ func TestCustomLevelEncoder(t *testing.T) {
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
 			enc := &mockArrayEncoder{}
-			customLevelEncoder(tt.level, enc)
+			LevelEncoder(tt.level, enc)
 			if len(enc.strings) != 1 {
 				t.Fatalf("Expected 1 string appended, got %d", len(enc.strings))
 			}

pkg/epp/framework/plugins/datalayer/extractor/metrics/extractor.go

@@ -40,10 +40,8 @@ const (
 	KVCacheUsagePercentKey = "KVCacheUsagePercent"
 	WaitingQueueSizeKey    = "WaitingQueueSize"
 	RunningRequestsSizeKey = "RunningRequestsSize"
-	MaxActiveModelsKey     = "MaxActiveModels"
 	ActiveModelsKey        = "ActiveModels"
 	WaitingModelsKey       = "WaitingModels"
-	UpdateTimeKey          = "UpdateTime"
 
 	// LoRA metrics based on MSP
 	LoraInfoRunningAdaptersMetricName = "running_lora_adapters"

pkg/sidecar/proxy/allowlist.go

@@ -23,7 +23,6 @@ import (
 	"time"
 
 	"github.com/go-logr/logr"
-	"github.com/llm-d/llm-d-router/pkg/common/routing"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/apis/meta/v1/unstructured"
 	"k8s.io/apimachinery/pkg/labels"
@@ -35,6 +34,9 @@ import (
 	"k8s.io/client-go/tools/clientcmd"
 	"k8s.io/utils/set"
 	"sigs.k8s.io/controller-runtime/pkg/log"
+
+	"github.com/llm-d/llm-d-router/pkg/common/observability/logging"
+	"github.com/llm-d/llm-d-router/pkg/common/routing"
 )
 
 const (
@@ -183,7 +185,7 @@ func (av *AllowlistValidator) Stop() {
 	// Stop all pod informers first
 	av.podInformersMu.Lock()
 	for poolName, stopCh := range av.podStopChans {
-		av.logger.V(4).Info("stopping pod informer", "pool", poolName)
+		av.logger.V(logging.DEBUG).Info("stopping pod informer", "pool", poolName)
 		close(stopCh)
 	}
 	// Clear the maps
@@ -209,7 +211,7 @@ func (av *AllowlistValidator) IsAllowed(hostPort string) bool {
 	defer av.allowedTargetsMu.RUnlock()
 
 	allowed := av.allowedTargets.Has(hostPort)
-	av.logger.V(4).Info("allowlist check", "hostPort", hostPort, "allowed", allowed)
+	av.logger.V(logging.DEBUG).Info("allowlist check", "hostPort", hostPort, "allowed", allowed)
 	return allowed
 }
 
@@ -337,22 +339,22 @@ func (av *AllowlistValidator) createPodInformer(poolName string, selector labels
 func (av *AllowlistValidator) onPodAdd(obj interface{}) {
 	pod := obj.(*unstructured.Unstructured)
 	podIP, _, _ := unstructured.NestedString(pod.Object, "status", "podIP")
-	av.logger.V(4).Info("Pod added", "name", pod.GetName(), "ip", podIP)
+	av.logger.V(logging.DEBUG).Info("Pod added", "name", pod.GetName(), "ip", podIP)
 	av.rebuildAllowlist()
 }
 
 // onPodUpdate handles updated pods
 func (av *AllowlistValidator) onPodUpdate(_, newObj interface{}) {
 	pod := newObj.(*unstructured.Unstructured)
 	podIP, _, _ := unstructured.NestedString(pod.Object, "status", "podIP")
-	av.logger.V(4).Info("Pod updated", "name", pod.GetName(), "ip", podIP)
+	av.logger.V(logging.DEBUG).Info("Pod updated", "name", pod.GetName(), "ip", podIP)
 	av.rebuildAllowlist()
 }
 
 // onPodDelete handles deleted pods
 func (av *AllowlistValidator) onPodDelete(obj interface{}) {
 	pod := obj.(*unstructured.Unstructured)
-	av.logger.V(4).Info("Pod deleted", "name", pod.GetName())
+	av.logger.V(logging.DEBUG).Info("Pod deleted", "name", pod.GetName())
 	av.rebuildAllowlist()
 }
 
@@ -398,5 +400,5 @@ func (av *AllowlistValidator) addPodToAllowlist(pod *unstructured.Unstructured,
 		av.allowedTargets.Insert(podName)
 	}
 
-	av.logger.V(5).Info("added pod to allowlist", "pod", podName, "ip", podIP, "pool", poolName)
+	av.logger.V(logging.TRACE).Info("added pod to allowlist", "pod", podName, "ip", podIP, "pool", poolName)
 }

pkg/sidecar/proxy/chat_completions.go

@@ -26,7 +26,7 @@ import (
 	"go.opentelemetry.io/otel/codes"
 	"go.opentelemetry.io/otel/trace"
 
-	logging "github.com/llm-d/llm-d-router/pkg/common/observability/logging"
+	"github.com/llm-d/llm-d-router/pkg/common/observability/logging"
 	"github.com/llm-d/llm-d-router/pkg/common/observability/tracing"
 	"github.com/llm-d/llm-d-router/pkg/common/routing"
 )
@@ -101,7 +101,7 @@ func (s *Server) disaggregatedPrefillHandler(apiType APIType) http.HandlerFunc {
 		}
 
 		if len(prefillHostPort) == 0 {
-			s.logger.V(4).Info("skip disaggregated prefill", "api", apiType.String())
+			s.logger.V(logging.DEBUG).Info("skip disaggregated prefill", "api", apiType.String())
 			span.SetAttributes(
 				attribute.Bool("llm_d.pd_proxy.disaggregation_used", false),
 				attribute.String("llm_d.pd_proxy.reason", "no_prefill_header"),
@@ -129,7 +129,7 @@ func (s *Server) disaggregatedPrefillHandler(apiType APIType) http.HandlerFunc {
 				http.Error(w, "Forbidden: prefill target not allowed by SSRF protection", http.StatusForbidden)
 				return
 			}
-			s.logger.V(4).Info("SSRF protection: prefill target allowed", "target", prefillHostPort)
+			s.logger.V(logging.DEBUG).Info("SSRF protection: prefill target allowed", "target", prefillHostPort)
 		}
 
 		kvCacheSource := strings.TrimSpace(r.Header.Get(routing.KVCacheSourceHeader))
@@ -166,7 +166,7 @@ func (s *Server) disaggregatedPrefillHandler(apiType APIType) http.HandlerFunc {
 				encoderHost = strings.TrimSpace(encoderHost)
 				if s.allowlistValidator.IsAllowed(encoderHost) {
 					allowedEncoders = append(allowedEncoders, encoderHost)
-					s.logger.V(4).Info("SSRF protection: encoder target allowed", "target", encoderHost)
+					s.logger.V(logging.DEBUG).Info("SSRF protection: encoder target allowed", "target", encoderHost)
 				} else {
 					s.logger.Info("SSRF protection: encoder target not in allowlist, removing from list",
 						"target", encoderHost,
@@ -178,7 +178,7 @@ func (s *Server) disaggregatedPrefillHandler(apiType APIType) http.HandlerFunc {
 		}
 
 		if len(allowedEncoders) > 0 && s.handleECConnector != nil {
-			s.logger.V(4).Info("encoder headers detected, using EC connector",
+			s.logger.V(logging.DEBUG).Info("encoder headers detected, using EC connector",
 				"encoderCount", len(allowedEncoders),
 				"encoderCandidates", len(encoderHostPorts),
 				"hasPrefiller", len(prefillHostPort) > 0)
@@ -201,12 +201,12 @@ func (s *Server) disaggregatedPrefillHandler(apiType APIType) http.HandlerFunc {
 		}
 
 		if len(prefillHostPort) > 0 {
-			s.logger.V(4).Info("using P/D protocol")
+			s.logger.V(logging.DEBUG).Info("using P/D protocol")
 			s.handlePDConnector(w, r, prefillHostPort, kvCacheSource, apiType)
 			return
 		}
 
-		s.logger.V(4).Info("no prefiller or encoder, using decoder only")
+		s.logger.V(logging.DEBUG).Info("no prefiller or encoder, using decoder only")
 		if !s.forwardDataParallel || !s.dataParallelHandler(w, r) {
 			if kvCacheSource != "" {
 				s.decodeWithP2PSource(w, r, kvCacheSource)

pkg/sidecar/proxy/connector_ec_common.go

@@ -14,7 +14,7 @@ import (
 	"fmt"
 	"net/http"
 
-	logging "github.com/llm-d/llm-d-router/pkg/common/observability/logging"
+	"github.com/llm-d/llm-d-router/pkg/common/observability/logging"
 	reqcommon "github.com/llm-d/llm-d-router/pkg/common/request"
 	"golang.org/x/sync/errgroup"
 )

pkg/sidecar/proxy/connector_ec_nixl.go

@@ -8,7 +8,7 @@ import (
 	"sync"
 
 	"github.com/google/uuid"
-	logging "github.com/llm-d/llm-d-router/pkg/common/observability/logging"
+	"github.com/llm-d/llm-d-router/pkg/common/observability/logging"
 )
 
 // fanoutEncoderCollect fans out per-image encoder requests and merges

pkg/sidecar/proxy/connector_ec_shared_storage.go

@@ -21,7 +21,7 @@ import (
 	"net/http"
 
 	"github.com/google/uuid"
-	logging "github.com/llm-d/llm-d-router/pkg/common/observability/logging"
+	"github.com/llm-d/llm-d-router/pkg/common/observability/logging"
 )
 
 // fanoutEncoderPrimer sends concurrent encoder requests for each multimodal

pkg/sidecar/proxy/connector_mooncake.go

@@ -29,6 +29,7 @@ import (
 	"go.opentelemetry.io/otel/codes"
 	"go.opentelemetry.io/otel/trace"
 
+	"github.com/llm-d/llm-d-router/pkg/common/observability/logging"
 	"github.com/llm-d/llm-d-router/pkg/common/observability/tracing"
 	reqcommon "github.com/llm-d/llm-d-router/pkg/common/request"
 )
@@ -38,7 +39,7 @@ const mooncakeBootstrapTimeout = 5 * time.Second // set to same value as the oth
 const mooncakeDataParallelRankHeader = "X-data-parallel-rank" // to send rank id in header to prefill
 
 func (s *Server) handleMooncake(w http.ResponseWriter, r *http.Request, prefillPodHostPort string) {
-	s.logger.V(4).Info("running Mooncake protocol", "url", prefillPodHostPort)
+	s.logger.V(logging.DEBUG).Info("running Mooncake protocol", "url", prefillPodHostPort)
 
 	body, err := io.ReadAll(r.Body)
 	if err != nil {
@@ -73,7 +74,7 @@ func (s *Server) handleMooncake(w http.ResponseWriter, r *http.Request, prefillP
 	}
 
 	transferID := "xfer-" + newUUID()
-	s.logger.V(5).Info("mooncake protocol info",
+	s.logger.V(logging.TRACE).Info("mooncake protocol info",
 		"transfer_id", transferID,
 		"bootstrap_addr", bootstrapAddr,
 		"dp_rank", dpRank,
@@ -100,7 +101,11 @@ func (s *Server) handleMooncake(w http.ResponseWriter, r *http.Request, prefillP
 		return
 	}
 
-	s.logger.V(5).Info("Prefill request", "body", string(prefillBody))
+	// Guarded: stringifying the body allocates a copy per request even when
+	// TRACE is disabled.
+	if trace := s.logger.V(logging.TRACE); trace.Enabled() {
+		trace.Info("Prefill request", "body", string(prefillBody))
+	}
 
 	// Build decode request body
 	decodeData := make(map[string]any)
@@ -123,7 +128,9 @@ func (s *Server) handleMooncake(w http.ResponseWriter, r *http.Request, prefillP
 		return
 	}
 
-	s.logger.V(5).Info("Decode request", "body", string(decodeBody))
+	if trace := s.logger.V(logging.TRACE); trace.Enabled() {
+		trace.Info("Decode request", "body", string(decodeBody))
+	}
 
 	s.handleMooncakeConcurrentRequests(w, r, prefillBody, decodeBody, prefillPodHostPort, dpRank)
 }
@@ -229,7 +236,7 @@ func (s *Server) handleMooncakeConcurrentRequests(w http.ResponseWriter, r *http
 		if isHTTPError(pw.statusCode) {
 			prefillSpan.SetStatus(codes.Error, "prefill request failed")
 		}
-		s.logger.V(5).Info("mooncake prefill request completed", "status", pw.statusCode)
+		s.logger.V(logging.TRACE).Info("mooncake prefill request completed", "status", pw.statusCode)
 	}()
 
 	// Decode Stage

pkg/sidecar/proxy/connector_nixlv2.go

@@ -32,6 +32,7 @@ import (
 	"go.opentelemetry.io/otel/codes"
 	"go.opentelemetry.io/otel/trace"
 
+	"github.com/llm-d/llm-d-router/pkg/common/observability/logging"
 	"github.com/llm-d/llm-d-router/pkg/common/observability/tracing"
 )
 
@@ -53,7 +54,7 @@ func tokenLimitMap(req map[string]any, apiType APIType) (map[string]any, bool) {
 
 func (s *Server) handleNIXLV2(w http.ResponseWriter, r *http.Request, prefillPodHostPort, kvCacheSource string, apiType APIType) {
 	tokenLimitFields := tokenLimitFieldsForAPIType(apiType)
-	s.logger.V(4).Info("running NIXL protocol V2", "url", prefillPodHostPort, "tokenLimitFields", tokenLimitFields)
+	s.logger.V(logging.DEBUG).Info("running NIXL protocol V2", "url", prefillPodHostPort, "tokenLimitFields", tokenLimitFields)
 
 	original, completionRequest, ok := s.readJSONBody(r, w)
 	if !ok {
@@ -198,8 +199,12 @@ func (s *Server) handleNIXLV2(w http.ResponseWriter, r *http.Request, prefillPod
 	}
 
 	// 2. Forward request to prefiller
-	s.logger.V(4).Info("sending prefill request", "to", prefillPodHostPort)
-	s.logger.V(5).Info("Prefill request", "body", string(pbody))
+	s.logger.V(logging.DEBUG).Info("sending prefill request", "to", prefillPodHostPort)
+	// Guarded: stringifying the body allocates a copy per request even when
+	// TRACE is disabled.
+	if trace := s.logger.V(logging.TRACE); trace.Enabled() {
+		trace.Info("Prefill request", "body", string(pbody))
+	}
 
 	// Retry on transient 5xx (502/503/504): these failures (e.g. connection
 	// reset → 502) are common when the prefill pod's accept queue overflows
@@ -284,7 +289,7 @@ retryLoop:
 		pCachedTokens = 0
 	}
 
-	s.logger.V(5).Info("received prefiller response", requestFieldKVTransferParams, pKVTransferParams)
+	s.logger.V(logging.TRACE).Info("received prefiller response", requestFieldKVTransferParams, pKVTransferParams)
 
 	// Decode Stage
 
@@ -416,13 +421,15 @@ retryLoop:
 
 	// 2. Forward to local decoder.
 
-	s.logger.V(5).Info("sending request to decoder", "body", string(dbody))
+	if trace := s.logger.V(logging.TRACE); trace.Enabled() {
+		trace.Info("sending request to decoder", "body", string(dbody))
+	}
 	decodeWriter, finalizeDecodeWriter := newCachedTokensResponseWriterWithFinalize(w, pCachedTokens)
 	dataParallelUsed := s.forwardDataParallel && s.dataParallelHandler(decodeWriter, dreq)
 	decodeSpan.SetAttributes(attribute.Bool("llm_d.pd_proxy.decode.data_parallel", dataParallelUsed))
 
 	if !dataParallelUsed {
-		s.logger.V(4).Info("sending request to decoder", "to", s.config.DecoderURL.Host)
+		s.logger.V(logging.DEBUG).Info("sending request to decoder", "to", s.config.DecoderURL.Host)
 		decodeSpan.SetAttributes(attribute.String("llm_d.pd_proxy.decode.target", s.config.DecoderURL.Host))
 		s.dispatchDecode(decodeWriter, dreq, completionRequest)
 	}
@@ -469,7 +476,7 @@ func (s *Server) runNIXLProtocolV2WriteParallel(
 	w http.ResponseWriter, r *http.Request, original []byte,
 	completionRequest map[string]any, uuidStr, transferID, prefillPodHostPort, kvCacheSource string,
 ) {
-	s.logger.V(4).Info("running NIXL protocol V2 (concurrent dispatch)",
+	s.logger.V(logging.DEBUG).Info("running NIXL protocol V2 (concurrent dispatch)",
 		"url", prefillPodHostPort, "request_id", uuidStr)
 
 	tracer := tracing.Tracer()
@@ -664,8 +671,10 @@ func (s *Server) runNIXLProtocolV2WriteParallel(
 	dreq.Body = io.NopCloser(bytes.NewReader(dbody))
 	dreq.ContentLength = int64(len(dbody))
 
-	s.logger.V(5).Info("concurrent-dispatch prefill request body", "body", string(pbody))
-	s.logger.V(5).Info("concurrent-dispatch decode request body", "body", string(dbody))
+	if trace := s.logger.V(logging.TRACE); trace.Enabled() {
+		trace.Info("concurrent-dispatch prefill request body", "body", string(pbody))
+		trace.Info("concurrent-dispatch decode request body", "body", string(dbody))
+	}
 
 	// Decode writes into a deferred writer that buffers everything until we
 	// commit() (prefill succeeded -> flush + stream on) or abort() (prefill

pkg/sidecar/proxy/connector_p2p.go

@@ -33,7 +33,7 @@ import (
 	"go.opentelemetry.io/otel/codes"
 	"go.opentelemetry.io/otel/trace"
 
-	logging "github.com/llm-d/llm-d-router/pkg/common/observability/logging"
+	"github.com/llm-d/llm-d-router/pkg/common/observability/logging"
 	"github.com/llm-d/llm-d-router/pkg/common/observability/tracing"
 	reqcommon "github.com/llm-d/llm-d-router/pkg/common/request"
 )