Skip to content

Commit 0ea1f2b

Browse files
committed
feat(epp): add OpenTelemetry spans for the scheduler scoring path
Wrap the scorer chain in a parent llm_d.epp.scoring span and each scorer invocation in an llm_d.epp.scorer.<type> child span, so a request trace shows which scorers ran, how long they took, and aggregate score signals. Span attributes are request- and chain-level only (scorer type/name/weight, candidate count, score max/avg); no per-endpoint keys are emitted, keeping span cardinality bounded. Spans are no-ops when tracing is uninitialized. Signed-off-by: Matt Van Horn <mvanhorn@gmail.com>
1 parent bcbca9a commit 0ea1f2b

2 files changed

Lines changed: 318 additions & 3 deletions

File tree

pkg/epp/scheduling/scheduler_profile.go

Lines changed: 95 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -22,15 +22,26 @@ import (
2222
"strings"
2323
"time"
2424

25+
"go.opentelemetry.io/otel/attribute"
26+
"go.opentelemetry.io/otel/trace"
2527
"sigs.k8s.io/controller-runtime/pkg/log"
2628

2729
errcommon "github.com/llm-d/llm-d-router/pkg/common/error"
2830
logutil "github.com/llm-d/llm-d-router/pkg/common/observability/logging"
31+
"github.com/llm-d/llm-d-router/pkg/common/observability/tracing"
2932
"github.com/llm-d/llm-d-router/pkg/epp/framework/interface/plugin"
3033
fwksched "github.com/llm-d/llm-d-router/pkg/epp/framework/interface/scheduling"
3134
"github.com/llm-d/llm-d-router/pkg/epp/metrics"
3235
)
3336

