Latency observability

Kiln measures token timing per request. Tokens from concurrent streams are never paired with one another, so an inter-token latency (ITL) sample always describes one request.

Use this page to answer three different questions:

These surfaces provide diagnostic wall-clock evidence. They are not device-kernel profiles, and they do not all measure the same population.

Choose an observation surface

Kiln does not authenticate the observability endpoints. Keep the server on loopback or place it behind an authenticated reverse proxy, especially when recent-request data is enabled.

Enable request timing

Set include_performance on a chat request:

{
  "model": "Qwen3.5-4B",
  "messages": [
    {
      "role": "user",
      "content": "Explain the pause."
    }
  ],
  "stream": true,
  "include_performance": true
}

For a non-streaming real-model request, Kiln adds the summary at metadata.performance.latency. For a streaming real-model request, the terminal chat chunk carries the same summary.

An explicit request value of include_performance: true also adds a kiln.token_timing event after each emitted model token. The server-wide performance-metadata default can enable terminal metadata, but it does not silently add Kiln-specific objects to an otherwise OpenAI-compatible stream. Leave the request field false or omitted when a client accepts only standard chat chunks.

Understand the clocks

All request boundaries use one process-local monotonic clock. Fields ending in _ms are floating-point milliseconds.

body_enqueued does not mean that the remote client received or rendered the bytes. TCP buffers, proxies, network transit, and client work are outside Kiln's clock.

The compatibility field queue_delay_ms is:

response_delivery_ms + handler_queue_ms

The public name client_delivery_ms is also retained for compatibility. Its actual boundary is handler receipt to response-body enqueue—not delivery to the remote client.

Read a request summary

The summary reports:

gap_samples is normally emitted_tokens - 1. Kiln retains at most 8,192 gaps per request. After that limit, percentiles and stall counts describe the retained suffix while gap_samples continues to count the full request.

A request that emits no token has null TTFT and ITL values. A one-token request has TTFT but no ITL sample.

Interpret phase attribution

Preserve the distinction between these values:

• null means the path did not observe or could not isolate that phase;
• 0 means the path measured the phase at zero at the reporting resolution;
• a positive value is request-impact wall time, not necessarily exclusive device work.

Phase values can overlap. decode_ms can contain narrower backend phases, and delivery can overlap later actor work. Never sum every phase and compare the result with request duration.

A shared batched invocation can be attributed to every ready request that participated in it. Request phase totals therefore explain causal overlap; they are not process-wide work totals. Use backend lifetime telemetry when you need device-work totals.

Stable serving permits resize, trim, adapter, and training work through writer-priority accelerator ownership. Their attribution remains null when no such operation overlapped the request's relevant boundary.

Understand stall reasons

For each inter-token gap, Kiln chooses the largest measured phase candidate. The candidate must explain at least the smaller of 250 ms or half of the gap; otherwise the reason is unexplained.

The closed reason set is:

actor_queue, actor_admission, actor_prefill, actor_decode,
actor_cycle_idle, response_delivery, handler_queue, client_delivery,
sampling, readback, gpu_lock_wait, graph_capture, graph_replay,
synchronization, resize, trim, adapter, training, unexplained

unexplained means the current instrumentation did not cover enough of the gap. It is not evidence by itself of allocator activity, VRAM rebalancing, a driver pause, or a particular backend defect.

Read per-token SSE events

With explicit request opt-in, a real-model stream emits a Kiln-specific object after the corresponding content enters the response-body channel:

{
  "object": "kiln.token_timing",
  "source": "batching_engine",
  "token_index": 7,
  "token_id": 4242,
  "ready_ms": 12.0,
  "producer_delivered_ms": 14.0,
  "handler_received_ms": 17.0,
  "body_enqueued_ms": 20.0,
  "response_delivery_ms": 2.0,
  "handler_queue_ms": 3.0,
  "queue_delay_ms": 5.0,
  "client_delivery_ms": 3.0,
  "blocking_phase": "actor_prefill",
  "blocking_phase_ms": 280.0
}

token_index is zero-based. token_id is the accepted model token represented by the row, including a special token that decodes to no visible text. The event does not include log probabilities or alternative candidates.

blocking_phase and blocking_phase_ms are null for the first token because there is no preceding gap. They can also be null when no gap observation exists.

Use the rolling decode endpoint

GET /v1/stats/decode summarizes request-local gaps retained during the last 60 seconds:

• sample_count: gaps in the active rolling window;
• tok_per_sec: gap count divided by the sum of those gap durations;
• p50_itl_ms, p99_itl_ms, p999_itl_ms, mean_itl_ms, and max_itl_ms;
• stall_threshold_ms: max(250 ms, 5 × p50 ITL); and
• stall_count, unexplained_stall_count, and stall_reasons.

This tok_per_sec value is a decode-cadence diagnostic. It excludes TTFT, prompt prefill before the first token, queueing outside the sampled gaps, and request-window concurrency. Do not compare it with end-to-end output throughput from a serving benchmark. When the rolling window is empty, counts and numeric summaries are zero.

Query Prometheus

GET /metrics exports the request timing families:

The histogram buckets are 5 ms, 10 ms, 25 ms, 50 ms, 100 ms, 250 ms, 500 ms, 1 s, 2.5 s, 5 s, 10 s, 30 s, 60 s, and +Inf. Labels use closed phase and reason sets. Request IDs, prompts, model names, adapter names, client identities, and error text are never labels.

Prometheus uses a fixed 250 ms stall definition so the counter remains comparable as workload mix changes. Request summaries and the rolling endpoint use the adaptive threshold. Account for that difference before comparing their counts.

histogram_quantile(
  0.999,
  sum by (le) (rate(kiln_token_itl_seconds_bucket[5m]))
)

sum by (reason) (rate(kiln_token_stalls_total[5m]))

histogram_quantile(
  0.99,
  sum by (phase, le) (
    rate(kiln_request_latency_phase_seconds_bucket[5m])
  )
)

Corroborate backend attribution

Request phases tell you which work overlapped a request. Health, trusted debug state, and backend metric families tell you what the process and accelerator were doing.

• Compare gpu_lock_wait_ms with typed resize, trim, training, and adapter overlap. The narrower values sit inside the broader lock wait; do not add them together.
• Treat readback_ms as an owned host-read boundary. Because accelerator work can be asynchronous, it can include waiting for earlier work on the same stream; it is not pure DMA time.
• Use CUDA and ROCm synchronization counters to identify typed host waits. Never infer request time by subtracting unlocked process-global snapshots.
• Use graph lifetime telemetry for capture, replay, cache, and retained-memory totals. Request graph phases explain overlap, not total device work.
• On Vulkan, inspect the effective capability gauges. Cross-request prefix reuse is currently correctness-quarantined on Vulkan, so exact repeats pay fresh prefill. Resident prefill is disabled by stable and admitted under experimental only when backend and request checks pass.

Hardware receipts and host names are evidence about specific benchmark runs. They do not alter these metric definitions, enable a route, or become machine-specific dispatch policy.

Diagnose a pause

1. Classify the symptom as slow TTFT, slow ITL, or slow end-to-end completion. Do not substitute one metric for another.
2. Open the affected request in Latency diagnosis or capture its terminal metadata. Confirm the pause is request-local.
3. Inspect the dominant stall reason and its duration. Preserve null, zero, and positive phase values.
4. Corroborate that reason with the matching actor, synchronization, graph, allocator, mutation, or training telemetry over the same interval.
5. Treat unexplained as an instrumentation gap. Gather more evidence before assigning a backend cause.
6. Reproduce with a source-bound workload. Change one configuration field per comparison arm, compare like-for-like metrics, and retain failed evidence.

The machine-readable field authorities are the inference schema and observability schema.