fix: skip TPOT recording for non-streaming requests

A non-streaming response arrives as a single body chunk, so the
first-token and completion timestamps coincide and RecordRequestTPOT's
validity check logged an error-level 'Request latency values are invalid
for TPOT calculation' line on every non-streaming request. TPOT has no
meaning without inter-token timing, so thread the existing
modelServerStreaming flag through (mirroring RecordRequestTTFT) and skip
recording silently for non-streaming responses.

Fixes #2166

Author: HipHoff

pkg/epp/handlers/response.go

@@ -90,7 +90,7 @@ func (s *StreamingServer) HandleResponseBody(ctx context.Context, reqCtx *Reques
 		metrics.RecordRequestLatencies(ctx, reqCtx.IncomingModelName, reqCtx.TargetModelName, fairnessID, priority, reqCtx.RequestReceivedTimestamp, reqCtx.ResponseCompleteTimestamp)
 		metrics.RecordResponseSizes(reqCtx.IncomingModelName, reqCtx.TargetModelName, fairnessID, priority, reqCtx.ResponseSize)
 		metrics.RecordRequestTTFT(ctx, reqCtx.IncomingModelName, reqCtx.TargetModelName, fairnessID, priority, reqCtx.modelServerStreaming, reqCtx.RequestReceivedTimestamp, reqCtx.FirstTokenTimestamp)
-		metrics.RecordRequestTPOT(ctx, reqCtx.IncomingModelName, reqCtx.TargetModelName, fairnessID, priority, reqCtx.RequestReceivedTimestamp, reqCtx.FirstTokenTimestamp, reqCtx.ResponseCompleteTimestamp, reqCtx.Usage.CompletionTokens)
+		metrics.RecordRequestTPOT(ctx, reqCtx.IncomingModelName, reqCtx.TargetModelName, fairnessID, priority, reqCtx.modelServerStreaming, reqCtx.RequestReceivedTimestamp, reqCtx.FirstTokenTimestamp, reqCtx.ResponseCompleteTimestamp, reqCtx.Usage.CompletionTokens)
 	}
 	return s.director.HandleResponseBody(ctx, reqCtx, endOfStream)
 }

pkg/epp/metrics/metrics.go

@@ -677,8 +677,16 @@ func RecordRequestTTFT(ctx context.Context, modelName, targetModelName, fairness
 	return true
 }
 
-// RecordRequestTPOT records the average time per output token.
-func RecordRequestTPOT(ctx context.Context, modelName, targetModelName, fairnessID, priority string, received time.Time, firstToken time.Time, complete time.Time, outputTokenCount int) bool {
+// RecordRequestTPOT records the average time per output token. TPOT is only
+// derivable for streaming responses: a non-streaming response arrives as a
+// single body chunk, so the first-token and completion timestamps coincide and
+// no inter-token timing exists. Such requests are skipped silently instead of
+// being logged as invalid (they would otherwise emit an error-level line per
+// request on non-streaming workloads).
+func RecordRequestTPOT(ctx context.Context, modelName, targetModelName, fairnessID, priority string, streaming bool, received time.Time, firstToken time.Time, complete time.Time, outputTokenCount int) bool {
+	if !streaming {
+		return false
+	}
 	modelName, targetModelName = boundModels(modelName, targetModelName)
 	fairnessID = boundFairnessID(fairnessID)
 	if firstToken.IsZero() || outputTokenCount <= 1 {

pkg/epp/metrics/metrics_test.go

@@ -1442,32 +1442,39 @@ func TestRecordRequestTPOT(t *testing.T) {
 		received := timeBaseline
 		firstToken := timeBaseline.Add(500 * time.Millisecond)
 		complete := timeBaseline.Add(2000 * time.Millisecond)
-		require.True(t, RecordRequestTPOT(ctx, "m10", "t10", "tenant-a", "3", received, firstToken, complete, 11))
+		require.True(t, RecordRequestTPOT(ctx, "m10", "t10", "tenant-a", "3", true, received, firstToken, complete, 11))
 
 		h, err := getHistogramVecLabelValues(t, llmdRequestTPOT, "m10", "t10", "tenant-a", "3")
 		require.NoError(t, err)
 		require.Equal(t, uint64(1), h.GetSampleCount())
 		require.InDelta(t, 0.15, h.GetSampleSum(), 0.001)
 	})
 
+	t.Run("non-streaming skipped without error log", func(t *testing.T) {
+		received := timeBaseline
+		firstToken := timeBaseline.Add(500 * time.Millisecond)
+		// Non-streaming: the whole body arrives at once, so complete == firstToken.
+		require.False(t, RecordRequestTPOT(ctx, "m10", "t10", "tenant-a", "3", false, received, firstToken, firstToken, 11))
+	})
+
 	t.Run("single token skipped", func(t *testing.T) {
-		require.False(t, RecordRequestTPOT(ctx, "m10", "t10", "tenant-a", "3", timeBaseline, timeBaseline.Add(100*time.Millisecond), timeBaseline.Add(200*time.Millisecond), 1))
+		require.False(t, RecordRequestTPOT(ctx, "m10", "t10", "tenant-a", "3", true, timeBaseline, timeBaseline.Add(100*time.Millisecond), timeBaseline.Add(200*time.Millisecond), 1))
 	})
 
 	t.Run("zero tokens skipped", func(t *testing.T) {
-		require.False(t, RecordRequestTPOT(ctx, "m10", "t10", "tenant-a", "3", timeBaseline, timeBaseline.Add(100*time.Millisecond), timeBaseline.Add(200*time.Millisecond), 0))
+		require.False(t, RecordRequestTPOT(ctx, "m10", "t10", "tenant-a", "3", true, timeBaseline, timeBaseline.Add(100*time.Millisecond), timeBaseline.Add(200*time.Millisecond), 0))
 	})
 
 	t.Run("zero first token timestamp", func(t *testing.T) {
-		require.False(t, RecordRequestTPOT(ctx, "m10", "t10", "tenant-a", "3", timeBaseline, time.Time{}, timeBaseline.Add(200*time.Millisecond), 10))
+		require.False(t, RecordRequestTPOT(ctx, "m10", "t10", "tenant-a", "3", true, timeBaseline, time.Time{}, timeBaseline.Add(200*time.Millisecond), 10))
 	})
 
 	t.Run("first token before received", func(t *testing.T) {
-		require.False(t, RecordRequestTPOT(ctx, "m10", "t10", "tenant-a", "3", timeBaseline.Add(100*time.Millisecond), timeBaseline, timeBaseline.Add(200*time.Millisecond), 10))
+		require.False(t, RecordRequestTPOT(ctx, "m10", "t10", "tenant-a", "3", true, timeBaseline.Add(100*time.Millisecond), timeBaseline, timeBaseline.Add(200*time.Millisecond), 10))
 	})
 
 	t.Run("complete before first token", func(t *testing.T) {
-		require.False(t, RecordRequestTPOT(ctx, "m10", "t10", "tenant-a", "3", timeBaseline, timeBaseline.Add(200*time.Millisecond), timeBaseline.Add(100*time.Millisecond), 10))
+		require.False(t, RecordRequestTPOT(ctx, "m10", "t10", "tenant-a", "3", true, timeBaseline, timeBaseline.Add(200*time.Millisecond), timeBaseline.Add(100*time.Millisecond), 10))
 	})
 }