37+
// tracerScope is the OTel instrumentation scope for scheduler-level scoring
38+
// spans emitted from this package.
39+
const tracerScope = "llm-d-router/pkg/epp/scheduling"
40+
41+
// internalSpanKind is hoisted to avoid allocating a span-start option on every
42+
// scoring call.
43+
var internalSpanKind = trace.WithSpanKind(trace.SpanKindInternal)
44+
3445
// NewSchedulerProfile creates a new SchedulerProfile object and returns its pointer.
3546
func NewSchedulerProfile() *SchedulerProfile {
3647
return &SchedulerProfile{
@@ -152,6 +163,26 @@ func (p *SchedulerProfile) runScorerPlugins(ctx context.Context, request *fwksch
152163
logger := log.FromContext(ctx)
153164
logger.V(logutil.DEBUG).Info("Before running scorer plugins", "endpoints", endpoints)
154165

166+
// Parent span over the whole scorer chain. Per-scorer child spans (and any
167+
// plugin-internal spans) nest under it. Attributes are request- and
168+
// chain-level only; no per-endpoint keys, to keep span cardinality bounded.
169+
// The tracer is resolved once and threaded into runScorer so the per-scorer
170+
// spans reuse it rather than rebuilding instrumentation options per scorer.
171+
tracer := tracing.Tracer(tracerScope)
172+
ctx, span := tracer.Start(ctx, "llm_d.epp.scoring", internalSpanKind)
173+
defer span.End()
174+
// On the default (tracing-disabled) path Start returns a non-recording span;
175+
// skip all attribute and child-span construction so the scoring hot path
176+
// stays allocation-free, matching the rest of this package.
177+
tracingActive := span.IsRecording()
178+
if tracingActive {
179+
span.SetAttributes(
180+
attribute.Int("llm_d.epp.scorer.count", len(p.scorers)),
181+
attribute.Int("llm_d.epp.scoring.candidate_endpoints", len(endpoints)),
182+
)
183+
setRequestSpanAttributes(span, request)
184+
}
185+
155186
weightedScorePerEndpoint := make(map[fwksched.Endpoint]float64, len(endpoints))
156187
for _, endpoint := range endpoints {
157188
weightedScorePerEndpoint[endpoint] = float64(0) // initialize weighted score per endpoint with 0 value
@@ -168,9 +199,7 @@ func (p *SchedulerProfile) runScorerPlugins(ctx context.Context, request *fwksch
168199
// Iterate through each scorer in the chain and accumulate the weighted scores.
169200
for _, scorer := range p.scorers {
170201
logger.V(logutil.VERBOSE).Info("Running scorer plugin", "plugin", scorer.TypedName())
171-
before := time.Now()
172-
scores := scorer.Score(ctx, request, endpoints)
173-
metrics.RecordPluginProcessingLatency(scorerExtensionPoint, scorer.TypedName().Type, scorer.TypedName().Name, time.Since(before))
202+
scores := runScorer(ctx, tracer, tracingActive, scorer, request, endpoints)
174203
for endpoint, score := range scores { // weight is relative to the sum of weights
175204
if debugEnabled {
176205
debug.Info("Calculated score", "plugin", scorer.TypedName(), "endpoint", endpoint.GetMetadata().NamespacedName, "score", score)
@@ -184,6 +213,69 @@ func (p *SchedulerProfile) runScorerPlugins(ctx context.Context, request *fwksch
184213
return weightedScorePerEndpoint
185214
}
186215

216+
// runScorer invokes a single weighted scorer and records its latency metric.
217+
// When tracing is active it wraps the call in an llm_d.epp.scorer.<type> span
218+
// annotated with the scorer's identity, weight, candidate count, and aggregate
219+
// score signals; aggregates are derived from the returned score map only, with
220+
// no per-endpoint attribute keys, to keep span cardinality bounded. When
221+
// tracing is inactive no span or attribute work is performed.
222+
func runScorer(ctx context.Context, tracer trace.Tracer, tracingActive bool, scorer *WeightedScorer, request *fwksched.InferenceRequest, endpoints []fwksched.Endpoint) map[fwksched.Endpoint]float64 {
223+
typedName := scorer.TypedName()
224+
225+
if !tracingActive {
226+
before := time.Now()
227+
scores := scorer.Score(ctx, request, endpoints)
228+
metrics.RecordPluginProcessingLatency(scorerExtensionPoint, typedName.Type, typedName.Name, time.Since(before))
229+
return scores
230+
}
231+
232+
ctx, span := tracer.Start(ctx, "llm_d.epp.scorer."+typedName.Type, internalSpanKind)
233+
defer span.End()
234+
span.SetAttributes(
235+
attribute.String("llm_d.epp.scorer.type", typedName.Type),
236+
attribute.String("llm_d.epp.scorer.name", typedName.Name),
237+
attribute.Float64("llm_d.epp.scorer.weight", scorer.Weight()),
238+
attribute.Int("llm_d.epp.scorer.candidate_endpoints", len(endpoints)),
239+
)
240+
241+
before := time.Now()
242+
scores := scorer.Score(ctx, request, endpoints)
243+
metrics.RecordPluginProcessingLatency(scorerExtensionPoint, typedName.Type, typedName.Name, time.Since(before))
244+
245+
if len(scores) > 0 {
246+
var maxScore, totalScore float64
247+
first := true
248+
for _, s := range scores {
249+
if first || s > maxScore {
250+
maxScore = s
251+
}
252+
first = false
253+
totalScore += s
254+
}
255+
span.SetAttributes(
256+
attribute.Float64("llm_d.epp.scorer.score.max", maxScore),
257+
attribute.Float64("llm_d.epp.scorer.score.avg", totalScore/float64(len(scores))),
258+
attribute.Int("llm_d.epp.scorer.endpoints_scored", len(scores)),
259+
)
260+
}
261+
262+
return scores
263+
}
264+
265+
// setRequestSpanAttributes mirrors the request-identity attribute schema used
266+
// by the scorer plugins so scheduler-level spans correlate with the same trace.
267+
func setRequestSpanAttributes(span trace.Span, request *fwksched.InferenceRequest) {
268+
if request == nil {
269+
return
270+
}
271+
if request.TargetModel != "" {
272+
span.SetAttributes(attribute.String("gen_ai.request.model", request.TargetModel))
273+
}
274+
if request.RequestID != "" {
275+
span.SetAttributes(attribute.String("gen_ai.request.id", request.RequestID))
276+
}
277+
}
278+
187279
func (p *SchedulerProfile) runPickerPlugin(ctx context.Context, weightedScorePerEndpoint map[fwksched.Endpoint]float64) *fwksched.ProfileRunResult {
188280
logger := log.FromContext(ctx)
189281

pkg/epp/scheduling/scheduler_profile_test.go

Lines changed: 223 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -23,6 +23,10 @@ import (
2323

2424
"github.com/google/go-cmp/cmp"
2525
"github.com/google/uuid"
26+
"go.opentelemetry.io/otel"
27+
sdktrace "go.opentelemetry.io/otel/sdk/trace"
28+
"go.opentelemetry.io/otel/sdk/trace/tracetest"
29+
tracenoop "go.opentelemetry.io/otel/trace/noop"
2630
k8stypes "k8s.io/apimachinery/pkg/types"
2731

2832
fwkdl "github.com/llm-d/llm-d-router/pkg/epp/framework/interface/datalayer"
@@ -603,6 +607,225 @@ func (p *filterOnlyPlugin) Filter(_ context.Context, _ *fwksched.InferenceReques
603607
return endpoints
604608
}
605609

610+
// fixedScoresScorer returns a caller-supplied score per endpoint name, letting
611+
// tests assert aggregate span attributes (max/avg) over a non-uniform map.
612+
type fixedScoresScorer struct {
613+
typedName fwkplugin.TypedName
614+
scores map[string]float64
615+
}
616+
617+
func (s *fixedScoresScorer) TypedName() fwkplugin.TypedName { return s.typedName }
618+
619+
func (s *fixedScoresScorer) Category() fwksched.ScorerCategory { return fwksched.Distribution }
620+
621+
func (s *fixedScoresScorer) Score(_ context.Context, _ *fwksched.InferenceRequest, endpoints []fwksched.Endpoint) map[fwksched.Endpoint]float64 {
622+
// A nil score table models a scorer that declines to score any endpoint,
623+
// exercising the empty-map aggregate guard in runScorer.
624+
if s.scores == nil {
625+
return map[fwksched.Endpoint]float64{}
626+
}
627+
out := make(map[fwksched.Endpoint]float64, len(endpoints))
628+
for _, e := range endpoints {
629+
out[e] = s.scores[e.GetMetadata().NamespacedName.Name]
630+
}
631+
return out
632+
}
633+
634+
// installSpanRecorder routes spans to an in-memory recorder for the duration of
635+
// the test and restores an explicit no-op provider afterward. Restoring the
636+
// no-op provider (rather than the global proxy returned by GetTracerProvider)
637+
// ensures later tests do not inherit this test's recording SDK provider.
638+
func installSpanRecorder(t *testing.T) *tracetest.SpanRecorder {
639+
t.Helper()
640+
recorder := tracetest.NewSpanRecorder()
641+
tp := sdktrace.NewTracerProvider(sdktrace.WithSpanProcessor(recorder))
642+
otel.SetTracerProvider(tp)
643+
t.Cleanup(func() { otel.SetTracerProvider(tracenoop.NewTracerProvider()) })
644+
return recorder
645+
}
646+
647+
// findSpan returns the first recorded span with the given name, or nil.
648+
func findSpan(spans tracetest.SpanStubs, name string) *tracetest.SpanStub {
649+
for i := range spans {
650+
if spans[i].Name == name {
651+
return &spans[i]
652+
}
653+
}
654+
return nil
655+
}
656+
657+
func spanFloat(t *testing.T, span *tracetest.SpanStub, key string) float64 {
658+
t.Helper()
659+
for _, a := range span.Attributes {
660+
if string(a.Key) == key {
661+
return a.Value.AsFloat64()
662+
}
663+
}
664+
t.Fatalf("span %q missing attribute %q", span.Name, key)
665+
return 0
666+
}
667+
668+
func spanInt(t *testing.T, span *tracetest.SpanStub, key string) int64 {
669+
t.Helper()
670+
for _, a := range span.Attributes {
671+
if string(a.Key) == key {
672+
return a.Value.AsInt64()
673+
}
674+
}
675+
t.Fatalf("span %q missing attribute %q", span.Name, key)
676+
return 0
677+
}
678+
679+
func spanHasAttr(span *tracetest.SpanStub, key string) bool {
680+
for _, a := range span.Attributes {
681+
if string(a.Key) == key {
682+
return true
683+
}
684+
}
685+
return false
686+
}
687+
688+
// TestRunScorerPluginsTracing verifies the scheduler scoring path emits a parent
689+
// llm_d.epp.scoring span with one llm_d.epp.scorer.<type> child per scorer,
690+
// carrying the documented identity, weight, candidate-count, and aggregate
691+
// score attributes, and no per-endpoint attribute keys.
692+
func TestRunScorerPluginsTracing(t *testing.T) {
693+
recorder := installSpanRecorder(t)
694+
695+
scorerA := &fixedScoresScorer{
696+
typedName: fwkplugin.TypedName{Type: "scorer-a", Name: "a"},
697+
scores: map[string]float64{"pod1": 0.2, "pod2": 0.8},
698+
}
699+
scorerB := &fixedScoresScorer{
700+
typedName: fwkplugin.TypedName{Type: "scorer-b", Name: "b"},
701+
scores: map[string]float64{"pod1": 0.5, "pod2": 0.5},
702+
}
703+
picker := &testPlugin{TypeRes: "picker", PickRes: k8stypes.NamespacedName{Name: "pod1"}}
704+
705+
profile := NewSchedulerProfile().
706+
WithScorers(NewWeightedScorer(scorerA, 0.25), NewWeightedScorer(scorerB, 0.75)).
707+
WithPicker(picker)
708+
709+
input := []fwksched.Endpoint{
710+
fwksched.NewEndpoint(&fwkdl.EndpointMetadata{NamespacedName: k8stypes.NamespacedName{Name: "pod1"}}, nil, nil),
711+
fwksched.NewEndpoint(&fwkdl.EndpointMetadata{NamespacedName: k8stypes.NamespacedName{Name: "pod2"}}, nil, nil),
712+
}
713+
request := &fwksched.InferenceRequest{TargetModel: "test-model", RequestID: "req-123"}
714+
715+
if _, err := profile.Run(context.Background(), request, input); err != nil {
716+
t.Fatalf("unexpected error: %v", err)
717+
}
718+
719+
spans := tracetest.SpanStubsFromReadOnlySpans(recorder.Ended())
720+
parent := findSpan(spans, "llm_d.epp.scoring")
721+
if parent == nil {
722+
t.Fatalf("missing parent span llm_d.epp.scoring; got %d spans", len(spans))
723+
}
724+
if got := spanInt(t, parent, "llm_d.epp.scorer.count"); got != 2 {
725+
t.Errorf("parent llm_d.epp.scorer.count = %d, want 2", got)
726+
}
727+
if got := spanInt(t, parent, "llm_d.epp.scoring.candidate_endpoints"); got != 2 {
728+
t.Errorf("parent candidate_endpoints = %d, want 2", got)
729+
}
730+
731+
childA := findSpan(spans, "llm_d.epp.scorer.scorer-a")
732+
childB := findSpan(spans, "llm_d.epp.scorer.scorer-b")
733+
if childA == nil || childB == nil {
734+
t.Fatalf("missing per-scorer child spans (a=%v b=%v)", childA != nil, childB != nil)
735+
}
736+
737+
// Both children must nest under the parent scoring span.
738+
if childA.Parent.SpanID() != parent.SpanContext.SpanID() {
739+
t.Errorf("scorer-a span is not a child of the scoring span")
740+
}
741+
742+
if got := spanFloat(t, childA, "llm_d.epp.scorer.weight"); got != 0.25 {
743+
t.Errorf("scorer-a weight = %v, want 0.25", got)
744+
}
745+
if got := spanInt(t, childA, "llm_d.epp.scorer.candidate_endpoints"); got != 2 {
746+
t.Errorf("scorer-a candidate_endpoints = %d, want 2", got)
747+
}
748+
// scorer-a scores {0.2, 0.8}: max 0.8, avg 0.5.
749+
if got := spanFloat(t, childA, "llm_d.epp.scorer.score.max"); got != 0.8 {
750+
t.Errorf("scorer-a score.max = %v, want 0.8", got)
751+
}
752+
if got := spanFloat(t, childA, "llm_d.epp.scorer.score.avg"); got != 0.5 {
753+
t.Errorf("scorer-a score.avg = %v, want 0.5", got)
754+
}
755+
if got := spanInt(t, childA, "llm_d.epp.scorer.endpoints_scored"); got != 2 {
756+
t.Errorf("scorer-a endpoints_scored = %d, want 2", got)
757+
}
758+
759+
// Cardinality guard: no per-pod/per-endpoint identifier attribute keys.
760+
for _, span := range []*tracetest.SpanStub{parent, childA, childB} {
761+
for _, a := range span.Attributes {
762+
key := string(a.Key)
763+
if strings.Contains(key, "pod") || strings.Contains(key, "endpoint.") || strings.Contains(key, "namespacedname") {
764+
t.Errorf("span %q carries per-endpoint attribute key %q", span.Name, key)
765+
}
766+
}
767+
}
768+
}
769+
770+
// TestRunScorerPluginsTracingDisabled verifies scoring works and records no
771+
// spans when the global provider is the default no-op, and that an empty
772+
// candidate set still emits the parent span without dividing by zero.
773+
func TestRunScorerPluginsTracingDisabled(t *testing.T) {
774+
// Explicitly install a no-op provider so this test exercises the
775+
// tracing-disabled path regardless of provider state left by other tests.
776+
otel.SetTracerProvider(tracenoop.NewTracerProvider())
777+
t.Cleanup(func() { otel.SetTracerProvider(tracenoop.NewTracerProvider()) })
778+
779+
scorer := &testPlugin{TypeRes: "noop", ScoreRes: 0.5}
780+
picker := &testPlugin{TypeRes: "picker", PickRes: k8stypes.NamespacedName{Name: "pod1"}}
781+
782+
profile := NewSchedulerProfile().
783+
WithScorers(NewWeightedScorer(scorer, 1)).
784+
WithPicker(picker)
785+
786+
input := []fwksched.Endpoint{
787+
fwksched.NewEndpoint(&fwkdl.EndpointMetadata{NamespacedName: k8stypes.NamespacedName{Name: "pod1"}}, nil, nil),
788+
}
789+
request := &fwksched.InferenceRequest{TargetModel: "test-model", RequestID: uuid.NewString()}
790+
791+
if _, err := profile.Run(context.Background(), request, input); err != nil {
792+
t.Fatalf("unexpected error with no-op tracer: %v", err)
793+
}
794+
if scorer.ScoreCallCount != 1 {
795+
t.Errorf("scorer called %d times, want 1", scorer.ScoreCallCount)
796+
}
797+
}
798+
799+
// TestRunScorerEmptyCandidateAvg verifies a scorer that returns an empty score
800+
// map does not trigger a divide-by-zero when computing the average attribute.
801+
func TestRunScorerEmptyCandidateAvg(t *testing.T) {
802+
recorder := installSpanRecorder(t)
803+
804+
empty := &fixedScoresScorer{typedName: fwkplugin.TypedName{Type: "empty", Name: "e"}}
805+
picker := &testPlugin{TypeRes: "picker", PickRes: k8stypes.NamespacedName{Name: "pod1"}}
806+
profile := NewSchedulerProfile().
807+
WithScorers(NewWeightedScorer(empty, 1)).
808+
WithPicker(picker)
809+
810+
input := []fwksched.Endpoint{
811+
fwksched.NewEndpoint(&fwkdl.EndpointMetadata{NamespacedName: k8stypes.NamespacedName{Name: "pod1"}}, nil, nil),
812+
}
813+
request := &fwksched.InferenceRequest{TargetModel: "test-model", RequestID: "req-1"}
814+
815+
if _, err := profile.Run(context.Background(), request, input); err != nil {
816+
t.Fatalf("unexpected error: %v", err)
817+
}
818+
819+
child := findSpan(tracetest.SpanStubsFromReadOnlySpans(recorder.Ended()), "llm_d.epp.scorer.empty")
820+
if child == nil {
821+
t.Fatal("missing scorer span for empty scorer")
822+
}
823+
// With no scored endpoints, aggregate attributes are omitted entirely.
824+
if spanHasAttr(child, "llm_d.epp.scorer.score.avg") {
825+
t.Error("empty scorer span should not carry a score.avg attribute")
826+
}
827+
}
828+
606829
func findEndpoints(endpoints []fwksched.Endpoint, names ...k8stypes.NamespacedName) []fwksched.Endpoint {
607830
res := []fwksched.Endpoint{}
608831
for _, endpoint := range endpoints {

0 commit comments

Comments
 (0)