# Copyright (c) 2026 LightSeek Foundation # # Permission is hereby granted, free of charge, to any person obtaining a copy # of this software and associated documentation files (the "Software"), to deal # in the Software without restriction, including without limitation the rights # to use, copy, modify, merge, publish, distribute, sublicense, and/or sell # copies of the Software, and to permit persons to whom the Software is # furnished to do so, subject to the following conditions: # # The above copyright notice and this permission notice shall be included in # all copies or substantial portions of the Software. # # THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR # IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, # FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE # AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER # LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, # OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE # SOFTWARE. from __future__ import annotations import pytest import torch from tokenspeed.runtime.engine.generation_output_processor import ( OutputProcesser, RequestState, ) from tokenspeed.runtime.engine.request_stats import ( NOOP_STATS, RequestStats, RequestStatsTracker, ) from tokenspeed.runtime.sampling.sampling_params import SamplingParams class _Sender: def __init__(self): self.items = [] def send_pyobj(self, obj): self.items.append(obj) class _Tokenizer: eos_token_id = None additional_stop_token_ids = None def decode(self, ids): return "".join(str(i) for i in ids) class _Metrics: enabled = False def __init__(self): self.nan_aborts = 0 def record_nan_abort(self): self.nan_aborts += 1 class _ForwardOp: request_ids = ["prefill", "decode"] request_pool_indices = [0, 1] input_lengths = [4, 1] extend_prefix_lens = [0] def num_extends(self): return 1 class _ExecutionResult: output_tokens = torch.tensor([11, 22], dtype=torch.int32) output_lengths = torch.tensor([1, 1], dtype=torch.int32) output_logprobs = None output_nan_flags = None grammar_completion = None next_input_ids = None def sync(self): return None def _state(input_ids: list[int], *, computed_length: int = 0) -> RequestState: state = RequestState( prompt_input_ids=input_ids, sampling_params=SamplingParams(max_new_tokens=8, stop=[], ignore_eos=True), stream=False, tokenizer=_Tokenizer(), ) state.computed_length = computed_length return state def test_mixed_forward_updates_reserve_for_decode_slots_only(): sender = _Sender() processor = OutputProcesser( sender, attn_tp_rank=0, metrics=_Metrics(), ) processor.rid_to_state["prefill"] = _state([1, 2, 3, 4]) processor.rid_to_state["decode"] = _state([5, 6, 7], computed_length=3) events = processor.post_process_forward_op(_ForwardOp(), _ExecutionResult()) reserve_events = [ event for event in events if type(event).__name__ == "UpdateReserveNumTokens" ] assert len(reserve_events) == 1 assert reserve_events[0].request_id == "decode" assert reserve_events[0].reserve_num_tokens_in_next_schedule_event == 1 def test_mark_abort_notify_client_flag(): """Pause-initiated aborts must flag the request to stream a terminating finish to the (passive) client; client-initiated aborts must not.""" sender = _Sender() processor = OutputProcesser(sender, attn_tp_rank=0, metrics=_Metrics()) pause_state = _state([1, 2, 3]) processor.rid_to_state["pause"] = pause_state processor.mark_abort("pause", notify_client=True) assert pause_state.to_abort assert pause_state.abort_notify_client assert pause_state.finished # finished_reason materialized client_state = _state([1, 2, 3]) processor.rid_to_state["client"] = client_state processor.mark_abort("client") # default: client tore down its own state assert client_state.to_abort assert not client_state.abort_notify_client def test_nan_flag_finishes_request_with_numerical_error(): """A request flagged by the NaN guard is finished with ABORT_CODE.NumericalError while the rest of the batch continues.""" from tokenspeed.runtime.engine.request_types import ABORT_CODE, FINISH_ABORT sender = _Sender() metrics = _Metrics() processor = OutputProcesser(sender, attn_tp_rank=0, metrics=metrics) prefill_state = _state([1, 2, 3, 4]) decode_state = _state([5, 6, 7], computed_length=3) processor.rid_to_state["prefill"] = prefill_state processor.rid_to_state["decode"] = decode_state result = _ExecutionResult() # Flag only the decode slot. result.output_nan_flags = torch.tensor([0, 1], dtype=torch.int32) events = processor.post_process_forward_op(_ForwardOp(), result) # Flagged request: aborted with NumericalError, removed from tracking. # The scheduler gets an Abort (NOT Finish) event — AbortEvent skips the # radix-tree insert and host-KV writeback, so corrupted KV is not reused. assert isinstance(decode_state.finished_reason, FINISH_ABORT) assert decode_state.finished_reason.err_type == ABORT_CODE.NumericalError assert "decode" not in processor.rid_to_state abort_events = [e for e in events if type(e).__name__ == "Abort"] assert [e.request_id for e in abort_events] == ["decode"] assert not [e for e in events if type(e).__name__ == "Finish"] assert metrics.nan_aborts == 1 # Unflagged request keeps running untouched. assert not prefill_state.finished assert "prefill" in processor.rid_to_state assert prefill_state.output_ids == [11] # The abort finish reason is streamed to the client. assert len(sender.items) == 1 out = sender.items[0] idx = out.rids.index("decode") assert out.finished_reasons[idx]["type"] == "abort" assert out.finished_reasons[idx]["err_type"] == ABORT_CODE.NumericalError.value def test_nan_flag_keeps_single_sanitized_token(): """A NaN-flagged spec-decode slot keeps exactly one (sanitized) token so extend-result accounting matches a normal mid-step finish.""" sender = _Sender() metrics = _Metrics() processor = OutputProcesser( sender, attn_tp_rank=0, spec_algorithm="eagle", spec_num_tokens=4, metrics=metrics, ) decode_state = _state([5, 6, 7], computed_length=3) processor.rid_to_state["decode"] = decode_state class _SpecForwardOp: request_ids = ["decode"] request_pool_indices = [0] input_lengths = [1] extend_prefix_lens = [] def num_extends(self): return 0 result = _ExecutionResult() result.output_tokens = torch.tensor([11, 22, 33, 44], dtype=torch.int32) result.output_lengths = torch.tensor([3], dtype=torch.int32) result.output_nan_flags = torch.tensor([1], dtype=torch.int32) events = processor.post_process_forward_op(_SpecForwardOp(), result) assert decode_state.finished # Only the first of the 3 accepted tokens is kept. assert decode_state.output_ids == [11] extend_events = [e for e in events if type(e).__name__ == "ExtendResult"] assert len(extend_events) == 1 assert list(extend_events[0].tokens) == [11] assert metrics.nan_aborts == 1 def test_nan_flag_skips_first_token_pd_handoff(): """NaN-terminated requests must not hand their bootstrap token to the PD transfer layer — their KV is suspect.""" sender = _Sender() processor = OutputProcesser(sender, attn_tp_rank=0, metrics=_Metrics()) processor.rid_to_state["prefill"] = _state([1, 2, 3, 4]) processor.rid_to_state["decode"] = _state([5, 6, 7], computed_length=3) result = _ExecutionResult() result.next_input_ids = None result.output_nan_flags = torch.tensor([1, 0], dtype=torch.int32) handoffs = [] processor.post_process_forward_op( _ForwardOp(), result, on_first_token=lambda rid, *a: handoffs.append(rid), ) # Flagged prefill slot is skipped; the healthy decode slot still hands off. assert handoffs == ["decode"] class _RecordingLogger: """Capture logger.info(fmt, *args) calls as formatted strings.""" def __init__(self): self.lines: list[str] = [] def info(self, fmt, *args): self.lines.append(fmt % args if args else fmt) def warning(self, *a, **k): pass def test_log_request_stats_disabled_by_default(): """Without --enable-log-request-stats, no ReqStats line is emitted and no timestamps are recorded (zero overhead path).""" import tokenspeed.runtime.engine.generation_output_processor as gop rec = _RecordingLogger() gop_logger, gop.logger = gop.logger, rec try: processor = OutputProcesser(_Sender(), attn_tp_rank=0, metrics=_Metrics()) assert processor.enable_log_request_stats is False state = _state([5, 6, 7], computed_length=3) state.sampling_params.max_new_tokens = 1 processor.rid_to_state["d"] = state class _DecodeOp: request_ids = ["d"] request_pool_indices = [0] input_lengths = [1] extend_prefix_lens = [] def num_extends(self): return 0 processor.post_process_forward_op(_DecodeOp(), _ExecutionResult()) finally: gop.logger = gop_logger assert state.finished assert not any("RequestStats(" in line for line in rec.lines) # disabled: request still carries the shared no-op tracker (never registered) assert state.stats is NOOP_STATS def test_log_request_stats_line_fields(): """The per-request stats line reports the right host-side derived values: queue/prefill/ttft/total ms, cache-hit, decode throughput, preemption.""" import tokenspeed.runtime.engine.generation_output_processor as gop from tokenspeed.runtime.engine.request_types import FINISH_LENGTH rec = _RecordingLogger() gop_logger, gop.logger = gop.logger, rec try: processor = OutputProcesser( _Sender(), attn_tp_rank=0, enable_log_request_stats=True, metrics=_Metrics() ) # prompt=4, cache=2 -> cache_hit 0.5; queue 10ms, prefill 20ms, ttft 30ms, # total 130ms; output=5 over a 100ms decode window -> decode_tps 40. rs = _state([1, 2, 3, 4]) rs.created_time = 1000.000 rs.cached_tokens = 2 rs.output_ids = [11, 12, 13, 14, 15] rs.finished_reason = FINISH_LENGTH(length=5) rs.stats = RequestStatsTracker() rs.stats.scheduled_time = 1000.010 rs.stats.prefill_done_time = 1000.030 rs.stats.first_token_time = 1000.030 rs.stats.preempt_count = 2 rs.stats.preempt_time = 0.005 processor._log_request_stats("rid-x", rs, finish_time=1000.130) finally: gop.logger = gop_logger assert len(rec.lines) == 1 line = rec.lines[0] assert line.startswith( "Req: rid-x Finish! RequestStats(status='finished', reason='length'" ) assert ( "prompt_tokens=4, cache_tokens=2, output_tokens=5, cache_hit_rate=0.5" in line ) assert "queue_ms=10.0, prefill_ms=20.0, ttft_ms=30.0, total_ms=130.0" in line assert "preempt_ms=5.0, preempt_count=2" in line assert "decode_tps=40.0" in line assert "acc_len=None, acc_rate=None" in line def test_log_request_stats_aborted_with_spec_acceptance(): """Aborted requests log status=aborted; with spec decode on, acc_len and acc_rate are populated.""" import tokenspeed.runtime.engine.generation_output_processor as gop from tokenspeed.runtime.engine.request_types import FINISH_ABORT rec = _RecordingLogger() gop_logger, gop.logger = gop.logger, rec try: processor = OutputProcesser( _Sender(), attn_tp_rank=0, spec_algorithm="eagle", spec_num_tokens=4, enable_log_request_stats=True, metrics=_Metrics(), ) rs = _state([1, 2, 3, 4]) rs.created_time = 1000.0 rs.spec_verify_ct = 10 rs.accept_draft_tokens = 3.0 rs.finished_reason = FINISH_ABORT("client abort") rs.stats = RequestStatsTracker() processor._log_request_stats("rid-a", rs, finish_time=1000.05) finally: gop.logger = gop_logger line = rec.lines[0] assert "status='aborted', reason='abort'" in line # acc_rate = (acc_len - 1) / draft = (3 - 1) / 4 = 0.5 assert "acc_len=3.0, acc_rate=0.5" in line def test_log_request_stats_noop_without_tracker(): """A request carrying the no-op tracker (flag off / finished-at-admission) is skipped by _log_request_stats's single guard, without raising.""" import tokenspeed.runtime.engine.generation_output_processor as gop from tokenspeed.runtime.engine.request_types import FINISH_LENGTH rec = _RecordingLogger() gop_logger, gop.logger = gop.logger, rec try: processor = OutputProcesser( _Sender(), attn_tp_rank=0, enable_log_request_stats=True, metrics=_Metrics() ) rs = _state([1, 2, 3]) rs.finished_reason = FINISH_LENGTH(length=1) assert rs.stats is NOOP_STATS # never registered -> no-op tracker processor._log_request_stats("no-tracker", rs, finish_time=123.0) finally: gop.logger = gop_logger assert rec.lines == [] def test_request_stats_from_state_total_on_degenerate_input(): """from_state never divides by zero / reads a missing stage: a request with no output and unset timestamps yields zeros and None, not an exception.""" from tokenspeed.runtime.engine.request_types import FINISH_ABORT rs = _state([1, 2, 3, 4]) rs.finished_reason = FINISH_ABORT("aborted before any output") rs.stats = RequestStatsTracker() # all timestamps still 0.0 # output_ids empty, no spec decode, no timestamps set. stats = RequestStats.from_state(rs, spec_algorithm=None, spec_num_tokens=None) assert stats.status == "aborted" and stats.reason == "abort" assert stats.output_tokens == 0 assert stats.cache_hit_rate == 0.0 assert stats.queue_ms == stats.prefill_ms == stats.ttft_ms == stats.total_ms == 0.0 assert stats.decode_tps == 0.0 assert stats.acc_len is None and stats.acc_rate is None def test_noop_stats_singleton_is_frozen(): """NOOP_STATS is shared, so its methods are no-ops and writes raise -- a future tracker mutator without a no-op override fails loudly, not silently.""" import pytest NOOP_STATS.mark_scheduled(5.0) # no-op, does not raise or record NOOP_STATS.record_decode_step(1.0, True) with pytest.raises(AttributeError): NOOP_STATS.scheduled_time = 1.0 def test_log_request_stats_records_timestamps_through_forward(): """End-to-end: with the flag on, a finishing request gets its post-forward timestamps recorded host-side and emits one ReqStats line. (scheduled_time is stamped pre-forward in the event loop; simulated here.)""" import time import tokenspeed.runtime.engine.generation_output_processor as gop rec = _RecordingLogger() gop_logger, gop.logger = gop.logger, rec try: processor = OutputProcesser( _Sender(), attn_tp_rank=0, enable_log_request_stats=True, metrics=_Metrics() ) # prefill already done; max_new_tokens=1 so it finishes after one token state = _state([5, 6, 7], computed_length=3) state.sampling_params.max_new_tokens = 1 processor.register("d", state) # attaches the stats tracker state.stats.mark_scheduled(time.time()) # event loop does this pre-forward class _DecodeOp: request_ids = ["d"] request_pool_indices = [0] input_lengths = [1] extend_prefix_lens = [] def num_extends(self): return 0 processor.post_process_forward_op(_DecodeOp(), _ExecutionResult()) finally: gop.logger = gop_logger assert state.finished # Lifecycle timestamps were stamped on the host, in order. assert state.stats.scheduled_time > 0.0 assert state.stats.prefill_done_time >= state.stats.scheduled_time assert state.stats.first_token_time > 0.0 assert state.stats.finish_time > 0.0 stats_lines = [line for line in rec.lines if "Req: d Finish! RequestStats(" in line] assert len(stats_lines) == 1 assert "status='finished', reason='length'" in stats_lines[0] def test_log_request_stats_logs_on_each_dp_replica_leader(): """Per-request logging is gated on attn_tp_rank == 0 (each DP replica's TP leader), not the global rank. So a request on a DP replica > 0 (whose leader has global_rank != 0) is still logged -- not missed -- while non-leader TP shards stay silent so the line isn't duplicated.""" import tokenspeed.runtime.engine.generation_output_processor as gop from tokenspeed.runtime.engine.request_types import FINISH_LENGTH def emit(attn_tp_rank): rec = _RecordingLogger() gop_logger, gop.logger = gop.logger, rec try: p = OutputProcesser( _Sender(), attn_tp_rank=attn_tp_rank, enable_log_request_stats=True, metrics=_Metrics(), ) rs = _state([1, 2, 3, 4]) rs.finished_reason = FINISH_LENGTH(length=1) rs.stats = RequestStatsTracker() p._log_request_stats("rid", rs, finish_time=1.0) finally: gop.logger = gop_logger return rec.lines # TP leader of ANY DP replica logs (attn_tp_rank == 0 even when global_rank != 0). assert any("Req: rid Finish! RequestStats(" in line for line in emit(0)) # Non-leader TP shards within a replica stay silent (no duplicate line). assert emit(1) == [] class _PrefillForwardOp: request_ids = ["prefill"] request_pool_indices = [3] input_lengths = [4] extend_prefix_lens = [0] def num_extends(self): return 1 class _PrefillExecutionResult: output_tokens = torch.tensor([101], dtype=torch.int32) output_lengths = torch.tensor([1], dtype=torch.int32) output_logprobs = None output_nan_flags = None grammar_completion = None next_input_ids = torch.tensor([[101, 102, 103]], dtype=torch.int32) def sync(self): return None class _EmptyPrefillExecutionResult(_PrefillExecutionResult): output_tokens = torch.tensor([], dtype=torch.int32) output_lengths = torch.tensor([0], dtype=torch.int32) class _MismatchedPrefillExecutionResult(_PrefillExecutionResult): next_input_ids = torch.tensor([[201, 202, 203]], dtype=torch.int32) def test_prefill_first_token_passes_spec_candidates(): sender = _Sender() processor = OutputProcesser(sender, attn_tp_rank=0, metrics=_Metrics()) processor.rid_to_state["prefill"] = _state([1, 2, 3, 4]) calls = [] processor.post_process_forward_op( _PrefillForwardOp(), _PrefillExecutionResult(), is_prefill_instance=True, on_first_token=lambda *args: calls.append(args), ) assert calls == [("prefill", 3, 101, [101, 102, 103])] def test_prefill_first_token_does_not_guess_from_next_input_ids(): sender = _Sender() processor = OutputProcesser(sender, attn_tp_rank=0, metrics=_Metrics()) processor.rid_to_state["prefill"] = _state([1, 2, 3, 4]) calls = [] processor.post_process_forward_op( _PrefillForwardOp(), _EmptyPrefillExecutionResult(), is_prefill_instance=True, on_first_token=lambda *args: calls.append(args), ) assert calls == [] def test_prefill_first_token_checks_spec_candidate_bootstrap(): sender = _Sender() processor = OutputProcesser(sender, attn_tp_rank=0, metrics=_Metrics()) processor.rid_to_state["prefill"] = _state([1, 2, 3, 4]) with pytest.raises(RuntimeError, match="Prefill bootstrap token mismatch"): processor.post_process_forward_op( _PrefillForwardOp(), _MismatchedPrefillExecutionResult(), is_prefill_instance=True, on_first_token=lambda *args: None, )