feat(coordinator): expose Prometheus metrics - #2435
Conversation
First slice of coordinator telemetry (part of llm-d#2276, spec in llm-d#2277): a new pkg/coordinator/metrics package under the llm_d_coordinator subsystem, a Prometheus /metrics endpoint on its own configurable port, and the request family recorded at the HTTP boundary. Later commits add the step, upstream, and execution-path metrics. The model_name label is capped at 1000 distinct values with an "other" overflow, matching EPP's cardinality guard. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
Wires the second slice of coordinator telemetry: the pipeline executor brackets every step with in-flight and duration observations, classifies step failures the same way the request handler classifies request errors, and each outbound call site emits an upstream_request_total / upstream_request_duration_seconds pair. Fan-out sites (encode per multimodal entry, replace-media-urls per URL) contribute one observation per call so the counter reflects real backend load, not just step count. ErrPipelineDone (conditional-decode cache hit) stays a clean early exit and is deliberately not counted as a step failure. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
…input tokens Closes out the metrics-doc surface (llm-d#2276, spec in llm-d#2277) with the three per-request outcome metrics: execution_path_total classifies the set of disaggregation phases that actually ran (decode-only / prefill-decode / encode-prefill-decode), conditional_decode_probes_total records how the worker answered each probe (served vs deferred on HTTP 412), and request_input_tokens observes the render-derived prompt token count. All three are recorded from the pipeline executor's defer path so pipelines that abort before decode do not spuriously emit outcomes. execution_path_total replaces the doc's original disagg_decision_total: the coordinator does not decide, it observes which path ran. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
The handler initialized `model` to `ModelUnknown` so pre-parse failures had a metric label to emit, then copied that same variable into `reqCtx.Model`. When the client body carried no `model` field (or an empty/non-string one), prefill and encode serialized `"model": "unknown"` into the upstream POST, changing what backends receive versus the prior empty-string behavior. Metric-label normalization already lives in the metrics package: every emitter in record.go routes through boundModel(), which maps "" to ModelUnknown. Initialize the handler variable as an empty string and let the metrics layer handle the sentinel, so reqCtx.Model carries only what the client actually sent. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
The Inc/Dec pair around step.Execute was not deferred, so a panic in a step skipped the Dec and left the gauge stuck above zero. chi's Recoverer at the server edge turned the panic into a 500, so nothing crashed and no one noticed, but the "steps in flight" gauge only grew. Wrap the call in a small closure and defer the Dec, so the gauge is balanced whether the step returns, errors, or panics. The panic still propagates to chi's Recoverer as before. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
When either server returned an error, run() exited without shutting down the other one. main() then called os.Exit(1), cutting off any in-flight requests or scrapes. Switch run() to errgroup.WithContext, matching cmd/epp/runner. Each goroutine drains its own server on gctx.Done(); g.Wait() waits for both. Signal, inference error, and metrics error now all produce a full graceful shutdown. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
The other steps measure how long the upstream took to start replying. Decode and conditional-decode were instead measuring the whole call, including sending the full reply back to the client. For streaming chat completions that is the entire token-generation time, so one metric was mixing two very different things: comparing p99 across upstream labels made no sense, and any decode alert fired every time a client asked for a long completion. Wrap the transport in a small timedRoundTripper. RoundTrip returns when headers arrive (or on transport error), which is what the other steps already measure via gwClient.Post. The histogram is comparable across upstreams again. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
request_running was incremented only after JSON parse, so slow body reads, 413 rejections, and malformed-JSON rejections never touched the gauge. Its help text says "Requests currently being processed by the coordinator", but a slow upload could hold the coordinator busy for tens of seconds while the gauge sat at 0. Move the Inc to handler entry under the empty-string label (which boundModel maps to "unknown"), and swap the label to the parsed model name after JSON parse. The Dec in the deferred cleanup uses whatever label was last Inc'd, so every path is balanced: pre-parse errors go in and out under "unknown"; successful requests transfer to the real model label and back to zero on return. Tests cover the three cases: pre-parse observability via a blocking Body reader, 413 balance, and the label swap during pipeline execution. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
pkg/sidecar/proxy documents 0 as "disable the metrics endpoint". The coordinator instead passed 0 straight into http.Server.Addr as ":0", which the OS interprets as "bind any available port". Skip the metrics goroutine in run() when MetricsPort is non-positive and log "metrics endpoint disabled" so operators see the state at startup. Document the semantics on ServerConfig.MetricsPort and in the --metrics-port flag help so the coordinator and sidecar now agree. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
TestBoundedLabel_ConcurrentAdmissionsUnderCap called require.Equal from 500 spawned goroutines. Go's testing.T.FailNow docs are explicit that FailNow must be called only from the test goroutine, so this is undefined behavior. Have each goroutine write its result at its own index of a pre-allocated slice, then assert on the test goroutine after wg.Wait. Same 500-way concurrency stress on bound(), no require inside a goroutine. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
classifyStepErrorCode in pipeline.go and classifyErrorCode in handlers.go were the same function. Both mapped pipeline errors to the error_code label used by step_errors_total and request_error_total. Move the classification into coordmetrics.ClassifyErrorCode. The metrics package cannot import pipeline without inverting the dependency direction, so the caller passes a ClassifyOptions with its BadRequest sentinel and an IsUpstream func. Both pipeline and handlers now define a package-level classifyOpts once and call the shared classifier. A new bucket is a one-line edit in metrics; both families pick it up. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
Four step call sites wrapped every outbound call in the same triplet: IncUpstreamRequestTotal, callStart := time.Now(), RecordUpstreamRequestDuration. Any future change to how the coordinator times a single upstream call had to land in all four places in lockstep. Introduce coordmetrics.StartUpstreamCall / (UpstreamCall).Done, one type plus two methods that own the triplet. Each site becomes two lines around the actual call. Done is called explicitly (not deferred) so the histogram still observes only the upstream call itself, not later body decoding — same semantic as the code it replaces. decode.go and conditional_decode.go keep the timedRoundTripper pattern: they measure at RoundTrip return via a transport wrapper, which is a distinct mechanism from the inline-time triplet and is documented as such in decode_proxy.go. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
…ithLabel
Three metric declarations composed their label list as
append([]string{}, append(baseLabel, "extra")...). The outer copy was
dead work for today's shape (base labels are len==cap==1 slice
literals, so the inner append already allocates a fresh backing array)
but read as intentional defense against aliasing that a reader had to
mentally verify. And it would silently become undefensive if a base
label were later declared with extra capacity.
Introduce a small withLabel helper alongside the base label slices. It
allocates a fresh backing array unconditionally and reads at the call
site as "base + extra label" instead of nested-append incantation.
Correct regardless of the base slice's capacity, so future changes to
modelLabel/stepLabel/upstreamLabel cannot reintroduce aliasing.
Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
Define a resettableCollector interface (prometheus.Collector + Reset) and change allCollectors() to return it. Reset() now calls c.Reset() directly. Any future collector without Reset fails at compile time, naming the exact offending entry, instead of being silently skipped. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
mustGauge already had the number it needed (a float64 from the gathered DTO), but it built an additional prometheus.Gauge, called Set to store the number in it, and returned the gauge. Callers then used promtestutil.ToFloat64 to unwrap it and get the same number back out. The fake gauge was doing no real work. mustGauge() returns the float64 directly - not using additional gauge. The two callers drop the promtestutil.ToFloat64 wrap and pass the value to require.InDelta as is. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
Docstring is re-written to name the real exit conditions (ctx, ListenAndServe) and note the Shutdown/metricsShutdownTimeout path. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
When a step panicked, only step_running was decremented. Nothing was observed on step_duration_seconds and step_errors_total was not incremented, even though the client saw a 500 from chi Recoverer. The per-step defer now records the duration, updates timings, and on recover() increments step_errors_total with error_code=internal before re-panicking so chi Recoverer still answers 500. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
A pipeline panic slipped past the error counter. The top-level defer in handleInference kept counting request_total and request_duration, but IncRequestErrorTotal sat below in the err-branch and never fired. The client got a 500 from chi Recoverer, and error-rate dashboards saw the 500 as a success. The defer now recovers first: on a non-nil recover it increments request_error_total with error_code=internal, does the total, duration, and running-gauge accounting, then re-panics so chi Recoverer still answers 500. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
result=served covered every non-412 response, so 4xx and 5xx from the worker counted as hits. Add a third label, error, and branch on status: 412 goes to deferred, other 4xx/5xx to error, 2xx/3xx to served. Response streaming to the client is unchanged. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
decode and conditional-decode forward a worker 4xx/5xx or transport failure to the client but returned nil, so request_error_total stayed at zero. Add UpstreamStreamedError. Both steps return it on failure; the handler counts it and skips http.Error so the streamed body survives. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
Every other value on the ladder doubles cleanly (2^k); 32778 was a digit-swap of 2^15. Fix the value and drop the "matches EPP" claim from the comment: EPP has the same typo and the coordinator now diverges to the correct ladder. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
Three comments in handlers_test.go and metrics_test.go referenced "pre-fix / Post-fix" or "used to guard against". Rewrite each to describe the invariant on its own terms. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
The docstring claimed time.Since on a zero start records a negative duration. It actually returns a very large positive duration. Fixed. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
handlers.go and pipeline.go each declared their own classifyOpts with the same body. Export the pipeline var as pipeline.ClassifyOpts and consume it from handlers so error classification lives in one place. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
The max parameter and struct field in boundedLabel shadowed the Go 1.21+ builtin. Rename both to limit. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
roytman
left a comment
There was a problem hiding this comment.
Thank you, @dmitripikus. I'm still working on the review, but I have 2 initial comments.
| ListenAddr string `mapstructure:"listen_addr"` | ||
| ListenAddr string `mapstructure:"listen_addr"` | ||
| // MetricsPort is the port for the Prometheus /metrics endpoint. A | ||
| // non-positive value disables the endpoint, matching pkg/sidecar/proxy |
There was a problem hiding this comment.
we have some inconsistency here (can be resolved in a separate PR)
- pkg/sidecar/proxy:
MetricsPort > 0→ enabled; 0 (default) or unset → disabled, falls back to MORIIO_METRICS_ADDR env var. Documented in the flag help text and README. - pkg/coordinator (this PR): same rule, explicitly copied: cfg.MetricsPort > 0 starts the goroutine, non-positive logs "metrics endpoint disabled" and skips it. Its own comment states it's "matching pkg/sidecar/proxy semantics."
- cmd/epp/runner: No disable path at all. serveMetrics is unconditionally wired into the run group; --metrics-port defaults to 9090 and has no "0 disables" semantics in its flag help, its Options.Validate(), or the server code. Setting --metrics-port=0 binds ":0" (OS picks a random ephemeral port) rather than disabling anything; a negative value would fail ListenAndServe and — since EPP's run-group cancels all tasks when one fails — take down the whole process.
There was a problem hiding this comment.
For now I replaced wrong statement "matching pkg/sidecar/proxy semantics": coordinator matches the > 0 gate but not the MORIIO_METRICS_ADDR env-var fallback. Now the comment states the rule directly.
The broader inconsistency with cmd/epp/runner (no disable gate; --metrics-port=0 binds a random ephemeral port, negative crashes the whole errgroup) is a real bug worth its own issue + PR. I have not filed either yet — I'll open the issue if you agree with the semantics, i.e. align EPP with coordinator: <= 0 disables, log "metrics endpoint disabled", update --metrics-port help text; leave sidecar's env-var fallback alone as legacy.
| var ( | ||
|
|
||
| // generalLatencyBuckets covers durations from 5ms to 1 hour; identical to | ||
| // the EPP request-duration ladder so PromQL translates cleanly between the |
There was a problem hiding this comment.
yes, it is identical to pkg/epp/metrics/metrics.go:60-64
| 1800, 2700, 3600, | ||
| } | ||
|
|
||
| // requestSizeBuckets ranges from 64 bytes to 1 GiB, matching the EPP |
There was a problem hiding this comment.
identical to pkg/epp/metrics/llm_d_router_metrics.go:73-77
| 16777216, 33554432, 67108864, 134217728, 268435456, 536870912, 1073741824, | ||
| } | ||
|
|
||
| // inputTokensBuckets is a power-of-two ladder from 1 to 1M input tokens; |
There was a problem hiding this comment.
Almost identical to EPP, fixes the typo 32778→32768
| // present on reg is treated as success, so calling Register more than once | ||
| // (e.g. across tests using a fresh prometheus.NewRegistry() each time) is | ||
| // safe. | ||
| func Register(reg prometheus.Registerer) error { |
There was a problem hiding this comment.
Register/Reset: are not a duplicate of EPP's Register/Reset - actually structurally here is better. EPP hand-repeats its ~60-metric list once in Register and again in Reset (llm_d_router_metrics.go:424-503, 506-578), and its label composition uses raw append(modelLabels, "error_code") with no aliasing guard - exactly the hazard withLabel was built to prevent.
The coordinator's single allCollectors() list feeding both functions, plus withLabel, is arguably a pattern EPP should adopt, not the reverse.
|
|
||
| // UpstreamStreamedError signals that a streaming step (decode, | ||
| // conditional-decode) saw an upstream failure after the response was already | ||
| // committed to the client. The reverse proxy either streamed a 4xx/5xx body |
There was a problem hiding this comment.
Should we mention here that we exceed the 412 error for conditional-decode
| err := step.Execute(ctx, reqCtx) | ||
| timings[idx] = stepTiming{name: step.Name(), duration: time.Since(start)} | ||
| var err error | ||
| func() { |
There was a problem hiding this comment.
The current code is correct, but the idiomatic Go fix for "I need a defer scoped to one loop iteration" is to extract a named function rather than an inline IIFE — it's the same defer-scoping trick, just without the closure-capturing-an-outer-variable smell:
func (p *Pipeline) runStep(ctx context.Context, reqCtx *RequestContext, step Step, idx int, timings []stepTiming) error {
name := step.Name()
coordmetrics.IncStepRunning(name)
start := time.Now()
defer func() {
d := time.Since(start)
coordmetrics.RecordStepDuration(name, d)
coordmetrics.DecStepRunning(name)
timings[idx] = stepTiming{name: name, duration: d}
if r := recover(); r != nil {
coordmetrics.IncStepErrorTotal(name, coordmetrics.ErrorCodeInternal)
panic(r)
}
}()
return step.Execute(ctx, reqCtx)
}and the loop becomes:
for idx, step := range p.steps {
if err := ctx.Err(); err != nil {
return fmt.Errorf("pipeline cancelled: %w", err)
}
logger.V(logutil.TRACE).Info("step starting", "step", step.Name())
if err := p.runStep(ctx, reqCtx, step, idx, timings); err != nil {
if errors.Is(err, ErrPipelineDone) {
executed[step.Name()] = true
return nil
}
coordmetrics.IncStepErrorTotal(step.Name(), coordmetrics.ClassifyErrorCode(err, ClassifyOpts))
return fmt.Errorf("step %q failed: %w", step.Name(), err)
}
executed[step.Name()] = true
logger.V(logutil.TRACE).Info("step complete", "step", step.Name())
}Why this is better, not just different:
- No outer-variable mutation through a closure. The current code does
var err error; func() { ...; err = step.Execute(...) }()— assigning into a variable declared outside the closure. A real function that just returns is the more direct idiom and is easier to read at a glance. - Independently testable.
runStepcan be unit-tested directly (call it, panic a stub step, assert the gauge/duration/error recording) without going through the whole Execute loop. - Same defer-scoping guarantee. A method's own body is exactly as valid a function boundary for defer as an anonymous IIFE — nothing is lost.
This is a pure readability refactor, not a correctness fix — the anonymous-function version in the PR is not buggy, this is just the more idiomatic shape for "defer must run once per loop iteration."
f23cc70 to
527629f
Compare
pkg/coordinator/metrics/cardinality.go was a near line-for-line reimplementation of pkg/epp/metrics/cardinality.go's boundedLabel. Both packages already imported pkg/common/observability/metrics for HelpMsgWithStability, so that package is the natural shared home. Lift the primitive there as BoundedLabel/NewBoundedLabel/Bound/Pin plus the OverflowValue constant, and reduce each caller to a package-local limiter plus thin wrappers (boundModel in coordinator; boundModel/boundModels/boundFairnessID/PreAdmitModelLabels in EPP). Coordinator's boundModel still gates empty -> ModelUnknown before consulting the primitive; EPP behavior is unchanged. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
run() had no test. Add cmd/coordinator/main_test.go with two cases:
- TestRun_MetricsDisabled_DrainsCleanlyOnCancel: with MetricsPort
set to 0, run starts only the inference server and returns nil
once the context is cancelled.
- TestRun_MetricsPortCollision_DrainsInferenceServer: with the
metrics port already bound by another listener, the metrics
server fails to start, run returns an error containing
"metrics server:", and the inference server is no longer
reachable on its port.
Both tests use the existing helpers in test/framework/net.
Move signal.NotifyContext from run into main and pass the context
into run. This lets tests cancel run without sending a signal to the
test process. Real invocation is unchanged.
Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
The MetricsPort doc comment sat between ListenAddr and the remaining fields. gofmt aligns only runs of consecutive fields, so the comment split the run and stripped ListenAddr's padding, leaving it as a modified line in the diff. Move the note to a trailing comment on MetricsPort so the six fields form one aligned run and ListenAddr keeps its original spacing. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
Call stop() explicitly after run() returns so the exit path no longer skips a deferred cleanup. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
The run() doc said MetricsPort disable semantics were "matching pkg/sidecar/proxy semantics." That overpromises: pkg/sidecar/proxy also falls back to the MORIIO_METRICS_ADDR env var when MetricsPort is non-positive, which the coordinator does not do. State the rule directly instead. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
"inference server" already refers to the vLLM backend elsewhere in this repo. Only run()'s doc comment, its three error-wrap strings, and its two tests introduced the same term for the coordinator's own HTTP server. Rename those sites to "coordinator server" so the term keeps one referent and the doc's contrast with "metrics server" reads cleanly. No behavior change. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
server.metrics_port is a ServerConfig field with a default of 9090 and its own --metrics-port CLI flag override, but config/coordinator/coordinator.yaml never listed it. Add a commented block after listen_addr describing the port, the non-positive-disables rule, the CLI flag, and the COORDINATOR_SERVER_METRICS_PORT env override, matching the yaml's existing convention for optional fields. Signed-off-by: Dmitri Pikus <DPIKUS@il.ibm.com>
What type of PR is this?
/kind feature
What this PR does / why we need it:
Adds Prometheus metrics to the coordinator. With EPP metrics alone, operators see per-leg sub-requests, not client requests, so they cannot answer request rate, latency, error mix, per-step wall time, upstream fan-out, or disaggregation path from the coordinator process itself.
Three commits map to the three families in the spec (#2277):
pkg/coordinator/metricspackage,/metricson its own port (default 9090,--metrics-port), andrequest_total/request_error_total/request_duration_seconds/request_size_bytes/request_running.step_running/step_duration_seconds/step_errors_totaland classifies failures (bad_request,upstream_4xx,upstream_5xx,internal); each outbound call site emitsupstream_request_total/upstream_request_duration_seconds.execution_path_total,conditional_decode_probes_total,request_input_tokens.Every
model_namelabel is capped at 1000 distinct values with anotheroverflow, matching EPP's cardinality guard.Deviations from the WIP doc in #2277, per review feedback that has not yet landed in the doc:
response_size_bytesdisagg_decision_totaltoexecution_path_total(the coordinator observes rather than decides).request_input_tokens(token IDs are available onRequestContext.TokenIDsafter render).Which issue(s) this PR fixes:
Part of #2276
Release note: