diff --git a/rust/src/chat/src/lib.rs b/rust/src/chat/src/lib.rs index 8284ddd1285..8e7ed02a403 100644 --- a/rust/src/chat/src/lib.rs +++ b/rust/src/chat/src/lib.rs @@ -172,6 +172,9 @@ impl ChatLlm { pub async fn chat(&self, mut request: ChatRequest) -> Result { request.validate()?; + // Stamp before rendering so render and tokenize count toward TTFT/e2e. + let arrival_time = vllm_llm::current_unix_timestamp_secs(); + let output_processor = self.backend.new_chat_output_processor( &mut request, NewChatOutputProcessorOptions { @@ -210,6 +213,7 @@ impl ChatLlm { data_parallel_rank: request.data_parallel_rank, reasoning_parser_kwargs, lora_request: request.lora_request, + arrival_time: Some(arrival_time), }; let decoded_stream = self.text.generate(text_request).await?.map_err(Error::from).boxed(); diff --git a/rust/src/llm/src/lib.rs b/rust/src/llm/src/lib.rs index b8e72632f1b..942bf55c288 100644 --- a/rust/src/llm/src/lib.rs +++ b/rust/src/llm/src/lib.rs @@ -14,6 +14,7 @@ pub use output::{ GenerateOutputStreamExt, GeneratePromptInfo, TokenUsage, }; pub use request::GenerateRequest; +pub use request_metrics::current_unix_timestamp_secs; pub use vllm_engine_core_client::protocol::logprobs::{Logprobs, PositionLogprobs, TokenLogprob}; use crate::inflight::InflightRequests; diff --git a/rust/src/llm/src/request.rs b/rust/src/llm/src/request.rs index 159cf823de4..45e5bd1ca64 100644 --- a/rust/src/llm/src/request.rs +++ b/rust/src/llm/src/request.rs @@ -1,5 +1,4 @@ use std::collections::BTreeMap; -use std::time::{SystemTime, UNIX_EPOCH}; use uuid::Uuid; use vllm_engine_core_client::protocol::lora::LoraRequest; @@ -8,6 +7,7 @@ use vllm_engine_core_client::protocol::request::{EngineCoreRequest, ReasoningPar use vllm_engine_core_client::protocol::sampling::EngineCoreSamplingParams; use crate::error::{Error, Result}; +use crate::request_metrics::current_unix_timestamp_secs; /// Tokenized decoder-only generate request accepted by [`crate::Llm`]. /// @@ -30,8 +30,9 @@ pub struct GenerateRequest { pub mm_features: Option, /// Unix timestamp, in seconds, when this request arrived at the frontend. /// - /// When omitted, the Rust frontend fills it immediately before sending the - /// request to engine-core, matching Python's default arrival-time behavior. + /// Stamped at the frontend entry, before render and tokenization, to match + /// Python's renderer-entry arrival_time. When omitted, it is filled as a + /// fallback before the request is sent to engine-core. pub arrival_time: Option, /// Optional salt used to partition prefix-cache entries for this request. pub cache_salt: Option, @@ -122,13 +123,6 @@ impl PreparedGenerateRequest { } } -fn current_unix_timestamp_secs() -> f64 { - SystemTime::now() - .duration_since(UNIX_EPOCH) - .expect("system clock is before unix epoch") - .as_secs_f64() -} - #[cfg(test)] mod tests { use std::collections::BTreeMap; diff --git a/rust/src/llm/src/request_metrics.rs b/rust/src/llm/src/request_metrics.rs index f57c54df35c..4f1673db154 100644 --- a/rust/src/llm/src/request_metrics.rs +++ b/rust/src/llm/src/request_metrics.rs @@ -330,7 +330,7 @@ fn diff_or_zero(end: f64, start: f64) -> f64 { /// /// Original Python request timestamp source: /// -pub(crate) fn current_unix_timestamp_secs() -> f64 { +pub fn current_unix_timestamp_secs() -> f64 { SystemTime::now() .duration_since(UNIX_EPOCH) .expect("system clock is before unix epoch") diff --git a/rust/src/server/src/grpc/convert.rs b/rust/src/server/src/grpc/convert.rs index 9de89727205..4327221221d 100644 --- a/rust/src/server/src/grpc/convert.rs +++ b/rust/src/server/src/grpc/convert.rs @@ -94,6 +94,7 @@ pub fn to_text_request( data_parallel_rank: None, reasoning_parser_kwargs: None, lora_request: None, + arrival_time: None, }) } diff --git a/rust/src/server/src/routes/inference/generate/convert.rs b/rust/src/server/src/routes/inference/generate/convert.rs index 7a6dcdfc45c..965155b5825 100644 --- a/rust/src/server/src/routes/inference/generate/convert.rs +++ b/rust/src/server/src/routes/inference/generate/convert.rs @@ -70,6 +70,7 @@ pub(super) fn prepare_generate_request( data_parallel_rank: ctx.data_parallel_rank, reasoning_parser_kwargs: None, lora_request: lora_resolution.lora_request.clone(), + arrival_time: None, }; Ok(PreparedRequest { diff --git a/rust/src/server/src/routes/openai/completions/convert.rs b/rust/src/server/src/routes/openai/completions/convert.rs index fa80e16e0f9..1355481b49b 100644 --- a/rust/src/server/src/routes/openai/completions/convert.rs +++ b/rust/src/server/src/routes/openai/completions/convert.rs @@ -144,6 +144,7 @@ pub(super) fn prepare_completion_request( data_parallel_rank: ctx.data_parallel_rank, reasoning_parser_kwargs: None, lora_request: lora_resolution.lora_request.clone(), + arrival_time: None, }; Ok(PreparedRequest { diff --git a/rust/src/text/src/lib.rs b/rust/src/text/src/lib.rs index 2987ef93e57..130eaec7f42 100644 --- a/rust/src/text/src/lib.rs +++ b/rust/src/text/src/lib.rs @@ -132,6 +132,10 @@ impl TextLlm { ) -> Result<(TextRequest, GenerateOutputStream)> { request.validate()?; + if request.arrival_time.is_none() { + request.arrival_time = Some(vllm_llm::current_unix_timestamp_secs()); + } + let tokenizer = self.backend.tokenizer(); let prompt_token_ids = match take(&mut request.prompt) { Prompt::Text(text) => tokenizer.encode(&text, request.add_special_tokens)?, diff --git a/rust/src/text/src/lower.rs b/rust/src/text/src/lower.rs index 7addcf2ad6b..164d2a3db06 100644 --- a/rust/src/text/src/lower.rs +++ b/rust/src/text/src/lower.rs @@ -56,7 +56,7 @@ pub fn lower_text_request( data_parallel_rank: request.data_parallel_rank, reasoning_parser_kwargs: request.reasoning_parser_kwargs.clone(), lora_request: request.lora_request.clone(), - arrival_time: None, + arrival_time: request.arrival_time, trace_headers: None, }; @@ -1143,6 +1143,44 @@ mod tests { assert_eq!(prepared.generate_request.request_id, "text-1"); } + #[test] + fn lower_text_request_passes_arrival_time_through() { + let request = TextRequest { + arrival_time: Some(42.5), + ..sample_request() + }; + + let prepared = lower_text_request( + request, + vec![1, 2, 3], + sample_sampling_hints(), + sample_sampling_limits(), + &stub_tokenizer(), + ) + .unwrap(); + + assert_eq!(prepared.generate_request.arrival_time, Some(42.5)); + } + + #[test] + fn lower_text_request_leaves_arrival_time_unset_when_absent() { + let request = TextRequest { + arrival_time: None, + ..sample_request() + }; + + let prepared = lower_text_request( + request, + vec![1, 2, 3], + sample_sampling_hints(), + sample_sampling_limits(), + &stub_tokenizer(), + ) + .unwrap(); + + assert_eq!(prepared.generate_request.arrival_time, None); + } + #[test] fn resolve_max_tokens_user_smaller_than_model_limit() { let result = resolve_max_tokens(Some(50), None, 200, 100); diff --git a/rust/src/text/src/request.rs b/rust/src/text/src/request.rs index c64e9ca05e6..09522868872 100644 --- a/rust/src/text/src/request.rs +++ b/rust/src/text/src/request.rs @@ -187,6 +187,12 @@ pub struct TextRequest { /// LoRA adapter selected for this request. #[serde(default)] pub lora_request: Option, + /// Wall-clock unix timestamp (seconds) when this request arrived at the + /// frontend, stamped before render/tokenize to match Python's + /// renderer-entry arrival_time. When unset, it is stamped before + /// tokenization. + #[serde(default)] + pub arrival_time: Option, } impl TextRequest { @@ -205,6 +211,7 @@ impl TextRequest { data_parallel_rank: None, reasoning_parser_kwargs: None, lora_request: None, + arrival_time: None, } }