CI / CI (push) Successful in 41m20s
Closes #64 Replaces the per-pod concurrency semaphore as the effective cap with admission gated on the vLLM engine's own scheduler gauges. ## Why `internal/proxy/proxy.go:119` built a semaphore of 4 slots *inside each gateway process*, and `api-gateway` runs 3 replicas, so the advertised cap was 12 while the engine's `--max-num-seqs` is 4. Nothing coordinated replicas, and the mismatch was invisible because the queue never rejected anything (`queue_full_requests_total 0`). Measured on the engine while investigating a 10-minute TTFT: - `vllm:cache_config_info{num_gpu_blocks="9527",block_size="16"}` = **152,432 tokens** of KV capacity for the whole engine. PP=2 splits layers, so both ranks hold KV for the same tokens — not 2x that. - Uncached prefill runs at **262 tok/s** contended, 525 tok/s over 7d (`vllm:request_prefill_time_seconds_sum/count`). - One request showed `llm_ttft_seconds_sum 590.981 / count 5` at the gateway and a `(480, 960]` s entry in `vllm:request_prefill_time_seconds_bucket`, with engine-side generation throughput at 0.0-0.1 tok/s throughout: a 65k-token prompt costs ~250 s of prefill and starves every other request while it runs. - `vllm:num_preemptions_total = 0`; KV peaked at `0.5399`. Reading the engine's own gauges is global by construction, needs no lock and no new datastore, and it also accounts for callers that never pass the gateway — namespace `poimen` is admitted directly on 80/8080 by `llm-serving-ingress`, and `memory/crates/mem-cli/src/kv_warmer.rs` is such a caller. A distributed lock would have been blind to that traffic. ## Changes - **new `internal/proxy/engine_state.go`** — 2s scrape of `http://<addr>/metrics` on its own client (the proxy transports carry socket options tuned for inference), hand-rolled exposition parse, `Healthy=false` after 3 consecutive failed polls with `engine_state_stale_total` counted once at the transition, and a startup self-check that raises `observer_degraded` and logs at error level instead of degrading to fail-open silently. - **admission gate** (`internal/proxy/scheduler.go`) — parks while `kv_cache_usage_perc >= 0.90` or `running + waiting >= ADMISSION_MAX_INFLIGHT`, bounded by `ADMISSION_MAX_PARK_SECONDS`, then `503 + Retry-After: 5`. Unknown or unhealthy state fails **open** on purpose: a metrics outage must not become an inference outage. - **parked streaming heartbeat** (`internal/proxy/proxy.go`) — `stream: true` requests get 200 + `text/event-stream` and a `: keep-alive` comment every 15s while parked, so a client idle timeout does not kill a request that is legitimately waiting. Non-streaming requests park silently. - **`internal/proxy/router.go`** — extract only the top-level `model` field with a `json.Decoder` token walk instead of unmarshalling the whole body into `map[string]interface{}` (that built the entire `messages`+`tools` tree per request, ~300 KB for a 65k-token prompt). `MaxBodySize` now comes from `MAX_BODY_BYTES`; the model path previously inherited the 100 MB default at `proxy.go:93` against a 512Mi container limit. - **`cmd/gateway/main.go`** — `GOMAXPROCS` from the cgroup CPU quota (cgroup v2 `cpu.max`, v1 fallback). The container is limited to `500m` while Go defaulted to the host core count and was being CFS-throttled. - **`k8s/deployment.yaml`** — `ADMISSION_MAX_PARK_SECONDS=120`, `ADMISSION_OBSERVE_MODELS=reasoning`, `VLLM_MAX_QUEUE_DEPTH=8`, `MAX_BODY_BYTES=1048576`; corrected the `llm-client` comment (the NetworkPolicy selects by namespace now, not by that label). - **deleted `k8s/configmap.yaml`** — absent from `k8s/kustomization.yaml`, and the live ConfigMap of that name carries an unrelated key (`gw-config-fixed.yaml`) plus a stale routing table. - **`internal/observability/`** — `admission_parked_total`, `admission_rejected_total{reason}`, `engine_state_stale_total`, and gauges `vllm_requests_running` / `vllm_kv_usage_perc` (the gateway's own reading, deliberately mirroring the vLLM series so a disagreement is visible) and `observer_degraded`. Names follow the existing convention, which carries no prefix. Out of scope here, in `riotpiao-poimen/homelab#51`: the engine flags (`--max-num-partial-prefills`, `--max-long-partial-prefills`, `--long-prefill-token-threshold`, `--max-num-batched-tokens`, `--max-num-seqs`, `--gpu-memory-utilization`) and the four dashboard panels in `generate-dashboards.py`. ## Verification - `go build ./...` clean, `go vet ./...` clean. - `go test ./...` — 368 tests, 0 failures (baseline on `main` is 368/0). - `structural-check.sh` on the changed files — 0 errors, 1 pre-existing warning (`:latest` image tag). - `go.mod` / `go.sum` byte-identical: no new dependency. Not yet verified: the real-engine load test (2x65k + 15x8k against `reasoning`). That run also produces the number for `ADMISSION_MAX_PARK_SECONDS`, which today is the provisional 120; retuning it is a follow-up since it is env-only and needs no rebuild. ## Accepted risks - **No tests were added** for the observer or the gate (deliberate: production is the test bed). The mitigation is the startup self-check, which is production self-diagnosis rather than a test, plus the `observer_degraded` alert. A parse failure that outlives the first poll logs and surfaces as a metric; it does not silently disable gating without a signal. - **The cap is soft, not hard.** Between polls each replica may admit more than one request, so there is no clean bound. Exposure is low (~11,500 requests over 7d ≈ 1.4/min) and the engine remains the hard limit — a race parks requests in vLLM's queue rather than over-committing KV. - **`ADMISSION_MAX_INFLIGHT` is manually coupled to `--max-num-seqs`** and can drift silently. It defaults to `VLLM_MAX_NUM_SEQS`, and startup logs the effective value. - The first scrape waits one interval, so the first ~2s of admission is ungated (fail-open). Scraping at `Start()` instead would make the gateway contact every observed backend before any request needs one, which is wasted work and a surprising side effect. ## Rollback Revert this commit and redeploy. The admission path is fail-open, so the code can also be neutralised without reverting by unsetting `ADMISSION_OBSERVE_MODELS`. Separately, the orphaned cluster object can be removed by hand: `kubectl delete cm -n api api-gateway-config` (not a code change, deliberately left to a human). --------- Reviewed-on: #65 Co-authored-by: poimen <[email protected]>
455 lines
12 KiB
Go
455 lines
12 KiB
Go
package observability
|
|
|
|
import (
|
|
"fmt"
|
|
"sync"
|
|
"time"
|
|
)
|
|
|
|
// Metrics holds all Prometheus metrics for the gateway.
|
|
type Metrics struct {
|
|
mu sync.RWMutex
|
|
|
|
// Request counters: request_total{route, upstream, status}
|
|
requestTotal map[string]int64
|
|
|
|
// Request latencies: request_duration_seconds (histogram)
|
|
// Stored as cumulative buckets for Prometheus text format
|
|
requestDuration map[string]int64 // stores duration samples in milliseconds
|
|
requestDurationBuckets map[string]map[float64]int64 // histogram buckets
|
|
|
|
// Bytes counters: gateway_bytes{direction, route, upstream}
|
|
bytesIn map[string]int64
|
|
bytesOut map[string]int64
|
|
|
|
// Upstream health: upstream_health{upstream} = 1 or 0
|
|
upstreamHealth map[string]int
|
|
|
|
// Streaming metrics
|
|
streamingResponsesTotal map[string]int64
|
|
streamingByteCount map[string]int64
|
|
|
|
// LLM inference metrics (TTFT and ITL)
|
|
// ttftMs: Time-to-First-Token in milliseconds
|
|
ttftMs map[string][]int64 // samples for histogram
|
|
// itlMs: Inter-Token Latency in milliseconds
|
|
itlMs map[string][]int64 // samples for histogram
|
|
// Token counts
|
|
tokenCount map[string]int64
|
|
|
|
// CAG metrics
|
|
warmupRequestsDelayed int64
|
|
prefixCacheHitTokens int64
|
|
queueFullRequests int64
|
|
|
|
// Admission control metrics (#64)
|
|
admissionParked int64
|
|
admissionRejected map[string]int64
|
|
engineStateStale int64
|
|
|
|
// Engine gauge readings mirrored from vLLM (#64)
|
|
vllmRequestsRunning int64
|
|
vllmKVUsagePerc float64
|
|
observerDegraded int
|
|
}
|
|
|
|
// NewMetrics creates a new Metrics instance.
|
|
func NewMetrics() *Metrics {
|
|
return &Metrics{
|
|
requestTotal: make(map[string]int64),
|
|
requestDuration: make(map[string]int64),
|
|
requestDurationBuckets: make(map[string]map[float64]int64),
|
|
bytesIn: make(map[string]int64),
|
|
bytesOut: make(map[string]int64),
|
|
upstreamHealth: make(map[string]int),
|
|
streamingResponsesTotal: make(map[string]int64),
|
|
streamingByteCount: make(map[string]int64),
|
|
ttftMs: make(map[string][]int64),
|
|
itlMs: make(map[string][]int64),
|
|
tokenCount: make(map[string]int64),
|
|
admissionRejected: make(map[string]int64),
|
|
}
|
|
}
|
|
|
|
// RecordRequest records a request with its route, upstream, status, and duration.
|
|
func (m *Metrics) RecordRequest(route, upstream string, statusCode int, duration time.Duration) {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
|
|
key := fmt.Sprintf("%s:%s:%d", route, upstream, statusCode)
|
|
m.requestTotal[key]++
|
|
|
|
// Record duration in milliseconds
|
|
durationKey := fmt.Sprintf("%s:%s", route, upstream)
|
|
m.requestDuration[durationKey] += int64(duration.Milliseconds())
|
|
|
|
// Record in histogram buckets
|
|
if _, ok := m.requestDurationBuckets[durationKey]; !ok {
|
|
m.requestDurationBuckets[durationKey] = make(map[float64]int64)
|
|
}
|
|
|
|
// Prometheus histogram buckets: .005, .01, .025, .05, .1, .25, .5, 1, 2.5, 5, 10
|
|
buckets := []float64{0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10}
|
|
durationSeconds := duration.Seconds()
|
|
|
|
for _, bucket := range buckets {
|
|
if durationSeconds <= bucket {
|
|
m.requestDurationBuckets[durationKey][bucket]++
|
|
}
|
|
}
|
|
}
|
|
|
|
// RecordBytesIn records incoming bytes.
|
|
func (m *Metrics) RecordBytesIn(route, upstream string, bytes int64) {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
|
|
key := fmt.Sprintf("%s:%s", route, upstream)
|
|
m.bytesIn[key] += bytes
|
|
}
|
|
|
|
// RecordBytesOut records outgoing bytes.
|
|
func (m *Metrics) RecordBytesOut(route, upstream string, bytes int64) {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
|
|
key := fmt.Sprintf("%s:%s", route, upstream)
|
|
m.bytesOut[key] += bytes
|
|
}
|
|
|
|
// SetUpstreamHealth sets the health status of an upstream (1 = healthy, 0 = unhealthy).
|
|
func (m *Metrics) SetUpstreamHealth(upstream string, healthy bool) {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
|
|
if healthy {
|
|
m.upstreamHealth[upstream] = 1
|
|
} else {
|
|
m.upstreamHealth[upstream] = 0
|
|
}
|
|
}
|
|
|
|
// RecordStreamingResponse records a streaming response with its total byte count and duration.
|
|
func (m *Metrics) RecordStreamingResponse(route, upstream string, totalBytes int64, duration time.Duration) {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
|
|
key := fmt.Sprintf("%s:%s", route, upstream)
|
|
m.streamingResponsesTotal[key]++
|
|
m.streamingByteCount[key] += totalBytes
|
|
|
|
// Also record as request duration
|
|
m.recordDuration(key, duration)
|
|
}
|
|
|
|
func (m *Metrics) recordDuration(key string, duration time.Duration) {
|
|
m.requestDuration[key] += int64(duration.Milliseconds())
|
|
|
|
if _, ok := m.requestDurationBuckets[key]; !ok {
|
|
m.requestDurationBuckets[key] = make(map[float64]int64)
|
|
}
|
|
|
|
buckets := []float64{0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10}
|
|
durationSeconds := duration.Seconds()
|
|
|
|
for _, bucket := range buckets {
|
|
if durationSeconds <= bucket {
|
|
m.requestDurationBuckets[key][bucket]++
|
|
}
|
|
}
|
|
}
|
|
|
|
// GetMetrics returns a copy of current metrics (for testing/export).
|
|
func (m *Metrics) GetMetrics() map[string]interface{} {
|
|
m.mu.RLock()
|
|
defer m.mu.RUnlock()
|
|
|
|
return map[string]interface{}{
|
|
"request_total": m.requestTotal,
|
|
"request_duration": m.requestDuration,
|
|
"request_duration_buckets": m.requestDurationBuckets,
|
|
"bytes_in": m.bytesIn,
|
|
"bytes_out": m.bytesOut,
|
|
"upstream_health": m.upstreamHealth,
|
|
"streaming_responses_total": m.streamingResponsesTotal,
|
|
"streaming_byte_count": m.streamingByteCount,
|
|
"llm_ttft_ms": m.ttftMs,
|
|
"llm_itl_ms": m.itlMs,
|
|
"llm_token_count": m.tokenCount,
|
|
}
|
|
}
|
|
|
|
// RecordTTFT records Time-to-First-Token in milliseconds
|
|
func (m *Metrics) RecordTTFT(model string, ttftMs int64) {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
|
|
key := fmt.Sprintf("llm:ttft:%s", model)
|
|
m.ttftMs[key] = append(m.ttftMs[key], ttftMs)
|
|
}
|
|
|
|
// RecordITL records Inter-Token Latency in milliseconds
|
|
func (m *Metrics) RecordITL(model string, itlMs int64) {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
|
|
key := fmt.Sprintf("llm:itl:%s", model)
|
|
m.itlMs[key] = append(m.itlMs[key], itlMs)
|
|
}
|
|
|
|
// RecordTokenCount records number of tokens in response
|
|
func (m *Metrics) RecordTokenCount(model string, count int64) {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
|
|
key := fmt.Sprintf("llm:tokens:%s", model)
|
|
m.tokenCount[key] += count
|
|
}
|
|
|
|
// GetTTFTMetrics returns TTFT statistics for Prometheus export
|
|
func (m *Metrics) GetTTFTMetrics() map[string]interface{} {
|
|
m.mu.RLock()
|
|
defer m.mu.RUnlock()
|
|
|
|
result := make(map[string]interface{})
|
|
for key, samples := range m.ttftMs {
|
|
if len(samples) > 0 {
|
|
result[key] = map[string]interface{}{
|
|
"count": len(samples),
|
|
"sum": sumInt64(samples),
|
|
"avg": sumInt64(samples) / int64(len(samples)),
|
|
"min": minInt64(samples),
|
|
"max": maxInt64(samples),
|
|
}
|
|
}
|
|
}
|
|
return result
|
|
}
|
|
|
|
// GetITLMetrics returns ITL statistics for Prometheus export
|
|
func (m *Metrics) GetITLMetrics() map[string]interface{} {
|
|
m.mu.RLock()
|
|
defer m.mu.RUnlock()
|
|
|
|
result := make(map[string]interface{})
|
|
for key, samples := range m.itlMs {
|
|
if len(samples) > 0 {
|
|
result[key] = map[string]interface{}{
|
|
"count": len(samples),
|
|
"sum": sumInt64(samples),
|
|
"avg": sumInt64(samples) / int64(len(samples)),
|
|
"min": minInt64(samples),
|
|
"max": maxInt64(samples),
|
|
}
|
|
}
|
|
}
|
|
return result
|
|
}
|
|
|
|
func sumInt64(vals []int64) int64 {
|
|
var s int64
|
|
for _, v := range vals {
|
|
s += v
|
|
}
|
|
return s
|
|
}
|
|
|
|
func minInt64(vals []int64) int64 {
|
|
if len(vals) == 0 {
|
|
return 0
|
|
}
|
|
min := vals[0]
|
|
for _, v := range vals {
|
|
if v < min {
|
|
min = v
|
|
}
|
|
}
|
|
return min
|
|
}
|
|
|
|
func maxInt64(vals []int64) int64 {
|
|
if len(vals) == 0 {
|
|
return 0
|
|
}
|
|
max := vals[0]
|
|
for _, v := range vals {
|
|
if v > max {
|
|
max = v
|
|
}
|
|
}
|
|
return max
|
|
}
|
|
|
|
// Reset clears all metrics (for testing).
|
|
func (m *Metrics) Reset() {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
|
|
m.requestTotal = make(map[string]int64)
|
|
m.requestDuration = make(map[string]int64)
|
|
m.requestDurationBuckets = make(map[string]map[float64]int64)
|
|
m.bytesIn = make(map[string]int64)
|
|
m.bytesOut = make(map[string]int64)
|
|
m.upstreamHealth = make(map[string]int)
|
|
m.streamingResponsesTotal = make(map[string]int64)
|
|
m.streamingByteCount = make(map[string]int64)
|
|
m.ttftMs = make(map[string][]int64)
|
|
m.itlMs = make(map[string][]int64)
|
|
m.tokenCount = make(map[string]int64)
|
|
m.warmupRequestsDelayed = 0
|
|
m.prefixCacheHitTokens = 0
|
|
m.queueFullRequests = 0
|
|
m.admissionParked = 0
|
|
m.admissionRejected = make(map[string]int64)
|
|
m.engineStateStale = 0
|
|
m.vllmRequestsRunning = 0
|
|
m.vllmKVUsagePerc = 0
|
|
m.observerDegraded = 0
|
|
}
|
|
|
|
// IncrQueueFull increments queue_full_requests_total.
|
|
func (m *Metrics) IncrQueueFull() {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
m.queueFullRequests++
|
|
}
|
|
|
|
// GetQueueFull returns queue_full_requests_total.
|
|
func (m *Metrics) GetQueueFull() int64 {
|
|
m.mu.RLock()
|
|
defer m.mu.RUnlock()
|
|
return m.queueFullRequests
|
|
}
|
|
|
|
// IncrWarmupDelayed increments warmup_requests_delayed_total.
|
|
func (m *Metrics) IncrWarmupDelayed() {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
m.warmupRequestsDelayed++
|
|
}
|
|
|
|
// GetWarmupDelayed returns warmup_requests_delayed_total.
|
|
func (m *Metrics) GetWarmupDelayed() int64 {
|
|
m.mu.RLock()
|
|
defer m.mu.RUnlock()
|
|
return m.warmupRequestsDelayed
|
|
}
|
|
|
|
// IncrPrefixCacheHitTokens increments vllm_prefix_cache_hit_tokens_total by n.
|
|
func (m *Metrics) IncrPrefixCacheHitTokens(n int64) {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
m.prefixCacheHitTokens += n
|
|
}
|
|
|
|
// GetPrefixCacheHitTokens returns vllm_prefix_cache_hit_tokens_total.
|
|
func (m *Metrics) GetPrefixCacheHitTokens() int64 {
|
|
m.mu.RLock()
|
|
defer m.mu.RUnlock()
|
|
return m.prefixCacheHitTokens
|
|
}
|
|
|
|
// IncrAdmissionParked increments admission_parked_total.
|
|
func (m *Metrics) IncrAdmissionParked() {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
m.admissionParked++
|
|
}
|
|
|
|
// GetAdmissionParked returns admission_parked_total.
|
|
func (m *Metrics) GetAdmissionParked() int64 {
|
|
m.mu.RLock()
|
|
defer m.mu.RUnlock()
|
|
return m.admissionParked
|
|
}
|
|
|
|
// IncrAdmissionRejected increments admission_rejected_total{reason=reason}.
|
|
func (m *Metrics) IncrAdmissionRejected(reason string) {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
m.admissionRejected[reason]++
|
|
}
|
|
|
|
// GetAdmissionRejected returns a copy of admission_rejected_total by reason.
|
|
func (m *Metrics) GetAdmissionRejected() map[string]int64 {
|
|
m.mu.RLock()
|
|
defer m.mu.RUnlock()
|
|
out := make(map[string]int64, len(m.admissionRejected))
|
|
for reason, count := range m.admissionRejected {
|
|
out[reason] = count
|
|
}
|
|
return out
|
|
}
|
|
|
|
// IncrEngineStateStale increments engine_state_stale_total.
|
|
func (m *Metrics) IncrEngineStateStale() {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
m.engineStateStale++
|
|
}
|
|
|
|
// GetEngineStateStale returns engine_state_stale_total.
|
|
func (m *Metrics) GetEngineStateStale() int64 {
|
|
m.mu.RLock()
|
|
defer m.mu.RUnlock()
|
|
return m.engineStateStale
|
|
}
|
|
|
|
// SetVLLMRequestsRunning sets vllm_requests_running from the gateway's own reading.
|
|
func (m *Metrics) SetVLLMRequestsRunning(n int64) {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
m.vllmRequestsRunning = n
|
|
}
|
|
|
|
// GetVLLMRequestsRunning returns vllm_requests_running.
|
|
func (m *Metrics) GetVLLMRequestsRunning() int64 {
|
|
m.mu.RLock()
|
|
defer m.mu.RUnlock()
|
|
return m.vllmRequestsRunning
|
|
}
|
|
|
|
// SetVLLMKVUsagePerc sets vllm_kv_usage_perc from the gateway's own reading.
|
|
func (m *Metrics) SetVLLMKVUsagePerc(v float64) {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
m.vllmKVUsagePerc = v
|
|
}
|
|
|
|
// GetVLLMKVUsagePerc returns vllm_kv_usage_perc.
|
|
func (m *Metrics) GetVLLMKVUsagePerc() float64 {
|
|
m.mu.RLock()
|
|
defer m.mu.RUnlock()
|
|
return m.vllmKVUsagePerc
|
|
}
|
|
|
|
// SetObserverDegraded sets observer_degraded (1 = startup self-check failed).
|
|
func (m *Metrics) SetObserverDegraded(degraded bool) {
|
|
m.mu.Lock()
|
|
defer m.mu.Unlock()
|
|
if degraded {
|
|
m.observerDegraded = 1
|
|
} else {
|
|
m.observerDegraded = 0
|
|
}
|
|
}
|
|
|
|
// GetObserverDegraded returns observer_degraded.
|
|
func (m *Metrics) GetObserverDegraded() int {
|
|
m.mu.RLock()
|
|
defer m.mu.RUnlock()
|
|
return m.observerDegraded
|
|
}
|
|
|
|
// globalMetrics is the singleton Metrics instance for gateway-wide telemetry.
|
|
var (
|
|
globalMetrics *Metrics
|
|
globalMetricsOnce sync.Once
|
|
)
|
|
|
|
// Global returns the singleton Metrics instance, initialising on first call.
|
|
func Global() *Metrics {
|
|
globalMetricsOnce.Do(func() { globalMetrics = NewMetrics() })
|
|
return globalMetrics
|
|
}
|