diff --git a/CONTEXT.md b/CONTEXT.md new file mode 100644 index 000000000..3f490be1a --- /dev/null +++ b/CONTEXT.md @@ -0,0 +1,17 @@ +# DwarfStar Server + +The local inference server coordinates one mutable model session while presenting stateless wire protocols to clients. + +## Language + +**Live Session**: +The one mutable model and KV state used for local inference at a time. +_Avoid_: Shared session, client session + +**Session-State Transaction**: +One admitted request's controlled attempt to reuse or extend the Live Session, ending in exactly one recorded state disposition. It does not imply that already-streamed output can be retracted. +_Avoid_: Database transaction, response transaction + +**Terminal Outcome**: +The single typed record of how an admitted request ended, including its primary reason and the resulting Live Session disposition. +_Avoid_: Finish reason, HTTP status diff --git a/docs/adr/0001-session-state-transaction.md b/docs/adr/0001-session-state-transaction.md new file mode 100644 index 000000000..511a773aa --- /dev/null +++ b/docs/adr/0001-session-state-transaction.md @@ -0,0 +1,56 @@ +# ADR 0001: Worker-Owned Session-State Transactions + +- Status: Accepted +- Date: 2026-07-10 + +## Context + +`ds4-server` has one mutable inference session and one worker, but request +lifecycle effects are spread across queue handling, generation, progress +callbacks, output branches, tracing, counters, and cleanup. Client-thread +`/stats` and model metadata also read the live session directly. Early returns +can therefore bypass consistent tracing or accounting, and failure precedence +is implicit. + +## Decision + +Every admitted request runs through one private worker-owned session-state +transaction and returns exactly one typed terminal outcome. + +- Only the worker reads or mutates live session position and mutates + continuation frontiers. Client parsing may validate call IDs against + mutex-protected frontier metadata, but `/stats` reads only a worker-published + immutable snapshot and client code uses an immutable configured context size. +- One idempotent terminalizer settles session state, finalizes output, closes + tracing, cleans up, applies counters, and publishes statistics. Each effect + occurs at most once even if terminalization is invoked again; the final + snapshot reports idle only after trace and cleanup complete. +- The first causal execution failure is primary. Rollback, checkpoint + maintenance, terminal reporting, tracing, statistics, and cleanup failures + are recorded as secondary and cannot overwrite it. +- Session rollback means retaining the strongest engine-guaranteed valid prefix + or invalidating the live state. Failed and cancelled execution does not + publish a newly parsed continuation frontier or canonicalize a new + checkpoint. Rollback is not a full KV snapshot restore. +- Socket bytes are irreversible. Once a write may have emitted bytes, rollback + cannot retract them and a broken stream is never retried as another HTTP or + terminal response. +- Session, output, trace, and statistics behavior are hidden behind coarse + private production and deterministic scripted adapters. They do not mirror + individual engine or protocol functions. + +## Compatibility requirements + +The migration preserves endpoint responses, streaming event order, +continuation/cache precedence, DSML recovery limits, tool identifiers, +checkpoint scheduling and payload compatibility, and current nonfatal +checkpoint-maintenance behavior. Protocol-adapter, continuation-policy, and KVC +format refactors are separate decisions. + +## Consequences + +Failure ordering and state disposition become explicit and testable, `/stats` +cannot race the worker's live checkpoint vector, and every admitted job is +accounted for once. The server gains a larger private transaction context and a +small amount of snapshot staleness between worker publication points. It does +not gain atomic network output or cheap full-session rollback. diff --git a/docs/superpowers/plans/2026-07-10-session-state-transaction.md b/docs/superpowers/plans/2026-07-10-session-state-transaction.md new file mode 100644 index 000000000..3c00dc9b7 --- /dev/null +++ b/docs/superpowers/plans/2026-07-10-session-state-transaction.md @@ -0,0 +1,103 @@ +# Session-State Transaction Implementation Plan + +> Execute on `server-enhancements`. Keep the existing local Metal server alive; +> compilation and unit tests must not launch a second model process. + +## Goal + +Every admitted request executes through one worker-owned transaction, produces +one typed terminal outcome, and publishes immutable statistics without changing +protocol, continuation, or checkpoint behavior. + +## Task 1: Pin the immutable stats boundary + +Files: `ds4_server.c` + +1. Add a server test that gives `send_stats()` a populated published snapshot + and no live session, then asserts the JSON values and lack of adapter access. +2. Run `make ds4_test && ./ds4_test --server`; confirm the new test fails against + the direct session accessor. +3. Add `ctx_size`, `server_stats_snapshot`, and a mutex-protected snapshot copy + to `server`. +4. Make model metadata, request parsing, and `/stats` use immutable copied + values. Add worker publication points for startup, progress, decode, and + terminal settlement. +5. Re-run the focused server suite and inspect all remaining + `ds4_session_pos/ctx` call sites for worker ownership. + +## Task 2: Add the typed lifecycle and terminalizer + +Files: `ds4_server.c` + +1. Add compile-failing scripted tests for typed phases, primary reason, session + and wire dispositions, and secondary failure bits. +2. Add a transaction script that records ordered effects and injectable + outcomes without sockets, model state, traces, or filesystem access. +3. Test repeated terminalization first: two calls must yield the same outcome + and exactly one commit/rollback, output finalization, trace close, statistics + application, and cleanup. +4. Implement `server_txn_fail_once()` and `server_txn_terminalize()` with + terminalization-started and per-effect completion bits. +5. Add table-driven cases proving first-failure precedence and irreversible + wire behavior. +6. Run `make ds4_test && ./ds4_test --server` after each red/green slice. + +## Task 3: Add private production and scripted adapters + +Files: `ds4_server.c` + +1. Define private coarse session, output, trace, and statistics adapter + interfaces. Keep them local to the server translation unit. +2. Implement the scripted adapters as an ordered operation program with + failpoints for restore, sync, decode, cancellation, output, commit, + rollback, trace, statistics, and cleanup. +3. Add strict tests for every required failure site, including compound cases + where rollback/trace/cleanup fail after an earlier primary failure. +4. Implement production adapters by moving complete lifecycle blocks. Do not + add wrappers that merely forward individual `ds4_session_*` or protocol + helper calls. + +## Task 4: Migrate request execution + +Files: `ds4_server.c` + +1. Give `job` an owned terminal outcome and readiness flag. +2. Move queued-disconnect handling, busy state, and admitted-request accounting + into `server_txn_run()` so every admitted job terminalizes. +3. Convert the existing early returns in generation to typed failures leading + to the single terminal path. +4. Migrate cache selection/restore, synchronization/prefill, extension, + decoding/recovery, continuation settlement, final output, trace, counters, + and cleanup into explicit phases while retaining branch bodies and ordering. +5. Delete `generate_job()` after its behavior has moved; do not leave a + forwarding wrapper. +6. Move shutdown checkpoint persistence into the worker epilogue. +7. Run `make ds4_test && ./ds4_test --server`, then inspect golden protocol and + continuation/KVC tests for exact compatibility. + +## Task 5: Record the architecture + +Files: `CONTEXT.md`, `docs/adr/0001-session-state-transaction.md`, +`tasks/todo.md` + +1. Keep the glossary limited to Live Session, Session-State Transaction, and + Terminal Outcome. +2. Record worker ownership, rollback versus wire semantics, exactly-once + terminal accounting, failure precedence, adapter boundaries, and behavioral + compatibility in the ADR. +3. Mark completed checklist items and add the concrete verification results and + any deferred platform checks to `tasks/todo.md`. + +## Task 6: Review and verify + +Files: all scoped changes + +1. Run `make` and `./ds4_test --server` without launching a second model. +2. Run any lightweight server-specific self-tests available in the tree. +3. Re-scan for client-thread session access and multiple terminalization paths. +4. Review production code, tests, documentation, and the complete diff using + the configured guard/review skills; fix blocking findings. +5. Confirm the original server process still listens on port 8000 and inspect + its new logs for failures. +6. Commit only scoped source, tests, context, ADR, plan, and task files. Exclude + `CLAUDE.local.md` and `ds4_agent_test`; do not push. diff --git a/docs/superpowers/specs/2026-07-10-session-state-transaction-design.md b/docs/superpowers/specs/2026-07-10-session-state-transaction-design.md new file mode 100644 index 000000000..f563322fa --- /dev/null +++ b/docs/superpowers/specs/2026-07-10-session-state-transaction-design.md @@ -0,0 +1,230 @@ +# Session-State Transaction Design + +Status: Accepted for implementation on `server-enhancements` + +## Objective + +Make every admitted `ds4-server` request pass through one worker-owned +session-state transaction and produce exactly one immutable terminal outcome. +The transaction controls live-session mutation, continuation frontiers, +checkpoint settlement, output finalization, tracing, counters, and cleanup. + +This is a state transaction, not a wire transaction. Bytes successfully handed +to the socket are irreversible and are never described as rolled back. + +## Scope + +This change includes: + +- a worker-published immutable snapshot for `/stats` and configured context + metadata; +- typed execution phase, terminal reason, session disposition, and wire + disposition values; +- a sticky first-failure latch and one idempotent terminalizer; +- private production and scripted session, output, trace, and statistics + adapters; +- deterministic failure tests for restore, sync, decode, cancellation, output, + commit, rollback, trace, statistics, and cleanup; +- incremental migration of the current cache-selection, sync, decode, + continuation settlement, checkpoint, output, trace, statistics, and cleanup + blocks into the transaction. + +This change does not redesign protocol events, continuation selection policy, +or the KVC payload/format. It does not add a public header or split unchanged +code into forwarding files. + +## Chosen module shape + +Three designs were compared: + +1. A minimal `run -> outcome` module with a small internal phase sequence. +2. An explicit state machine whose legal transitions are represented in an + enum and switch. +3. A common-path transaction centered on one cleanup label and a rollback + journal. + +The implementation combines their strongest properties: one narrow +worker-facing call, an explicit forward-only lifecycle, and a single idempotent +terminalizer with per-effect completion bits. The explicit lifecycle makes +failure injection and illegal transitions testable; the narrow entry point +keeps the worker and clients unaware of model, checkpoint, or protocol details. + +The private worker-facing interface is conceptually: + +```c +static server_txn_outcome server_txn_run(server *s, job *j); +``` + +`worker_main()` invokes it for every `ENQUEUE_OK` job, including a job whose +client disconnected while queued. The returned value is stored in the job +before `done` is signalled. Queue-full and stopping responses are pre-admission +and therefore outside the transaction. + +## Typed lifecycle + +The lifecycle is forward-only, except for the existing single bounded DSML +recovery retry: + +```text +ADMITTED + -> RESTORE + -> SYNCHRONIZE + -> EXTEND + -> DECODE [contains the existing bounded recovery retry, at most once] + -> SETTLE + -> TERMINALIZE + -> DONE +``` + +The implementation records: + +- `server_txn_phase`: where execution is or where a result was decided; +- `server_txn_reason`: model stop, length, tool calls, continuation conflict, + client gone, cancellation, shutdown, restore/sync/decode/output/commit + failure, or invariant failure. A queued disconnect is recorded as client + gone decided in the restore phase with the session unchanged; +- `server_session_disposition`: unchanged, valid prefix retained, committed, + or invalidated; +- `server_wire_disposition`: untouched, started, irreversible, complete, or + broken; +- secondary failure bits for rollback, checkpoint maintenance, output + finalization, trace, statistics, and cleanup. + +The terminal outcome owns all of its values; it contains no borrowed request, +session, trace, or output pointers. + +## Ownership invariants + +- The worker is the only thread that calls the production session adapter or + mutates live token position, checkpoint scheduling, or continuation + frontiers. +- The configured context size is copied into `server` during initialization. + Client threads use that immutable value for parsing and model metadata. +- Shutdown checkpoint persistence runs in the worker epilogue. After joining, + the main thread only waits for clients and destroys resources. +- `/stats` serializes one copied `server_stats_snapshot`. It never calls + `ds4_session_pos()`, `ds4_session_ctx()`, or any adapter. + +The snapshot contains all fields emitted by `/stats`, including counters, +queue depth, clients, busy state, live tokens, context size, and a monotonically +increasing version. Queue/client owners may update their own scalar fields +under `server.mu`; only the worker publishes live-session fields and terminal +statistics. + +## Adapter boundaries + +The module has four private adapter families, each with production and scripted +implementations: + +- Session: plans/restores a usable frontier, synchronizes prompt state, performs + decode/recovery, and settles commit or rollback as cohesive operations. +- Output: observes peer state, manages prefill/open/delta/terminal writes, and + owns the monotonic wire ledger. +- Trace: consumes transaction observations and closes one request trace. +- Statistics: publishes progress snapshots and applies one terminal accounting + observation. + +These are not mirrors of `ds4.h` or the protocol helper set. Each production +operation owns a substantial existing lifecycle block. Scripted adapters use an +ordered in-memory operation log whose tests fail on an unexpected sequence; +they never open a socket, load a model, touch a KVC file, or inspect a live +session. + +## Exactly-once terminalization + +Every path reaches `server_txn_terminalize()`. It marks terminalization started +before invoking any effect and caches the final outcome. Calling it again +returns that cached outcome without repeating any effect. + +Terminalization uses monotonic per-effect flags and attempts this controlled +sequence: + +1. Freeze the first causal reason and intended state disposition. +2. Detach session callbacks and commit or roll back continuation/checkpoint + state as appropriate. +3. Attempt the one allowed terminal wire projection, respecting the wire + ledger; a broken wire forbids retries or an alternate HTTP response. +4. Close the typed trace record while transaction-owned trace data is live. +5. Release all transaction-owned resources once. +6. Apply terminal counters once and publish the final immutable snapshot, so + `busy=false` means tracing and cleanup have also completed. +7. Cache and return the terminal outcome. + +Frontier settlement remains before the final protocol event, preserving the +current continuation semantics and protocol event ordering. Trace, cleanup, +and counters cannot replace the primary outcome; their failures are secondary. + +## Failure precedence + +`server_txn_fail_once()` records the first causal execution failure. Later +failures cannot replace it. + +- A session restore, sync, or decode failure beats failures encountered while + reporting or cleaning up that failure. +- A stream write failure observed before cancellation remains primary; the + cancellation is a consequence. +- If cancellation conditions are observed together, shutdown takes precedence + over peer disconnect. +- A required in-memory continuation commit failure is primary when no earlier + failure exists and leaves the session invalidated. +- An output-finalization failure is primary only when execution had not already + failed. Once a write may have emitted bytes, the wire becomes broken and is + never retried. +- Rollback, checkpoint maintenance/canonicalization, tracing, statistics, and + cleanup failures are secondary. They are recorded and surfaced in the typed + outcome but do not overwrite the primary result. + +Successful model termination and delivery are orthogonal: for example, a model +may stop normally while the terminal wire write fails. The terminal reason is +then output failure, while the recorded model finish remains stop. + +## Rollback and irreversible output + +Rollback means settling the live session to the strongest valid state supported +by the engine contract. It is not an ACID snapshot restore: + +- interrupted `ds4_session_sync()` retains its guaranteed valid prefix; +- a generic restore, sync, or decode failure may invalidate the live session; +- failed or cancelled execution does not publish newly parsed Responses, + Anthropic, thinking, or tool-call continuation frontiers and does not run + commit-only checkpoint canonicalization; +- a suppressed continued-store frontier and deferred disk checkpoint are + restored or consumed using the existing rules; +- no full per-request KV snapshot is introduced, and token-only rewind is not + treated as a complete backend rollback. + +The output adapter marks the wire irreversible before any operation that may +partially write. Session rollback never changes that wire disposition and never +causes an alternate response or replay of a terminal event. + +## Compatibility contract + +Migration keeps the existing branch bodies and ordering until scripted and +socketpair tests pin equivalent behavior. Specifically, this change preserves: + +- OpenAI chat/completions, Responses, and Anthropic endpoint status and bodies; +- streaming header, keepalive, delta, usage, finish, and `[DONE]` ordering; +- cache-source and continuation-frontier precedence; +- stop-sequence trimming, DSML repair/recovery limits, and tool-call IDs; +- checkpoint filenames, payloads, scheduling, consume/discard timing, and + canonicalization behavior; +- current nonfatal treatment of checkpoint maintenance failures. + +## Verification strategy + +Deterministic scripted tests run the same phase driver as production and assert +typed restore, synchronization, decode, cancellation, commit, rollback, trace, +statistics, and cleanup failures. The shared output seam injects failures at +prefill, stream-open, incremental-update, flush, and terminal-finalization +operations. Tests also pin terminal-effect ordering, shutdown/output causal +precedence, settlement-time broken-wire behavior, repeated terminalizer +invocation, and checkpoint-failure disposition. A production +queued-disconnect test proves terminal accounting without a live session. The +`/stats` tests prove serialization works with `server.session == NULL` and +that queued work wins over a coalesced idle snapshot refresh. + +Existing server socketpair/protocol, continuation, and KVC tests cover deferred +checkpoint handling, recovery behavior, protocol bytes, and cache compatibility. +Build verification uses `make`; server unit verification uses +`./ds4_test --server`. Live verification uses the user's local Metal server after the +replacement binary passes those gates. diff --git a/ds4.c b/ds4.c index 640511eb0..ee2a38dea 100644 --- a/ds4.c +++ b/ds4.c @@ -1857,6 +1857,10 @@ static void model_prefetch_cpu_mapping(const ds4_model *m) { /* Read the GGUF metadata table. Values stay in the mmap; we store offsets so * later validation can decode only the keys it needs. */ static void parse_metadata(ds4_model *m, ds4_cursor *c) { + /* n_kv comes from the header. Every entry consumes at least one byte in the + * file, so a count larger than the bytes remaining cannot be real; reject it + * before calloc so a tiny file can't request an enormous allocation. */ + if (m->n_kv > c->size - c->pos) ds4_die("GGUF metadata count exceeds file size"); m->kv = calloc((size_t)m->n_kv, sizeof(m->kv[0])); if (!m->kv) ds4_die("out of memory while allocating metadata table"); @@ -1887,6 +1891,10 @@ static void parse_metadata(ds4_model *m, ds4_cursor *c) { /* Read the tensor directory and convert relative GGUF offsets to absolute * mmap offsets. Tensor bytes are still never copied here. */ static void parse_tensors(ds4_model *m, ds4_cursor *c) { + /* As in parse_metadata: each tensor directory entry needs at least one byte + * in the file, so reject a count larger than the bytes remaining before the + * allocation. */ + if (m->n_tensors > c->size - c->pos) ds4_die("GGUF tensor count exceeds file size"); m->tensors = calloc((size_t)m->n_tensors, sizeof(m->tensors[0])); if (!m->tensors) ds4_die("out of memory while allocating tensor table"); @@ -22241,7 +22249,8 @@ static void vocab_load(ds4_vocab *vocab, const ds4_model *model) { ds4_die("GGUF tokenizer token table is missing or invalid"); } if (!model_get_array(model, "tokenizer.ggml.merges", &merges) || - merges.type != GGUF_VALUE_STRING) { + merges.type != GGUF_VALUE_STRING || + merges.len > INT32_MAX) { ds4_die("GGUF tokenizer merge table is missing or invalid"); } @@ -27778,6 +27787,10 @@ void ds4_session_rewind(ds4_session *s, int pos) { s->mtp_draft_valid = false; } +bool ds4_session_is_valid(const ds4_session *s) { + return s && s->checkpoint_valid; +} + int ds4_session_pos(ds4_session *s) { return s->checkpoint.len; } diff --git a/ds4.h b/ds4.h index 9d040c92b..7cadf1fdf 100644 --- a/ds4.h +++ b/ds4.h @@ -268,6 +268,7 @@ int ds4_session_eval_speculative_argmax(ds4_session *s, int first_token, char *err, size_t errlen); void ds4_session_invalidate(ds4_session *s); void ds4_session_rewind(ds4_session *s, int pos); +bool ds4_session_is_valid(const ds4_session *s); int ds4_session_pos(ds4_session *s); int ds4_session_ctx(ds4_session *s); int ds4_session_prefill_cap(ds4_session *s); diff --git a/ds4_agent.c b/ds4_agent.c index 1c5209154..b4f76d4f0 100644 --- a/ds4_agent.c +++ b/ds4_agent.c @@ -3685,8 +3685,29 @@ static char *agent_session_title_from_text(const char *text, size_t text_len, * * The DS4 payload stores the exact token sequence and graph state. The rendered * text is retained for listing, history rendering, and stripped-session rebuilds. */ + +/* Bytes from the current position to EOF, restoring the position. Returns false + * if the stream is not seekable. Used to cap a file-declared length before + * allocating, so a tiny cache file can't drive a multi-GB xmalloc. */ +static bool agent_fp_remaining(FILE *fp, uint64_t *out) { + off_t pos = ftello(fp); + if (pos < 0 || fseeko(fp, 0, SEEK_END) != 0) return false; + off_t end = ftello(fp); + if (end < 0 || fseeko(fp, pos, SEEK_SET) != 0) return false; + *out = end > pos ? (uint64_t)(end - pos) : 0; + return true; +} + static bool agent_kv_read_text(FILE *fp, uint32_t text_bytes, char **text_out, char *err, size_t err_len) { + /* text_bytes is read from the on-disk header; cap it against the bytes + * actually left in the file before allocating, so a 1-byte file declaring + * text_bytes = 0xFFFFFFFF can't request ~4 GiB. */ + uint64_t remaining = 0; + if (!agent_fp_remaining(fp, &remaining) || text_bytes > remaining) { + if (err && err_len) snprintf(err, err_len, "truncated cached text"); + return false; + } char *text = xmalloc((size_t)text_bytes + 1); if (fread(text, 1, text_bytes, fp) != text_bytes) { if (err && err_len) snprintf(err, err_len, "truncated cached text"); @@ -3736,6 +3757,14 @@ static bool agent_kv_read_title_trailer(FILE *fp, const ds4_kvstore_entry *hdr, return false; } uint32_t title_bytes = ds4_kvstore_le_get32(tb); + /* Same cap as agent_kv_read_text: reject a title length larger than the + * bytes left in the file before allocating. */ + uint64_t title_remaining = 0; + if (!agent_fp_remaining(fp, &title_remaining) || title_bytes > title_remaining) { + if (err && err_len) snprintf(err, err_len, "truncated agent session title trailer"); + fseeko(fp, payload_pos, SEEK_SET); + return false; + } char *title = xmalloc((size_t)title_bytes + 1); if (fread(title, 1, title_bytes, fp) != title_bytes) { if (err && err_len) snprintf(err, err_len, "truncated agent session title trailer"); @@ -6690,6 +6719,11 @@ static void agent_bash_job_free(agent_bash_job *job) { } if (job->pipe_fd >= 0) close(job->pipe_fd); if (job->tmp_fd >= 0) close(job->tmp_fd); + /* Remove the mkstemp() output file created in agent_bash_start(); only + * that function's error paths unlinked it, so a job that started + * successfully otherwise leaves /tmp/ds4_agent_output_* behind for the + * lifetime of the process (unbounded accumulation across many jobs). */ + if (job->path[0]) unlink(job->path); free(job->cmd); free(job); } diff --git a/ds4_distributed.c b/ds4_distributed.c index d31c8e2a6..b1058c241 100644 --- a/ds4_distributed.c +++ b/ds4_distributed.c @@ -7000,6 +7000,17 @@ static int dist_worker_handle_snapshot_load( snprintf(err, sizeof(err), "invalid distributed snapshot load header"); } + /* Reject a token_count larger than the worker context up front, before the + * allocation and the read loop below. token_count is only bounded to + * ~UINT32_MAX/4 by the header check above, so without this a peer could + * drive a multi-GB malloc and a full-length socket read before the + * matching-state check further down (which also tests token_count > ctx_size) + * finally rejects the request. */ + if (!err[0] && begin.token_count > (uint32_t)state->ctx_size) { + dist_discard_bytes(upstream->fd, body_bytes); + snprintf(err, sizeof(err), "snapshot token count exceeds worker context size"); + } + int *tokens = NULL; if (!err[0]) { tokens = malloc((size_t)begin.token_count * sizeof(tokens[0])); diff --git a/ds4_help.c b/ds4_help.c index d32e088cf..4cce34f5c 100644 --- a/ds4_help.c +++ b/ds4_help.c @@ -304,8 +304,10 @@ static void print_server_api(FILE *fp, const help_colors *c) { opt(fp, c, "--host HOST", "Bind address. Default: 127.0.0.1"); opt(fp, c, "--port N", "Bind port. Default: 8000"); opt(fp, c, "--cors", "Add Access-Control-Allow-* headers for browser JS clients."); + opt(fp, c, "--max-queue N", "Reject requests with 429 when N jobs are already waiting. 0 disables. Default: 0"); opt(fp, c, "--trace FILE", "Write prompts, cache decisions, output, and tool calls."); para(fp, c, "Endpoints: /v1/chat/completions, /v1/responses, /v1/completions, and /v1/messages."); + para(fp, c, "GET /health and GET /stats report liveness and operational counters even mid-generation."); para(fp, c, "Model endpoint aliases include deepseek-v4-flash and deepseek-v4-pro; both serve the loaded GGUF."); fputc('\n', fp); } diff --git a/ds4_kvstore.c b/ds4_kvstore.c index 6b663b51b..f287e6776 100644 --- a/ds4_kvstore.c +++ b/ds4_kvstore.c @@ -545,10 +545,29 @@ double ds4_kvstore_entry_eviction_score( effective_hits *= exp2(-elapsed / (double)DS4_KVSTORE_HIT_HALF_LIFE_SECONDS); if (effective_hits < KV_CACHE_MIN_EFFECTIVE_HITS) effective_hits = 0.0; } + /* Freshness grace: a just-written file has had no chance to be hit yet, + * so score it like a once-hit file and let the grace decay on the same + * half-life. Without it, the newest waypoints of the live conversation + * are always the first eviction victims while stale never-hit files + * survive on age alone. */ + double freshness = 0.0; + if (used_at) { + freshness = now > used_at ? + exp2(-(double)(now - used_at) / + (double)DS4_KVSTORE_HIT_HALF_LIFE_SECONDS) : 1.0; + if (freshness < KV_CACHE_MIN_EFFECTIVE_HITS) freshness = 0.0; + } + if (effective_hits < freshness) effective_hits = freshness; double score = (effective_hits + 1.0) * (double)e->tokens / (double)e->file_size; - if (kv_cache_reason_is_anchor(e->reason)) - score *= KV_CACHE_ANCHOR_REASON_SCORE_FACTOR; + if (kv_cache_reason_is_anchor(e->reason)) { + /* The anchor bonus exists so restart/eviction recovery points stay + * around, but a never-hit anchor that has aged past the half-life is + * not anyone's recovery point anymore — let it compete on density + * alone instead of outliving the live conversation's waypoints. */ + double activity = effective_hits > 1.0 ? 1.0 : effective_hits; + score *= 1.0 + (KV_CACHE_ANCHOR_REASON_SCORE_FACTOR - 1.0) * activity; + } if (kv_cache_incoming_supersedes_continued(e, incoming)) { double h = effective_hits > 0.0 ? effective_hits / (effective_hits + 1.0) : 0.0; @@ -742,8 +761,12 @@ int ds4_kvstore_continued_store_target(const ds4_kvstore *kc, int live_tokens) { const int step = kv_cache_continued_step(kc); if (step <= 0) return 0; if (live_tokens < kc->opt.min_tokens) return 0; - if (live_tokens % step != 0) return 0; - if (live_tokens <= kc->continued_last_store_tokens) return 0; + /* Threshold-crossing rather than exact-multiple: prefills resumed from an + * unaligned cached position (disk hits, live text continuations) never + * land on multiples of the step, which used to leave arbitrarily large + * gaps between waypoint snapshots. Storing the current prefix at any + * position is safe; evict stores already do it. */ + if (live_tokens < kc->continued_last_store_tokens + step) return 0; return live_tokens; } @@ -1320,7 +1343,12 @@ int ds4_kvstore_try_load_text(ds4_kvstore *kc, const char *key_kind = ds4_kvstore_key_kind(hdr.ext_flags); bool consumed = false; if (kc->opt.cold_max_tokens > 0 && loaded > kc->opt.cold_max_tokens) { - unlink(path); + /* This entry is superseded once the caller extends the restored + * state, but unlinking it here would lose the only recoverable + * copy if the tail prefill then fails or is cancelled. Report it + * as consumed and let the caller unlink after the extension + * succeeds; without a result struct nobody could, so delete. */ + if (!result) unlink(path); consumed = true; kv_logf(kc, DS4_KVSTORE_LOG_KVCACHE, "%s: kv cache hit text%s%s tokens=%d text=%u quant=%u key=%s load=%.1f ms consumed file=%s", diff --git a/ds4_metal.m b/ds4_metal.m index 7e3f8bd5c..4c448a5f5 100644 --- a/ds4_metal.m +++ b/ds4_metal.m @@ -1,5 +1,6 @@ #import #import +#include #include #include @@ -14,6 +15,8 @@ #include #include #include +#include +#include #include #include #include @@ -283,6 +286,7 @@ static int ds4_gpu_stream_expert_cache_note_expert_size( static void ds4_gpu_stream_expert_pending_load_clear(void); static void ds4_gpu_stream_expert_pread_pool_shutdown(void); static int ds4_gpu_stream_expert_timing_summary_enabled(void); +static void ds4_gpu_stream_expert_pread_pool_stats_print(void); static int ds4_gpu_stream_expert_cache_entry_protected( uint32_t layer, uint32_t expert, @@ -2789,6 +2793,7 @@ void ds4_gpu_print_memory_report(const char *label) { ds4_gpu_stream_expert_timing_print("delta", delta); g_stream_expert_timing_last_report = total; } + ds4_gpu_stream_expert_pread_pool_stats_print(); } if (getenv("DS4_METAL_STREAMING_EXPERT_LAYER_STATS") != NULL) { fprintf(stderr, "ds4: streaming expert cache per-layer stats:\n"); @@ -3066,6 +3071,20 @@ static int ds4_gpu_model_map_log_enabled(void) { @[@"DS4_METAL_SET_ROWS_SOURCE", @"metal/set_rows.metal"], ]; + /* Shader sources resolve against the current directory first, then against + * the directory containing the executable, so the binary can be launched + * from any working directory (e.g. inside another project). */ + NSString *exe_dir = nil; + { + char exe_path[4096]; + uint32_t exe_len = sizeof(exe_path); + if (_NSGetExecutablePath(exe_path, &exe_len) == 0) { + NSString *resolved = [[NSString stringWithUTF8String:exe_path] + stringByResolvingSymlinksInPath]; + exe_dir = [resolved stringByDeletingLastPathComponent]; + } + } + NSMutableString *source = [NSMutableString stringWithString:base]; for (NSArray *spec in required_sources) { const char *override_path = getenv([spec[0] UTF8String]); @@ -3075,6 +3094,8 @@ static int ds4_gpu_model_map_log_enabled(void) { } [paths addObject:spec[1]]; [paths addObject:[@"./" stringByAppendingString:spec[1]]]; + if (exe_dir) + [paths addObject:[exe_dir stringByAppendingPathComponent:spec[1]]]; NSString *loaded = nil; NSString *loaded_path = nil; @@ -7819,9 +7840,12 @@ static int ds4_gpu_stream_expert_pread_into( return 1; } +static void ds4_gpu_stream_expert_pread_thread_qos(void); + static void *ds4_gpu_stream_expert_pread_worker(void *arg) { ds4_gpu_stream_expert_pread_worker_args *wa = (ds4_gpu_stream_expert_pread_worker_args *)arg; + ds4_gpu_stream_expert_pread_thread_qos(); for (uint32_t i = wa->worker_index; i < wa->n_tasks; i += wa->n_workers) { ds4_gpu_stream_expert_pread_task *task = &wa->tasks[i]; task->ok = ds4_gpu_stream_expert_pread_into(task->offset, @@ -7847,14 +7871,37 @@ static int ds4_gpu_stream_expert_pread_into( static int g_stream_expert_pread_pool_initialized; static int g_stream_expert_pread_pool_stopping; +/* Dispatch stats for the timing summary: qd_avg = task_ms / wall_ms is + * the effective pread concurrency the pool actually sustains. */ +static uint64_t g_stream_expert_pread_pool_stat_dispatches; +static uint64_t g_stream_expert_pread_pool_stat_tasks; +static uint64_t g_stream_expert_pread_pool_stat_workers; +static uint64_t g_stream_expert_pread_pool_stat_bytes; +static double g_stream_expert_pread_pool_stat_task_ms; +static double g_stream_expert_pread_pool_stat_wall_ms; +static double g_stream_expert_pread_pool_stat_t0; +static const ds4_gpu_stream_expert_pread_task *g_stream_expert_pread_pool_stat_task_ptr; +static uint32_t g_stream_expert_pread_pool_stat_task_n; +static int g_stream_expert_pread_pool_stat_pending; + static int ds4_gpu_stream_expert_pread_pool_enabled(void) { const char *env = getenv("DS4_METAL_STREAMING_EXPERT_PREAD_POOL"); return !(env && strcmp(env, "0") == 0); } +/* Expert reads are on the token critical path: exempt reader threads + * from the IO throttling / background QoS a demoted parent would hand + * them (plain nice does not throttle IO, taskpolicy -b does). */ +static void ds4_gpu_stream_expert_pread_thread_qos(void) { + if (getenv("DS4_METAL_DISABLE_STREAMING_EXPERT_PREAD_QOS") != NULL) return; + (void)pthread_set_qos_class_self_np(QOS_CLASS_USER_INITIATED, 0); + (void)setiopolicy_np(IOPOL_TYPE_DISK, IOPOL_SCOPE_THREAD, IOPOL_IMPORTANT); +} + static void *ds4_gpu_stream_expert_pread_pool_worker(void *arg) { const uint32_t worker_index = (uint32_t)(uintptr_t)arg; uint64_t seen_generation = 0; + ds4_gpu_stream_expert_pread_thread_qos(); for (;;) { pthread_mutex_lock(&g_stream_expert_pread_pool_mutex); @@ -7987,6 +8034,11 @@ static int ds4_gpu_stream_expert_pread_pool_begin( g_stream_expert_pread_pool_active_workers = n_workers; g_stream_expert_pread_pool_remaining_workers = n_workers; g_stream_expert_pread_pool_generation++; + g_stream_expert_pread_pool_stat_t0 = ds4_gpu_now_ms(); + g_stream_expert_pread_pool_stat_task_ptr = tasks; + g_stream_expert_pread_pool_stat_task_n = n_tasks; + g_stream_expert_pread_pool_stat_workers += n_workers; + g_stream_expert_pread_pool_stat_pending = 1; pthread_cond_broadcast(&g_stream_expert_pread_pool_start_cond); pthread_mutex_unlock(&g_stream_expert_pread_pool_mutex); return 1; @@ -8000,10 +8052,51 @@ static int ds4_gpu_stream_expert_pread_pool_wait(void) { pthread_cond_wait(&g_stream_expert_pread_pool_done_cond, &g_stream_expert_pread_pool_mutex); } + if (g_stream_expert_pread_pool_stat_pending) { + const ds4_gpu_stream_expert_pread_task *st = + g_stream_expert_pread_pool_stat_task_ptr; + g_stream_expert_pread_pool_stat_wall_ms += + ds4_gpu_now_ms() - g_stream_expert_pread_pool_stat_t0; + g_stream_expert_pread_pool_stat_dispatches++; + g_stream_expert_pread_pool_stat_tasks += + g_stream_expert_pread_pool_stat_task_n; + for (uint32_t i = 0; i < g_stream_expert_pread_pool_stat_task_n; i++) { + g_stream_expert_pread_pool_stat_task_ms += st[i].ms; + g_stream_expert_pread_pool_stat_bytes += st[i].read_bytes; + } + g_stream_expert_pread_pool_stat_task_ptr = NULL; + g_stream_expert_pread_pool_stat_task_n = 0; + g_stream_expert_pread_pool_stat_pending = 0; + } pthread_mutex_unlock(&g_stream_expert_pread_pool_mutex); return 1; } +static void ds4_gpu_stream_expert_pread_pool_stats_print(void) { + pthread_mutex_lock(&g_stream_expert_pread_pool_mutex); + const uint64_t dispatches = g_stream_expert_pread_pool_stat_dispatches; + const uint64_t tasks = g_stream_expert_pread_pool_stat_tasks; + const uint64_t workers = g_stream_expert_pread_pool_stat_workers; + const uint64_t bytes = g_stream_expert_pread_pool_stat_bytes; + const double task_ms = g_stream_expert_pread_pool_stat_task_ms; + const double wall_ms = g_stream_expert_pread_pool_stat_wall_ms; + pthread_mutex_unlock(&g_stream_expert_pread_pool_mutex); + if (dispatches == 0) return; + fprintf(stderr, + "ds4: streaming pread pool dispatches=%llu tasks=%llu " + "tasks_avg=%.1f workers_avg=%.1f bytes=%.2f GiB wall_avg=%.3f ms " + "qd_avg=%.2f pool_gbps=%.2f task_gbps=%.2f\n", + (unsigned long long)dispatches, + (unsigned long long)tasks, + (double)tasks / (double)dispatches, + (double)workers / (double)dispatches, + ds4_gpu_gib(bytes), + wall_ms / (double)dispatches, + wall_ms > 0.0 ? task_ms / wall_ms : 0.0, + wall_ms > 0.0 ? (double)bytes / 1e6 / wall_ms : 0.0, + task_ms > 0.0 ? (double)bytes / 1e6 / task_ms : 0.0); +} + static int ds4_gpu_stream_expert_pread_pool_dispatch( ds4_gpu_stream_expert_pread_task *tasks, uint32_t n_tasks, diff --git a/ds4_server.c b/ds4_server.c index 34a9d5084..a50afea6a 100644 --- a/ds4_server.c +++ b/ds4_server.c @@ -22,6 +22,7 @@ #include #include #include +#include #include #include #include @@ -56,6 +57,27 @@ static void stop_signal_handler(int sig) { } } +#ifdef DS4_SERVER_TEST +typedef enum { + TEST_TXN_EVENT_RESTORE = 0, + TEST_TXN_EVENT_SYNCHRONIZE, + TEST_TXN_EVENT_EXTEND, + TEST_TXN_EVENT_DECODE, + TEST_TXN_EVENT_OUTPUT_PREFILL, + TEST_TXN_EVENT_OUTPUT_OPEN, + TEST_TXN_EVENT_OUTPUT_UPDATE, + TEST_TXN_EVENT_OUTPUT_FLUSH, + TEST_TXN_EVENT_TRACE_OBSERVE, + TEST_TXN_EVENT_STATS_OBSERVE, + TEST_TXN_EVENT_COMMIT, + TEST_TXN_EVENT_ROLLBACK, + TEST_TXN_EVENT_OUTPUT, + TEST_TXN_EVENT_STATS, + TEST_TXN_EVENT_TRACE, + TEST_TXN_EVENT_CLEANUP, +} test_txn_event; +#endif + typedef struct { char *ptr; size_t len; @@ -219,6 +241,13 @@ static bool json_u16(const char **p, uint32_t *out) { } static bool json_string(const char **p, char **out) { + /* Always define *out. Every failure path below returns false without + * producing a string, and several callers reparse in place with + * `free(x); json_string(&p, &x)` (e.g. duplicate JSON keys, the "model" + * field). Without this, a non-string or malformed value leaves *out + * holding the just-freed pointer, which a later cleanup frees again -- + * a double-free. Nulling on entry closes that whole class at the root. */ + *out = NULL; json_ws(p); if (**p != '"') return false; (*p)++; @@ -281,7 +310,11 @@ static bool json_number(const char **p, double *out) { static bool json_int(const char **p, int *out) { double v = 0.0; if (!json_number(p, &v)) return false; - if (v < 0) v = 0; + /* json_number() uses strtod(), which accepts "NaN"/"Infinity". NaN fails + * every comparison, so a plain `v < 0` clamp would let it through to the + * (int) cast, which is undefined for NaN; `!(v >= 0)` folds NaN (and + * negatives) to 0. +/-Infinity are handled by the two clamps. */ + if (!(v >= 0)) v = 0; if (v > INT_MAX) v = INT_MAX; *out = (int)v; return true; @@ -628,7 +661,7 @@ typedef struct { * them to a prior assistant tool call. If that call_id is still known in * memory, the live KV is the authoritative prefix, including any hidden * thinking that the client did not replay. These fields carry the parsed - * evidence needed by generate_job() to append only the new suffix. + * evidence needed by server_txn_run() to append only the new suffix. * * A tool-output-only request has no stateless prefix to match. If the live * call_id binding is gone by the time the worker executes it, DS4 must ask @@ -2269,6 +2302,19 @@ static bool role_is_user_like(const char *role) { return !strcmp(role, "user") || !strcmp(role, "tool") || !strcmp(role, "function"); } +static bool text_is_ascii_ws_only(const char *s) { + if (!s) return true; + for (; *s; s++) { + if (!isspace((unsigned char)*s)) return false; + } + return true; +} + +static const char *canonical_reasoning_text(const chat_msg *m) { + if (!m || text_is_ascii_ws_only(m->reasoning)) return ""; + return m->reasoning; +} + static bool chat_history_uses_tool_context(const chat_msgs *msgs, const char *tool_schemas) { if (tool_schemas && tool_schemas[0]) return true; @@ -2337,7 +2383,7 @@ static char *render_chat_prompt_text(const chat_msgs *msgs, const char *tool_sch if (think) { if (tool_context || i > last_user_idx) { buf_puts(&out, ""); - buf_puts(&out, m->reasoning ? m->reasoning : ""); + buf_puts(&out, canonical_reasoning_text(m)); buf_puts(&out, ""); } else { buf_puts(&out, ""); @@ -2408,7 +2454,7 @@ static char *render_live_tool_tail(const chat_msgs *msgs, int start, buf_puts(&out, "<｜Assistant｜>"); if (think) { buf_puts(&out, ""); - buf_puts(&out, m->reasoning ? m->reasoning : ""); + buf_puts(&out, canonical_reasoning_text(m)); buf_puts(&out, ""); } else { buf_puts(&out, ""); @@ -2429,14 +2475,6 @@ static char *render_live_tool_tail(const chat_msgs *msgs, int start, return buf_take(&out); } -static bool chat_msg_has_call_id(const chat_msg *m, const char *id) { - if (!m || !id || !id[0] || strcmp(m->role, "assistant")) return false; - for (int i = 0; i < m->calls.len; i++) { - if (m->calls.v[i].id && !strcmp(m->calls.v[i].id, id)) return true; - } - return false; -} - static void chat_msg_collect_tool_call_ids(const chat_msg *m, stop_list *ids) { if (!m || !ids) return; id_list_push_unique(ids, m->tool_call_id); @@ -2445,17 +2483,6 @@ static void chat_msg_collect_tool_call_ids(const chat_msg *m, stop_list *ids) { } } -static const chat_msg *responses_find_prior_call_msg(const chat_msgs *msgs, - int before, - const char *id) { - if (!msgs || !id || !id[0]) return NULL; - if (before > msgs->len) before = msgs->len; - for (int i = before - 1; i >= 0; i--) { - if (chat_msg_has_call_id(&msgs->v[i], id)) return &msgs->v[i]; - } - return NULL; -} - /* Validate Responses tool outputs before rendering. * * A tool output with a call_id is meaningful only if either: @@ -2468,7 +2495,7 @@ static const chat_msg *responses_find_prior_call_msg(const chat_msgs *msgs, * reasoning state for the assistant call. Official Responses clients can * carry that state with reasoning items / encrypted reasoning content; when * they do not, the request is still renderable as visible history. Mark that - * condition so generate_job() can prefer live / visible checkpoints and emit a + * condition so server_txn_run() can prefer live / visible checkpoints and emit a * warning if it must fall back to visible replay instead of aborting the * session. */ static bool responses_validate_tool_outputs(server *s, const chat_msgs *msgs, @@ -2480,8 +2507,25 @@ static bool responses_validate_tool_outputs(server *s, const chat_msgs *msgs, if (requires_live_tool_state) *requires_live_tool_state = false; if (requires_live_reasoning) *requires_live_reasoning = false; const bool needs_reasoning = ds4_think_mode_enabled(think_mode); - for (int i = 0; i < msgs->len; i++) { + + /* Map call_id -> the nearest preceding assistant message that declares it, + * built as we scan forward. This replaces a per-id backward rescan + * (responses_find_prior_call_msg) that made the whole pass O(n^2) over an + * attacker-supplied, uncapped message array. Only assistant messages declare + * call ids (via their calls[] array), so registering them as we pass and + * looking up on tool messages reproduces the nearest-preceding result. */ + rax *by_call_id = raxNew(); + bool ok = true; + for (int i = 0; i < msgs->len && ok; i++) { const chat_msg *m = &msgs->v[i]; + if (!strcmp(m->role, "assistant")) { + for (int k = 0; k < m->calls.len; k++) { + const char *cid = m->calls.v[k].id; + if (cid && cid[0]) + raxInsert(by_call_id, (unsigned char *)cid, strlen(cid), (void *)m, NULL); + } + continue; + } if (strcmp(m->role, "tool") && strcmp(m->role, "function")) continue; stop_list ids = {0}; @@ -2489,13 +2533,15 @@ static bool responses_validate_tool_outputs(server *s, const chat_msgs *msgs, for (int j = 0; j < ids.len; j++) { const char *id = ids.v[j]; const bool live_known = responses_live_has_call_id(s, id); - const chat_msg *prior = responses_find_prior_call_msg(msgs, i, id); + void *found = id && id[0] + ? raxFind(by_call_id, (unsigned char *)id, strlen(id)) : raxNotFound; + const chat_msg *prior = found == raxNotFound ? NULL : (const chat_msg *)found; if (!live_known && !prior) { snprintf(err, errlen, "Responses continuation state is not available for call_id %s; retry by replaying the full input history", id); - id_list_free(&ids); - return false; + ok = false; + break; } if (!prior) { if (requires_live_tool_state) *requires_live_tool_state = true; @@ -2509,12 +2555,13 @@ static bool responses_validate_tool_outputs(server *s, const chat_msgs *msgs, } id_list_free(&ids); } - return true; + raxFree(by_call_id); + return ok; } /* Record the call ids and suffix candidate for a live Responses continuation. * - * This only prepares evidence. generate_job() later checks that the live + * This only prepares evidence. server_txn_run() later checks that the live * server state is still exactly at the remembered token frontier before using * it. If another request already replaced the session, normal token/text/disk * prefix matching handles the request instead. */ @@ -2570,8 +2617,21 @@ static bool anthropic_validate_tool_results(server *s, const chat_msgs *msgs, char *err, size_t errlen) { if (requires_live_tool_state) *requires_live_tool_state = false; if (!msgs) return true; - for (int i = 0; i < msgs->len; i++) { + + /* Same O(1) call_id -> prior assistant message map as + * responses_validate_tool_outputs, replacing the O(n^2) backward rescan. */ + rax *by_call_id = raxNew(); + bool ok = true; + for (int i = 0; i < msgs->len && ok; i++) { const chat_msg *m = &msgs->v[i]; + if (!strcmp(m->role, "assistant")) { + for (int k = 0; k < m->calls.len; k++) { + const char *cid = m->calls.v[k].id; + if (cid && cid[0]) + raxInsert(by_call_id, (unsigned char *)cid, strlen(cid), (void *)m, NULL); + } + continue; + } if (!anthropic_msg_is_tool_result_tail(m)) continue; stop_list ids = {0}; @@ -2579,13 +2639,15 @@ static bool anthropic_validate_tool_results(server *s, const chat_msgs *msgs, for (int j = 0; j < ids.len; j++) { const char *id = ids.v[j]; const bool live_known = anthropic_live_has_call_id(s, id); - const chat_msg *prior = responses_find_prior_call_msg(msgs, i, id); + void *found = id && id[0] + ? raxFind(by_call_id, (unsigned char *)id, strlen(id)) : raxNotFound; + const chat_msg *prior = found == raxNotFound ? NULL : (const chat_msg *)found; if (!live_known && !prior) { snprintf(err, errlen, "Anthropic continuation state is not available for tool_use_id %s; retry by replaying the full messages history", id); - id_list_free(&ids); - return false; + ok = false; + break; } if (!prior && requires_live_tool_state) { *requires_live_tool_state = true; @@ -2593,7 +2655,8 @@ static bool anthropic_validate_tool_results(server *s, const chat_msgs *msgs, } id_list_free(&ids); } - return true; + raxFree(by_call_id); + return ok; } /* Prepare the Anthropic live-tool fast path. @@ -2601,7 +2664,7 @@ static bool anthropic_validate_tool_results(server *s, const chat_msgs *msgs, * Anthropic's visible replay normally includes the assistant tool_use JSON and * the user tool_result. That replay is still only a description of what the * model sampled. If the incoming tool_result IDs match the live sampled - * frontier, generate_job() can skip replay matching entirely and append just + * frontier, server_txn_run() can skip replay matching entirely and append just * EOS + tool_result + next assistant prefix to the real KV. */ static void anthropic_prepare_live_continuation(request *r, const chat_msgs *msgs) { @@ -2680,7 +2743,26 @@ static bool parse_chat_request(ds4_engine *e, server *s, const char *body, int d goto bad; } tool_choice_none = !strcmp(choice, "none"); + /* Like the Responses parser: "required" and forced function + * targets need constrained decoding we don't implement, so + * reject instead of silently downgrading to auto. */ + if (!tool_choice_none && strcmp(choice, "auto") != 0) { + snprintf(err, errlen, "tool_choice=%s not supported", choice); + free(choice); + free(key); + chat_msgs_free(&msgs); + free(tool_schemas); + request_free(r); + return false; + } free(choice); + } else if (*p == '{') { + snprintf(err, errlen, "forced tool_choice not supported"); + free(key); + chat_msgs_free(&msgs); + free(tool_schemas); + request_free(r); + return false; } else if (!json_skip_value(&p)) { free(key); goto bad; @@ -3145,7 +3227,7 @@ static bool parse_responses_content_array(const char **p, char **out) { * can render plain reasoning summaries/content, but it cannot decrypt * reasoning.encrypted_content. If live state is unavailable and the replay * only contains visible messages/tool calls, later validation marks it as a - * lower-fidelity replay; generate_job() logs that and continues from the + * lower-fidelity replay; server_txn_run() logs that and continues from the * visible transcript rather than killing a recoverable agent session. * * Reasoning items are merged into the next assistant message so @@ -4163,6 +4245,18 @@ static bool send_all(int fd, const void *p, size_t n) { return true; } +/* True when the client socket is closed or reset. A live but idle client + * reports EAGAIN; stray unread bytes count as alive. Never consumes data, so + * it is safe to call at any point of the request lifecycle. */ +static bool client_socket_gone(int fd) { + if (fd < 0) return true; + char b; + ssize_t n = recv(fd, &b, 1, MSG_PEEK | MSG_DONTWAIT); + if (n > 0) return false; + if (n == 0) return true; + return !(errno == EAGAIN || errno == EWOULDBLOCK || errno == EINTR); +} + static void json_escape(buf *b, const char *s) { buf_putc(b, '"'); for (; *s; s++) { @@ -4460,9 +4554,16 @@ static bool parse_generated_message_ex(const char *text, bool require_thinking_c if (require_thinking_closed) { const char *think_end = find_last_substr(text, ""); if (!think_end) { - /* Model did not close thinking, ignore any DSML in reasoning */ - fprintf(stderr, "ds4-server: thinking not closed, ignoring DSML in reasoning\n"); - split_reasoning_content(text, strlen(text), content_out, reasoning_out); + /* Thinking mode is on but the model never emitted — + * typically the response was truncated at max_tokens mid-thought + * (see #509). The accumulated text is unfinished reasoning, not a + * final answer: surface it as reasoning_content and leave content + * empty, matching what the live streaming classifier already does. + * Any DSML here is unclosed reasoning too, so it is deliberately + * not executed as a tool call. */ + size_t think_off = !strncmp(text, "", 7) ? 7 : 0; + *reasoning_out = xstrdup(text + think_off); + *content_out = xstrdup(""); return true; } tool_search = think_end + 8; @@ -4493,7 +4594,11 @@ static bool parse_generated_message_ex(const char *text, bool require_thinking_c } size_t content_len = trim_tool_separator_ws(text, 0, (size_t)(start - text)); - const char *raw_block_start = start; + /* Capture the raw block from the trimmed-content boundary, not from the + * marker match: any whitespace separator the model sampled between the + * content and the block lives in the KV cache, so byte-exact replay must + * include it even when it is not the canonical "\n\n". */ + const char *raw_block_start = text + content_len; const char *tool_calls_start = DS4_TOOL_CALLS_START; const char *tool_calls_end = DS4_TOOL_CALLS_END; const char *invoke_start = DS4_INVOKE_START; @@ -4798,7 +4903,9 @@ static bool http_response(int fd, bool enable_cors, int code, const char *type, code == 400 ? "Bad Request" : code == 404 ? "Not Found" : code == 409 ? "Conflict" : - code == 500 ? "Internal Server Error" : "Error"; + code == 429 ? "Too Many Requests" : + code == 500 ? "Internal Server Error" : + code == 503 ? "Service Unavailable" : "Error"; const size_t body_len = body ? strlen(body) : 0; buf h = {0}; buf_printf(&h, @@ -4822,7 +4929,28 @@ static bool http_error(int fd, bool enable_cors, int code, const char *msg) { buf b = {0}; buf_puts(&b, "{\"error\":{\"message\":"); json_escape(&b, msg); - buf_puts(&b, ",\"type\":\"invalid_request_error\"}}\n"); + buf_puts(&b, ",\"type\":\""); + buf_puts(&b, code >= 500 ? "api_error" : + code == 429 ? "rate_limit_error" : "invalid_request_error"); + buf_puts(&b, "\"}}\n"); + bool ok = http_response(fd, enable_cors, code, "application/json", b.ptr); + buf_free(&b); + return ok; +} + +/* Anthropic SDKs classify errors by the {"type":"error","error":{...}} + * envelope; give /v1/messages clients that shape instead of the OpenAI one. */ +static bool http_error_api(int fd, bool enable_cors, int code, const char *msg, + api_style api) { + if (api != API_ANTHROPIC) return http_error(fd, enable_cors, code, msg); + buf b = {0}; + buf_puts(&b, "{\"type\":\"error\",\"error\":{\"type\":\""); + buf_puts(&b, code >= 500 ? "api_error" : + code == 429 ? "rate_limit_error" : + code == 529 ? "overloaded_error" : "invalid_request_error"); + buf_puts(&b, "\",\"message\":"); + json_escape(&b, msg); + buf_puts(&b, "}}\n"); bool ok = http_response(fd, enable_cors, code, "application/json", b.ptr); buf_free(&b); return ok; @@ -7651,6 +7779,7 @@ typedef struct { size_t len; size_t bytes; int refs; + int invokes; uint64_t seen; tool_memory_entry *entries; } tool_memory_block; @@ -7705,14 +7834,465 @@ typedef struct { int live_tokens; char *visible_text; size_t visible_len; + /* True when this frontier ends in an assistant tool-call turn rather than + * a final answer; only used to label the cache hit source. */ + bool tool_turn; } visible_live_state; static bool id_list_contains(const stop_list *ids, const char *id); static void id_list_push_unique(stop_list *ids, const char *id); +/* Operational counters for GET /stats. Guarded by server.mu; every field is + * cheap to maintain because it piggybacks on decisions the request path + * already makes. */ +typedef struct { + uint64_t requests; + uint64_t queue_rejected; + uint64_t queue_dropped_disconnected; + uint64_t prefill_cancelled; + uint64_t cache_memory_token; + uint64_t cache_memory_text; + uint64_t cache_responses_visible; + uint64_t cache_responses_tool_output; + uint64_t cache_anthropic_tool_output; + uint64_t cache_thinking_visible; + uint64_t cache_tool_visible; + uint64_t cache_disk_text; + uint64_t cache_cold; + uint64_t prompt_tokens; + uint64_t cached_tokens; + uint64_t generated_tokens; + double last_prefill_tps; + double last_decode_tps; +} server_stats; + +/* Client threads serialize this value copy and never inspect the mutable model + * session. Only the worker publishes live_tokens; the remaining fields are + * sampled under server.mu at the same publication point. */ +typedef struct { + server_stats counters; + int queue_depth; + int clients; + int live_tokens; + int ctx_size; + bool busy; + uint64_t version; +} server_stats_snapshot; + +typedef enum { + SERVER_TXN_PHASE_ADMITTED = 0, + SERVER_TXN_PHASE_RESTORE, + SERVER_TXN_PHASE_SYNCHRONIZE, + SERVER_TXN_PHASE_EXTEND, + SERVER_TXN_PHASE_DECODE, + SERVER_TXN_PHASE_SETTLE, + SERVER_TXN_PHASE_TERMINALIZE, + SERVER_TXN_PHASE_DONE, +} server_txn_phase; + +typedef enum { + SERVER_TXN_COMPLETED = 0, + SERVER_TXN_REJECTED, + SERVER_TXN_CANCELLED, + SERVER_TXN_FAILED, +} server_txn_class; + +typedef enum { + SERVER_TXN_REASON_NONE = 0, + SERVER_TXN_REASON_STOP, + SERVER_TXN_REASON_LENGTH, + SERVER_TXN_REASON_TOOL_CALLS, + SERVER_TXN_REASON_CONTINUATION_UNAVAILABLE, + SERVER_TXN_REASON_CLIENT_GONE, + SERVER_TXN_REASON_CANCELLED, + SERVER_TXN_REASON_SHUTDOWN, + SERVER_TXN_REASON_RESTORE_FAILED, + SERVER_TXN_REASON_SYNC_FAILED, + SERVER_TXN_REASON_DECODE_FAILED, + SERVER_TXN_REASON_OUTPUT_FAILED, + SERVER_TXN_REASON_COMMIT_FAILED, + SERVER_TXN_REASON_INTERNAL, +} server_txn_reason; + +typedef enum { + SERVER_TXN_FINISH_NONE = 0, + SERVER_TXN_FINISH_STOP, + SERVER_TXN_FINISH_LENGTH, + SERVER_TXN_FINISH_TOOL_CALLS, + SERVER_TXN_FINISH_ERROR, +} server_txn_finish; + +typedef enum { + SERVER_SESSION_UNCHANGED = 0, + SERVER_SESSION_VALID_PREFIX, + SERVER_SESSION_COMMITTED, + SERVER_SESSION_INVALIDATED, +} server_session_disposition; + +typedef enum { + SERVER_WIRE_UNTOUCHED = 0, + SERVER_WIRE_STARTED, + SERVER_WIRE_IRREVERSIBLE, + SERVER_WIRE_COMPLETE, + SERVER_WIRE_BROKEN, +} server_wire_disposition; + +enum { + SERVER_TXN_SECONDARY_ROLLBACK = 1u << 0, + SERVER_TXN_SECONDARY_CHECKPOINT = 1u << 1, + SERVER_TXN_SECONDARY_OUTPUT = 1u << 2, + SERVER_TXN_SECONDARY_TRACE = 1u << 3, + SERVER_TXN_SECONDARY_STATS = 1u << 4, + SERVER_TXN_SECONDARY_CLEANUP = 1u << 5, +}; + +typedef struct { + server_txn_class class; + server_txn_phase decided_at; + server_txn_reason reason; + server_txn_finish finish; + server_session_disposition session; + server_wire_disposition wire; + uint32_t secondary; + int prompt_tokens; + int cached_tokens; + int generated_tokens; + char detail[160]; +} server_txn_outcome; + +typedef enum { + SERVER_TXN_STEP_CONTINUE = 0, + SERVER_TXN_STEP_TERMINAL, +} server_txn_step_status; + +typedef struct { + server_txn_step_status status; + server_txn_class class; + server_txn_reason reason; + server_txn_finish finish; + server_session_disposition session; + server_wire_disposition wire; + int prompt_tokens; + int cached_tokens; + int generated_tokens; + const char *detail; + uint32_t secondary; +} server_txn_step_result; + +typedef struct { + bool ok; + server_session_disposition session; + server_wire_disposition wire; + server_txn_class failure_class; + server_txn_reason failure_reason; + const char *failure_detail; + uint32_t secondary; +} server_txn_settle_result; + +typedef struct { + bool ok; + server_wire_disposition wire; + uint32_t secondary; +} server_txn_output_result; + +typedef struct server_txn server_txn; + +typedef enum { + SERVER_OUTPUT_PREFILL_TICK = 0, + SERVER_OUTPUT_STREAM_OPEN, + SERVER_OUTPUT_STREAM_UPDATE, + SERVER_OUTPUT_STREAM_FLUSH, +} server_output_operation; + +typedef struct { + server_output_operation operation; + const char *text; + size_t text_len; + size_t safe_len; + double now; + bool *headers_sent; + double *last_keepalive; +} server_output_observation; + +typedef enum { + SERVER_TRACE_BEGIN = 0, + SERVER_TRACE_EVENT, + SERVER_TRACE_PIECE, +} server_trace_operation; + +typedef struct { + server_trace_operation operation; + const char *text; + size_t text_len; +} server_trace_observation; + +typedef struct { + bool ok; + uint64_t trace_id; +} server_trace_result; + +typedef enum { + SERVER_STATS_QUEUED_DROP = 0, + SERVER_STATS_ADMIT, + SERVER_STATS_CACHE, + SERVER_STATS_PREFILL_CANCEL, + SERVER_STATS_PROGRESS, + SERVER_STATS_PREFILL_DONE, +} server_statistics_operation; + +typedef struct { + server_statistics_operation operation; + const char *cache_source; + int prompt_tokens; + int cached_tokens; + int live_tokens; + double elapsed; +} server_statistics_observation; + +typedef struct { + void *ctx; + server_txn_step_result (*advance)(void *ctx, + const server_txn_outcome *outcome, + server_txn_phase phase); + server_txn_settle_result (*settle)( + void *ctx, const server_txn_outcome *outcome, bool commit); + bool (*cleanup)(void *ctx, const server_txn_outcome *outcome); +} server_session_adapter; + +typedef struct { + void *ctx; + server_txn_output_result (*apply)( + void *ctx, const server_output_observation *observation); + server_txn_output_result (*finish)( + void *ctx, const server_txn_outcome *outcome); +} server_output_adapter; + +typedef struct { + void *ctx; + server_trace_result (*record)( + void *ctx, const server_trace_observation *observation); + bool (*finish)(void *ctx, const server_txn_outcome *outcome); +} server_trace_adapter; + +typedef struct { + void *ctx; + bool (*record)( + void *ctx, const server_statistics_observation *observation); + bool (*finish)(void *ctx, const server_txn_outcome *outcome); +} server_statistics_adapter; + +typedef struct { + server_session_adapter session; + server_output_adapter output; + server_trace_adapter trace; + server_statistics_adapter stats; +} server_txn_adapters; + +struct server_txn { + server_txn_outcome outcome; + server_txn_adapters adapters; + server_txn_phase phase; + bool failure_latched; + bool terminalizing; + bool terminalized; + bool settle_done; + bool output_done; + bool trace_done; + bool stats_done; + bool cleanup_done; +}; + +static void server_txn_init(server_txn *tx, + const server_txn_adapters *adapters) { + memset(tx, 0, sizeof(*tx)); + if (adapters) tx->adapters = *adapters; + tx->phase = SERVER_TXN_PHASE_ADMITTED; + tx->outcome.decided_at = SERVER_TXN_PHASE_ADMITTED; +} + +static void server_txn_complete(server_txn *tx, server_txn_reason reason, + server_txn_finish finish) { + if (!tx || tx->failure_latched || tx->terminalizing) return; + tx->outcome.class = SERVER_TXN_COMPLETED; + tx->outcome.decided_at = tx->phase; + tx->outcome.reason = reason; + tx->outcome.finish = finish; +} + +static bool server_txn_fail_once(server_txn *tx, server_txn_phase phase, + server_txn_class class, + server_txn_reason reason, + server_session_disposition session, + const char *detail) { + if (!tx || tx->failure_latched) return false; + tx->failure_latched = true; + tx->outcome.class = class; + tx->outcome.decided_at = phase; + tx->outcome.reason = reason; + if (tx->outcome.finish == SERVER_TXN_FINISH_NONE) { + tx->outcome.finish = SERVER_TXN_FINISH_ERROR; + } + tx->outcome.session = session; + snprintf(tx->outcome.detail, sizeof(tx->outcome.detail), "%s", + detail ? detail : ""); + return true; +} + +static server_txn_outcome server_txn_terminalize(server_txn *tx) { + if (tx->terminalized || tx->terminalizing) return tx->outcome; + tx->terminalizing = true; + tx->phase = SERVER_TXN_PHASE_TERMINALIZE; + if (tx->outcome.reason == SERVER_TXN_REASON_NONE) { + server_txn_fail_once(tx, SERVER_TXN_PHASE_TERMINALIZE, + SERVER_TXN_FAILED, SERVER_TXN_REASON_INTERNAL, + SERVER_SESSION_INVALIDATED, + "transaction reached terminalization without an outcome"); + } + + const bool commit = tx->outcome.class == SERVER_TXN_COMPLETED; + if (!tx->settle_done) { + tx->settle_done = true; + server_txn_settle_result result = { + .ok = false, + .session = tx->outcome.session, + .wire = tx->outcome.wire, + }; + if (tx->adapters.session.settle) { + result = tx->adapters.session.settle( + tx->adapters.session.ctx, &tx->outcome, commit); + } + tx->outcome.secondary |= result.secondary; + tx->outcome.wire = result.wire; + if (result.failure_reason != SERVER_TXN_REASON_NONE) { + if (!server_txn_fail_once( + tx, SERVER_TXN_PHASE_SETTLE, + result.failure_class, result.failure_reason, + result.session, result.failure_detail) && + result.failure_reason == SERVER_TXN_REASON_OUTPUT_FAILED) { + tx->outcome.secondary |= SERVER_TXN_SECONDARY_OUTPUT; + } + } + if (result.ok) { + tx->outcome.session = result.session; + } else { + tx->outcome.session = SERVER_SESSION_INVALIDATED; + if (commit) { + server_txn_fail_once(tx, SERVER_TXN_PHASE_SETTLE, + SERVER_TXN_FAILED, + SERVER_TXN_REASON_COMMIT_FAILED, + SERVER_SESSION_INVALIDATED, + "session commit failed"); + } else { + tx->outcome.secondary |= SERVER_TXN_SECONDARY_ROLLBACK; + } + } + } + + if (!tx->output_done) { + tx->output_done = true; + if (tx->outcome.wire != SERVER_WIRE_BROKEN) { + server_txn_output_result result = { + .ok = false, + .wire = tx->outcome.wire, + }; + if (tx->adapters.output.finish) { + result = tx->adapters.output.finish( + tx->adapters.output.ctx, &tx->outcome); + } + tx->outcome.secondary |= result.secondary; + tx->outcome.wire = result.wire; + if (!result.ok) { + tx->outcome.wire = SERVER_WIRE_BROKEN; + if (!server_txn_fail_once(tx, SERVER_TXN_PHASE_TERMINALIZE, + SERVER_TXN_FAILED, + SERVER_TXN_REASON_OUTPUT_FAILED, + tx->outcome.session, + "terminal output failed")) { + tx->outcome.secondary |= SERVER_TXN_SECONDARY_OUTPUT; + } + } + } + } + + if (!tx->trace_done) { + tx->trace_done = true; + if (!tx->adapters.trace.finish || + !tx->adapters.trace.finish(tx->adapters.trace.ctx, &tx->outcome)) { + tx->outcome.secondary |= SERVER_TXN_SECONDARY_TRACE; + } + } + if (!tx->cleanup_done) { + tx->cleanup_done = true; + if (!tx->adapters.session.cleanup || + !tx->adapters.session.cleanup( + tx->adapters.session.ctx, &tx->outcome)) { + tx->outcome.secondary |= SERVER_TXN_SECONDARY_CLEANUP; + } + } + if (!tx->stats_done) { + tx->stats_done = true; + if (!tx->adapters.stats.finish || + !tx->adapters.stats.finish(tx->adapters.stats.ctx, &tx->outcome)) { + tx->outcome.secondary |= SERVER_TXN_SECONDARY_STATS; + } + } + + tx->phase = SERVER_TXN_PHASE_DONE; + tx->terminalized = true; + tx->terminalizing = false; + return tx->outcome; +} + +static server_txn_outcome +server_txn_run_adapters(const server_txn_adapters *adapters) { + static const server_txn_phase phases[] = { + SERVER_TXN_PHASE_RESTORE, + SERVER_TXN_PHASE_SYNCHRONIZE, + SERVER_TXN_PHASE_EXTEND, + SERVER_TXN_PHASE_DECODE, + }; + server_txn tx; + server_txn_init(&tx, adapters); + for (size_t i = 0; i < sizeof(phases) / sizeof(phases[0]); i++) { + tx.phase = phases[i]; + if (!tx.adapters.session.advance) { + server_txn_fail_once(&tx, tx.phase, SERVER_TXN_FAILED, + SERVER_TXN_REASON_INTERNAL, + SERVER_SESSION_INVALIDATED, + "session adapter has no phase runner"); + break; + } + const server_txn_step_result step = + tx.adapters.session.advance( + tx.adapters.session.ctx, &tx.outcome, tx.phase); + tx.outcome.secondary |= step.secondary; + tx.outcome.wire = step.wire; + tx.outcome.prompt_tokens = step.prompt_tokens; + tx.outcome.cached_tokens = step.cached_tokens; + tx.outcome.generated_tokens = step.generated_tokens; + if (step.status == SERVER_TXN_STEP_CONTINUE) continue; + if (step.class == SERVER_TXN_COMPLETED) { + server_txn_complete(&tx, step.reason, step.finish); + tx.outcome.session = step.session; + } else { + server_txn_fail_once(&tx, tx.phase, step.class, step.reason, + step.session, step.detail); + } + break; + } + if (tx.outcome.reason == SERVER_TXN_REASON_NONE) { + server_txn_fail_once(&tx, tx.phase, SERVER_TXN_FAILED, + SERVER_TXN_REASON_INTERNAL, + SERVER_SESSION_INVALIDATED, + "session adapter finished without an outcome"); + } + return server_txn_terminalize(&tx); +} + struct server { ds4_engine *engine; ds4_session *session; + int ctx_size; int default_tokens; kv_disk_cache kv; tool_memory tool_mem; @@ -7728,11 +8308,20 @@ struct server { job *head; job *tail; bool stopping; + bool stats_refresh_requested; int clients; + int queue_depth; + int max_queue; + bool busy; + double started_at; + server_stats stats; + server_stats_snapshot stats_snapshot; uint64_t seq; FILE *trace; pthread_mutex_t trace_mu; uint64_t trace_seq; + pthread_t worker_thread; + bool worker_bound; }; /* Jobs are stack-owned by the client thread. The worker signals completion @@ -7741,12 +8330,29 @@ struct server { struct job { int fd; request req; + server_txn_outcome outcome; + bool outcome_ready; bool done; pthread_mutex_t mu; pthread_cond_t cv; job *next; }; +static void server_publish_stats_snapshot(server *s, int live_tokens) { + if (s->worker_bound && !pthread_equal(s->worker_thread, pthread_self())) { + die("worker ownership violation while publishing session statistics"); + } + pthread_mutex_lock(&s->mu); + s->stats_snapshot.counters = s->stats; + s->stats_snapshot.queue_depth = s->queue_depth; + s->stats_snapshot.clients = s->clients; + s->stats_snapshot.live_tokens = live_tokens; + s->stats_snapshot.ctx_size = s->ctx_size; + s->stats_snapshot.busy = s->busy; + s->stats_snapshot.version++; + pthread_mutex_unlock(&s->mu); +} + /* ========================================================================= * Tool Call Text Memory. * ========================================================================= @@ -7822,6 +8428,18 @@ static tool_memory_block *tool_memory_find_block_locked(tool_memory *m, return v == raxNotFound ? NULL : v; } +/* Number of invoke elements inside one remembered DSML block. A block is + * only replayable into a message that carries exactly this many calls. */ +static int dsml_count_invokes(const char *dsml) { + int n = 0; + for (const char *p = dsml; (p = strstr(p, DS4_INVOKE_START)) != NULL; + p += strlen(DS4_INVOKE_START)) n++; + if (n > 0) return n; + for (const char *p = dsml; (p = strstr(p, DS4_INVOKE_START_SHORT)) != NULL; + p += strlen(DS4_INVOKE_START_SHORT)) n++; + return n; +} + static tool_memory_block *tool_memory_get_block_locked(tool_memory *m, const char *dsml, size_t len) { @@ -7833,6 +8451,7 @@ static tool_memory_block *tool_memory_get_block_locked(tool_memory *m, b->dsml = xstrndup(dsml, len); b->len = len; b->bytes = len + 1 + sizeof(*b); + b->invokes = dsml_count_invokes(b->dsml); if (!raxInsert(m->by_block, (unsigned char *)b->dsml, b->len, b, NULL)) { free(b->dsml); free(b); @@ -7965,6 +8584,7 @@ static void visible_live_clear_locked(visible_live_state *st) { st->visible_text = NULL; st->visible_len = 0; st->live_tokens = 0; + st->tool_turn = false; st->valid = false; } @@ -7981,13 +8601,15 @@ static void thinking_live_clear(server *s) { pthread_mutex_unlock(&s->tool_mu); } -static void thinking_live_remember(server *s, const char *visible_text) { +static void thinking_live_remember(server *s, const char *visible_text, + bool tool_turn) { if (!s || !visible_text || !visible_text[0]) return; pthread_mutex_lock(&s->tool_mu); visible_live_clear_locked(&s->thinking_live); s->thinking_live.visible_text = xstrdup(visible_text); s->thinking_live.visible_len = strlen(visible_text); s->thinking_live.live_tokens = ds4_session_pos(s->session); + s->thinking_live.tool_turn = tool_turn; s->thinking_live.valid = true; pthread_mutex_unlock(&s->tool_mu); } @@ -8167,7 +8789,14 @@ static void tool_memory_attach_to_messages(server *s, chat_msgs *msgs, } if (source == TOOL_MEMORY_RAM) matched_source = TOOL_MEMORY_RAM; } - if (exact && matched) { + /* Replaying a block into a message that carries fewer calls than the + * block has invokes would duplicate the missing invokes into the + * rendered prompt (e.g. a client that splits one turn's parallel + * calls across two assistant messages). Such messages fall back to + * canonical JSON rendering. */ + const bool complete = matched && + (matched->invokes <= 0 || matched->invokes == calls->len); + if (exact && matched && complete) { calls->raw_dsml = xstrdup(matched->dsml); if (stats) { if (matched_source == TOOL_MEMORY_RAM) stats->mem++; @@ -8544,6 +9173,23 @@ static void kv_cache_restore_tool_memory_for_messages(server *s, const chat_msgs stop_list wanted = {0}; collect_tool_call_ids(msgs, &wanted); if (wanted.len == 0) return; + /* Agent requests replay every historical tool-call id on every turn. + * tool_memory_remember() already holds them in RAM, so only scan the + * cache directory for ids that are actually missing (the common case is + * none, except right after a server restart). */ + int missing = 0; + for (int i = 0; i < wanted.len; i++) { + if (tool_memory_has_id(s, wanted.v[i])) { + free(wanted.v[i]); + } else { + wanted.v[missing++] = wanted.v[i]; + } + } + wanted.len = missing; + if (wanted.len == 0) { + id_list_free(&wanted); + return; + } /* Tool replay payloads are stored next to KV checkpoints; keep them model * scoped too, since token positions and graph state are not portable across * Flash/Pro shapes even when the rendered chat text is identical. */ @@ -8724,9 +9370,9 @@ static bool kv_cache_store_live_prefix(server *s, const ds4_tokens *tokens, NULL, 0, NULL); } -static void kv_cache_store_current(server *s, const char *reason) { +static bool kv_cache_store_current(server *s, const char *reason) { const ds4_tokens *tokens = ds4_session_tokens(s->session); - if (!tokens) return; + if (!tokens) return true; char *visible_text = NULL; uint8_t visible_ext = 0; @@ -8756,13 +9402,16 @@ static void kv_cache_store_current(server *s, const char *reason) { * key that payload by the visible protocol transcript, not by rendering the * hidden sampled tokens. On load, DS4 restores the hidden KV payload and * tokenizes only the visible suffix that follows this key. */ + bool ok; if (visible_text) { - kv_cache_store_live_prefix_text(s, tokens, tokens->len, reason, - visible_text, visible_ext, visible_key); + ok = kv_cache_store_live_prefix_text(s, tokens, tokens->len, reason, + visible_text, visible_ext, + visible_key); free(visible_text); } else { - kv_cache_store_live_prefix(s, tokens, tokens->len, reason); + ok = kv_cache_store_live_prefix(s, tokens, tokens->len, reason); } + return ok; } static void kv_cache_note_store(kv_disk_cache *kc, int tokens) { @@ -8794,15 +9443,17 @@ static void kv_cache_discard_failed_disk_entry(server *s, const char *path) { ds4_session_invalidate(s->session); } -static void kv_cache_maybe_store_continued(server *s) { +static bool kv_cache_maybe_store_continued(server *s) { kv_disk_cache *kc = &s->kv; const ds4_tokens *tokens = ds4_session_tokens(s->session); - if (!tokens) return; + if (!tokens) return true; const int target = kv_cache_continued_store_target(kc, tokens->len); - if (target == 0) return; + if (target == 0) return true; if (kv_cache_store_live_prefix(s, tokens, target, "continued")) { kv_cache_note_store(kc, target); + return true; } + return false; } #ifdef DS4_SERVER_TEST @@ -8816,9 +9467,11 @@ static int kv_cache_try_load_text(server *s, const char *prompt_text, ds4_tokens *effective_prompt, char **loaded_path_out, uint8_t *loaded_ext_flags_out, + bool *loaded_consumed_out, bool responses_protocol) { if (loaded_path_out) *loaded_path_out = NULL; if (loaded_ext_flags_out) *loaded_ext_flags_out = 0; + if (loaded_consumed_out) *loaded_consumed_out = false; ds4_kvstore_load_result lr = {0}; ds4_kvstore_trailer_hooks hooks = kv_cache_tool_map_hooks(s, NULL); int loaded = ds4_kvstore_try_load_text(&s->kv, s->engine, s->session, @@ -8827,6 +9480,7 @@ static int kv_cache_try_load_text(server *s, const char *prompt_text, if (loaded > 0) { if (loaded_path_out && lr.path) *loaded_path_out = xstrdup(lr.path); if (loaded_ext_flags_out) *loaded_ext_flags_out = lr.ext_flags; + if (loaded_consumed_out) *loaded_consumed_out = lr.consumed; } ds4_kvstore_load_result_free(&lr); return loaded; @@ -8835,11 +9489,13 @@ static int kv_cache_try_load_text(server *s, const char *prompt_text, static int kv_cache_try_load(server *s, const request *req, ds4_tokens *effective_prompt, char **loaded_path_out, - uint8_t *loaded_ext_flags_out) { + uint8_t *loaded_ext_flags_out, + bool *loaded_consumed_out) { return kv_cache_try_load_text(s, req ? req->prompt_text : NULL, effective_prompt, loaded_path_out, loaded_ext_flags_out, + loaded_consumed_out, req && req->api == API_RESPONSES); } @@ -9309,6 +9965,27 @@ static void trace_finish( pthread_mutex_unlock(&s->trace_mu); } +static void server_trace_adapter_event( + const server_trace_adapter *adapter, uint32_t *secondary, + const char *fmt, ...) { + char message[512]; + va_list ap; + va_start(ap, fmt); + int n = vsnprintf(message, sizeof(message), fmt, ap); + va_end(ap); + size_t len = n > 0 ? (size_t)n : 0; + if (len >= sizeof(message)) len = sizeof(message) - 1; + const server_trace_observation observation = { + .operation = SERVER_TRACE_EVENT, + .text = message, + .text_len = len, + }; + if (!adapter || !adapter->record || + !adapter->record(adapter->ctx, &observation).ok) { + if (secondary) *secondary |= SERVER_TXN_SECONDARY_TRACE; + } +} + typedef struct { server *srv; req_kind kind; @@ -9331,9 +10008,28 @@ typedef struct { bool enable_cors; bool headers_sent; bool stream_failed; + server_wire_disposition *wire; + uint32_t *secondary; + server_output_adapter output; + server_statistics_adapter stats; double last_keepalive; } server_prefill_progress; +/* Cooperative prefill cancellation: ds4_session_sync() polls this at chunk + * boundaries and stops with a valid token prefix. Cancels on shutdown, on a + * failed SSE keepalive write, and on a disconnected client socket, so a gone + * client cannot burn minutes of prefill for a response nobody will read. */ +static bool server_sync_cancel_cb(void *ud) { + server_prefill_progress *p = ud; + if (g_stop_requested) return true; + if (p->stream_failed) return true; + if (client_socket_gone(p->fd)) { + p->stream_failed = true; + return true; + } + return false; +} + static void request_ctx_span(char *buf, size_t len, int cached, int prompt) { int suffix = prompt - cached; if (suffix < 0) suffix = 0; @@ -9630,34 +10326,32 @@ static void server_progress_cb(void *ud, const char *event, int current, int tot if (!is_chunk && !is_display) return; double now = now_sec(); - /* Keep the HTTP/SSE connection alive while prefill runs. We write the SSE - * response headers the first time the callback fires and then emit a - * comment line (`:` prefix, ignored by SSE clients) every few seconds. - * Best-effort: if the client has already gone away, the writes fail - * silently and the outer code will discover the closed socket the next - * time it tries to stream a real event. */ + /* Keep the HTTP/SSE connection alive through the output adapter while the + * worker is inside session synchronization. */ if (p->stream && p->fd >= 0 && !p->stream_failed) { - if (!p->headers_sent) { - p->headers_sent = true; - if (sse_headers(p->fd, p->enable_cors)) { - p->last_keepalive = now; - } else { - p->stream_failed = true; - } - } else if (now - p->last_keepalive >= 5.0) { - static const char ka[] = ": prefill\n\n"; - if (send_all(p->fd, ka, sizeof(ka) - 1)) { - p->last_keepalive = now; - } else { - p->stream_failed = true; - } + const server_output_observation observation = { + .operation = SERVER_OUTPUT_PREFILL_TICK, + .now = now, + .headers_sent = &p->headers_sent, + .last_keepalive = &p->last_keepalive, + }; + server_txn_output_result result = { + .ok = false, + .wire = p->wire ? *p->wire : SERVER_WIRE_UNTOUCHED, + }; + if (p->output.apply) { + result = p->output.apply(p->output.ctx, &observation); } + if (p->wire) *p->wire = result.wire; + if (!result.ok) p->stream_failed = true; } if (is_display) return; double elapsed = now - p->t0; if (p->seen && current == p->last_current) { if (p->srv && current > p->cached_tokens) { - kv_cache_maybe_store_continued(p->srv); + if (!kv_cache_maybe_store_continued(p->srv) && p->secondary) { + *p->secondary |= SERVER_TXN_SECONDARY_CHECKPOINT; + } } return; } @@ -9698,11 +10392,22 @@ static void server_progress_cb(void *ud, const char *event, int current, int tot avg_tps, elapsed); if (p->srv && current > p->cached_tokens) { - kv_cache_maybe_store_continued(p->srv); + if (!kv_cache_maybe_store_continued(p->srv) && p->secondary) { + *p->secondary |= SERVER_TXN_SECONDARY_CHECKPOINT; + } + } + if (p->srv && p->stats.record) { + const server_statistics_observation observation = { + .operation = SERVER_STATS_PROGRESS, + .live_tokens = ds4_session_pos(p->srv->session), + }; + if (!p->stats.record(p->stats.ctx, &observation) && p->secondary) { + *p->secondary |= SERVER_TXN_SECONDARY_STATS; + } } } -static void send_prefill_failure_response(server *s, const job *j, +static bool send_prefill_failure_response(server *s, const job *j, const server_prefill_progress *progress, const char *ctx, const char *flags, const char *err) { @@ -9713,17 +10418,18 @@ static void send_prefill_failure_response(server *s, const job *j, "ds4-server: %s ctx=%s%s%s prefill failed after stream closed: %s", kind, ctx, flags && flags[0] ? " " : "", flags && flags[0] ? flags : "", err); - return; + return false; } - if (!sse_error_event(j->fd, &j->req, err)) { + bool ok = sse_error_event(j->fd, &j->req, err); + if (!ok) { server_log(DS4_LOG_GENERATION, "ds4-server: %s ctx=%s%s%s prefill SSE error failed: %s", kind, ctx, flags && flags[0] ? " " : "", flags && flags[0] ? flags : "", err); } - return; + return ok; } - http_error(j->fd, s->enable_cors, 500, err); + return http_error_api(j->fd, s->enable_cors, 500, err, j->req.api); } static char *build_tool_checkpoint_suffix(const request *r, const char *content, @@ -9799,29 +10505,71 @@ static char *build_toolless_thinking_visible_text(const request *r, } static void remember_thinking_checkpoint(server *s, const job *j, const char *ctx, - uint64_t trace_id, const char *content) { + const server_trace_adapter *trace, + uint32_t *secondary, + const char *content) { char *visible = build_toolless_thinking_visible_text(&j->req, content); if (!visible) return; - thinking_live_remember(s, visible); + thinking_live_remember(s, visible, false); server_log(DS4_LOG_KVCACHE, "ds4-server: thinking live checkpoint remembered ctx=%s live=%d visible=%zu", ctx, ds4_session_pos(s->session), strlen(visible)); - trace_event(s, trace_id, - "thinking live checkpoint remembered: live=%d visible=%zu", - ds4_session_pos(s->session), strlen(visible)); + server_trace_adapter_event( + trace, secondary, + "thinking live checkpoint remembered: live=%d visible=%zu", + ds4_session_pos(s->session), strlen(visible)); free(visible); } +/* Chat/completions and Anthropic have no protocol object that binds the next + * request to this live tool-call frontier, and the sampled bytes (hidden + * reasoning, exact DSML spelling) never token-match the client's replay. But + * the text the next request will render for this turn is predictable: it is + * the same prompt_text + suffix that canonicalize_tool_checkpoint() builds. + * Remember it as a visible key for the live frontier so the next request + * continues in memory instead of taking the evict-store + disk-restore round + * trip on every agent turn. */ +static void remember_tool_visible_checkpoint(server *s, const job *j, + const char *ctx, + const server_trace_adapter *trace, + uint32_t *secondary, + const char *content, + const char *reasoning, + const tool_calls *calls) { + if (!j->req.prompt_text || !j->req.prompt_text[0]) { + thinking_live_clear(s); + return; + } + char *suffix = build_tool_checkpoint_suffix(&j->req, content, reasoning, calls); + buf visible = {0}; + buf_puts(&visible, j->req.prompt_text); + buf_puts(&visible, suffix ? suffix : ""); + thinking_live_remember(s, visible.ptr ? visible.ptr : "", true); + server_log(DS4_LOG_KVCACHE, + "ds4-server: tool live checkpoint remembered ctx=%s live=%d visible=%zu", + ctx, ds4_session_pos(s->session), visible.len); + server_trace_adapter_event( + trace, secondary, + "tool live checkpoint remembered: live=%d visible=%zu", + ds4_session_pos(s->session), visible.len); + buf_free(&visible); + free(suffix); +} + /* After a successful tool-call finish, make the live checkpoint match what the * next request will render. Usually that is just the exact DSML remembered by * tool id. If a client sends a tool call without an id we know, the fallback * renderer still builds valid DSML from JSON, and this function either rewrites * the short suffix in place or reloads an older disk checkpoint before replay. */ -static void canonicalize_tool_checkpoint(server *s, const job *j, const char *ctx, - uint64_t trace_id, const char *content, +static bool canonicalize_tool_checkpoint(server *s, const job *j, const char *ctx, + const server_txn_adapters *effects, + uint32_t *secondary, + server_wire_disposition *wire, + const char *content, const char *reasoning, const tool_calls *calls) { - if (!calls || calls->len == 0 || !j->req.prompt_text) return; + if (!calls || calls->len == 0 || !j->req.prompt_text) return true; + bool ok = true; char *suffix_text = build_tool_checkpoint_suffix(&j->req, content, reasoning, calls); @@ -9849,9 +10597,10 @@ static void canonicalize_tool_checkpoint(server *s, const job *j, const char *ct free(live_text); if (common < j->req.prompt.len) { - trace_event(s, trace_id, - "tool checkpoint canonicalization skipped: common=%d prompt=%d live=%d canonical=%d", - common, j->req.prompt.len, live_len, canonical.len); + server_trace_adapter_event( + effects ? &effects->trace : NULL, secondary, + "tool checkpoint canonicalization skipped: common=%d prompt=%d live=%d canonical=%d", + common, j->req.prompt.len, live_len, canonical.len); goto done; } @@ -9863,18 +10612,21 @@ static void canonicalize_tool_checkpoint(server *s, const job *j, const char *ct server_log(DS4_LOG_KVCACHE, "ds4-server: tool checkpoint canonicalized ctx=%s common=%d live=%d canonical=%d", ctx, common, live_len, canonical.len); - trace_event(s, trace_id, - "tool checkpoint canonicalized: common=%d live=%d canonical=%d", - common, live_len, canonical.len); + server_trace_adapter_event( + effects ? &effects->trace : NULL, secondary, + "tool checkpoint canonicalized: common=%d live=%d canonical=%d", + common, live_len, canonical.len); } else if (rr == DS4_SESSION_REWRITE_REBUILD_NEEDED) { /* The generated DSML suffix and the canonical prompt share a prefix, * but the generated tail is too large to overwrite safely inside the * live raw-window ring. Prefer an older disk checkpoint over replaying * a very long conversation from token zero. */ char *path = NULL; + bool path_consumed = false; ds4_tokens effective = {0}; int loaded = kv_cache_try_load_text(s, rendered.ptr ? rendered.ptr : "", - &effective, &path, NULL, false); + &effective, &path, NULL, + &path_consumed, false); if (loaded == 0) ds4_session_invalidate(s->session); char sync_err[160] = {0}; @@ -9914,6 +10666,10 @@ static void canonicalize_tool_checkpoint(server *s, const job *j, const char *ct .fd = j->fd, .stream = j->req.stream, .enable_cors = s->enable_cors, + .wire = wire, + .secondary = secondary, + .output = effects ? effects->output : (server_output_adapter) {0}, + .stats = effects ? effects->stats : (server_statistics_adapter) {0}, /* Tool checkpoint rebuild only runs after the response stream is * already in flight, so the SSE headers were sent long ago. * Pre-arm the flag so the progress callback only emits keepalive @@ -9923,33 +10679,47 @@ static void canonicalize_tool_checkpoint(server *s, const job *j, const char *ct snprintf(rebuild_progress.ctx, sizeof(rebuild_progress.ctx), "%s", rebuild_ctx); ds4_session_set_progress(s->session, server_progress_cb, &rebuild_progress); ds4_session_set_display_progress(s->session, server_progress_cb, &rebuild_progress); + ds4_session_set_cancel(s->session, server_sync_cancel_cb, &rebuild_progress); if (ds4_session_sync(s->session, sync_prompt, sync_err, sizeof(sync_err)) == 0) { + ds4_session_set_cancel(s->session, NULL, NULL); ds4_session_set_progress(s->session, NULL, NULL); ds4_session_set_display_progress(s->session, NULL, NULL); + if (path_consumed && path && unlink(path) != 0 && errno != ENOENT && + secondary) { + *secondary |= SERVER_TXN_SECONDARY_CHECKPOINT; + } const double rebuild_sec = now_sec() - rebuild_t0; if (loaded > 0) { server_log(DS4_LOG_KVCACHE, "ds4-server: tool checkpoint rebuild done ctx=%s request_ctx=%s source=disk cached=%d replay=%d target=%d %.3fs", rebuild_ctx, ctx, loaded, replay_tokens, canonical.len, rebuild_sec); - trace_event(s, trace_id, - "tool checkpoint canonicalized via disk: common=%d live=%d canonical=%d cached=%d file=%s", - common, live_len, canonical.len, loaded, path ? path : ""); + server_trace_adapter_event( + effects ? &effects->trace : NULL, secondary, + "tool checkpoint canonicalized via disk: common=%d live=%d canonical=%d cached=%d file=%s", + common, live_len, canonical.len, loaded, + path ? path : ""); } else { server_log(DS4_LOG_KVCACHE, "ds4-server: tool checkpoint rebuild done ctx=%s request_ctx=%s source=full cached=0 replay=%d target=%d %.3fs", rebuild_ctx, ctx, replay_tokens, canonical.len, rebuild_sec); - trace_event(s, trace_id, - "tool checkpoint canonicalized via rebuild: common=%d live=%d canonical=%d reason=%s", - common, live_len, canonical.len, err); + server_trace_adapter_event( + effects ? &effects->trace : NULL, secondary, + "tool checkpoint canonicalized via rebuild: common=%d live=%d canonical=%d reason=%s", + common, live_len, canonical.len, err); } } else { + ds4_session_set_cancel(s->session, NULL, NULL); ds4_session_set_progress(s->session, NULL, NULL); ds4_session_set_display_progress(s->session, NULL, NULL); server_log(DS4_LOG_KVCACHE, "ds4-server: tool checkpoint rebuild failed ctx=%s request_ctx=%s source=%s cached=%d replay=%d target=%d error=\"%s\"", rebuild_ctx, ctx, source, loaded, replay_tokens, canonical.len, sync_err); - trace_event(s, trace_id, "tool checkpoint canonicalization failed after rebuild request: %s", sync_err); + server_trace_adapter_event( + effects ? &effects->trace : NULL, secondary, + "tool checkpoint canonicalization failed after rebuild request: %s", + sync_err); + ok = false; } ds4_tokens_free(&effective); free(path); @@ -9957,13 +10727,17 @@ static void canonicalize_tool_checkpoint(server *s, const job *j, const char *ct server_log(DS4_LOG_KVCACHE, "ds4-server: tool checkpoint canonicalization failed ctx=%s common=%d live=%d canonical=%d error=\"%s\"", ctx, common, live_len, canonical.len, err); - trace_event(s, trace_id, "tool checkpoint canonicalization failed: %s", err); + server_trace_adapter_event( + effects ? &effects->trace : NULL, secondary, + "tool checkpoint canonicalization failed: %s", err); + ok = false; } done: ds4_tokens_free(&canonical); buf_free(&rendered); free(suffix_text); + return ok; } static bool should_canonicalize_tool_checkpoint(const server *s, const tool_calls *calls) { @@ -9976,44 +10750,491 @@ static bool should_canonicalize_tool_checkpoint(const server *s, const tool_call return true; } -/* Execute one request on the worker-owned session. - * - * Clients resend full prompts as text. The worker first tries the old exact - * token-prefix hit, then a rendered-text prefix hit for the live checkpoint, - * then disk text-prefix restart snapshots, then a cold prefill. On text-prefix - * hits we build a fresh effective prompt from the checkpoint's exact token - * history plus a newly tokenized string suffix; the canonical full-prompt - * tokens are not sliced because BPE may merge across the byte boundary. Cold - * prompt caching is handled before generation: if the stable checkpoint is - * shorter than the full prompt, we prefill to that boundary, store it, and - * immediately continue to the real prompt. The live graph therefore always - * moves forward. */ -static void generate_job(server *s, job *j) { +typedef enum { + PRODUCTION_REPLY_NONE = 0, + PRODUCTION_REPLY_RESPONSES_CONFLICT, + PRODUCTION_REPLY_ANTHROPIC_CONFLICT, + PRODUCTION_REPLY_PREFILL_ERROR, + PRODUCTION_REPLY_NORMAL, +} production_reply; + +typedef struct production_txn { + server *srv; + job *job; + server_txn_adapters effects; + production_reply reply; + server_wire_disposition wire; + server_txn_class first_failure_class; + server_txn_reason first_failure_reason; + server_session_disposition first_failure_session; + char first_failure_detail[160]; + uint32_t phase_secondary; + bool normal_ready; + bool callbacks_attached; + bool count_generated; + bool counted_request; + bool session_entered; + bool responses_protocol; + bool structured_stream; + bool openai_live_chat; + bool responses_live_chat; + bool responses_live_continuation; + bool anthropic_live_continuation; + bool thinking_live_continuation; + bool disk_cache_consume; + bool recovered_tool_parse_failure; + bool saw_tool_start; + bool saw_tool_end; + int cached; + int prompt_tokens; + int completion; + size_t plain_stream_pos; + double started_at; + double decode_started_at; + uint64_t trace_id; + trace_cache_diag trace_cache; + char cache_source[32]; + int disk_cached; + long responses_created_at; + const char *final_finish; + const ds4_tokens *prompt_for_sync; char err[160]; - err[0] = '\0'; - const int old_pos = ds4_session_pos(s->session); - const int common = ds4_session_common_prefix(s->session, &j->req.prompt); - trace_cache_diag cache_diag = {0}; - trace_cache_capture(&cache_diag, ds4_session_tokens(s->session), - &j->req.prompt, old_pos, common); - ds4_tokens effective_prompt = {0}; - const ds4_tokens *prompt_for_sync = &j->req.prompt; - const bool responses_protocol = j->req.api == API_RESPONSES; - bool responses_live_continuation = false; - bool anthropic_live_continuation = false; - bool thinking_live_continuation = false; - const char *responses_live_match = NULL; - int responses_live_match_ids = 0; - int anthropic_live_match_ids = 0; - /* Responses gets the first chance to continue from live state. This is - * the whole point of the API shape: a request that is bound to prior live - * output by visible transcript or tool call ids does not need to prove an - * exact token-prefix match. Exact token/text/disk matching remains the - * fallback when the live state is absent or no longer describes the - * request. */ - int cached = responses_live_visible_prefix_prompt(s, &j->req, old_pos, - &effective_prompt); - const char *cache_source = cached > 0 ? "responses-visible" : "none"; + char ctx_span[48]; + char req_flags[64]; + char response_id[96]; + char *disk_cache_path; + ds4_tokens effective_prompt; + server_prefill_progress progress; + anthropic_stream anthropic_live; + openai_stream openai_live; + responses_stream responses_live; + thinking_state thinking; + buf text; + tool_calls parsed_calls; + char *parsed_content; + char *parsed_reasoning; +} production_txn; + +static server_txn_step_result production_session_advance( + void *ctx, const server_txn_outcome *outcome, server_txn_phase phase); +static server_txn_settle_result production_session_settle( + void *ctx, const server_txn_outcome *outcome, bool commit); +static bool production_session_cleanup( + void *ctx, const server_txn_outcome *outcome); +static server_txn_output_result production_output_finish( + void *ctx, const server_txn_outcome *outcome); +static server_txn_output_result production_output_apply( + void *ctx, const server_output_observation *observation); +static bool production_trace_finish( + void *ctx, const server_txn_outcome *outcome); +static server_trace_result production_trace_record( + void *ctx, const server_trace_observation *observation); +static bool production_statistics_finish( + void *ctx, const server_txn_outcome *outcome); +static bool production_statistics_record( + void *ctx, const server_statistics_observation *observation); + +static bool production_latch_failure( + production_txn *p, server_txn_class class, + server_txn_reason reason, server_session_disposition session, + const char *detail) { + if (p->first_failure_reason != SERVER_TXN_REASON_NONE) { + if (reason == SERVER_TXN_REASON_OUTPUT_FAILED) { + p->phase_secondary |= SERVER_TXN_SECONDARY_OUTPUT; + } + return false; + } + p->first_failure_class = class; + p->first_failure_reason = reason; + p->first_failure_session = session; + snprintf(p->first_failure_detail, sizeof(p->first_failure_detail), "%s", + detail ? detail : ""); + return true; +} + +static server_txn_reason production_peer_gone_reason(void) { + return g_stop_requested ? SERVER_TXN_REASON_SHUTDOWN : + SERVER_TXN_REASON_CLIENT_GONE; +} + +static server_session_disposition production_live_session( + const production_txn *p) { + return ds4_session_is_valid(p->srv->session) ? + SERVER_SESSION_VALID_PREFIX : SERVER_SESSION_INVALIDATED; +} + +static void production_observe_trace( + production_txn *p, server_trace_operation operation, + const char *text, size_t text_len) { + if (!p->effects.trace.record) { + p->phase_secondary |= SERVER_TXN_SECONDARY_TRACE; + return; + } + const server_trace_observation observation = { + .operation = operation, + .text = text, + .text_len = text_len, + }; + const server_trace_result result = + p->effects.trace.record(p->effects.trace.ctx, &observation); + if (operation == SERVER_TRACE_BEGIN) p->trace_id = result.trace_id; + if (!result.ok) p->phase_secondary |= SERVER_TXN_SECONDARY_TRACE; +} + +static void production_observe_trace_event( + production_txn *p, const char *fmt, ...) { + char message[512]; + va_list ap; + va_start(ap, fmt); + int n = vsnprintf(message, sizeof(message), fmt, ap); + va_end(ap); + size_t len = n > 0 ? (size_t)n : 0; + if (len >= sizeof(message)) len = sizeof(message) - 1; + production_observe_trace(p, SERVER_TRACE_EVENT, message, len); +} + +static void production_observe_stats( + production_txn *p, + const server_statistics_observation *observation) { + if (!p->effects.stats.record || + !p->effects.stats.record(p->effects.stats.ctx, observation)) { + p->phase_secondary |= SERVER_TXN_SECONDARY_STATS; + } +} + +static server_txn_output_result production_output_apply( + void *ctx, const server_output_observation *observation) { + production_txn *p = ctx; + server *s = p->srv; + job *j = p->job; + bool ok = true; + + if (p->wire == SERVER_WIRE_BROKEN) { + return (server_txn_output_result) { + .ok = true, + .wire = SERVER_WIRE_BROKEN, + }; + } + + switch (observation->operation) { + case SERVER_OUTPUT_PREFILL_TICK: + if (!observation->headers_sent || !observation->last_keepalive) { + snprintf(p->err, sizeof(p->err), + "prefill output state is unavailable"); + ok = false; + break; + } + if (!*observation->headers_sent) { + *observation->headers_sent = true; + p->wire = SERVER_WIRE_IRREVERSIBLE; + if (sse_headers(j->fd, s->enable_cors)) { + *observation->last_keepalive = observation->now; + } else { + ok = false; + } + } else if (observation->now - *observation->last_keepalive >= 5.0) { + static const char keepalive[] = ": prefill\n\n"; + p->wire = SERVER_WIRE_IRREVERSIBLE; + if (send_all(j->fd, keepalive, sizeof(keepalive) - 1)) { + *observation->last_keepalive = observation->now; + } else { + ok = false; + } + } + break; + + case SERVER_OUTPUT_STREAM_OPEN: + if (!j->req.stream) break; + if (!p->progress.headers_sent) p->wire = SERVER_WIRE_IRREVERSIBLE; + if (!p->progress.headers_sent && + !sse_headers(j->fd, s->enable_cors)) { + server_log(DS4_LOG_GENERATION, + "ds4-server: %s ctx=%s%s%s sse headers failed", + j->req.kind == REQ_CHAT ? "chat" : "completion", + p->ctx_span, + p->req_flags[0] ? " " : "", + p->req_flags); + snprintf(p->err, sizeof(p->err), "SSE headers failed"); + ok = false; + break; + } + p->progress.headers_sent = true; + if (j->req.api == API_ANTHROPIC && + !anthropic_sse_start_live(j->fd, &j->req, p->response_id, + p->prompt_tokens, + &p->anthropic_live)) { + server_log(DS4_LOG_GENERATION, + "ds4-server: chat ctx=%s anthropic stream start failed", + p->ctx_span); + snprintf(p->err, sizeof(p->err), + "Anthropic stream start failed"); + ok = false; + break; + } + if (j->req.api == API_OPENAI && j->req.kind == REQ_CHAT && + !sse_chunk(j->fd, &j->req, p->response_id, NULL, NULL)) { + server_log(DS4_LOG_GENERATION, + "ds4-server: chat ctx=%s openai role chunk failed", + p->ctx_span); + snprintf(p->err, sizeof(p->err), + "OpenAI role chunk failed"); + ok = false; + break; + } + if (p->openai_live_chat) { + openai_stream_start(&j->req, &p->openai_live); + } + if (p->responses_live_chat) { + responses_stream_init(&j->req, &p->responses_live); + p->responses_live.active = true; + if (!responses_sse_created(j->fd, &j->req, + &p->responses_live, + p->responses_created_at)) { + server_log(DS4_LOG_GENERATION, + "ds4-server: chat ctx=%s%s%s responses created event failed", + p->ctx_span, + p->req_flags[0] ? " " : "", + p->req_flags); + snprintf(p->err, sizeof(p->err), + "Responses created event failed"); + ok = false; + break; + } + } + p->wire = SERVER_WIRE_IRREVERSIBLE; + break; + + case SERVER_OUTPUT_STREAM_UPDATE: + if (!j->req.stream) break; + if (!p->structured_stream && + observation->safe_len > p->plain_stream_pos) { + char *delta = xstrndup( + observation->text + p->plain_stream_pos, + observation->safe_len - p->plain_stream_pos); + ok = sse_chunk(j->fd, &j->req, p->response_id, delta, NULL); + free(delta); + if (ok) p->plain_stream_pos = observation->safe_len; + } + if (ok && j->req.api == API_ANTHROPIC) { + ok = anthropic_sse_stream_update( + j->fd, s, &j->req, p->response_id, + &p->anthropic_live, observation->text, + observation->safe_len, false); + } + if (ok && p->openai_live_chat) { + ok = openai_sse_stream_update( + j->fd, s, &j->req, p->response_id, + &p->openai_live, observation->text, + observation->safe_len, false); + } + if (ok && p->responses_live_chat) { + ok = responses_sse_stream_update( + j->fd, &j->req, &p->responses_live, + observation->text, observation->safe_len, false); + } + if (!ok) { + snprintf(p->err, sizeof(p->err), + "client stream write failed"); + } + break; + + case SERVER_OUTPUT_STREAM_FLUSH: + if (j->req.stream && !p->structured_stream && + observation->text_len > p->plain_stream_pos) { + char *tail = xstrndup( + observation->text + p->plain_stream_pos, + observation->text_len - p->plain_stream_pos); + ok = sse_chunk(j->fd, &j->req, p->response_id, tail, NULL); + free(tail); + if (ok) p->plain_stream_pos = observation->text_len; + else snprintf(p->err, sizeof(p->err), + "client stream write failed"); + } + break; + } + + if (!ok) { + p->wire = SERVER_WIRE_BROKEN; + production_latch_failure( + p, SERVER_TXN_FAILED, SERVER_TXN_REASON_OUTPUT_FAILED, + production_live_session(p), p->err); + } + return (server_txn_output_result) { + .ok = ok, + .wire = p->wire, + }; +} + +static server_trace_result production_trace_record( + void *ctx, const server_trace_observation *observation) { + production_txn *p = ctx; + server *s = p->srv; + uint64_t trace_id = p->trace_id; + if (observation->operation == SERVER_TRACE_BEGIN) { + trace_id = trace_begin( + s, p->job, p->cached, p->prompt_tokens, &p->trace_cache, + p->cache_source, p->disk_cached, p->disk_cache_path); + } else if (observation->operation == SERVER_TRACE_EVENT) { + trace_event(s, p->trace_id, "%.*s", (int)observation->text_len, + observation->text ? observation->text : ""); + } else { + trace_piece(s, p->trace_id, observation->text, + observation->text_len); + } + return (server_trace_result) { + .ok = !s->trace || !ferror(s->trace), + .trace_id = trace_id, + }; +} + +static bool production_statistics_record( + void *ctx, const server_statistics_observation *observation) { + production_txn *p = ctx; + server *s = p->srv; + if (observation->operation == SERVER_STATS_QUEUED_DROP) { + pthread_mutex_lock(&s->mu); + s->stats.queue_dropped_disconnected++; + pthread_mutex_unlock(&s->mu); + } else if (observation->operation == SERVER_STATS_ADMIT) { + pthread_mutex_lock(&s->mu); + s->busy = true; + s->stats.requests++; + pthread_mutex_unlock(&s->mu); + server_publish_stats_snapshot(s, observation->live_tokens); + } else if (observation->operation == SERVER_STATS_CACHE) { + pthread_mutex_lock(&s->mu); + const char *source = observation->cache_source; + if (!strcmp(source, "memory-token")) s->stats.cache_memory_token++; + else if (!strcmp(source, "memory-text")) s->stats.cache_memory_text++; + else if (!strcmp(source, "responses-visible")) s->stats.cache_responses_visible++; + else if (!strcmp(source, "responses-tool-output")) s->stats.cache_responses_tool_output++; + else if (!strcmp(source, "anthropic-tool-output")) s->stats.cache_anthropic_tool_output++; + else if (!strcmp(source, "thinking-visible")) s->stats.cache_thinking_visible++; + else if (!strcmp(source, "tool-visible")) s->stats.cache_tool_visible++; + else if (!strcmp(source, "disk-text")) s->stats.cache_disk_text++; + else s->stats.cache_cold++; + s->stats.prompt_tokens += (uint64_t)observation->prompt_tokens; + s->stats.cached_tokens += + (uint64_t)(observation->cached_tokens > 0 ? + observation->cached_tokens : 0); + pthread_mutex_unlock(&s->mu); + } else if (observation->operation == SERVER_STATS_PREFILL_CANCEL) { + pthread_mutex_lock(&s->mu); + s->stats.prefill_cancelled++; + pthread_mutex_unlock(&s->mu); + } else if (observation->operation == SERVER_STATS_PROGRESS) { + server_publish_stats_snapshot(s, observation->live_tokens); + } else if (observation->operation == SERVER_STATS_PREFILL_DONE && + observation->prompt_tokens > observation->cached_tokens && + observation->elapsed > 0.0) { + pthread_mutex_lock(&s->mu); + s->stats.last_prefill_tps = + (double)(observation->prompt_tokens - + observation->cached_tokens) / observation->elapsed; + pthread_mutex_unlock(&s->mu); + } + return true; +} + +static server_txn_step_result production_continue(production_txn *p) { + return (server_txn_step_result) { + .status = SERVER_TXN_STEP_CONTINUE, + .wire = p->wire, + .prompt_tokens = p->prompt_tokens, + .cached_tokens = p->cached, + .generated_tokens = p->completion, + .secondary = p->phase_secondary, + }; +} + +static server_txn_step_result production_terminal( + production_txn *p, server_txn_class class, + server_txn_reason reason, server_txn_finish finish, + server_session_disposition session, const char *detail) { + if (p->first_failure_reason != SERVER_TXN_REASON_NONE) { + class = p->first_failure_class; + reason = p->first_failure_reason; + session = p->first_failure_session; + detail = p->first_failure_detail; + } + return (server_txn_step_result) { + .status = SERVER_TXN_STEP_TERMINAL, + .class = class, + .reason = reason, + .finish = finish, + .session = session, + .wire = p->wire, + .prompt_tokens = p->prompt_tokens, + .cached_tokens = p->cached, + .generated_tokens = p->completion, + .detail = detail, + .secondary = p->phase_secondary, + }; +} + +/* Execute one request on the worker-owned session. + * + * Clients resend full prompts as text. The worker first tries the old exact + * token-prefix hit, then a rendered-text prefix hit for the live checkpoint, + * then disk text-prefix restart snapshots, then a cold prefill. On text-prefix + * hits we build a fresh effective prompt from the checkpoint's exact token + * history plus a newly tokenized string suffix; the canonical full-prompt + * tokens are not sliced because BPE may merge across the byte boundary. Cold + * prompt caching is handled before generation: if the stable checkpoint is + * shorter than the full prompt, we prefill to that boundary, store it, and + * immediately continue to the real prompt. The live graph therefore always + * moves forward. */ +static server_txn_step_result production_restore( + production_txn *p, const server_txn_outcome *outcome) { + server *s = p->srv; + job *j = p->job; + (void)outcome; + if (client_socket_gone(j->fd)) { + const server_txn_reason reason = production_peer_gone_reason(); + const char *detail = reason == SERVER_TXN_REASON_SHUTDOWN ? + "shutdown requested" : "client disconnected while queued"; + server_log(DS4_LOG_WARNING, + "ds4-server: dropping queued request: %s", detail); + const server_statistics_observation stats = { + .operation = SERVER_STATS_QUEUED_DROP, + }; + production_observe_stats(p, &stats); + return production_terminal( + p, SERVER_TXN_CANCELLED, reason, SERVER_TXN_FINISH_ERROR, + SERVER_SESSION_UNCHANGED, detail); + } + if (s->worker_bound && !pthread_equal(s->worker_thread, pthread_self())) { + die("worker ownership violation while executing a session transaction"); + } + p->counted_request = true; + p->session_entered = true; + const server_statistics_observation admitted = { + .operation = SERVER_STATS_ADMIT, + .live_tokens = ds4_session_pos(s->session), + }; + production_observe_stats(p, &admitted); + + const int old_pos = ds4_session_pos(s->session); + const int common = ds4_session_common_prefix(s->session, &j->req.prompt); + trace_cache_capture(&p->trace_cache, ds4_session_tokens(s->session), + &j->req.prompt, old_pos, common); + p->prompt_for_sync = &j->req.prompt; + const bool responses_protocol = j->req.api == API_RESPONSES; + bool responses_live_continuation = false; + bool anthropic_live_continuation = false; + bool thinking_live_continuation = false; + const char *responses_live_match = NULL; + int responses_live_match_ids = 0; + int anthropic_live_match_ids = 0; + /* Responses gets the first chance to continue from live state. This is + * the whole point of the API shape: a request that is bound to prior live + * output by visible transcript or tool call ids does not need to prove an + * exact token-prefix match. Exact token/text/disk matching remains the + * fallback when the live state is absent or no longer describes the + * request. */ + int cached = responses_live_visible_prefix_prompt(s, &j->req, old_pos, + &p->effective_prompt); + const char *cache_source = cached > 0 ? "responses-visible" : "none"; if (cached > 0) { responses_live_match = "visible-prefix"; if (responses_live_matches_request(s, &j->req.responses_live_call_ids, @@ -10024,22 +11245,22 @@ static void generate_job(server *s, job *j) { } if (cached == 0) { cached = responses_live_continuation_prompt(s, &j->req, old_pos, - &effective_prompt, + &p->effective_prompt, &responses_live_match_ids); cache_source = cached > 0 ? "responses-tool-output" : "none"; if (cached > 0) responses_live_match = "tool-output-ids"; } if (cached > 0) { responses_live_continuation = true; - prompt_for_sync = &effective_prompt; + p->prompt_for_sync = &p->effective_prompt; } else { cached = anthropic_live_continuation_prompt(s, &j->req, old_pos, - &effective_prompt, + &p->effective_prompt, &anthropic_live_match_ids); if (cached > 0) { anthropic_live_continuation = true; cache_source = "anthropic-tool-output"; - prompt_for_sync = &effective_prompt; + p->prompt_for_sync = &p->effective_prompt; } } if (cached == 0 && responses_protocol && @@ -10049,17 +11270,21 @@ static void generate_job(server *s, job *j) { * live frontier no longer matches. Since the request did not replay * the prior assistant call, there is no stateless prefix to match and * no disk key to search by. */ - ds4_tokens_free(&effective_prompt); - http_error(j->fd, s->enable_cors, 409, - "Responses continuation state is not available; retry by replaying the full input history"); - return; + p->reply = PRODUCTION_REPLY_RESPONSES_CONFLICT; + return production_terminal( + p, SERVER_TXN_REJECTED, + SERVER_TXN_REASON_CONTINUATION_UNAVAILABLE, + SERVER_TXN_FINISH_ERROR, SERVER_SESSION_UNCHANGED, + "Responses continuation state is not available; retry by replaying the full input history"); } else if (cached == 0 && j->req.api == API_ANTHROPIC && j->req.anthropic_requires_live_tool_state) { - ds4_tokens_free(&effective_prompt); - http_error(j->fd, s->enable_cors, 409, - "Anthropic continuation state is not available; retry by replaying the full messages history"); - return; + p->reply = PRODUCTION_REPLY_ANTHROPIC_CONFLICT; + return production_terminal( + p, SERVER_TXN_REJECTED, + SERVER_TXN_REASON_CONTINUATION_UNAVAILABLE, + SERVER_TXN_FINISH_ERROR, SERVER_SESSION_UNCHANGED, + "Anthropic continuation state is not available; retry by replaying the full messages history"); } else if (cached == 0) { cached = common == old_pos && j->req.prompt.len >= old_pos ? common : 0; cache_source = cached > 0 ? "memory-token" : "none"; @@ -10067,23 +11292,27 @@ static void generate_job(server *s, job *j) { if (cached == 0) { int thinking_cached = thinking_live_visible_prefix_prompt(s, &j->req, old_pos, - &effective_prompt); + &p->effective_prompt); if (thinking_cached > 0) { cached = thinking_cached; - cache_source = "thinking-visible"; + pthread_mutex_lock(&s->tool_mu); + cache_source = s->thinking_live.tool_turn ? + "tool-visible" : "thinking-visible"; + pthread_mutex_unlock(&s->tool_mu); thinking_live_continuation = true; - prompt_for_sync = &effective_prompt; + p->prompt_for_sync = &p->effective_prompt; } } int disk_cached = 0; - char *disk_cache_path = NULL; + bool disk_cache_consume = false; uint8_t disk_cache_ext_flags = 0; if (cached == 0) { - int text_cached = live_text_prefix_prompt(s, &j->req, &effective_prompt); + int text_cached = live_text_prefix_prompt(s, &j->req, + &p->effective_prompt); if (text_cached > 0) { cached = text_cached; cache_source = "memory-text"; - prompt_for_sync = &effective_prompt; + p->prompt_for_sync = &p->effective_prompt; } } if (cached == 0 && old_pos > 0) { @@ -10091,25 +11320,35 @@ static void generate_job(server *s, job *j) { "ds4-server: live kv cache miss%s live=%d prompt=%d common=%d reason=%s", responses_protocol ? " RESPPROTO" : "", old_pos, j->req.prompt.len, common, - trace_cache_miss_reason(&cache_diag)); + trace_cache_miss_reason(&p->trace_cache)); } if (cached == 0) s->kv.continued_last_store_tokens = 0; if (s->kv.enabled && cached == 0 && old_pos >= s->kv.opt.min_tokens) { /* Loading a disk snapshot replaces the live Metal session. Persist the * current checkpoint first, otherwise a cache hit for an older prefix * would silently discard the newer conversation state. */ - kv_cache_store_current(s, "evict"); + if (!kv_cache_store_current(s, "evict")) { + p->phase_secondary |= SERVER_TXN_SECONDARY_CHECKPOINT; + } } if (cached == 0) { - disk_cached = kv_cache_try_load(s, &j->req, &effective_prompt, - &disk_cache_path, - &disk_cache_ext_flags); + disk_cached = kv_cache_try_load(s, &j->req, &p->effective_prompt, + &p->disk_cache_path, + &disk_cache_ext_flags, + &disk_cache_consume); if (disk_cached > 0) { cached = disk_cached; cache_source = "disk-text"; - prompt_for_sync = &effective_prompt; + p->prompt_for_sync = &p->effective_prompt; } } + /* Restart the continued-store cadence from the continuation point, so the + * threshold-crossing rule measures the step from where this prefill + * actually resumes instead of firing a near-duplicate store on the first + * chunk after a hit. */ + if (cached > 0 && s->kv.continued_last_store_tokens < cached) { + s->kv.continued_last_store_tokens = cached; + } const bool responses_reasoning_state_preserved = cached > 0 && ((!strcmp(cache_source, "responses-visible") || @@ -10120,7 +11359,14 @@ static void generate_job(server *s, job *j) { responses_protocol && j->req.responses_requires_live_reasoning && !responses_reasoning_state_preserved; - const int prompt_tokens = prompt_for_sync->len; + const int prompt_tokens = p->prompt_for_sync->len; + const server_statistics_observation cache_stats = { + .operation = SERVER_STATS_CACHE, + .cache_source = cache_source, + .prompt_tokens = prompt_tokens, + .cached_tokens = cached, + }; + production_observe_stats(p, &cache_stats); /* OpenAI usage details: the reusable prefix is a cache read, while the * effective prompt suffix evaluated by ds4_session_sync() is written into * the live KV cache and can be reused by the next request. */ @@ -10128,11 +11374,8 @@ static void generate_job(server *s, job *j) { j->req.cache_write_tokens = prompt_tokens > cached ? prompt_tokens - cached : 0; const double t0 = now_sec(); - uint64_t trace_id = trace_begin(s, j, cached, prompt_tokens, &cache_diag, - cache_source, disk_cached, disk_cache_path); - char ctx_span[48]; - request_ctx_span(ctx_span, sizeof(ctx_span), cached, prompt_tokens); - server_prefill_progress progress = { + request_ctx_span(p->ctx_span, sizeof(p->ctx_span), cached, prompt_tokens); + p->progress = (server_prefill_progress) { .srv = s, .kind = j->req.kind, .prompt_tokens = prompt_tokens, @@ -10143,11 +11386,25 @@ static void generate_job(server *s, job *j) { .fd = j->fd, .stream = j->req.stream, .enable_cors = s->enable_cors, + .wire = &p->wire, + .secondary = &p->phase_secondary, + .output = p->effects.output, + .stats = p->effects.stats, }; - snprintf(progress.ctx, sizeof(progress.ctx), "%s", ctx_span); - char req_flags[64]; - log_flags(req_flags, sizeof(req_flags), responses_protocol, + snprintf(p->progress.ctx, sizeof(p->progress.ctx), "%s", p->ctx_span); + log_flags(p->req_flags, sizeof(p->req_flags), responses_protocol, j->req.has_tools, false, false, false); + p->responses_protocol = responses_protocol; + p->responses_live_continuation = responses_live_continuation; + p->anthropic_live_continuation = anthropic_live_continuation; + p->thinking_live_continuation = thinking_live_continuation; + p->disk_cache_consume = disk_cache_consume; + p->cached = cached; + p->prompt_tokens = prompt_tokens; + p->started_at = t0; + p->disk_cached = disk_cached; + snprintf(p->cache_source, sizeof(p->cache_source), "%s", cache_source); + production_observe_trace(p, SERVER_TRACE_BEGIN, NULL, 0); if (responses_live_continuation) { server_log(DS4_LOG_PREFILL, "ds4-server: responses live continuation RESPPROTO match=%s ids=%d cached=%d prompt=%d", @@ -10180,18 +11437,33 @@ static void generate_job(server *s, job *j) { cache_source, cached, prompt_tokens); - trace_event(s, trace_id, - "responses replay missing reasoning state; continuing from visible history source=%s cached=%d", - cache_source, cached); + production_observe_trace_event( + p, + "responses replay missing reasoning state; continuing from visible history source=%s cached=%d", + cache_source, cached); } server_log(DS4_LOG_PREFILL, "ds4-server: %s ctx=%s%s%s prompt start", j->req.kind == REQ_CHAT ? "chat" : "completion", - ctx_span, - req_flags[0] ? " " : "", - req_flags); - ds4_session_set_progress(s->session, server_progress_cb, &progress); - ds4_session_set_display_progress(s->session, server_progress_cb, &progress); + p->ctx_span, + p->req_flags[0] ? " " : "", + p->req_flags); + ds4_session_set_progress(s->session, server_progress_cb, &p->progress); + ds4_session_set_display_progress(s->session, server_progress_cb, + &p->progress); + ds4_session_set_cancel(s->session, server_sync_cancel_cb, &p->progress); + p->callbacks_attached = true; + return production_continue(p); +} + +static server_txn_step_result production_synchronize( + production_txn *p, const server_txn_outcome *outcome) { + server *s = p->srv; + job *j = p->job; + const ds4_tokens *prompt_for_sync = p->prompt_for_sync; + const int cached = p->cached; + const int prompt_tokens = p->prompt_tokens; + (void)outcome; int cold_store_len = 0; if (cached == 0 && @@ -10224,18 +11496,47 @@ static void generate_job(server *s, job *j) { { ds4_tokens prefix = {0}; tokens_copy_prefix(&prefix, prompt_for_sync, cold_store_len); - if (ds4_session_sync(s->session, &prefix, err, sizeof(err)) != 0) { + int sync_rc = ds4_session_sync(s->session, &prefix, p->err, + sizeof(p->err)); + if (sync_rc != 0) { ds4_tokens_free(&prefix); - ds4_tokens_free(&effective_prompt); - ds4_session_set_progress(s->session, NULL, NULL); - ds4_session_set_display_progress(s->session, NULL, NULL); kv_cache_restore_suppressed_continued(&s->kv, suppressed_continued_last, cold_store_len); - kv_cache_discard_failed_disk_entry(s, disk_cache_path); - free(disk_cache_path); - trace_event(s, trace_id, "prefill failed: %s", err); - send_prefill_failure_response(s, j, &progress, ctx_span, req_flags, err); - return; + if (sync_rc == DS4_SESSION_SYNC_INTERRUPTED) { + /* Cancelled (shutdown or client gone): the session keeps a + * valid prefix and the disk entry is still good. */ + const server_statistics_observation cancelled = { + .operation = SERVER_STATS_PREFILL_CANCEL, + }; + production_observe_stats(p, &cancelled); + server_log(DS4_LOG_PREFILL, + "ds4-server: prefill cancelled ctx=%s reason=%s", + p->ctx_span, + g_stop_requested ? "shutdown" : "client-gone"); + production_observe_trace_event(p, "prefill cancelled"); + } else { + kv_cache_discard_failed_disk_entry(s, p->disk_cache_path); + production_observe_trace_event(p, "prefill failed: %s", + p->err); + p->reply = PRODUCTION_REPLY_PREFILL_ERROR; + } + p->wire = p->progress.stream_failed ? SERVER_WIRE_BROKEN : + p->progress.headers_sent ? SERVER_WIRE_IRREVERSIBLE : + SERVER_WIRE_UNTOUCHED; + return production_terminal( + p, + sync_rc == DS4_SESSION_SYNC_INTERRUPTED ? + SERVER_TXN_CANCELLED : SERVER_TXN_FAILED, + sync_rc == DS4_SESSION_SYNC_INTERRUPTED ? + (g_stop_requested ? SERVER_TXN_REASON_SHUTDOWN : + SERVER_TXN_REASON_CLIENT_GONE) : + SERVER_TXN_REASON_SYNC_FAILED, + SERVER_TXN_FINISH_ERROR, + sync_rc == DS4_SESSION_SYNC_INTERRUPTED ? + SERVER_SESSION_VALID_PREFIX : SERVER_SESSION_INVALIDATED, + sync_rc == DS4_SESSION_SYNC_INTERRUPTED ? + (g_stop_requested ? "shutdown requested" : + "client disconnected") : p->err); } if (kv_cache_store_live_prefix(s, prompt_for_sync, cold_store_len, "cold")) { kv_cache_note_store(&s->kv, cold_store_len); @@ -10244,38 +11545,87 @@ static void generate_job(server *s, job *j) { kv_cache_restore_suppressed_continued(&s->kv, suppressed_continued_last, cold_store_len); suppressed_continued_last = -1; + p->phase_secondary |= SERVER_TXN_SECONDARY_CHECKPOINT; } ds4_tokens_free(&prefix); } - if (ds4_session_sync(s->session, prompt_for_sync, err, sizeof(err)) != 0) { - ds4_tokens_free(&effective_prompt); - ds4_session_set_progress(s->session, NULL, NULL); - ds4_session_set_display_progress(s->session, NULL, NULL); + int prompt_sync_rc = ds4_session_sync(s->session, prompt_for_sync, p->err, + sizeof(p->err)); + if (prompt_sync_rc != 0) { kv_cache_restore_suppressed_continued(&s->kv, suppressed_continued_last, cold_store_len); - kv_cache_discard_failed_disk_entry(s, disk_cache_path); - free(disk_cache_path); - trace_event(s, trace_id, "prefill failed: %s", err); - send_prefill_failure_response(s, j, &progress, ctx_span, req_flags, err); - return; + if (prompt_sync_rc == DS4_SESSION_SYNC_INTERRUPTED) { + const server_statistics_observation cancelled = { + .operation = SERVER_STATS_PREFILL_CANCEL, + }; + production_observe_stats(p, &cancelled); + server_log(DS4_LOG_PREFILL, + "ds4-server: prefill cancelled ctx=%s reason=%s", + p->ctx_span, + g_stop_requested ? "shutdown" : "client-gone"); + production_observe_trace_event(p, "prefill cancelled"); + } else { + kv_cache_discard_failed_disk_entry(s, p->disk_cache_path); + production_observe_trace_event(p, "prefill failed: %s", p->err); + p->reply = PRODUCTION_REPLY_PREFILL_ERROR; + } + p->wire = p->progress.stream_failed ? SERVER_WIRE_BROKEN : + p->progress.headers_sent ? SERVER_WIRE_IRREVERSIBLE : + SERVER_WIRE_UNTOUCHED; + return production_terminal( + p, + prompt_sync_rc == DS4_SESSION_SYNC_INTERRUPTED ? + SERVER_TXN_CANCELLED : SERVER_TXN_FAILED, + prompt_sync_rc == DS4_SESSION_SYNC_INTERRUPTED ? + (g_stop_requested ? SERVER_TXN_REASON_SHUTDOWN : + SERVER_TXN_REASON_CLIENT_GONE) : + SERVER_TXN_REASON_SYNC_FAILED, + SERVER_TXN_FINISH_ERROR, + prompt_sync_rc == DS4_SESSION_SYNC_INTERRUPTED ? + SERVER_SESSION_VALID_PREFIX : SERVER_SESSION_INVALIDATED, + prompt_sync_rc == DS4_SESSION_SYNC_INTERRUPTED ? + (g_stop_requested ? "shutdown requested" : + "client disconnected") : p->err); + } + /* The prefill extended past this snapshot, so its deferred consume-unlink + * is now safe: the live state supersedes it and the next store persists a + * longer prefix. Keeping it until here means a cancelled or failed tail + * prefill can still hit it on retry. */ + if (p->disk_cache_consume && p->disk_cache_path) { + if (unlink(p->disk_cache_path) != 0 && errno != ENOENT) { + p->phase_secondary |= SERVER_TXN_SECONDARY_CHECKPOINT; + } } - free(disk_cache_path); + free(p->disk_cache_path); + p->disk_cache_path = NULL; /* Once a non-live request wins, old protocol live bindings are stale. Keep * a binding only when this request explicitly continued from it. */ - if (!responses_live_continuation) responses_live_clear(s); - if (!anthropic_live_continuation) anthropic_live_clear(s); - if (!thinking_live_continuation) thinking_live_clear(s); + if (!p->responses_live_continuation) responses_live_clear(s); + if (!p->anthropic_live_continuation) anthropic_live_clear(s); + if (!p->thinking_live_continuation) thinking_live_clear(s); + ds4_session_set_cancel(s->session, NULL, NULL); ds4_session_set_progress(s->session, NULL, NULL); ds4_session_set_display_progress(s->session, NULL, NULL); - kv_cache_maybe_store_continued(s); + p->callbacks_attached = false; + if (!kv_cache_maybe_store_continued(s)) { + p->phase_secondary |= SERVER_TXN_SECONDARY_CHECKPOINT; + } + const double prefill_sec = now_sec() - p->started_at; + const server_statistics_observation prefill_done = { + .operation = SERVER_STATS_PREFILL_DONE, + .prompt_tokens = prompt_tokens, + .cached_tokens = cached, + .elapsed = prefill_sec, + }; + production_observe_stats(p, &prefill_done); server_log(DS4_LOG_PREFILL, "ds4-server: %s ctx=%s%s%s prompt done %.3fs", j->req.kind == REQ_CHAT ? "chat" : "completion", - ctx_span, - req_flags[0] ? " " : "", - req_flags, - now_sec() - t0); + p->ctx_span, + p->req_flags[0] ? " " : "", + p->req_flags, + prefill_sec); if (cold_store_len == prompt_for_sync->len) { if (kv_cache_store_live_prefix(s, prompt_for_sync, cold_store_len, "cold")) { kv_cache_note_store(&s->kv, cold_store_len); @@ -10283,85 +11633,96 @@ static void generate_job(server *s, job *j) { } else { kv_cache_restore_suppressed_continued(&s->kv, suppressed_continued_last, cold_store_len); + p->phase_secondary |= SERVER_TXN_SECONDARY_CHECKPOINT; } } - char id[96]; - snprintf(id, sizeof(id), "%s-%llu", + snprintf(p->response_id, sizeof(p->response_id), "%s-%llu", j->req.kind == REQ_CHAT ? "chatcmpl" : "cmpl", (unsigned long long)++s->seq); - bool structured_stream = request_uses_structured_stream(&j->req); - anthropic_stream anthropic_live = {0}; - openai_stream openai_live = {0}; - responses_stream responses_live = {0}; - const bool openai_live_chat = request_uses_openai_live_stream(&j->req); - const bool responses_live_chat = request_uses_responses_live_stream(&j->req); - long responses_created_at = (long)time(NULL); + p->structured_stream = request_uses_structured_stream(&j->req); + p->openai_live_chat = request_uses_openai_live_stream(&j->req); + p->responses_live_chat = request_uses_responses_live_stream(&j->req); + p->responses_created_at = (long)time(NULL); + return production_continue(p); +} + +static server_txn_step_result production_extend( + production_txn *p, const server_txn_outcome *outcome) { + job *j = p->job; + (void)outcome; if (j->req.stream) { - if (progress.stream_failed) { + p->wire = p->progress.stream_failed ? SERVER_WIRE_BROKEN : + p->progress.headers_sent ? SERVER_WIRE_IRREVERSIBLE : + SERVER_WIRE_UNTOUCHED; + if (p->progress.stream_failed) { server_log(DS4_LOG_GENERATION, "ds4-server: %s ctx=%s%s%s stream closed during prefill", j->req.kind == REQ_CHAT ? "chat" : "completion", - ctx_span, - req_flags[0] ? " " : "", - req_flags); - ds4_tokens_free(&effective_prompt); - return; - } - /* The prefill progress callback may have already sent the SSE headers - * to keep the connection alive during a long prefill. Only emit them - * here when prefill never fired (e.g. fully cached prompt). */ - if (!progress.headers_sent && !sse_headers(j->fd, s->enable_cors)) { - server_log(DS4_LOG_GENERATION, - "ds4-server: %s ctx=%s%s%s sse headers failed", - j->req.kind == REQ_CHAT ? "chat" : "completion", - ctx_span, - req_flags[0] ? " " : "", - req_flags); - ds4_tokens_free(&effective_prompt); - return; - } - progress.headers_sent = true; - if (j->req.api == API_ANTHROPIC && - !anthropic_sse_start_live(j->fd, &j->req, id, - prompt_tokens, &anthropic_live)) { - server_log(DS4_LOG_GENERATION, "ds4-server: chat ctx=%s anthropic stream start failed", ctx_span); - ds4_tokens_free(&effective_prompt); - return; - } - if (j->req.api == API_OPENAI && j->req.kind == REQ_CHAT && - !sse_chunk(j->fd, &j->req, id, NULL, NULL)) { - server_log(DS4_LOG_GENERATION, "ds4-server: chat ctx=%s openai role chunk failed", ctx_span); - ds4_tokens_free(&effective_prompt); - return; + p->ctx_span, + p->req_flags[0] ? " " : "", + p->req_flags); + production_latch_failure( + p, SERVER_TXN_FAILED, SERVER_TXN_REASON_OUTPUT_FAILED, + production_live_session(p), "stream closed during prefill"); + return production_terminal( + p, SERVER_TXN_FAILED, SERVER_TXN_REASON_OUTPUT_FAILED, + SERVER_TXN_FINISH_ERROR, production_live_session(p), + "stream closed during prefill"); } - if (openai_live_chat) openai_stream_start(&j->req, &openai_live); - if (responses_live_chat) { - responses_stream_init(&j->req, &responses_live); - responses_live.active = true; - if (!responses_sse_created(j->fd, &j->req, &responses_live, responses_created_at)) { - server_log(DS4_LOG_GENERATION, - "ds4-server: chat ctx=%s%s%s responses created event failed", - ctx_span, - req_flags[0] ? " " : "", - req_flags); - responses_stream_free(&responses_live); - ds4_tokens_free(&effective_prompt); - return; - } + } + + const server_output_observation observation = { + .operation = SERVER_OUTPUT_STREAM_OPEN, + }; + server_txn_output_result result = { + .ok = false, + .wire = p->wire, + }; + if (p->effects.output.apply) { + result = p->effects.output.apply(p->effects.output.ctx, &observation); + } + p->wire = result.wire; + if (!result.ok) { + if (p->first_failure_reason == SERVER_TXN_REASON_NONE) { + production_latch_failure( + p, SERVER_TXN_FAILED, SERVER_TXN_REASON_OUTPUT_FAILED, + production_live_session(p), "stream open failed"); } + return production_terminal( + p, SERVER_TXN_FAILED, SERVER_TXN_REASON_OUTPUT_FAILED, + SERVER_TXN_FINISH_ERROR, production_live_session(p), p->err); } + return production_continue(p); +} + +static server_txn_step_result production_decode( + production_txn *p, const server_txn_outcome *outcome) { + server *s = p->srv; + job *j = p->job; + const int prompt_tokens = p->prompt_tokens; + const bool responses_protocol = p->responses_protocol; + bool openai_live_chat = p->openai_live_chat; + const char *finish = "error"; + const char *final_finish = finish; + int completion = 0; + double decode_t0 = 0.0; + buf text = {0}; + thinking_state thinking = {0}; + tool_calls parsed_calls = {0}; + char *parsed_content = NULL; + char *parsed_reasoning = NULL; + (void)outcome; bool dsml_recovery_attempted = false; uint64_t rng = j->req.seed ? j->req.seed : (((uint64_t)time(NULL) << 32) ^ ((uint64_t)s->seq << 1) ^ (uint64_t)(uintptr_t)j); decode_again: - ; - buf text = {0}; - size_t plain_stream_pos = 0; + text = (buf) {0}; + p->plain_stream_pos = 0; size_t stop_scan_from = 0; - const char *finish = "length"; - int completion = 0; + finish = "length"; + completion = 0; int max_tokens = j->req.max_tokens; int room = ds4_session_ctx(s->session) - ds4_session_pos(s->session); bool saw_tool_start = false; @@ -10372,27 +11733,56 @@ static void generate_job(server *s, job *j) { int next_decode_log = 50; if (max_tokens < 0) max_tokens = 0; if (max_tokens > room) max_tokens = room; - trace_event(s, trace_id, "prefill done; decode_max=%d ctx_room=%d", max_tokens, room); - const double decode_t0 = now_sec(); + production_observe_trace_event( + p, "prefill done; decode_max=%d ctx_room=%d", max_tokens, room); + decode_t0 = now_sec(); double last_decode_log_t = decode_t0; int last_decode_log_completion = 0; - thinking_state thinking = thinking_state_from_prompt(&j->req); + thinking = thinking_state_from_prompt(&j->req); const bool thinking_gates_tool_markers = ds4_think_mode_enabled(j->req.think_mode); bool tool_scan_waiting_for_think_close = thinking_gates_tool_markers && thinking.inside; size_t think_recovery_scan_from = 0; const bool think_tool_recovery_enabled = getenv("DS4_SERVER_DISABLE_THINK_TOOL_RECOVERY") == NULL; + if (ds4_think_mode_enabled(j->req.think_mode) && + (j->req.temperature != DS4_DEFAULT_TEMPERATURE || + j->req.top_p != DS4_DEFAULT_TOP_P || + j->req.min_p != DS4_DEFAULT_MIN_P || + j->req.top_k != 0)) + { + /* Same behavior as the official DeepSeek API, but say so once instead + * of silently ignoring the request's sampling parameters. */ + server_log(DS4_LOG_GENERATION, + "ds4-server: thinking mode ignores request sampling params " + "(temperature/top_p/top_k/min_p); using defaults"); + } dsml_decode_tracker dsml_tracker; dsml_decode_tracker_init(&dsml_tracker); while (!g_stop_requested && completion < max_tokens && ds4_session_pos(s->session) < ds4_session_ctx(s->session)) { + /* Streaming clients reveal a disconnect through failed SSE writes; + * non-streaming clients write nothing until the end, so poll the + * socket instead of decoding minutes of output for a dead peer. */ + if (!j->req.stream && client_socket_gone(j->fd)) { + const server_txn_reason reason = production_peer_gone_reason(); + snprintf(p->err, sizeof(p->err), "%s", + reason == SERVER_TXN_REASON_SHUTDOWN ? + "shutdown requested" : "client disconnected"); + production_latch_failure( + p, SERVER_TXN_CANCELLED, reason, + production_live_session(p), p->err); + finish = "error"; + break; + } dsml_decode_state dsml_state = j->req.kind == REQ_CHAT && j->req.has_tools ? dsml_tracker.decode : DSML_DECODE_OUTSIDE; const bool in_tool_call = dsml_decode_state_is_tool(dsml_state); if (!(j->req.kind == REQ_CHAT && j->req.has_tools && (saw_tool_start || in_tool_call))) { - kv_cache_maybe_store_continued(s); + if (!kv_cache_maybe_store_continued(s)) { + p->phase_secondary |= SERVER_TXN_SECONDARY_CHECKPOINT; + } } float temperature = j->req.temperature; int top_k = j->req.top_k; @@ -10425,15 +11815,22 @@ static void generate_job(server *s, job *j) { ds4_token_eos(s->engine), toks, (int)(sizeof(toks) / sizeof(toks[0])), - err, - sizeof(err)); + p->err, + sizeof(p->err)); if (ntok < 0) { finish = "error"; + production_latch_failure( + p, SERVER_TXN_FAILED, SERVER_TXN_REASON_DECODE_FAILED, + production_live_session(p), p->err); break; } } else { - if (ds4_session_eval(s->session, token, err, sizeof(err)) != 0) { + if (ds4_session_eval(s->session, token, p->err, + sizeof(p->err)) != 0) { finish = "error"; + production_latch_failure( + p, SERVER_TXN_FAILED, SERVER_TXN_REASON_DECODE_FAILED, + production_live_session(p), p->err); break; } toks[0] = token; @@ -10453,7 +11850,7 @@ static void generate_job(server *s, job *j) { char *piece = ds4_token_text(s->engine, token, &piece_len); completion++; - trace_piece(s, trace_id, piece, piece_len); + production_observe_trace(p, SERVER_TRACE_PIECE, piece, piece_len); buf_append(&text, piece, piece_len); thinking_state_feed(&thinking, piece, piece_len); if (j->req.kind == REQ_CHAT && j->req.has_tools) { @@ -10467,52 +11864,37 @@ static void generate_job(server *s, job *j) { size_t stream_len = hit_stop ? stop_pos : stop_list_stream_safe_len(&j->req.stops, text.len); if (stream_len > text.len) stream_len = text.len; - stream_len = utf8_stream_safe_len(text.ptr, plain_stream_pos, + stream_len = utf8_stream_safe_len(text.ptr, p->plain_stream_pos, stream_len, hit_stop); if (!hit_stop && j->req.stops.max_len > 1) { const size_t hold = j->req.stops.max_len - 1; stop_scan_from = text.len > hold ? text.len - hold : 0; } - if (j->req.stream && !structured_stream && stream_len > plain_stream_pos) { - char *delta = xstrndup(text.ptr + plain_stream_pos, stream_len - plain_stream_pos); - bool ok = sse_chunk(j->fd, &j->req, id, delta, NULL); - free(delta); - if (!ok) { - finish = "error"; - snprintf(err, sizeof(err), "client stream write failed"); - free(piece); - stop_decode = true; - break; - } - plain_stream_pos = stream_len; + const server_output_observation output = { + .operation = SERVER_OUTPUT_STREAM_UPDATE, + .text = text.ptr, + .text_len = text.len, + .safe_len = stream_len, + }; + server_txn_output_result output_result = { + .ok = false, + .wire = p->wire, + }; + if (p->effects.output.apply) { + output_result = p->effects.output.apply( + p->effects.output.ctx, &output); } - if (j->req.stream && j->req.api == API_ANTHROPIC && - !anthropic_sse_stream_update(j->fd, s, &j->req, id, - &anthropic_live, text.ptr, stream_len, - false)) { + p->wire = output_result.wire; + if (!output_result.ok) { finish = "error"; - snprintf(err, sizeof(err), "client stream write failed"); - free(piece); - stop_decode = true; - break; - } - if (openai_live_chat && - !openai_sse_stream_update(j->fd, s, &j->req, id, - &openai_live, text.ptr, stream_len, - false)) { - finish = "error"; - snprintf(err, sizeof(err), "client stream write failed"); - free(piece); - stop_decode = true; - break; - } - if (responses_live_chat && - !responses_sse_stream_update(j->fd, &j->req, - &responses_live, text.ptr, stream_len, - false)) { - finish = "error"; - snprintf(err, sizeof(err), "client stream write failed"); + if (p->first_failure_reason == SERVER_TXN_REASON_NONE) { + production_latch_failure( + p, SERVER_TXN_FAILED, + SERVER_TXN_REASON_OUTPUT_FAILED, + production_live_session(p), + "client stream write failed"); + } free(piece); stop_decode = true; break; @@ -10532,9 +11914,13 @@ static void generate_job(server *s, job *j) { chat_think_tool_recovery(s, &text, &thinking, &think_recovery_scan_from, &completion, max_tokens, - err, sizeof(err)) : 0; + p->err, sizeof(p->err)) : 0; if (recovered < 0) { finish = "error"; + production_latch_failure( + p, SERVER_TXN_FAILED, + SERVER_TXN_REASON_DECODE_FAILED, + production_live_session(p), p->err); stop_decode = true; break; } @@ -10542,11 +11928,11 @@ static void generate_job(server *s, job *j) { server_log(DS4_LOG_WARNING, "ds4-server: chat ctx=%s%s%s tool call inside unclosed ; " "forced after %d generated tokens", - ctx_span, - req_flags[0] ? " " : "", - req_flags, + p->ctx_span, + p->req_flags[0] ? " " : "", + p->req_flags, completion); - trace_event(s, trace_id, + production_observe_trace_event(p, "think tool recovery after %d generated tokens", completion); dsml_decode_tracker_update(&dsml_tracker, text.ptr, text.len); @@ -10572,25 +11958,29 @@ static void generate_job(server *s, job *j) { saw_orphan_tool_end = true; server_log(DS4_LOG_WARNING, "ds4-server: chat ctx=%s%s%s ignored orphan tool-call end marker after %d generated tokens", - ctx_span, - req_flags[0] ? " " : "", - req_flags, + p->ctx_span, + p->req_flags[0] ? " " : "", + p->req_flags, completion); - trace_event(s, trace_id, + production_observe_trace_event(p, "ignored orphan tool-call end marker after %d generated tokens", completion); } if (saw_tool_start && !old_start) { - trace_event(s, trace_id, "entered tool-call block after %d generated tokens", completion); + production_observe_trace_event(p, + "entered tool-call block after %d generated tokens", + completion); } if (saw_tool_end && !old_end) { - trace_event(s, trace_id, "closed tool-call block after %d generated tokens", completion); + production_observe_trace_event(p, + "closed tool-call block after %d generated tokens", + completion); } const size_t marker_hold = 80; size_t hold_from = text.len > marker_hold ? text.len - marker_hold : 0; if (hold_from > tool_scan_from) tool_scan_from = hold_from; if (s->trace && completion >= next_tool_progress) { - trace_event(s, trace_id, + production_observe_trace_event(p, "progress gen=%d dsml_start=%d dsml_end=%d", completion, saw_tool_start ? 1 : 0, saw_tool_end ? 1 : 0); next_tool_progress += 128; @@ -10608,6 +11998,11 @@ static void generate_job(server *s, job *j) { decode_t0, &last_decode_log_t, &last_decode_log_completion); + const server_statistics_observation progress = { + .operation = SERVER_STATS_PROGRESS, + .live_tokens = ds4_session_pos(s->session), + }; + production_observe_stats(p, &progress); next_decode_log += 50; } @@ -10632,7 +12027,10 @@ static void generate_job(server *s, job *j) { if (g_stop_requested && strcmp(finish, "error") != 0) { finish = "error"; - snprintf(err, sizeof(err), "shutdown requested"); + snprintf(p->err, sizeof(p->err), "shutdown requested"); + production_latch_failure( + p, SERVER_TXN_CANCELLED, SERVER_TXN_REASON_SHUTDOWN, + production_live_session(p), p->err); } if (j->req.kind == REQ_CHAT && j->req.has_tools && @@ -10661,11 +12059,13 @@ static void generate_job(server *s, job *j) { completed_truncation = true; server_log(DS4_LOG_WARNING, "ds4-server: chat ctx=%s%s%s repaired unterminated tool call (%d calls recovered)", - ctx_span, - req_flags[0] ? " " : "", - req_flags, + p->ctx_span, + p->req_flags[0] ? " " : "", + p->req_flags, test_calls.len); - trace_event(s, trace_id, "repaired unterminated tool call (%d calls recovered)", test_calls.len); + production_observe_trace_event(p, + "repaired unterminated tool call (%d calls recovered)", + test_calls.len); } tool_calls_free(&test_calls); } @@ -10675,10 +12075,10 @@ static void generate_job(server *s, job *j) { char recovery_err[160] = {0}; server_log(DS4_LOG_WARNING, "ds4-server: chat ctx=%s%s%s unterminated tool call; continuing with model-visible tool error", - ctx_span, - req_flags[0] ? " " : "", - req_flags); - trace_event(s, trace_id, + p->ctx_span, + p->req_flags[0] ? " " : "", + p->req_flags); + production_observe_trace_event(p, "unterminated tool call; continuing with model-visible tool error"); if (continue_after_invalid_dsml(s, &j->req, &thinking, "unterminated tool call", @@ -10689,11 +12089,11 @@ static void generate_job(server *s, job *j) { dsml_recovery_attempted = true; server_log(DS4_LOG_GENERATION, "ds4-server: chat ctx=%s%s%s tool-error continuation appended %d tokens", - ctx_span, - req_flags[0] ? " " : "", - req_flags, + p->ctx_span, + p->req_flags[0] ? " " : "", + p->req_flags, recovery_tokens); - trace_event(s, trace_id, + production_observe_trace_event(p, "tool-error continuation appended %d tokens", recovery_tokens); buf_free(&repaired); @@ -10701,11 +12101,18 @@ static void generate_job(server *s, job *j) { goto decode_again; } finish = "error"; - snprintf(err, sizeof(err), "invalid tool call recovery failed: %s", + snprintf(p->err, sizeof(p->err), + "invalid tool call recovery failed: %s", recovery_err[0] ? recovery_err : "unknown error"); + production_latch_failure( + p, SERVER_TXN_FAILED, SERVER_TXN_REASON_DECODE_FAILED, + production_live_session(p), p->err); } else { finish = "error"; - snprintf(err, sizeof(err), "unterminated tool call"); + snprintf(p->err, sizeof(p->err), "unterminated tool call"); + production_latch_failure( + p, SERVER_TXN_FAILED, SERVER_TXN_REASON_DECODE_FAILED, + production_live_session(p), p->err); } } buf_free(&repaired); @@ -10723,16 +12130,34 @@ static void generate_job(server *s, job *j) { &last_decode_log_completion); } - if (j->req.stream && !structured_stream && text.len > plain_stream_pos) { - char *tail = xstrndup(text.ptr + plain_stream_pos, text.len - plain_stream_pos); - if (!sse_chunk(j->fd, &j->req, id, tail, NULL)) finish = "error"; - free(tail); + const server_output_observation flush = { + .operation = SERVER_OUTPUT_STREAM_FLUSH, + .text = text.ptr, + .text_len = text.len, + .safe_len = text.len, + }; + server_txn_output_result flush_result = { + .ok = false, + .wire = p->wire, + }; + if (p->effects.output.apply) { + flush_result = p->effects.output.apply( + p->effects.output.ctx, &flush); + } + p->wire = flush_result.wire; + if (!flush_result.ok) { + finish = "error"; + if (p->first_failure_reason == SERVER_TXN_REASON_NONE) { + production_latch_failure( + p, SERVER_TXN_FAILED, SERVER_TXN_REASON_OUTPUT_FAILED, + production_live_session(p), "client stream write failed"); + } } - tool_calls parsed_calls = {0}; - char *parsed_content = NULL; - char *parsed_reasoning = NULL; - const char *final_finish = finish; + parsed_calls = (tool_calls) {0}; + parsed_content = NULL; + parsed_reasoning = NULL; + final_finish = finish; bool recovered_tool_parse_failure = false; if (j->req.kind == REQ_CHAT) { bool parsed_ok = parse_generated_message_for_response( @@ -10741,8 +12166,8 @@ static void generate_job(server *s, job *j) { saw_tool_start, ds4_think_mode_enabled(j->req.think_mode), &final_finish, - err, - sizeof(err), + p->err, + sizeof(p->err), &parsed_content, &parsed_reasoning, &parsed_calls, @@ -10755,13 +12180,13 @@ static void generate_job(server *s, job *j) { if (!j->req.stream && !dsml_recovery_attempted) { int recovery_tokens = 0; char recovery_err[160] = {0}; - const char *detail = err[0] ? err : "invalid tool call"; + const char *detail = p->err[0] ? p->err : "invalid tool call"; server_log(DS4_LOG_WARNING, "ds4-server: chat ctx=%s%s%s invalid tool call; continuing with model-visible tool error", - ctx_span, - req_flags[0] ? " " : "", - req_flags); - trace_event(s, trace_id, + p->ctx_span, + p->req_flags[0] ? " " : "", + p->req_flags); + production_observe_trace_event(p, "invalid tool call; continuing with model-visible tool error"); if (continue_after_invalid_dsml(s, &j->req, &thinking, detail, @@ -10772,11 +12197,11 @@ static void generate_job(server *s, job *j) { dsml_recovery_attempted = true; server_log(DS4_LOG_GENERATION, "ds4-server: chat ctx=%s%s%s tool-error continuation appended %d tokens", - ctx_span, - req_flags[0] ? " " : "", - req_flags, + p->ctx_span, + p->req_flags[0] ? " " : "", + p->req_flags, recovery_tokens); - trace_event(s, trace_id, + production_observe_trace_event(p, "tool-error continuation appended %d tokens", recovery_tokens); free(parsed_content); @@ -10786,19 +12211,27 @@ static void generate_job(server *s, job *j) { goto decode_again; } final_finish = "error"; - snprintf(err, sizeof(err), "invalid tool call recovery failed: %s", + snprintf(p->err, sizeof(p->err), + "invalid tool call recovery failed: %s", recovery_err[0] ? recovery_err : "unknown error"); + production_latch_failure( + p, SERVER_TXN_FAILED, SERVER_TXN_REASON_DECODE_FAILED, + production_live_session(p), p->err); } if (!parsed_ok) { /* Print raw DSML snippet for debugging */ size_t dsml_snippet_len = 0; const char *dsml_start = NULL; - const char *p; - for (p = text.ptr; p && (size_t)(p - text.ptr) < text.len - 20; p++) { - if ((strncmp(p, DS4_TOOL_CALLS_START, strlen(DS4_TOOL_CALLS_START)) == 0) || - (strncmp(p, DS4_TOOL_CALLS_START_SHORT, strlen(DS4_TOOL_CALLS_START_SHORT)) == 0) || - (strncmp(p, "", 12) == 0)) { - dsml_start = p; + const char *scan; + for (scan = text.ptr; + scan && (size_t)(scan - text.ptr) < text.len - 20; + scan++) { + if ((strncmp(scan, DS4_TOOL_CALLS_START, + strlen(DS4_TOOL_CALLS_START)) == 0) || + (strncmp(scan, DS4_TOOL_CALLS_START_SHORT, + strlen(DS4_TOOL_CALLS_START_SHORT)) == 0) || + (strncmp(scan, "", 12) == 0)) { + dsml_start = scan; break; } } @@ -10810,9 +12243,9 @@ static void generate_job(server *s, job *j) { size_t text_snippet_len = text.len > 300 ? 300 : text.len; server_log(DS4_LOG_WARNING, "ds4-server: chat ctx=%s%s%s invalid tool call returned as assistant text finish=%s [text_len=%zu saw_start=%d saw_end=%d text_snippet: %.*s]", - ctx_span, - req_flags[0] ? " " : "", - req_flags, + p->ctx_span, + p->req_flags[0] ? " " : "", + p->req_flags, final_finish, text.len, saw_tool_start, @@ -10821,20 +12254,23 @@ static void generate_job(server *s, job *j) { text.ptr ? text.ptr : "(null)"); server_log(DS4_LOG_WARNING, "ds4-server: chat ctx=%s%s%s invalid tool call dsml_snippet: %.*s", - ctx_span, - req_flags[0] ? " " : "", - req_flags, + p->ctx_span, + p->req_flags[0] ? " " : "", + p->req_flags, (int)dsml_snippet_len, dsml_start ? dsml_start : "(none)"); - trace_event(s, trace_id, + production_observe_trace_event(p, "invalid tool call returned as assistant text finish=%s", final_finish); } } if (parsed_calls.len) { - if (openai_live_chat) apply_openai_stream_tool_ids(&parsed_calls, &openai_live); + if (openai_live_chat) { + apply_openai_stream_tool_ids(&parsed_calls, &p->openai_live); + } if (j->req.api == API_ANTHROPIC && j->req.stream) - apply_anthropic_stream_tool_ids(&parsed_calls, &anthropic_live); + apply_anthropic_stream_tool_ids(&parsed_calls, + &p->anthropic_live); assign_tool_call_ids(s, &parsed_calls, j->req.api); tool_memory_remember(s, &parsed_calls); final_finish = "tool_calls"; @@ -10842,239 +12278,521 @@ static void generate_job(server *s, job *j) { responses_live_clear(s); } } - log_tool_calls_summary(ctx_span, &parsed_calls, + log_tool_calls_summary(p->ctx_span, &parsed_calls, responses_protocol); - trace_finish(s, trace_id, &j->req, final_finish, completion, - saw_tool_start, saw_tool_end, - parsed_content ? parsed_content : (text.ptr ? text.ptr : ""), - parsed_reasoning, &parsed_calls, now_sec() - t0); - - if (j->req.api == API_RESPONSES) { - if (strcmp(final_finish, "error") && strcmp(final_finish, "length")) { - /* Store the post-turn visible transcript plus the live token - * frontier. The next Responses request may replay only this - * visible surface, while the real session also contains hidden - * reasoning and exact sampled tool-call bytes. */ - char *visible_suffix = - build_responses_visible_assistant_suffix(&j->req, - parsed_content ? parsed_content : "", - parsed_reasoning, - &parsed_calls); - buf visible = {0}; - buf_puts(&visible, j->req.prompt_text ? j->req.prompt_text : ""); - buf_puts(&visible, visible_suffix ? visible_suffix : ""); - responses_live_remember(s, visible.ptr ? visible.ptr : "", - parsed_calls.len ? &parsed_calls : NULL); - buf_free(&visible); - free(visible_suffix); - } else { - responses_live_clear(s); - } - } - if (j->req.api == API_ANTHROPIC) { - if (parsed_calls.len && strcmp(final_finish, "error") && - strcmp(final_finish, "length")) - { - anthropic_live_remember(s, &parsed_calls); - } else { - anthropic_live_clear(s); + p->reply = PRODUCTION_REPLY_NORMAL; + p->normal_ready = true; + p->count_generated = true; + p->recovered_tool_parse_failure = recovered_tool_parse_failure; + p->saw_tool_start = saw_tool_start; + p->saw_tool_end = saw_tool_end; + p->completion = completion; + p->decode_started_at = decode_t0; + p->final_finish = final_finish; + p->thinking = thinking; + p->text = text; + p->parsed_calls = parsed_calls; + p->parsed_content = parsed_content; + p->parsed_reasoning = parsed_reasoning; + if (!strcmp(final_finish, "error")) { + if (p->first_failure_reason == SERVER_TXN_REASON_NONE) { + production_latch_failure( + p, SERVER_TXN_FAILED, SERVER_TXN_REASON_DECODE_FAILED, + production_live_session(p), p->err); } + return production_terminal( + p, p->first_failure_class, p->first_failure_reason, + SERVER_TXN_FINISH_ERROR, p->first_failure_session, p->err); + } else if (!strcmp(final_finish, "tool_calls")) { + return production_terminal( + p, SERVER_TXN_COMPLETED, SERVER_TXN_REASON_TOOL_CALLS, + SERVER_TXN_FINISH_TOOL_CALLS, SERVER_SESSION_VALID_PREFIX, NULL); + } else if (!strcmp(final_finish, "length")) { + return production_terminal( + p, SERVER_TXN_COMPLETED, SERVER_TXN_REASON_LENGTH, + SERVER_TXN_FINISH_LENGTH, SERVER_SESSION_VALID_PREFIX, NULL); + } + return production_terminal( + p, SERVER_TXN_COMPLETED, SERVER_TXN_REASON_STOP, + SERVER_TXN_FINISH_STOP, SERVER_SESSION_VALID_PREFIX, NULL); +} + +static server_txn_step_result production_session_advance( + void *ctx, const server_txn_outcome *outcome, + server_txn_phase phase) { + production_txn *p = ctx; + switch (phase) { + case SERVER_TXN_PHASE_RESTORE: + return production_restore(p, outcome); + case SERVER_TXN_PHASE_SYNCHRONIZE: + return production_synchronize(p, outcome); + case SERVER_TXN_PHASE_EXTEND: + return production_extend(p, outcome); + case SERVER_TXN_PHASE_DECODE: + return production_decode(p, outcome); + default: + return production_terminal( + p, SERVER_TXN_FAILED, SERVER_TXN_REASON_INTERNAL, + SERVER_TXN_FINISH_ERROR, SERVER_SESSION_INVALIDATED, + "production adapter received an invalid phase"); } +} - if (j->req.kind == REQ_CHAT && parsed_calls.len && - j->req.api != API_RESPONSES && - should_canonicalize_tool_checkpoint(s, &parsed_calls)) - { - /* Chat/completions has no protocol object that binds the next request - * to this live KV state. Canonicalize only the fallback tool-call - * path where we lack exact sampled DSML replay; when raw DSML is known, - * replaying those bytes keeps future prompts aligned without rebuilding - * hidden reasoning. Responses deliberately skips this path because its - * previous_response_id contract binds the next turn to live state. */ - canonicalize_tool_checkpoint(s, j, ctx_span, trace_id, - parsed_content ? parsed_content : "", - parsed_reasoning, &parsed_calls); - thinking_live_clear(s); - } else if (parsed_calls.len) { - thinking_live_clear(s); - } else if (!parsed_calls.len && - should_remember_thinking_checkpoint(&j->req, &thinking, final_finish)) { - remember_thinking_checkpoint(s, j, ctx_span, trace_id, - parsed_content ? parsed_content : ""); - } else if (!parsed_calls.len) { - thinking_live_clear(s); +static server_txn_outcome server_txn_run(server *s, job *j) { + production_txn production = { + .srv = s, + .job = j, + .wire = SERVER_WIRE_UNTOUCHED, + }; + production.effects = (server_txn_adapters) { + .session = { + .ctx = &production, + .advance = production_session_advance, + .settle = production_session_settle, + .cleanup = production_session_cleanup, + }, + .output = { + .ctx = &production, + .apply = production_output_apply, + .finish = production_output_finish, + }, + .trace = { + .ctx = &production, + .record = production_trace_record, + .finish = production_trace_finish, + }, + .stats = { + .ctx = &production, + .record = production_statistics_record, + .finish = production_statistics_finish, + }, + }; + return server_txn_run_adapters(&production.effects); +} + +static server_txn_settle_result production_session_settle( + void *ctx, const server_txn_outcome *outcome, bool commit) { + production_txn *p = ctx; + server *s = p->srv; + job *j = p->job; + if (p->callbacks_attached) { + ds4_session_set_cancel(s->session, NULL, NULL); + ds4_session_set_progress(s->session, NULL, NULL); + ds4_session_set_display_progress(s->session, NULL, NULL); + p->callbacks_attached = false; + } + if (!p->normal_ready) { + return (server_txn_settle_result) { + .ok = true, + .session = outcome->session, + .wire = p->wire, + .secondary = p->phase_secondary, + }; } - if (j->req.stream) { - bool response_ok = true; + const char *final_finish = p->final_finish ? p->final_finish : "error"; + bool canonicalization_failed = false; + tool_calls *parsed_calls = &p->parsed_calls; + const char *parsed_content = p->parsed_content; + const char *parsed_reasoning = p->parsed_reasoning; + if (commit) { + if (j->req.api == API_RESPONSES) { + if (strcmp(final_finish, "error") && strcmp(final_finish, "length")) { + char *visible_suffix = + build_responses_visible_assistant_suffix( + &j->req, parsed_content ? parsed_content : "", + parsed_reasoning, parsed_calls); + buf visible = {0}; + buf_puts(&visible, + j->req.prompt_text ? j->req.prompt_text : ""); + buf_puts(&visible, visible_suffix ? visible_suffix : ""); + responses_live_remember( + s, visible.ptr ? visible.ptr : "", + parsed_calls->len ? parsed_calls : NULL); + buf_free(&visible); + free(visible_suffix); + } else { + responses_live_clear(s); + } + } if (j->req.api == API_ANTHROPIC) { - response_ok = anthropic_sse_finish_live(j->fd, s, &j->req, id, &anthropic_live, - text.ptr ? text.ptr : "", text.len, - &parsed_calls, final_finish, completion); - } else if (openai_live_chat) { - response_ok = openai_sse_finish_live(j->fd, s, &j->req, id, &openai_live, - text.ptr ? text.ptr : "", text.len, - &parsed_calls, final_finish, - prompt_tokens, completion); - } else if (responses_live_chat) { - /* If parse recovered a malformed tool call back to plain text, - * pass parsed_content so the streaming tail can be flushed; in - * the normal path parsed_content is the assistant text we already - * streamed and the diff is empty. */ - const char *recover = - recovered_tool_parse_failure ? parsed_content : NULL; - response_ok = responses_sse_finish_live(j->fd, &j->req, &responses_live, - text.ptr ? text.ptr : "", text.len, - recover, - &parsed_calls, final_finish, - prompt_tokens, completion, - responses_created_at); - } else if (structured_stream) { - response_ok = sse_chat_finish(j->fd, &j->req, id, - parsed_content ? parsed_content : (text.ptr ? text.ptr : ""), - parsed_reasoning, - &parsed_calls, final_finish, - prompt_tokens, completion); + if (parsed_calls->len && strcmp(final_finish, "error") && + strcmp(final_finish, "length")) { + anthropic_live_remember(s, parsed_calls); + } else { + anthropic_live_clear(s); + } + } + + if (j->req.kind == REQ_CHAT && parsed_calls->len && + j->req.api != API_RESPONSES && + should_canonicalize_tool_checkpoint(s, parsed_calls)) { + if (!canonicalize_tool_checkpoint( + s, j, p->ctx_span, &p->effects, + &p->phase_secondary, &p->wire, + parsed_content ? parsed_content : "", parsed_reasoning, + parsed_calls)) { + p->phase_secondary |= SERVER_TXN_SECONDARY_CHECKPOINT; + canonicalization_failed = true; + } + thinking_live_clear(s); + } else if (parsed_calls->len) { + if (j->req.kind == REQ_CHAT && j->req.api != API_RESPONSES && + !strcmp(final_finish, "tool_calls")) { + remember_tool_visible_checkpoint( + s, j, p->ctx_span, &p->effects.trace, + &p->phase_secondary, + parsed_content ? parsed_content : "", parsed_reasoning, + parsed_calls); + } else { + thinking_live_clear(s); + } + } else if (should_remember_thinking_checkpoint( + &j->req, &p->thinking, final_finish)) { + remember_thinking_checkpoint( + s, j, p->ctx_span, &p->effects.trace, + &p->phase_secondary, + parsed_content ? parsed_content : ""); } else { - response_ok = sse_chunk(j->fd, &j->req, id, NULL, final_finish) && - sse_done(j->fd, &j->req, id, prompt_tokens, completion); + thinking_live_clear(s); } - if (!response_ok) { - server_log(DS4_LOG_DEFAULT, - "ds4-server: %s ctx=%s%s%s final stream failed", - j->req.kind == REQ_CHAT ? "chat" : "completion", - ctx_span, - req_flags[0] ? " " : "", - req_flags); - } - } else if (j->req.api == API_ANTHROPIC) { - anthropic_final_response(j->fd, s->enable_cors, &j->req, id, - parsed_content ? parsed_content : (text.ptr ? text.ptr : ""), - parsed_reasoning, - &parsed_calls, final_finish, - prompt_tokens, completion); - } else if (j->req.api == API_RESPONSES) { - responses_final_response(j->fd, s->enable_cors, &j->req, id, - parsed_content ? parsed_content : (text.ptr ? text.ptr : ""), - parsed_reasoning, - &parsed_calls, final_finish, - prompt_tokens, completion); } else { - final_response(j->fd, s->enable_cors, &j->req, id, - parsed_content ? parsed_content : (text.ptr ? text.ptr : ""), - parsed_reasoning, - &parsed_calls, final_finish, - prompt_tokens, completion); + /* Rollback: this turn's frontier is not kept, so a live binding + * remembered for it must not survive to match a later request. */ + if (j->req.api == API_RESPONSES) responses_live_clear(s); + if (j->req.api == API_ANTHROPIC) anthropic_live_clear(s); + thinking_live_clear(s); } - if (j->req.kind == REQ_CHAT && j->req.has_tools) { - char flags[80]; - log_flags(flags, sizeof(flags), - responses_protocol, - true, - thinking.inside, - saw_tool_start, - saw_tool_end); - if (!strcmp(final_finish, "error") && err[0]) { - server_log(DS4_LOG_GENERATION, - "ds4-server: chat ctx=%s gen=%d%s%s finish=%s error=\"%s\" %.3fs", - ctx_span, - completion, - flags[0] ? " " : "", - flags, - final_finish, - err, - now_sec() - t0); + + server_session_disposition disposition = outcome->session; + if (commit) { + if (!ds4_session_is_valid(s->session)) { + disposition = SERVER_SESSION_INVALIDATED; } else { - server_log(DS4_LOG_GENERATION, - "ds4-server: chat ctx=%s gen=%d%s%s finish=%s %.3fs", - ctx_span, - completion, - flags[0] ? " " : "", - flags, - final_finish, - now_sec() - t0); + disposition = canonicalization_failed ? + SERVER_SESSION_VALID_PREFIX : SERVER_SESSION_COMMITTED; } - } else { + } else if (p->session_entered) { + disposition = production_live_session(p); + } + return (server_txn_settle_result) { + .ok = true, + .session = disposition, + .wire = p->wire, + .failure_class = p->first_failure_class, + .failure_reason = outcome->class == SERVER_TXN_COMPLETED ? + p->first_failure_reason : SERVER_TXN_REASON_NONE, + .failure_detail = p->first_failure_detail, + .secondary = p->phase_secondary, + }; +} + +static server_txn_output_result production_output_finish( + void *ctx, const server_txn_outcome *outcome) { + production_txn *p = ctx; + server *s = p->srv; + job *j = p->job; + bool ok = true; + + if (p->reply == PRODUCTION_REPLY_NONE) { + return (server_txn_output_result) {.ok = true, .wire = p->wire}; + } + + p->wire = SERVER_WIRE_IRREVERSIBLE; + if (p->reply == PRODUCTION_REPLY_RESPONSES_CONFLICT) { + ok = http_error( + j->fd, s->enable_cors, 409, + "Responses continuation state is not available; retry by replaying the full input history"); + } else if (p->reply == PRODUCTION_REPLY_ANTHROPIC_CONFLICT) { + ok = http_error_api( + j->fd, s->enable_cors, 409, + "Anthropic continuation state is not available; retry by replaying the full messages history", + API_ANTHROPIC); + } else if (p->reply == PRODUCTION_REPLY_PREFILL_ERROR) { + ok = send_prefill_failure_response( + s, j, &p->progress, p->ctx_span, p->req_flags, p->err); + } else if (p->reply == PRODUCTION_REPLY_NORMAL) { + const char *final_finish = p->final_finish ? p->final_finish : "error"; + const char *parsed_content = p->parsed_content; + const char *parsed_reasoning = p->parsed_reasoning; + tool_calls *parsed_calls = &p->parsed_calls; + buf *text = &p->text; + if (j->req.stream) { + if (j->req.api == API_ANTHROPIC) { + ok = anthropic_sse_finish_live( + j->fd, s, &j->req, p->response_id, + &p->anthropic_live, + text->ptr ? text->ptr : "", text->len, parsed_calls, + final_finish, p->completion); + } else if (p->openai_live_chat) { + ok = openai_sse_finish_live( + j->fd, s, &j->req, p->response_id, + &p->openai_live, + text->ptr ? text->ptr : "", text->len, parsed_calls, + final_finish, p->prompt_tokens, p->completion); + } else if (p->responses_live_chat) { + const char *recover = p->recovered_tool_parse_failure ? + parsed_content : NULL; + ok = responses_sse_finish_live( + j->fd, &j->req, &p->responses_live, + text->ptr ? text->ptr : "", text->len, recover, + parsed_calls, final_finish, p->prompt_tokens, + p->completion, p->responses_created_at); + } else if (p->structured_stream) { + ok = sse_chat_finish( + j->fd, &j->req, p->response_id, + parsed_content ? parsed_content : + (text->ptr ? text->ptr : ""), + parsed_reasoning, parsed_calls, final_finish, + p->prompt_tokens, p->completion); + } else { + ok = sse_chunk(j->fd, &j->req, p->response_id, NULL, + final_finish) && + sse_done(j->fd, &j->req, p->response_id, + p->prompt_tokens, p->completion); + } + if (!ok) { + server_log( + DS4_LOG_DEFAULT, + "ds4-server: %s ctx=%s%s%s final stream failed", + j->req.kind == REQ_CHAT ? "chat" : "completion", + p->ctx_span, p->req_flags[0] ? " " : "", + p->req_flags); + } + } else if (outcome->reason == SERVER_TXN_REASON_CLIENT_GONE) { + p->wire = SERVER_WIRE_UNTOUCHED; + return (server_txn_output_result) {.ok = true, .wire = p->wire}; + } else if (j->req.api == API_ANTHROPIC) { + ok = anthropic_final_response( + j->fd, s->enable_cors, &j->req, p->response_id, + parsed_content ? parsed_content : + (text->ptr ? text->ptr : ""), + parsed_reasoning, parsed_calls, final_finish, + p->prompt_tokens, p->completion); + } else if (j->req.api == API_RESPONSES) { + ok = responses_final_response( + j->fd, s->enable_cors, &j->req, p->response_id, + parsed_content ? parsed_content : + (text->ptr ? text->ptr : ""), + parsed_reasoning, parsed_calls, final_finish, + p->prompt_tokens, p->completion); + } else { + ok = final_response( + j->fd, s->enable_cors, &j->req, p->response_id, + parsed_content ? parsed_content : + (text->ptr ? text->ptr : ""), + parsed_reasoning, parsed_calls, final_finish, + p->prompt_tokens, p->completion); + } + } + + p->wire = ok ? SERVER_WIRE_COMPLETE : SERVER_WIRE_BROKEN; + return (server_txn_output_result) {.ok = ok, .wire = p->wire}; +} + +static bool production_statistics_finish( + void *ctx, const server_txn_outcome *outcome) { + production_txn *p = ctx; + server *s = p->srv; + if (p->count_generated) { + const double decode_sec = now_sec() - p->decode_started_at; + pthread_mutex_lock(&s->mu); + s->stats.generated_tokens += (uint64_t)p->completion; + if (p->completion > 0 && decode_sec > 0.0) { + s->stats.last_decode_tps = (double)p->completion / decode_sec; + } + pthread_mutex_unlock(&s->mu); + p->count_generated = false; + } + if (p->counted_request) { + pthread_mutex_lock(&s->mu); + s->busy = false; + pthread_mutex_unlock(&s->mu); + p->counted_request = false; + } + (void)outcome; + const int live_tokens = p->session_entered ? + ds4_session_pos(s->session) : s->stats_snapshot.live_tokens; + server_publish_stats_snapshot(s, live_tokens); + return true; +} + +static bool production_trace_finish( + void *ctx, const server_txn_outcome *outcome) { + production_txn *p = ctx; + server *s = p->srv; + if (!p->trace_id) return true; + const char *finish = p->final_finish; + if (!finish) finish = outcome->class == SERVER_TXN_COMPLETED ? "stop" : "error"; + trace_event( + s, p->trace_id, + "terminal class=%d reason=%d phase=%d session=%d wire=%d secondary=0x%x", + (int)outcome->class, (int)outcome->reason, + (int)outcome->decided_at, (int)outcome->session, + (int)outcome->wire, outcome->secondary); + trace_finish( + s, p->trace_id, &p->job->req, finish, p->completion, + p->saw_tool_start, p->saw_tool_end, + p->parsed_content ? p->parsed_content : + (p->text.ptr ? p->text.ptr : ""), + p->parsed_reasoning, &p->parsed_calls, + now_sec() - p->started_at); + return !s->trace || !ferror(s->trace); +} + +static bool production_session_cleanup( + void *ctx, const server_txn_outcome *outcome) { + production_txn *p = ctx; + server *s = p->srv; + job *j = p->job; + if (p->callbacks_attached) { + ds4_session_set_cancel(s->session, NULL, NULL); + ds4_session_set_progress(s->session, NULL, NULL); + ds4_session_set_display_progress(s->session, NULL, NULL); + p->callbacks_attached = false; + } + if (p->normal_ready) { + const char *final_finish = p->final_finish ? p->final_finish : "error"; char flags[80]; - log_flags(flags, sizeof(flags), - responses_protocol, + log_flags(flags, sizeof(flags), p->responses_protocol, j->req.has_tools, - thinking.inside, - false, - false); - if (!strcmp(final_finish, "error") && err[0]) { - server_log(DS4_LOG_GENERATION, - "ds4-server: %s ctx=%s gen=%d%s%s finish=%s error=\"%s\" %.3fs", - j->req.kind == REQ_CHAT ? "chat" : "completion", - ctx_span, - completion, - flags[0] ? " " : "", - flags, - final_finish, - err, - now_sec() - t0); + p->thinking.inside, + j->req.has_tools ? p->saw_tool_start : false, + j->req.has_tools ? p->saw_tool_end : false); + const char *terminal_error = outcome->detail[0] ? + outcome->detail : p->err; + if (!strcmp(final_finish, "error") && terminal_error[0]) { + server_log( + DS4_LOG_GENERATION, + "ds4-server: %s ctx=%s gen=%d%s%s finish=%s error=\"%s\" %.3fs", + j->req.kind == REQ_CHAT ? "chat" : "completion", + p->ctx_span, p->completion, flags[0] ? " " : "", flags, + final_finish, terminal_error, now_sec() - p->started_at); } else { - server_log(DS4_LOG_GENERATION, - "ds4-server: %s ctx=%s gen=%d%s%s finish=%s %.3fs", - j->req.kind == REQ_CHAT ? "chat" : "completion", - ctx_span, - completion, - flags[0] ? " " : "", - flags, - final_finish, - now_sec() - t0); + server_log( + DS4_LOG_GENERATION, + "ds4-server: %s ctx=%s gen=%d%s%s finish=%s %.3fs", + j->req.kind == REQ_CHAT ? "chat" : "completion", + p->ctx_span, p->completion, flags[0] ? " " : "", flags, + final_finish, now_sec() - p->started_at); } } - free(parsed_content); - free(parsed_reasoning); - tool_calls_free(&parsed_calls); - anthropic_stream_free(&anthropic_live); - openai_stream_free(&openai_live); - responses_stream_free(&responses_live); - buf_free(&text); - ds4_tokens_free(&effective_prompt); + free(p->parsed_content); + p->parsed_content = NULL; + free(p->parsed_reasoning); + p->parsed_reasoning = NULL; + tool_calls_free(&p->parsed_calls); + anthropic_stream_free(&p->anthropic_live); + openai_stream_free(&p->openai_live); + responses_stream_free(&p->responses_live); + buf_free(&p->text); + ds4_tokens_free(&p->effective_prompt); + free(p->disk_cache_path); + p->disk_cache_path = NULL; + (void)outcome; + return true; } -static bool enqueue(server *s, job *j) { +enum { ENQUEUE_OK = 0, ENQUEUE_STOPPING, ENQUEUE_FULL }; + +static int enqueue(server *s, job *j) { pthread_mutex_lock(&s->mu); if (s->stopping) { pthread_mutex_unlock(&s->mu); - return false; + return ENQUEUE_STOPPING; + } + if (s->max_queue > 0 && s->queue_depth >= s->max_queue) { + s->stats.queue_rejected++; + s->stats_refresh_requested = true; + pthread_cond_signal(&s->cv); + pthread_mutex_unlock(&s->mu); + return ENQUEUE_FULL; } if (s->tail) s->tail->next = j; else s->head = j; s->tail = j; + s->queue_depth++; + const int waiting = s->queue_depth; + const bool busy = s->busy; pthread_cond_signal(&s->cv); pthread_mutex_unlock(&s->mu); - return true; + if (waiting > 1 || busy) { + server_log(DS4_LOG_DEFAULT, + "ds4-server: request queued behind %d job(s)%s", + waiting - 1, busy ? " (worker busy)" : ""); + } + return ENQUEUE_OK; } -static job *dequeue(server *s) { - pthread_mutex_lock(&s->mu); - while (!s->head && !s->stopping) pthread_cond_wait(&s->cv, &s->mu); - if (!s->head) { +static job *dequeue(server *s, int live_tokens) { + for (;;) { + pthread_mutex_lock(&s->mu); + while (!s->head && !s->stopping && !s->stats_refresh_requested) { + pthread_cond_wait(&s->cv, &s->mu); + } + if (s->head) { + job *j = s->head; + s->head = j->next; + if (!s->head) s->tail = NULL; + if (s->queue_depth > 0) s->queue_depth--; + pthread_mutex_unlock(&s->mu); + j->next = NULL; + return j; + } + if (s->stats_refresh_requested) { + s->stats_refresh_requested = false; + pthread_mutex_unlock(&s->mu); + server_publish_stats_snapshot(s, live_tokens); + continue; + } pthread_mutex_unlock(&s->mu); return NULL; } - job *j = s->head; - s->head = j->next; - if (!s->head) s->tail = NULL; - pthread_mutex_unlock(&s->mu); - j->next = NULL; - return j; +} + +static bool job_publish_terminal_outcome(job *j, + const server_txn_outcome *outcome) { + bool published = false; + pthread_mutex_lock(&j->mu); + if (!j->outcome_ready) { + j->outcome = *outcome; + j->outcome_ready = true; + j->done = true; + pthread_cond_signal(&j->cv); + published = true; + } + pthread_mutex_unlock(&j->mu); + return published; } static void *worker_main(void *arg) { server *s = arg; + s->worker_thread = pthread_self(); + s->worker_bound = true; + server_publish_stats_snapshot(s, ds4_session_pos(s->session)); for (;;) { - job *j = dequeue(s); + job *j = dequeue(s, ds4_session_pos(s->session)); if (!j) break; - generate_job(s, j); - pthread_mutex_lock(&j->mu); - j->done = true; - pthread_cond_signal(&j->cv); - pthread_mutex_unlock(&j->mu); + server_txn_outcome outcome = server_txn_run(s, j); + if (!job_publish_terminal_outcome(j, &outcome)) { + /* The terminalizer is idempotent, so a duplicate publish means an + * engine bug; the first outcome already reached the client, so + * dropping the duplicate is safer than killing a loaded server. */ + server_log(DS4_LOG_WARNING, + "ds4-server: dropped duplicate terminal outcome for an admitted request"); + } + } + const ds4_tokens *tokens = ds4_session_tokens(s->session); + if (s->kv.enabled && tokens && tokens->len >= s->kv.opt.min_tokens) { + server_log(DS4_LOG_KVCACHE, + "ds4-server: persisting current KV cache before shutdown tokens=%d", + tokens->len); + if (!kv_cache_store_current(s, "shutdown")) { + server_log(DS4_LOG_WARNING, + "ds4-server: shutdown KV persist failed; next start will re-prefill"); + } } + server_publish_stats_snapshot(s, ds4_session_pos(s->session)); return NULL; } @@ -11117,11 +12835,39 @@ static long content_length(const char *h, size_t n) { return 0; } -static bool read_http_request(int fd, http_request *r) { +/* True when the header block contains `name` and its value contains `value` + * (both case-insensitive). */ +static bool header_value_contains(const char *h, size_t n, + const char *name, const char *value) { + const size_t name_len = strlen(name); + const char *p = h, *end = h + n; + while (p < end) { + const char *line = p; + while (p < end && *p != '\n') p++; + size_t len = (size_t)(p - line); + if (len && line[len - 1] == '\r') len--; + if (len > name_len && strncasecmp(line, name, name_len) == 0 && + line[name_len] == ':') + { + char v[128]; + size_t vlen = len - name_len - 1; + if (vlen >= sizeof(v)) vlen = sizeof(v) - 1; + memcpy(v, line + name_len + 1, vlen); + v[vlen] = '\0'; + for (size_t k = 0; v[k]; k++) v[k] = (char)tolower((unsigned char)v[k]); + return strstr(v, value) != NULL; + } + if (p < end) p++; + } + return false; +} + +static bool read_http_request(int fd, http_request *r, const char **errmsg) { buf b = {0}; ssize_t hend = -1; const size_t max_header = 64 * 1024; const size_t max_body = 64 * 1024 * 1024; + if (errmsg) *errmsg = "bad HTTP request"; while (hend < 0 && b.len < max_header) { char tmp[4096]; @@ -11144,6 +12890,19 @@ static bool read_http_request(int fd, http_request *r) { char *q = strchr(r->path, '?'); if (q) *q = '\0'; + if (header_value_contains(b.ptr, (size_t)hend, "Transfer-Encoding", "chunked")) { + /* Chunked bodies used to be silently read as Content-Length: 0 and + * fail JSON parsing with a misleading error. */ + if (errmsg) *errmsg = "chunked transfer encoding is not supported; send Content-Length"; + goto fail; + } + if (header_value_contains(b.ptr, (size_t)hend, "Expect", "100-continue")) { + /* curl-style clients wait up to a second for this interim response + * before sending a large POST body. */ + static const char cont[] = "HTTP/1.1 100 Continue\r\n\r\n"; + if (!send_all(fd, cont, sizeof(cont) - 1)) goto fail; + } + long clen = content_length(b.ptr, (size_t)hend); if (clen < 0 || (size_t)clen > max_body) goto fail; while (b.len < (size_t)hend + (size_t)clen) { @@ -11210,7 +12969,7 @@ static void append_model_json(buf *b, const server *s, const char *id) { append_model_json_values(b, id, ds4_engine_model_name(s->engine), - ds4_session_ctx(s->session), + s->ctx_size, s->default_tokens); } @@ -11235,9 +12994,92 @@ static bool send_models(server *s, int fd) { return ok; } +/* Both handlers run on the client thread, so they answer immediately even + * while the worker is deep inside a multi-minute prefill. */ +static bool send_health(server *s, int fd) { + buf b = {0}; + buf_puts(&b, "{\"status\":\"ok\",\"model\":"); + json_escape(&b, ds4_engine_model_name(s->engine)); + buf_printf(&b, ",\"uptime_s\":%.0f}\n", now_sec() - s->started_at); + bool ok = http_response(fd, s->enable_cors, 200, "application/json", b.ptr); + buf_free(&b); + return ok; +} + +static bool send_stats(server *s, int fd) { + pthread_mutex_lock(&s->mu); + const server_stats_snapshot snapshot = s->stats_snapshot; + pthread_mutex_unlock(&s->mu); + const server_stats st = snapshot.counters; + const uint64_t cache_hits = st.cache_memory_token + st.cache_memory_text + + st.cache_responses_visible + + st.cache_responses_tool_output + + st.cache_anthropic_tool_output + + st.cache_thinking_visible + + st.cache_tool_visible + st.cache_disk_text; + buf b = {0}; + buf_printf(&b, + "{\"uptime_s\":%.0f," + "\"busy\":%s," + "\"queue_depth\":%d," + "\"clients\":%d," + "\"live_tokens\":%d," + "\"ctx_size\":%d," + "\"requests\":%llu," + "\"queue_rejected\":%llu," + "\"queue_dropped_disconnected\":%llu," + "\"prefill_cancelled\":%llu," + "\"prompt_tokens\":%llu," + "\"cached_tokens\":%llu," + "\"generated_tokens\":%llu," + "\"last_prefill_tps\":%.2f," + "\"last_decode_tps\":%.2f," + "\"cache\":{" + "\"hits\":%llu," + "\"cold\":%llu," + "\"memory_token\":%llu," + "\"memory_text\":%llu," + "\"responses_visible\":%llu," + "\"responses_tool_output\":%llu," + "\"anthropic_tool_output\":%llu," + "\"thinking_visible\":%llu," + "\"tool_visible\":%llu," + "\"disk_text\":%llu}}\n", + now_sec() - s->started_at, + snapshot.busy ? "true" : "false", + snapshot.queue_depth, + snapshot.clients, + snapshot.live_tokens, + snapshot.ctx_size, + (unsigned long long)st.requests, + (unsigned long long)st.queue_rejected, + (unsigned long long)st.queue_dropped_disconnected, + (unsigned long long)st.prefill_cancelled, + (unsigned long long)st.prompt_tokens, + (unsigned long long)st.cached_tokens, + (unsigned long long)st.generated_tokens, + st.last_prefill_tps, + st.last_decode_tps, + (unsigned long long)cache_hits, + (unsigned long long)st.cache_cold, + (unsigned long long)st.cache_memory_token, + (unsigned long long)st.cache_memory_text, + (unsigned long long)st.cache_responses_visible, + (unsigned long long)st.cache_responses_tool_output, + (unsigned long long)st.cache_anthropic_tool_output, + (unsigned long long)st.cache_thinking_visible, + (unsigned long long)st.cache_tool_visible, + (unsigned long long)st.cache_disk_text); + bool ok = http_response(fd, s->enable_cors, 200, "application/json", b.ptr); + buf_free(&b); + return ok; +} + static void client_done(server *s) { pthread_mutex_lock(&s->mu); if (s->clients > 0) s->clients--; + s->stats_refresh_requested = true; + pthread_cond_signal(&s->cv); pthread_cond_broadcast(&s->clients_cv); pthread_mutex_unlock(&s->mu); } @@ -11251,8 +13093,9 @@ static void *client_main(void *arg) { free(ca); http_request hr = {0}; - if (!read_http_request(fd, &hr)) { - http_error(fd, s->enable_cors, 400, "bad HTTP request"); + const char *read_err = NULL; + if (!read_http_request(fd, &hr, &read_err)) { + http_error(fd, s->enable_cors, 400, read_err ? read_err : "bad HTTP request"); goto done; } @@ -11267,6 +13110,20 @@ static void *client_main(void *arg) { http_request_free(&hr); goto done; } + if (!strcmp(hr.method, "GET") && + (!strcmp(hr.path, "/health") || !strcmp(hr.path, "/v1/health"))) + { + send_health(s, fd); + http_request_free(&hr); + goto done; + } + if (!strcmp(hr.method, "GET") && + (!strcmp(hr.path, "/stats") || !strcmp(hr.path, "/v1/stats"))) + { + send_stats(s, fd); + http_request_free(&hr); + goto done; + } const char *model_path_prefix = "/v1/models/"; const size_t model_path_prefix_len = strlen(model_path_prefix); if (!strcmp(hr.method, "GET") && @@ -11281,7 +13138,7 @@ static void *client_main(void *arg) { request req; char err[160]; bool ok = false; - const int ctx_size = ds4_session_ctx(s->session); + const int ctx_size = s->ctx_size; if (!strcmp(hr.method, "POST") && !strcmp(hr.path, "/v1/messages")) { ok = parse_anthropic_request(s->engine, s, hr.body, s->default_tokens, ctx_size, &req, err, sizeof(err)); @@ -11299,10 +13156,12 @@ static void *client_main(void *arg) { http_request_free(&hr); goto done; } + const bool anthropic_endpoint = !strcmp(hr.path, "/v1/messages"); if (ok) req.raw_body = xstrndup(hr.body, hr.body_len); http_request_free(&hr); if (!ok) { - http_error(fd, s->enable_cors, 400, err); + http_error_api(fd, s->enable_cors, 400, err, + anthropic_endpoint ? API_ANTHROPIC : API_OPENAI); goto done; } if (!req.model_from_request) { @@ -11324,9 +13183,15 @@ static void *client_main(void *arg) { pthread_cond_init(&j.cv, NULL); pthread_mutex_lock(&j.mu); - if (!enqueue(s, &j)) { + const int enq = enqueue(s, &j); + if (enq != ENQUEUE_OK) { pthread_mutex_unlock(&j.mu); - http_error(fd, s->enable_cors, 503, "server shutting down"); + if (enq == ENQUEUE_FULL) { + http_error_api(fd, s->enable_cors, 429, + "server request queue is full; retry later", j.req.api); + } else { + http_error_api(fd, s->enable_cors, 503, "server shutting down", j.req.api); + } pthread_cond_destroy(&j.cv); pthread_mutex_destroy(&j.mu); request_free(&j.req); @@ -11377,6 +13242,10 @@ static void configure_client_socket(int fd) { tv.tv_usec = 0; setsockopt(fd, SOL_SOCKET, SO_RCVTIMEO, &tv, sizeof(tv)); setsockopt(fd, SOL_SOCKET, SO_SNDTIMEO, &tv, sizeof(tv)); + /* Per-token SSE writes are tiny; without this Nagle adds latency jitter + * whenever the client is not on loopback. */ + int yes = 1; + setsockopt(fd, IPPROTO_TCP, TCP_NODELAY, &yes, sizeof(yes)); } static void set_client_socket_nonblocking(int fd) { @@ -11402,6 +13271,7 @@ typedef struct { bool disable_exact_dsml_tool_replay; int tool_memory_max_ids; bool enable_cors; + int max_queue; } server_config; static int parse_int_arg(const char *s, const char *opt) { @@ -11574,6 +13444,8 @@ static server_config parse_options(int argc, char **argv) { c.port = parse_int_arg(need_arg(&i, argc, argv, arg), arg); } else if (!strcmp(arg, "--cors")) { c.enable_cors = true; + } else if (!strcmp(arg, "--max-queue")) { + c.max_queue = parse_nonneg_int_arg(need_arg(&i, argc, argv, arg), arg); } else if (!strcmp(arg, "--trace")) { c.trace_path = need_arg(&i, argc, argv, arg); } else if (!strcmp(arg, "--kv-disk-dir")) { @@ -11736,10 +13608,14 @@ int main(int argc, char **argv) { memset(&s, 0, sizeof(s)); s.engine = engine; s.session = session; + s.ctx_size = cfg.ctx_size; s.default_tokens = cfg.default_tokens; s.disable_exact_dsml_tool_replay = cfg.disable_exact_dsml_tool_replay; s.tool_mem.max_entries = cfg.tool_memory_max_ids; s.enable_cors = cfg.enable_cors; + s.max_queue = cfg.max_queue; + s.started_at = now_sec(); + s.stats_snapshot.ctx_size = cfg.ctx_size; if (cfg.kv_disk_dir) { kv_cache_open(&s.kv, cfg.kv_disk_dir, cfg.kv_disk_space_mb, cfg.kv_cache_reject_different_quant, cfg.kv_cache); @@ -11801,11 +13677,15 @@ int main(int argc, char **argv) { ca->fd = fd; pthread_mutex_lock(&s.mu); s.clients++; + s.stats_refresh_requested = true; + pthread_cond_signal(&s.cv); pthread_mutex_unlock(&s.mu); pthread_t th; if (pthread_create(&th, NULL, client_main, ca) != 0) { pthread_mutex_lock(&s.mu); s.clients--; + s.stats_refresh_requested = true; + pthread_cond_signal(&s.cv); pthread_cond_broadcast(&s.clients_cv); pthread_mutex_unlock(&s.mu); free(ca); @@ -11829,13 +13709,6 @@ int main(int argc, char **argv) { while (s.clients > 0) pthread_cond_wait(&s.clients_cv, &s.mu); pthread_mutex_unlock(&s.mu); - const ds4_tokens *tokens = ds4_session_tokens(s.session); - if (s.kv.enabled && tokens && tokens->len >= s.kv.opt.min_tokens) { - server_log(DS4_LOG_KVCACHE, - "ds4-server: persisting current KV cache before shutdown tokens=%d", - tokens->len); - kv_cache_store_current(&s, "shutdown"); - } server_close_resources(&s); return 0; } @@ -12046,104 +13919,982 @@ static void test_responses_input_tool_search_output_rejects_bad_tools(void) { chat_msgs_free(&msgs); } -static void test_responses_input_function_call_namespace_round_trips_to_dsml(void) { - const char *tools_json = - "[{\"type\":\"namespace\",\"name\":\"mcp__perplexity__\"," - "\"tools\":[{\"type\":\"function\",\"name\":\"perplexity_search\"," - "\"parameters\":{\"type\":\"object\",\"properties\":{" - "\"query\":{\"type\":\"string\"}}}}]}]"; - const char *tools_p = tools_json; - char *schemas = NULL; - tool_schema_orders orders = {0}; - TEST_ASSERT(parse_tools_value(&tools_p, &schemas, &orders)); +static void test_responses_input_function_call_namespace_round_trips_to_dsml(void) { + const char *tools_json = + "[{\"type\":\"namespace\",\"name\":\"mcp__perplexity__\"," + "\"tools\":[{\"type\":\"function\",\"name\":\"perplexity_search\"," + "\"parameters\":{\"type\":\"object\",\"properties\":{" + "\"query\":{\"type\":\"string\"}}}}]}]"; + const char *tools_p = tools_json; + char *schemas = NULL; + tool_schema_orders orders = {0}; + TEST_ASSERT(parse_tools_value(&tools_p, &schemas, &orders)); + + const char *input_json = + "[{\"type\":\"function_call\",\"call_id\":\"call_ns\"," + "\"name\":\"perplexity_search\",\"namespace\":\"mcp__perplexity__\"," + "\"arguments\":{\"query\":\"deepseek\"}}]"; + const char *input_p = input_json; + chat_msgs msgs = {0}; + TEST_ASSERT(parse_responses_input(&input_p, &msgs, NULL, NULL)); + TEST_ASSERT(msgs.len == 1); + TEST_ASSERT(msgs.v[0].calls.len == 1); + TEST_ASSERT(!strcmp(msgs.v[0].calls.v[0].name, + "mcp__perplexity__perplexity_search")); + + char *prompt = render_chat_prompt_text(&msgs, schemas, &orders, DS4_THINK_HIGH); + TEST_ASSERT(prompt != NULL); + TEST_ASSERT(strstr(prompt, + "<｜DSML｜invoke name=\"mcp__perplexity__perplexity_search\">") != NULL); + TEST_ASSERT(strstr(prompt, "<｜DSML｜invoke name=\"perplexity_search\">") == NULL); + + free(prompt); + chat_msgs_free(&msgs); + free(schemas); + tool_schema_orders_free(&orders); +} + +static void test_responses_output_sends_tool_search_call_item(void) { + tool_calls calls = {0}; + tool_call tc = {0}; + tc.id = xstrdup("call_search"); + tc.name = xstrdup("tool_search"); + tc.arguments = xstrdup("{\"limit\":3,\"query\":\"perplexity\"}"); + tool_calls_push(&calls, tc); + const char *tools_json = + "[{\"type\":\"tool_search\",\"execution\":\"client\"," + "\"parameters\":{\"type\":\"object\",\"properties\":{" + "\"query\":{\"type\":\"string\"},\"limit\":{\"type\":\"number\"}}}}]"; + const char *tools_p = tools_json; + char *schemas = NULL; + tool_schema_orders orders = {0}; + TEST_ASSERT(parse_tools_value(&tools_p, &schemas, &orders)); + responses_tool_item item = { + .fc_id = "fc_search", + .call_id = "call_search", + .is_custom = false, + .output_index = 0, + }; + + buf out = {0}; + responses_append_function_call_item(&out, &calls.v[0], &item, + "completed", true, &orders); + TEST_ASSERT(strstr(out.ptr, "\"type\":\"tool_search_call\"") != NULL); + TEST_ASSERT(strstr(out.ptr, "\"execution\":\"client\"") != NULL); + TEST_ASSERT(strstr(out.ptr, "\"status\":\"completed\"") != NULL); + TEST_ASSERT(strstr(out.ptr, "\"arguments\":{\"limit\":3,\"query\":\"perplexity\"}") != NULL); + TEST_ASSERT(strstr(out.ptr, "\"type\":\"function_call\"") == NULL); + + buf_free(&out); + free(schemas); + tool_schema_orders_free(&orders); + tool_calls_free(&calls); +} + +static tool_calls make_swapped_bash_call(void) { + tool_calls calls = {0}; + tool_call tc = {0}; + tc.name = xstrdup("bash"); + tc.arguments = xstrdup("{\"description\":\"list files\",\"command\":\"ls -la\",\"timeout\":10}"); + tool_calls_push(&calls, tc); + return calls; +} + +static tool_schema_orders make_bash_order(void) { + tool_schema_orders orders = {0}; + tool_schema_orders_add_json(&orders, + "{\"name\":\"bash\",\"input_schema\":{\"type\":\"object\",\"properties\":{" + "\"command\":{\"type\":\"string\"}," + "\"description\":{\"type\":\"string\"}}}}"); + return orders; +} + +static char *read_socket_text(int fd) { + buf b = {0}; + char tmp[1024]; + ssize_t n; + while ((n = read(fd, tmp, sizeof(tmp))) > 0) { + buf_append(&b, tmp, (size_t)n); + } + return buf_take(&b); +} + +static void test_stats_uses_published_snapshot(void) { + server s; + memset(&s, 0, sizeof(s)); + pthread_mutex_init(&s.mu, NULL); + s.started_at = now_sec(); + s.stats_snapshot.version = 7; + s.stats_snapshot.busy = true; + s.stats_snapshot.queue_depth = 3; + s.stats_snapshot.clients = 4; + s.stats_snapshot.live_tokens = 1234; + s.stats_snapshot.ctx_size = 524288; + s.stats_snapshot.counters.requests = 9; + s.stats_snapshot.counters.cache_memory_token = 2; + + int sv[2] = {-1, -1}; + TEST_ASSERT(socketpair(AF_UNIX, SOCK_STREAM, 0, sv) == 0); + if (sv[0] >= 0 && sv[1] >= 0) { + TEST_ASSERT(send_stats(&s, sv[0])); + shutdown(sv[0], SHUT_WR); + char *out = read_socket_text(sv[1]); + TEST_ASSERT(strstr(out, "\"busy\":true") != NULL); + TEST_ASSERT(strstr(out, "\"queue_depth\":3") != NULL); + TEST_ASSERT(strstr(out, "\"clients\":4") != NULL); + TEST_ASSERT(strstr(out, "\"live_tokens\":1234") != NULL); + TEST_ASSERT(strstr(out, "\"ctx_size\":524288") != NULL); + TEST_ASSERT(strstr(out, "\"requests\":9") != NULL); + TEST_ASSERT(strstr(out, "\"hits\":2") != NULL); + free(out); + close(sv[0]); + close(sv[1]); + } + pthread_mutex_destroy(&s.mu); +} + +static void test_dequeue_prioritizes_jobs_then_publishes_idle_stats(void) { + server s; + memset(&s, 0, sizeof(s)); + pthread_mutex_init(&s.mu, NULL); + pthread_cond_init(&s.cv, NULL); + s.worker_thread = pthread_self(); + s.worker_bound = true; + s.stats_snapshot.version = 4; + s.clients = 3; + s.stats.requests = 8; + s.max_queue = 1; + + job queued; + memset(&queued, 0, sizeof(queued)); + s.head = &queued; + s.tail = &queued; + s.queue_depth = 1; + + job rejected; + memset(&rejected, 0, sizeof(rejected)); + TEST_ASSERT(enqueue(&s, &rejected) == ENQUEUE_FULL); + TEST_ASSERT(s.stats_refresh_requested); + TEST_ASSERT(s.stats.queue_rejected == 1); + s.stopping = true; + + TEST_ASSERT(dequeue(&s, 456) == &queued); + TEST_ASSERT(s.queue_depth == 0); + TEST_ASSERT(s.stats_refresh_requested); + TEST_ASSERT(s.stats_snapshot.version == 4); + + TEST_ASSERT(dequeue(&s, 456) == NULL); + TEST_ASSERT(!s.stats_refresh_requested); + TEST_ASSERT(s.stats_snapshot.version == 5); + TEST_ASSERT(s.stats_snapshot.live_tokens == 456); + TEST_ASSERT(s.stats_snapshot.clients == 3); + TEST_ASSERT(s.stats_snapshot.counters.requests == 8); + TEST_ASSERT(s.stats_snapshot.counters.queue_rejected == 1); + + pthread_cond_destroy(&s.cv); + pthread_mutex_destroy(&s.mu); +} + +static void test_production_txn_terminalizes_queued_disconnect(void) { + server s; + memset(&s, 0, sizeof(s)); + pthread_mutex_init(&s.mu, NULL); + s.ctx_size = 1024; + s.stats_snapshot.ctx_size = 1024; + s.stats_snapshot.live_tokens = 77; + + int sv[2] = {-1, -1}; + TEST_ASSERT(socketpair(AF_UNIX, SOCK_STREAM, 0, sv) == 0); + if (sv[0] < 0 || sv[1] < 0) { + pthread_mutex_destroy(&s.mu); + return; + } + close(sv[1]); + job j; + memset(&j, 0, sizeof(j)); + j.fd = sv[0]; + + server_txn_outcome outcome = server_txn_run(&s, &j); + TEST_ASSERT(outcome.class == SERVER_TXN_CANCELLED); + TEST_ASSERT(outcome.reason == SERVER_TXN_REASON_CLIENT_GONE); + TEST_ASSERT(outcome.session == SERVER_SESSION_UNCHANGED); + TEST_ASSERT(outcome.wire == SERVER_WIRE_UNTOUCHED); + TEST_ASSERT(s.stats.queue_dropped_disconnected == 1); + TEST_ASSERT(s.stats.requests == 0); + TEST_ASSERT(!s.busy); + TEST_ASSERT(s.stats_snapshot.live_tokens == 77); + close(sv[0]); + pthread_mutex_destroy(&s.mu); +} + +static void test_production_txn_shutdown_beats_queued_disconnect(void) { + server s; + memset(&s, 0, sizeof(s)); + pthread_mutex_init(&s.mu, NULL); + s.stats_snapshot.live_tokens = 77; + + int sv[2] = {-1, -1}; + TEST_ASSERT(socketpair(AF_UNIX, SOCK_STREAM, 0, sv) == 0); + if (sv[0] < 0 || sv[1] < 0) { + pthread_mutex_destroy(&s.mu); + return; + } + close(sv[1]); + job j; + memset(&j, 0, sizeof(j)); + j.fd = sv[0]; + + const sig_atomic_t saved_stop = g_stop_requested; + g_stop_requested = 1; + server_txn_outcome outcome = server_txn_run(&s, &j); + g_stop_requested = saved_stop; + + TEST_ASSERT(outcome.class == SERVER_TXN_CANCELLED); + TEST_ASSERT(outcome.reason == SERVER_TXN_REASON_SHUTDOWN); + TEST_ASSERT(outcome.session == SERVER_SESSION_UNCHANGED); + TEST_ASSERT(outcome.wire == SERVER_WIRE_UNTOUCHED); + TEST_ASSERT(s.stats.queue_dropped_disconnected == 1); + close(sv[0]); + pthread_mutex_destroy(&s.mu); +} + +static void test_production_settle_rollback_clears_live_bindings(void) { + server s; + memset(&s, 0, sizeof(s)); + pthread_mutex_init(&s.mu, NULL); + pthread_mutex_init(&s.tool_mu, NULL); + s.responses_live.visible_text = xstrdup("turn"); + s.responses_live.visible_len = 4; + s.responses_live.valid = true; + s.thinking_live.visible_text = xstrdup("turn"); + s.thinking_live.visible_len = 4; + s.thinking_live.valid = true; + s.anthropic_live.valid = true; + + job j; + memset(&j, 0, sizeof(j)); + j.req.api = API_RESPONSES; + production_txn p; + memset(&p, 0, sizeof(p)); + p.srv = &s; + p.job = &j; + p.normal_ready = true; + p.wire = SERVER_WIRE_UNTOUCHED; + const server_txn_outcome outcome = { + .class = SERVER_TXN_FAILED, + .reason = SERVER_TXN_REASON_DECODE_FAILED, + .session = SERVER_SESSION_VALID_PREFIX, + }; + + server_txn_settle_result r = production_session_settle(&p, &outcome, false); + TEST_ASSERT(r.ok); + TEST_ASSERT(r.session == SERVER_SESSION_VALID_PREFIX); + TEST_ASSERT(!s.responses_live.valid); + TEST_ASSERT(!s.thinking_live.valid); + TEST_ASSERT(s.anthropic_live.valid); + + j.req.api = API_ANTHROPIC; + r = production_session_settle(&p, &outcome, false); + TEST_ASSERT(r.ok); + TEST_ASSERT(!s.anthropic_live.valid); + + pthread_mutex_destroy(&s.tool_mu); + pthread_mutex_destroy(&s.mu); +} + +static void test_job_terminal_outcome_is_published_once(void) { + job j; + memset(&j, 0, sizeof(j)); + pthread_mutex_init(&j.mu, NULL); + pthread_cond_init(&j.cv, NULL); + const server_txn_outcome first = { + .class = SERVER_TXN_COMPLETED, + .reason = SERVER_TXN_REASON_STOP, + .finish = SERVER_TXN_FINISH_STOP, + .session = SERVER_SESSION_COMMITTED, + .wire = SERVER_WIRE_COMPLETE, + }; + const server_txn_outcome second = { + .class = SERVER_TXN_FAILED, + .reason = SERVER_TXN_REASON_INTERNAL, + }; + TEST_ASSERT(job_publish_terminal_outcome(&j, &first)); + TEST_ASSERT(!job_publish_terminal_outcome(&j, &second)); + TEST_ASSERT(j.done); + TEST_ASSERT(j.outcome_ready); + TEST_ASSERT(j.outcome.reason == SERVER_TXN_REASON_STOP); + TEST_ASSERT(j.outcome.finish == SERVER_TXN_FINISH_STOP); + pthread_cond_destroy(&j.cv); + pthread_mutex_destroy(&j.mu); +} + +typedef struct { + const server_txn_adapters *adapters; + int settle_calls; + int output_calls; + int output_apply_calls; + int trace_calls; + int trace_record_calls; + int stats_calls; + int stats_record_calls; + int cleanup_calls; + server_txn_phase phases[8]; + int phase_count; + server_txn_phase fail_phase; + server_txn_class fail_class; + server_txn_reason fail_reason; + server_session_disposition fail_session; + bool fail_settle; + bool fail_output; + int fail_output_operation; + bool fail_trace; + bool fail_trace_record; + bool fail_stats; + bool fail_stats_record; + bool fail_cleanup; + uint32_t settle_secondary; + server_txn_reason settle_failure_reason; + server_wire_disposition wire; + test_txn_event events[32]; + int event_count; +} test_txn_effects; + +static server_txn_output_result test_txn_output_apply( + void *ctx, const server_output_observation *observation); +static server_trace_result test_txn_trace_record( + void *ctx, const server_trace_observation *observation); +static bool test_txn_stats_record( + void *ctx, const server_statistics_observation *observation); + +static void test_txn_record(test_txn_effects *effects, + test_txn_event event) { + TEST_ASSERT(effects->event_count < + (int)(sizeof(effects->events) / sizeof(effects->events[0]))); + if (effects->event_count < + (int)(sizeof(effects->events) / sizeof(effects->events[0]))) { + effects->events[effects->event_count++] = event; + } +} + +static void test_txn_expect_events(const test_txn_effects *effects, + const test_txn_event *expected, + int expected_count) { + TEST_ASSERT(effects->event_count == expected_count); + int count = effects->event_count < expected_count ? + effects->event_count : expected_count; + for (int i = 0; i < count; i++) { + TEST_ASSERT(effects->events[i] == expected[i]); + } +} + +static server_txn_step_result test_txn_advance(void *ctx, + const server_txn_outcome *outcome, + server_txn_phase phase) { + (void)outcome; + test_txn_effects *effects = ctx; + uint32_t secondary = 0; + test_txn_record( + effects, (test_txn_event)(TEST_TXN_EVENT_RESTORE + + phase - SERVER_TXN_PHASE_RESTORE)); + if (effects->phase_count < (int)(sizeof(effects->phases) / + sizeof(effects->phases[0]))) { + effects->phases[effects->phase_count++] = phase; + } + if (phase == effects->fail_phase) { + return (server_txn_step_result) { + .status = SERVER_TXN_STEP_TERMINAL, + .class = effects->fail_class, + .reason = effects->fail_reason, + .session = effects->fail_session, + .wire = effects->wire, + .detail = "scripted phase failure", + .secondary = secondary, + }; + } + if (phase == SERVER_TXN_PHASE_RESTORE && effects->adapters) { + const server_trace_observation trace = { + .operation = SERVER_TRACE_BEGIN, + }; + server_trace_result trace_result = effects->adapters->trace.record( + effects->adapters->trace.ctx, &trace); + if (!trace_result.ok) secondary |= SERVER_TXN_SECONDARY_TRACE; + const server_statistics_observation stats = { + .operation = SERVER_STATS_ADMIT, + }; + if (!effects->adapters->stats.record( + effects->adapters->stats.ctx, &stats)) { + secondary |= SERVER_TXN_SECONDARY_STATS; + } + } + if (phase == SERVER_TXN_PHASE_SYNCHRONIZE && effects->adapters) { + const server_output_observation output = { + .operation = SERVER_OUTPUT_PREFILL_TICK, + }; + server_txn_output_result output_result = + effects->adapters->output.apply( + effects->adapters->output.ctx, &output); + if (!output_result.ok) { + return (server_txn_step_result) { + .status = SERVER_TXN_STEP_TERMINAL, + .class = SERVER_TXN_FAILED, + .reason = SERVER_TXN_REASON_OUTPUT_FAILED, + .finish = SERVER_TXN_FINISH_ERROR, + .session = SERVER_SESSION_VALID_PREFIX, + .wire = output_result.wire, + .detail = "scripted prefill output failure", + .secondary = secondary, + }; + } + const server_statistics_observation stats = { + .operation = SERVER_STATS_CACHE, + }; + if (!effects->adapters->stats.record( + effects->adapters->stats.ctx, &stats)) { + secondary |= SERVER_TXN_SECONDARY_STATS; + } + } + if (phase == SERVER_TXN_PHASE_EXTEND && effects->adapters) { + const server_output_observation output = { + .operation = SERVER_OUTPUT_STREAM_OPEN, + }; + server_txn_output_result output_result = + effects->adapters->output.apply( + effects->adapters->output.ctx, &output); + if (!output_result.ok) { + return (server_txn_step_result) { + .status = SERVER_TXN_STEP_TERMINAL, + .class = SERVER_TXN_FAILED, + .reason = SERVER_TXN_REASON_OUTPUT_FAILED, + .finish = SERVER_TXN_FINISH_ERROR, + .session = SERVER_SESSION_VALID_PREFIX, + .wire = output_result.wire, + .detail = "scripted stream-open failure", + .secondary = secondary, + }; + } + } + if (phase == SERVER_TXN_PHASE_DECODE) { + if (effects->adapters) { + const server_trace_observation trace = { + .operation = SERVER_TRACE_EVENT, + .text = "decode", + .text_len = 6, + }; + server_trace_result trace_result = effects->adapters->trace.record( + effects->adapters->trace.ctx, &trace); + if (!trace_result.ok) secondary |= SERVER_TXN_SECONDARY_TRACE; + const server_trace_observation piece = { + .operation = SERVER_TRACE_PIECE, + .text = "x", + .text_len = 1, + }; + trace_result = effects->adapters->trace.record( + effects->adapters->trace.ctx, &piece); + if (!trace_result.ok) secondary |= SERVER_TXN_SECONDARY_TRACE; + const server_output_observation output = { + .operation = SERVER_OUTPUT_STREAM_UPDATE, + .text = "x", + .text_len = 1, + .safe_len = 1, + }; + server_txn_output_result output_result = + effects->adapters->output.apply( + effects->adapters->output.ctx, &output); + if (!output_result.ok) { + return (server_txn_step_result) { + .status = SERVER_TXN_STEP_TERMINAL, + .class = SERVER_TXN_FAILED, + .reason = SERVER_TXN_REASON_OUTPUT_FAILED, + .finish = SERVER_TXN_FINISH_ERROR, + .session = SERVER_SESSION_VALID_PREFIX, + .wire = output_result.wire, + .detail = "scripted stream-update failure", + .secondary = secondary, + }; + } + const server_output_observation flush = { + .operation = SERVER_OUTPUT_STREAM_FLUSH, + .text = "x", + .text_len = 1, + .safe_len = 1, + }; + output_result = effects->adapters->output.apply( + effects->adapters->output.ctx, &flush); + if (!output_result.ok) { + return (server_txn_step_result) { + .status = SERVER_TXN_STEP_TERMINAL, + .class = SERVER_TXN_FAILED, + .reason = SERVER_TXN_REASON_OUTPUT_FAILED, + .finish = SERVER_TXN_FINISH_ERROR, + .session = SERVER_SESSION_VALID_PREFIX, + .wire = output_result.wire, + .detail = "scripted stream-flush failure", + .secondary = secondary, + }; + } + const server_statistics_observation stats = { + .operation = SERVER_STATS_PROGRESS, + }; + if (!effects->adapters->stats.record( + effects->adapters->stats.ctx, &stats)) { + secondary |= SERVER_TXN_SECONDARY_STATS; + } + const server_statistics_observation prefill_done = { + .operation = SERVER_STATS_PREFILL_DONE, + }; + if (!effects->adapters->stats.record( + effects->adapters->stats.ctx, &prefill_done)) { + secondary |= SERVER_TXN_SECONDARY_STATS; + } + } + return (server_txn_step_result) { + .status = SERVER_TXN_STEP_TERMINAL, + .class = SERVER_TXN_COMPLETED, + .reason = SERVER_TXN_REASON_STOP, + .finish = SERVER_TXN_FINISH_STOP, + .session = SERVER_SESSION_COMMITTED, + .wire = SERVER_WIRE_IRREVERSIBLE, + .secondary = secondary, + }; + } + return (server_txn_step_result) { + .status = SERVER_TXN_STEP_CONTINUE, + .wire = effects->wire, + .secondary = secondary, + }; +} - const char *input_json = - "[{\"type\":\"function_call\",\"call_id\":\"call_ns\"," - "\"name\":\"perplexity_search\",\"namespace\":\"mcp__perplexity__\"," - "\"arguments\":{\"query\":\"deepseek\"}}]"; - const char *input_p = input_json; - chat_msgs msgs = {0}; - TEST_ASSERT(parse_responses_input(&input_p, &msgs, NULL, NULL)); - TEST_ASSERT(msgs.len == 1); - TEST_ASSERT(msgs.v[0].calls.len == 1); - TEST_ASSERT(!strcmp(msgs.v[0].calls.v[0].name, - "mcp__perplexity__perplexity_search")); +static server_txn_settle_result +test_txn_settle(void *ctx, const server_txn_outcome *outcome, bool commit) { + test_txn_effects *effects = ctx; + effects->settle_calls++; + test_txn_record(effects, commit ? TEST_TXN_EVENT_COMMIT : + TEST_TXN_EVENT_ROLLBACK); + return (server_txn_settle_result) { + .ok = !effects->fail_settle, + .session = commit ? + (effects->settle_secondary & SERVER_TXN_SECONDARY_CHECKPOINT ? + SERVER_SESSION_VALID_PREFIX : SERVER_SESSION_COMMITTED) : + outcome->session, + .wire = effects->settle_failure_reason == + SERVER_TXN_REASON_OUTPUT_FAILED ? + SERVER_WIRE_BROKEN : outcome->wire, + .failure_class = SERVER_TXN_FAILED, + .failure_reason = effects->settle_failure_reason, + .failure_detail = "scripted settlement output failure", + .secondary = effects->settle_secondary, + }; +} - char *prompt = render_chat_prompt_text(&msgs, schemas, &orders, DS4_THINK_HIGH); - TEST_ASSERT(prompt != NULL); - TEST_ASSERT(strstr(prompt, - "<｜DSML｜invoke name=\"mcp__perplexity__perplexity_search\">") != NULL); - TEST_ASSERT(strstr(prompt, "<｜DSML｜invoke name=\"perplexity_search\">") == NULL); +static server_txn_output_result test_txn_output_apply( + void *ctx, const server_output_observation *observation) { + test_txn_effects *effects = ctx; + effects->output_apply_calls++; + const test_txn_event events[] = { + TEST_TXN_EVENT_OUTPUT_PREFILL, + TEST_TXN_EVENT_OUTPUT_OPEN, + TEST_TXN_EVENT_OUTPUT_UPDATE, + TEST_TXN_EVENT_OUTPUT_FLUSH, + }; + test_txn_record(effects, events[observation->operation]); + const bool fail = effects->fail_output_operation == + (int)observation->operation + 1; + effects->wire = fail ? SERVER_WIRE_BROKEN : SERVER_WIRE_IRREVERSIBLE; + return (server_txn_output_result) { + .ok = !fail, + .wire = effects->wire, + }; +} - free(prompt); - chat_msgs_free(&msgs); - free(schemas); - tool_schema_orders_free(&orders); +static server_trace_result test_txn_trace_record( + void *ctx, const server_trace_observation *observation) { + (void)observation; + test_txn_effects *effects = ctx; + effects->trace_record_calls++; + test_txn_record(effects, TEST_TXN_EVENT_TRACE_OBSERVE); + return (server_trace_result) { + .ok = !effects->fail_trace_record, + .trace_id = 1, + }; } -static void test_responses_output_sends_tool_search_call_item(void) { - tool_calls calls = {0}; - tool_call tc = {0}; - tc.id = xstrdup("call_search"); - tc.name = xstrdup("tool_search"); - tc.arguments = xstrdup("{\"limit\":3,\"query\":\"perplexity\"}"); - tool_calls_push(&calls, tc); - const char *tools_json = - "[{\"type\":\"tool_search\",\"execution\":\"client\"," - "\"parameters\":{\"type\":\"object\",\"properties\":{" - "\"query\":{\"type\":\"string\"},\"limit\":{\"type\":\"number\"}}}}]"; - const char *tools_p = tools_json; - char *schemas = NULL; - tool_schema_orders orders = {0}; - TEST_ASSERT(parse_tools_value(&tools_p, &schemas, &orders)); - responses_tool_item item = { - .fc_id = "fc_search", - .call_id = "call_search", - .is_custom = false, - .output_index = 0, +static bool test_txn_stats_record( + void *ctx, const server_statistics_observation *observation) { + (void)observation; + test_txn_effects *effects = ctx; + effects->stats_record_calls++; + test_txn_record(effects, TEST_TXN_EVENT_STATS_OBSERVE); + return !effects->fail_stats_record; +} + +static server_txn_output_result test_txn_output( + void *ctx, const server_txn_outcome *outcome) { + (void)outcome; + test_txn_effects *effects = ctx; + effects->output_calls++; + test_txn_record(effects, TEST_TXN_EVENT_OUTPUT); + return (server_txn_output_result) { + .ok = !effects->fail_output, + .wire = effects->fail_output ? SERVER_WIRE_IRREVERSIBLE : + SERVER_WIRE_COMPLETE, }; +} - buf out = {0}; - responses_append_function_call_item(&out, &calls.v[0], &item, - "completed", true, &orders); - TEST_ASSERT(strstr(out.ptr, "\"type\":\"tool_search_call\"") != NULL); - TEST_ASSERT(strstr(out.ptr, "\"execution\":\"client\"") != NULL); - TEST_ASSERT(strstr(out.ptr, "\"status\":\"completed\"") != NULL); - TEST_ASSERT(strstr(out.ptr, "\"arguments\":{\"limit\":3,\"query\":\"perplexity\"}") != NULL); - TEST_ASSERT(strstr(out.ptr, "\"type\":\"function_call\"") == NULL); +static bool test_txn_trace(void *ctx, const server_txn_outcome *outcome) { + (void)outcome; + test_txn_effects *effects = ctx; + effects->trace_calls++; + test_txn_record(effects, TEST_TXN_EVENT_TRACE); + return !effects->fail_trace; +} - buf_free(&out); - free(schemas); - tool_schema_orders_free(&orders); - tool_calls_free(&calls); +static bool test_txn_stats(void *ctx, const server_txn_outcome *outcome) { + (void)outcome; + test_txn_effects *effects = ctx; + effects->stats_calls++; + test_txn_record(effects, TEST_TXN_EVENT_STATS); + return !effects->fail_stats; } -static tool_calls make_swapped_bash_call(void) { - tool_calls calls = {0}; - tool_call tc = {0}; - tc.name = xstrdup("bash"); - tc.arguments = xstrdup("{\"description\":\"list files\",\"command\":\"ls -la\",\"timeout\":10}"); - tool_calls_push(&calls, tc); - return calls; +static bool test_txn_cleanup(void *ctx, + const server_txn_outcome *outcome) { + (void)outcome; + test_txn_effects *effects = ctx; + effects->cleanup_calls++; + test_txn_record(effects, TEST_TXN_EVENT_CLEANUP); + return !effects->fail_cleanup; } -static tool_schema_orders make_bash_order(void) { - tool_schema_orders orders = {0}; - tool_schema_orders_add_json(&orders, - "{\"name\":\"bash\",\"input_schema\":{\"type\":\"object\",\"properties\":{" - "\"command\":{\"type\":\"string\"}," - "\"description\":{\"type\":\"string\"}}}}"); - return orders; +static void test_txn_terminalizer_is_idempotent(void) { + test_txn_effects effects = {0}; + const server_txn_adapters adapters = { + .session = { + .ctx = &effects, + .advance = test_txn_advance, + .settle = test_txn_settle, + .cleanup = test_txn_cleanup, + }, + .output = {.ctx = &effects, .finish = test_txn_output}, + .trace = {.ctx = &effects, .finish = test_txn_trace}, + .stats = {.ctx = &effects, .finish = test_txn_stats}, + }; + server_txn tx; + server_txn_init(&tx, &adapters); + server_txn_complete(&tx, SERVER_TXN_REASON_STOP, SERVER_TXN_FINISH_STOP); + + server_txn_outcome first = server_txn_terminalize(&tx); + server_txn_outcome second = server_txn_terminalize(&tx); + + TEST_ASSERT(first.class == SERVER_TXN_COMPLETED); + TEST_ASSERT(first.reason == SERVER_TXN_REASON_STOP); + TEST_ASSERT(first.finish == SERVER_TXN_FINISH_STOP); + TEST_ASSERT(first.session == SERVER_SESSION_COMMITTED); + TEST_ASSERT(first.wire == SERVER_WIRE_COMPLETE); + TEST_ASSERT(first.class == second.class); + TEST_ASSERT(first.decided_at == second.decided_at); + TEST_ASSERT(first.reason == second.reason); + TEST_ASSERT(first.finish == second.finish); + TEST_ASSERT(first.session == second.session); + TEST_ASSERT(first.wire == second.wire); + TEST_ASSERT(first.secondary == second.secondary); + TEST_ASSERT(!strcmp(first.detail, second.detail)); + TEST_ASSERT(effects.settle_calls == 1); + TEST_ASSERT(effects.output_calls == 1); + TEST_ASSERT(effects.trace_calls == 1); + TEST_ASSERT(effects.stats_calls == 1); + TEST_ASSERT(effects.cleanup_calls == 1); + const test_txn_event expected[] = { + TEST_TXN_EVENT_COMMIT, + TEST_TXN_EVENT_OUTPUT, + TEST_TXN_EVENT_TRACE, + TEST_TXN_EVENT_CLEANUP, + TEST_TXN_EVENT_STATS, + }; + test_txn_expect_events(&effects, expected, + (int)(sizeof(expected) / sizeof(expected[0]))); } -static char *read_socket_text(int fd) { - buf b = {0}; - char tmp[1024]; - ssize_t n; - while ((n = read(fd, tmp, sizeof(tmp))) > 0) { - buf_append(&b, tmp, (size_t)n); - } - return buf_take(&b); +static server_txn_outcome test_txn_run_script(test_txn_effects *effects) { + const server_txn_adapters adapters = { + .session = { + .ctx = effects, + .advance = test_txn_advance, + .settle = test_txn_settle, + .cleanup = test_txn_cleanup, + }, + .output = { + .ctx = effects, + .apply = test_txn_output_apply, + .finish = test_txn_output, + }, + .trace = { + .ctx = effects, + .record = test_txn_trace_record, + .finish = test_txn_trace, + }, + .stats = { + .ctx = effects, + .record = test_txn_stats_record, + .finish = test_txn_stats, + }, + }; + effects->adapters = &adapters; + return server_txn_run_adapters(&adapters); +} + +static void test_txn_scripted_success_order(void) { + test_txn_effects effects = {0}; + server_txn_outcome outcome = test_txn_run_script(&effects); + TEST_ASSERT(outcome.class == SERVER_TXN_COMPLETED); + TEST_ASSERT(outcome.reason == SERVER_TXN_REASON_STOP); + const test_txn_event expected[] = { + TEST_TXN_EVENT_RESTORE, + TEST_TXN_EVENT_TRACE_OBSERVE, + TEST_TXN_EVENT_STATS_OBSERVE, + TEST_TXN_EVENT_SYNCHRONIZE, + TEST_TXN_EVENT_OUTPUT_PREFILL, + TEST_TXN_EVENT_STATS_OBSERVE, + TEST_TXN_EVENT_EXTEND, + TEST_TXN_EVENT_OUTPUT_OPEN, + TEST_TXN_EVENT_DECODE, + TEST_TXN_EVENT_TRACE_OBSERVE, + TEST_TXN_EVENT_TRACE_OBSERVE, + TEST_TXN_EVENT_OUTPUT_UPDATE, + TEST_TXN_EVENT_OUTPUT_FLUSH, + TEST_TXN_EVENT_STATS_OBSERVE, + TEST_TXN_EVENT_STATS_OBSERVE, + TEST_TXN_EVENT_COMMIT, + TEST_TXN_EVENT_OUTPUT, + TEST_TXN_EVENT_TRACE, + TEST_TXN_EVENT_CLEANUP, + TEST_TXN_EVENT_STATS, + }; + test_txn_expect_events(&effects, expected, + (int)(sizeof(expected) / sizeof(expected[0]))); +} + +static void test_txn_scripted_phase_outcomes(void) { + const struct { + server_txn_phase phase; + server_txn_class class; + server_txn_reason reason; + server_session_disposition session; + } cases[] = { + {SERVER_TXN_PHASE_RESTORE, SERVER_TXN_FAILED, + SERVER_TXN_REASON_RESTORE_FAILED, SERVER_SESSION_INVALIDATED}, + {SERVER_TXN_PHASE_SYNCHRONIZE, SERVER_TXN_FAILED, + SERVER_TXN_REASON_SYNC_FAILED, SERVER_SESSION_INVALIDATED}, + {SERVER_TXN_PHASE_SYNCHRONIZE, SERVER_TXN_CANCELLED, + SERVER_TXN_REASON_CANCELLED, SERVER_SESSION_VALID_PREFIX}, + {SERVER_TXN_PHASE_DECODE, SERVER_TXN_FAILED, + SERVER_TXN_REASON_DECODE_FAILED, SERVER_SESSION_INVALIDATED}, + {SERVER_TXN_PHASE_EXTEND, SERVER_TXN_FAILED, + SERVER_TXN_REASON_OUTPUT_FAILED, SERVER_SESSION_VALID_PREFIX}, + }; + for (size_t i = 0; i < sizeof(cases) / sizeof(cases[0]); i++) { + test_txn_effects effects = { + .fail_phase = cases[i].phase, + .fail_class = cases[i].class, + .fail_reason = cases[i].reason, + .fail_session = cases[i].session, + }; + server_txn_outcome outcome = test_txn_run_script(&effects); + TEST_ASSERT(outcome.class == cases[i].class); + TEST_ASSERT(outcome.reason == cases[i].reason); + TEST_ASSERT(outcome.decided_at == cases[i].phase); + TEST_ASSERT(outcome.session == cases[i].session); + TEST_ASSERT(effects.settle_calls == 1); + TEST_ASSERT(effects.output_calls == 1); + TEST_ASSERT(effects.trace_calls == 1); + TEST_ASSERT(effects.stats_calls == 1); + TEST_ASSERT(effects.cleanup_calls == 1); + } +} + +static void test_txn_scripted_failure_precedence(void) { + test_txn_effects effects = { + .fail_phase = SERVER_TXN_PHASE_DECODE, + .fail_class = SERVER_TXN_FAILED, + .fail_reason = SERVER_TXN_REASON_DECODE_FAILED, + .fail_session = SERVER_SESSION_INVALIDATED, + .fail_settle = true, + .fail_output = true, + .fail_trace = true, + .fail_stats = true, + .fail_cleanup = true, + }; + server_txn_outcome outcome = test_txn_run_script(&effects); + TEST_ASSERT(outcome.reason == SERVER_TXN_REASON_DECODE_FAILED); + TEST_ASSERT(outcome.decided_at == SERVER_TXN_PHASE_DECODE); + TEST_ASSERT(outcome.session == SERVER_SESSION_INVALIDATED); + TEST_ASSERT(outcome.wire == SERVER_WIRE_BROKEN); + TEST_ASSERT(outcome.secondary & SERVER_TXN_SECONDARY_ROLLBACK); + TEST_ASSERT(outcome.secondary & SERVER_TXN_SECONDARY_OUTPUT); + TEST_ASSERT(outcome.secondary & SERVER_TXN_SECONDARY_TRACE); + TEST_ASSERT(outcome.secondary & SERVER_TXN_SECONDARY_STATS); + TEST_ASSERT(outcome.secondary & SERVER_TXN_SECONDARY_CLEANUP); + const test_txn_event expected[] = { + TEST_TXN_EVENT_RESTORE, + TEST_TXN_EVENT_TRACE_OBSERVE, + TEST_TXN_EVENT_STATS_OBSERVE, + TEST_TXN_EVENT_SYNCHRONIZE, + TEST_TXN_EVENT_OUTPUT_PREFILL, + TEST_TXN_EVENT_STATS_OBSERVE, + TEST_TXN_EVENT_EXTEND, + TEST_TXN_EVENT_OUTPUT_OPEN, + TEST_TXN_EVENT_DECODE, + TEST_TXN_EVENT_ROLLBACK, + TEST_TXN_EVENT_OUTPUT, + TEST_TXN_EVENT_TRACE, + TEST_TXN_EVENT_CLEANUP, + TEST_TXN_EVENT_STATS, + }; + test_txn_expect_events(&effects, expected, + (int)(sizeof(expected) / sizeof(expected[0]))); +} + +static void test_txn_scripted_commit_and_output_failures(void) { + test_txn_effects commit = {.fail_settle = true}; + server_txn_outcome commit_outcome = test_txn_run_script(&commit); + TEST_ASSERT(commit_outcome.reason == SERVER_TXN_REASON_COMMIT_FAILED); + TEST_ASSERT(commit_outcome.finish == SERVER_TXN_FINISH_STOP); + TEST_ASSERT(commit_outcome.session == SERVER_SESSION_INVALIDATED); + + test_txn_effects output = {.fail_output = true}; + server_txn_outcome output_outcome = test_txn_run_script(&output); + TEST_ASSERT(output_outcome.reason == SERVER_TXN_REASON_OUTPUT_FAILED); + TEST_ASSERT(output_outcome.wire == SERVER_WIRE_BROKEN); + TEST_ASSERT(output.output_calls == 1); + + test_txn_effects checkpoint = { + .settle_secondary = SERVER_TXN_SECONDARY_CHECKPOINT, + }; + server_txn_outcome checkpoint_outcome = test_txn_run_script(&checkpoint); + TEST_ASSERT(checkpoint_outcome.reason == SERVER_TXN_REASON_STOP); + TEST_ASSERT(checkpoint_outcome.secondary & SERVER_TXN_SECONDARY_CHECKPOINT); + TEST_ASSERT(checkpoint_outcome.session == SERVER_SESSION_VALID_PREFIX); + + test_txn_effects settle_output = { + .settle_failure_reason = SERVER_TXN_REASON_OUTPUT_FAILED, + }; + server_txn_outcome settle_output_outcome = + test_txn_run_script(&settle_output); + TEST_ASSERT(settle_output_outcome.reason == + SERVER_TXN_REASON_OUTPUT_FAILED); + TEST_ASSERT(settle_output_outcome.decided_at == SERVER_TXN_PHASE_SETTLE); + TEST_ASSERT(settle_output_outcome.wire == SERVER_WIRE_BROKEN); + TEST_ASSERT(settle_output.output_calls == 0); +} + +static void test_txn_scripted_operational_adapter_failures(void) { + test_txn_effects prefill = { + .fail_output_operation = SERVER_OUTPUT_PREFILL_TICK + 1, + }; + server_txn_outcome prefill_outcome = test_txn_run_script(&prefill); + TEST_ASSERT(prefill_outcome.reason == SERVER_TXN_REASON_OUTPUT_FAILED); + TEST_ASSERT(prefill_outcome.decided_at == SERVER_TXN_PHASE_SYNCHRONIZE); + TEST_ASSERT(prefill_outcome.wire == SERVER_WIRE_BROKEN); + TEST_ASSERT(prefill.output_apply_calls == 1); + + test_txn_effects open = { + .fail_output_operation = SERVER_OUTPUT_STREAM_OPEN + 1, + }; + server_txn_outcome open_outcome = test_txn_run_script(&open); + TEST_ASSERT(open_outcome.reason == SERVER_TXN_REASON_OUTPUT_FAILED); + TEST_ASSERT(open_outcome.decided_at == SERVER_TXN_PHASE_EXTEND); + TEST_ASSERT(open_outcome.wire == SERVER_WIRE_BROKEN); + TEST_ASSERT(open.output_apply_calls == 2); + + test_txn_effects update = { + .fail_output_operation = SERVER_OUTPUT_STREAM_UPDATE + 1, + }; + server_txn_outcome update_outcome = test_txn_run_script(&update); + TEST_ASSERT(update_outcome.reason == SERVER_TXN_REASON_OUTPUT_FAILED); + TEST_ASSERT(update_outcome.decided_at == SERVER_TXN_PHASE_DECODE); + TEST_ASSERT(update_outcome.wire == SERVER_WIRE_BROKEN); + TEST_ASSERT(update.output_apply_calls == 3); + + test_txn_effects flush = { + .fail_output_operation = SERVER_OUTPUT_STREAM_FLUSH + 1, + }; + server_txn_outcome flush_outcome = test_txn_run_script(&flush); + TEST_ASSERT(flush_outcome.reason == SERVER_TXN_REASON_OUTPUT_FAILED); + TEST_ASSERT(flush_outcome.decided_at == SERVER_TXN_PHASE_DECODE); + TEST_ASSERT(flush_outcome.wire == SERVER_WIRE_BROKEN); + TEST_ASSERT(flush.output_apply_calls == 4); + + test_txn_effects observations = { + .fail_trace_record = true, + .fail_stats_record = true, + }; + server_txn_outcome observations_outcome = + test_txn_run_script(&observations); + TEST_ASSERT(observations_outcome.reason == SERVER_TXN_REASON_STOP); + TEST_ASSERT(observations_outcome.secondary & SERVER_TXN_SECONDARY_TRACE); + TEST_ASSERT(observations_outcome.secondary & SERVER_TXN_SECONDARY_STATS); + TEST_ASSERT(observations.trace_record_calls == 3); + TEST_ASSERT(observations.stats_record_calls == 4); +} + +static void test_production_failure_latch_preserves_causal_order(void) { + const sig_atomic_t saved_stop = g_stop_requested; + g_stop_requested = 0; + TEST_ASSERT(production_peer_gone_reason() == + SERVER_TXN_REASON_CLIENT_GONE); + g_stop_requested = 1; + TEST_ASSERT(production_peer_gone_reason() == SERVER_TXN_REASON_SHUTDOWN); + g_stop_requested = saved_stop; + + production_txn shutdown_first = {0}; + TEST_ASSERT(production_latch_failure( + &shutdown_first, SERVER_TXN_CANCELLED, SERVER_TXN_REASON_SHUTDOWN, + SERVER_SESSION_VALID_PREFIX, "shutdown requested")); + TEST_ASSERT(!production_latch_failure( + &shutdown_first, SERVER_TXN_FAILED, SERVER_TXN_REASON_OUTPUT_FAILED, + SERVER_SESSION_VALID_PREFIX, "client stream write failed")); + TEST_ASSERT(shutdown_first.first_failure_reason == + SERVER_TXN_REASON_SHUTDOWN); + TEST_ASSERT(shutdown_first.phase_secondary & + SERVER_TXN_SECONDARY_OUTPUT); + + production_txn output_first = {0}; + TEST_ASSERT(production_latch_failure( + &output_first, SERVER_TXN_FAILED, SERVER_TXN_REASON_OUTPUT_FAILED, + SERVER_SESSION_VALID_PREFIX, "client stream write failed")); + TEST_ASSERT(!production_latch_failure( + &output_first, SERVER_TXN_CANCELLED, SERVER_TXN_REASON_SHUTDOWN, + SERVER_SESSION_VALID_PREFIX, "shutdown requested")); + TEST_ASSERT(output_first.first_failure_reason == + SERVER_TXN_REASON_OUTPUT_FAILED); + TEST_ASSERT(!(output_first.phase_secondary & + SERVER_TXN_SECONDARY_OUTPUT)); +} + +static void test_txn_broken_wire_is_never_finalized_again(void) { + test_txn_effects effects = {0}; + const server_txn_adapters adapters = { + .session = { + .ctx = &effects, + .advance = test_txn_advance, + .settle = test_txn_settle, + .cleanup = test_txn_cleanup, + }, + .output = {.ctx = &effects, .finish = test_txn_output}, + .trace = {.ctx = &effects, .finish = test_txn_trace}, + .stats = {.ctx = &effects, .finish = test_txn_stats}, + }; + server_txn tx; + server_txn_init(&tx, &adapters); + tx.phase = SERVER_TXN_PHASE_DECODE; + server_txn_fail_once(&tx, tx.phase, SERVER_TXN_FAILED, + SERVER_TXN_REASON_OUTPUT_FAILED, + SERVER_SESSION_VALID_PREFIX, + "stream write failed"); + tx.outcome.wire = SERVER_WIRE_BROKEN; + server_txn_outcome outcome = server_txn_terminalize(&tx); + TEST_ASSERT(outcome.reason == SERVER_TXN_REASON_OUTPUT_FAILED); + TEST_ASSERT(outcome.wire == SERVER_WIRE_BROKEN); + TEST_ASSERT(effects.output_calls == 0); } static void test_context_length_error_uses_protocol_standard_shape(void) { @@ -13133,6 +15884,31 @@ static void test_render_preserves_reasoning_with_tools(void) { chat_msgs_free(&msgs); } +static void test_render_canonicalizes_blank_reasoning_with_tools(void) { + chat_msgs msgs = {0}; + chat_msg user = {0}; + user.role = xstrdup("user"); + user.content = xstrdup("hello"); + chat_msgs_push(&msgs, user); + chat_msg assistant = {0}; + assistant.role = xstrdup("assistant"); + assistant.reasoning = xstrdup(" \t\n"); + assistant.content = xstrdup("answer"); + chat_msgs_push(&msgs, assistant); + chat_msg tool = {0}; + tool.role = xstrdup("tool"); + tool.content = xstrdup("result"); + chat_msgs_push(&msgs, tool); + + char *prompt = render_chat_prompt_text(&msgs, "{}", NULL, DS4_THINK_HIGH); + TEST_ASSERT(prompt != NULL); + TEST_ASSERT(strstr(prompt, "<｜Assistant｜>answer") != NULL); + TEST_ASSERT(strstr(prompt, " \t\n") == NULL); + + free(prompt); + chat_msgs_free(&msgs); +} + static void test_render_chat_prompt_text_renders_tools_before_system(void) { /* The tool-schema block must sit at the head of the system region so the * client's system content stays at the tail, right before <｜User｜>. @@ -13603,6 +16379,30 @@ static void test_thinking_dsml_after_think_close_is_executable(void) { tool_calls_free(&calls); } +static void test_thinking_unclosed_is_reasoning_not_content(void) { + /* Regression for #509: when thinking mode is on and the model is truncated + * (e.g. at max_tokens) before it emits , the partial output is + * unfinished reasoning. It must surface as reasoning_content with empty + * content, not leak into content as if it were the final answer. */ + const char *generated = + "We need to compute 17 * 24. This is a simple multiplication. " + "17 * 24 = 17 * (20 + 4) ="; + + char *content = NULL; + char *reasoning = NULL; + tool_calls calls = {0}; + TEST_ASSERT(parse_generated_message_ex(generated, true, + &content, &reasoning, &calls)); + TEST_ASSERT(calls.len == 0); + TEST_ASSERT(reasoning && strstr(reasoning, "We need to compute 17 * 24") != NULL); + TEST_ASSERT(strstr(reasoning, "") == NULL); + TEST_ASSERT(content && content[0] == '\0'); + + free(content); + free(reasoning); + tool_calls_free(&calls); +} + static void test_tool_checkpoint_suffix_is_future_prompt_canonical(void) { tool_schema_orders orders = make_bash_order(); const char *tool_schemas = @@ -13813,6 +16613,102 @@ static void test_tool_memory_replays_sampled_dsml(void) { pthread_mutex_destroy(&s.tool_mu); } +static void test_tool_memory_attach_requires_all_block_invokes(void) { + const char *generated = + DS4_TOOL_CALLS_START "\n" + "<｜DSML｜invoke name=\"bash\">\n" + "<｜DSML｜parameter name=\"command\" string=\"true\">ls\n" + "\n" + "<｜DSML｜invoke name=\"bash\">\n" + "<｜DSML｜parameter name=\"command\" string=\"true\">pwd\n" + "\n" + ""; + + char *content = NULL; + char *reasoning = NULL; + tool_calls sampled = {0}; + TEST_ASSERT(parse_generated_message_ex(generated, false, &content, &reasoning, &sampled)); + TEST_ASSERT(sampled.len == 2); + + server s; + memset(&s, 0, sizeof(s)); + pthread_mutex_init(&s.tool_mu, NULL); + assign_tool_call_ids(&s, &sampled, API_OPENAI); + tool_memory_remember(&s, &sampled); + + /* A message replaying only one of the block's two calls must not attach + * the raw block: rendering it would duplicate the other invoke. */ + chat_msgs partial = {0}; + chat_msg one = {0}; + one.role = xstrdup("assistant"); + tool_call tc = {0}; + tc.id = xstrdup(sampled.v[0].id); + tc.name = xstrdup("bash"); + tc.arguments = xstrdup("{\"command\":\"ls\"}"); + tool_calls_push(&one.calls, tc); + chat_msgs_push(&partial, one); + tool_replay_stats stats = {0}; + tool_memory_attach_to_messages(&s, &partial, &stats); + TEST_ASSERT(partial.v[0].calls.raw_dsml == NULL); + TEST_ASSERT(stats.canonical == 1); + TEST_ASSERT(stats.mem == 0); + + /* A message carrying both calls attaches the block as before. */ + chat_msgs full = {0}; + chat_msg both = {0}; + both.role = xstrdup("assistant"); + for (int i = 0; i < 2; i++) { + tool_call c = {0}; + c.id = xstrdup(sampled.v[i].id); + c.name = xstrdup("bash"); + c.arguments = xstrdup("{}"); + tool_calls_push(&both.calls, c); + } + chat_msgs_push(&full, both); + tool_replay_stats stats2 = {0}; + tool_memory_attach_to_messages(&s, &full, &stats2); + TEST_ASSERT(full.v[0].calls.raw_dsml != NULL); + TEST_ASSERT(stats2.mem == 1); + TEST_ASSERT(stats2.canonical == 0); + + chat_msgs_free(&partial); + chat_msgs_free(&full); + free(content); + free(reasoning); + tool_calls_free(&sampled); + tool_memory_free(&s.tool_mem); + pthread_mutex_destroy(&s.tool_mu); +} + +static void test_raw_dsml_capture_keeps_sampled_separator(void) { + /* A single-newline separator is not the canonical "\n\n", but the model + * sampled it, so byte-exact replay must include it in the raw block. */ + const char *generated = + "done\n" + DS4_TOOL_CALLS_START "\n" + "<｜DSML｜invoke name=\"bash\">\n" + "<｜DSML｜parameter name=\"command\" string=\"true\">ls\n" + "\n" + DS4_TOOL_CALLS_END; + + char *content = NULL; + char *reasoning = NULL; + tool_calls calls = {0}; + TEST_ASSERT(parse_generated_message_ex(generated, false, &content, &reasoning, &calls)); + TEST_ASSERT(calls.len == 1); + TEST_ASSERT(content && !strcmp(content, "done")); + TEST_ASSERT(calls.raw_dsml != NULL); + TEST_ASSERT(calls.raw_dsml[0] == '\n'); + TEST_ASSERT(!strncmp(calls.raw_dsml + 1, DS4_TOOL_CALLS_START, + strlen(DS4_TOOL_CALLS_START))); + /* content + raw block must reassemble the sampled bytes exactly. */ + TEST_ASSERT(strlen(content) + strlen(calls.raw_dsml) == strlen(generated)); + + free(content); + free(reasoning); + tool_calls_free(&calls); +} + static void test_anthropic_tool_memory_replays_sampled_dsml(void) { const char *sampled_dsml = "\n\n" DS4_TOOL_CALLS_START "\n" @@ -14803,7 +17699,7 @@ static void test_kv_cache_chat_anchor_ignores_multiturn_tail(void) { ds4_tokens_free(&prompt); } -static void test_kv_cache_continued_uses_aligned_frontiers(void) { +static void test_kv_cache_continued_uses_step_thresholds(void) { kv_disk_cache kc = {0}; kc.enabled = true; kc.opt = kv_cache_default_options(); @@ -14811,11 +17707,16 @@ static void test_kv_cache_continued_uses_aligned_frontiers(void) { TEST_ASSERT(kv_cache_continued_store_target(&kc, 10239) == 0); TEST_ASSERT(kv_cache_continued_store_target(&kc, 10240) == 10240); + /* A full step must pass since the last store, from wherever it was. */ kc.continued_last_store_tokens = 4096; - TEST_ASSERT(kv_cache_continued_store_target(&kc, 10240) == 10240); + TEST_ASSERT(kv_cache_continued_store_target(&kc, 10240) == 0); + TEST_ASSERT(kv_cache_continued_store_target(&kc, 14336) == 14336); + /* Unaligned resume positions (disk hits) get waypoints too. */ kc.continued_last_store_tokens = 24576; - TEST_ASSERT(kv_cache_continued_store_target(&kc, 30720) == 30720); + TEST_ASSERT(kv_cache_continued_store_target(&kc, 30720) == 0); + TEST_ASSERT(kv_cache_continued_store_target(&kc, 34816) == 34816); + TEST_ASSERT(kv_cache_continued_store_target(&kc, 45374) == 45374); kc.continued_last_store_tokens = 10240; TEST_ASSERT(kv_cache_continued_store_target(&kc, 18432) == 0); @@ -14824,7 +17725,7 @@ static void test_kv_cache_continued_uses_aligned_frontiers(void) { kc.opt.boundary_align_tokens = 0; kc.continued_last_store_tokens = 20480; TEST_ASSERT(kv_cache_continued_store_target(&kc, 29999) == 0); - TEST_ASSERT(kv_cache_continued_store_target(&kc, 30000) == 30000); + TEST_ASSERT(kv_cache_continued_store_target(&kc, 30480) == 30480); } static void test_kv_cache_cold_store_suppresses_duplicate_continued_boundary(void) { @@ -15244,6 +18145,47 @@ static void test_kv_cache_eviction_prefers_anchor_reason(void) { rmdir(dir); } +static void test_kv_cache_eviction_evicts_stale_anchor_before_fresh_waypoint(void) { + /* Observed in production: the newest continued waypoints of the live + * conversation (hits=0 because they were written minutes ago) were + * evicted while stale never-hit anchors survived on the reason bonus. + * A stale anchor must lose to a fresh waypoint of equal density. */ + char tmpl[] = "/tmp/ds4-kv-stale-anchor-test.XXXXXX"; + char *dir = mkdtemp(tmpl); + TEST_ASSERT(dir != NULL); + if (!dir) return; + + const char *anchor_sha = "1111111111111111111111111111111111111111"; + const char *waypoint_sha = "2222222222222222222222222222222222222222"; + uint64_t now = (uint64_t)time(NULL); + uint64_t stale = now - 30u * 24u * 3600u; + test_kv_stub_file(dir, anchor_sha, KV_REASON_COLD, 2048, 0, stale, 2048); + test_kv_stub_file(dir, waypoint_sha, KV_REASON_CONTINUED, 2048, 0, now, 2048); + + char anchor_name[44], waypoint_name[44]; + snprintf(anchor_name, sizeof(anchor_name), "%.40s.kv", anchor_sha); + snprintf(waypoint_name, sizeof(waypoint_name), "%.40s.kv", waypoint_sha); + char *anchor_path = path_join(dir, anchor_name); + char *waypoint_path = path_join(dir, waypoint_name); + + kv_disk_cache kc = {0}; + kc.enabled = true; + kc.dir = xstrdup(dir); + kc.opt = kv_cache_default_options(); + kc.budget_bytes = (KV_CACHE_FIXED_HEADER + 4u + 2048u) + 16u; + kv_cache_evict(&kc, NULL, 0, NULL); + + TEST_ASSERT(access(anchor_path, F_OK) != 0); + TEST_ASSERT(access(waypoint_path, F_OK) == 0); + + kv_cache_close(&kc); + unlink(anchor_path); + unlink(waypoint_path); + free(anchor_path); + free(waypoint_path); + rmdir(dir); +} + static void test_kv_cache_eviction_makes_room_before_store(void) { char tmpl[] = "/tmp/ds4-kv-pre-store-evict-test.XXXXXX"; char *dir = mkdtemp(tmpl); @@ -15415,9 +18357,10 @@ static void test_kv_cache_eviction_score_decays_stale_hits(void) { double f_on = kv_entry_eviction_score(&fresh, NULL, now, NULL); TEST_ASSERT(s_on < f_on); - /* A fresh entry's score never decays below its (0+1) * tokens/size floor, - * regardless of how old another entry's hit history is. */ - TEST_ASSERT(f_on == 1.0 * (double)fresh.tokens / (double)fresh.file_size); + /* A fresh never-hit entry gets the freshness grace: it scores like a + * once-hit file, (1+1) * tokens/size, and never below the (0+1) floor. */ + TEST_ASSERT(f_on == 2.0 * (double)fresh.tokens / (double)fresh.file_size); + TEST_ASSERT(f_on >= 1.0 * (double)fresh.tokens / (double)fresh.file_size); } static void test_kv_cache_eviction_decayed_hits_tie_break_by_age(void) { @@ -15758,6 +18701,20 @@ static void test_thinking_canonical_non_thinking_mode_noop(void) { } static void ds4_server_unit_tests_run(void) { + test_stats_uses_published_snapshot(); + test_dequeue_prioritizes_jobs_then_publishes_idle_stats(); + test_production_txn_terminalizes_queued_disconnect(); + test_production_txn_shutdown_beats_queued_disconnect(); + test_production_settle_rollback_clears_live_bindings(); + test_job_terminal_outcome_is_published_once(); + test_txn_terminalizer_is_idempotent(); + test_txn_scripted_success_order(); + test_txn_scripted_phase_outcomes(); + test_txn_scripted_failure_precedence(); + test_txn_scripted_commit_and_output_failures(); + test_txn_scripted_operational_adapter_failures(); + test_production_failure_latch_preserves_causal_order(); + test_txn_broken_wire_is_never_finalized_again(); test_request_defaults_use_min_p_filtering(); test_reasoning_effort_mapping(); test_api_thinking_controls_parse(); @@ -15765,6 +18722,7 @@ static void ds4_server_unit_tests_run(void) { test_render_non_thinking_prompt_closes_think(); test_render_drops_old_reasoning_without_tools(); test_render_preserves_reasoning_with_tools(); + test_render_canonicalizes_blank_reasoning_with_tools(); test_render_chat_prompt_text_renders_tools_before_system(); test_tool_schema_order_from_anthropic_schema(); test_tool_schema_order_from_openai_tools(); @@ -15803,9 +18761,12 @@ static void ds4_server_unit_tests_run(void) { test_invalid_dsml_tool_error_suffix_includes_system_prompt(); test_thinking_dsml_is_not_executable_before_think_close(); test_thinking_dsml_after_think_close_is_executable(); + test_thinking_unclosed_is_reasoning_not_content(); test_tool_checkpoint_suffix_is_future_prompt_canonical(); test_tool_checkpoint_minifies_json_parameters(); test_tool_memory_replays_sampled_dsml(); + test_tool_memory_attach_requires_all_block_invokes(); + test_raw_dsml_capture_keeps_sampled_separator(); test_anthropic_tool_memory_replays_sampled_dsml(); test_anthropic_live_tail_renders_tool_results_only(); test_anthropic_tool_result_id_validation(); @@ -15842,7 +18803,7 @@ static void ds4_server_unit_tests_run(void) { test_kv_cache_store_len_uses_configured_boundary(); test_kv_cache_chat_anchor_uses_last_user_before_assistant(); test_kv_cache_chat_anchor_ignores_multiturn_tail(); - test_kv_cache_continued_uses_aligned_frontiers(); + test_kv_cache_continued_uses_step_thresholds(); test_kv_cache_cold_store_suppresses_duplicate_continued_boundary(); test_kv_cache_file_size_must_fit_budget(); test_sha1_bytes_hex_matches_known_vector(); @@ -15851,6 +18812,7 @@ static void ds4_server_unit_tests_run(void) { test_kv_cache_lookup_rejects_stale_payload_abi(); test_kv_cache_eviction_values_fresh_snapshots(); test_kv_cache_eviction_prefers_anchor_reason(); + test_kv_cache_eviction_evicts_stale_anchor_before_fresh_waypoint(); test_kv_cache_eviction_makes_room_before_store(); test_kv_cache_eviction_ignores_oversize_incoming(); test_kv_cache_eviction_prefers_superseded_continued_prefix(); diff --git a/gguf-tools/deepseek4-quantize.c b/gguf-tools/deepseek4-quantize.c index 3955b4352..1ac48fec0 100644 --- a/gguf-tools/deepseek4-quantize.c +++ b/gguf-tools/deepseek4-quantize.c @@ -153,6 +153,37 @@ static uint64_t read_u64_le_fp(FILE *fp, const char *what) { return v; } +/* Bytes from the current position to EOF, restoring the position afterwards. */ +static uint64_t bytes_remaining_fp(FILE *fp, const char *what) { + off_t cur = ftello(fp); + if (cur < 0 || fseeko(fp, 0, SEEK_END) != 0) { + fprintf(stderr, "error: seek failed while sizing %s\n", what); + exit(1); + } + off_t end = ftello(fp); + if (end < 0 || fseeko(fp, cur, SEEK_SET) != 0) { + fprintf(stderr, "error: seek failed while sizing %s\n", what); + exit(1); + } + return end > cur ? (uint64_t)(end - cur) : 0; +} + +/* Read a u64 length prefix and reject it if it claims more than the bytes left + * in the file. Without this a crafted length can (a) be so large that + * (size_t)len + 1 wraps to 0, so xmalloc() returns a 1-byte buffer that the + * following fread() then overflows, or (b) request a multi-GB allocation from a + * tiny file. */ +static uint64_t read_checked_len_fp(FILE *fp, const char *what) { + uint64_t n = read_u64_le_fp(fp, what); + uint64_t remaining = bytes_remaining_fp(fp, what); + if (n > remaining) { + fprintf(stderr, "error: %s (%" PRIu64 ") exceeds %" PRIu64 + " bytes remaining in file\n", what, n, remaining); + exit(1); + } + return n; +} + static uint32_t read_u32_le_fp(FILE *fp, const char *what) { uint32_t v; if (fread(&v, 1, sizeof(v), fp) != sizeof(v)) { @@ -475,7 +506,7 @@ static void shard_load(shard *s) { if (s->loaded) return; FILE *fp = fopen(s->path, "rb"); if (!fp) die_errno("open", s->path); - uint64_t header_len = read_u64_le_fp(fp, "safetensors header length"); + uint64_t header_len = read_checked_len_fp(fp, "safetensors header length"); char *header = xmalloc((size_t)header_len + 1); if (fread(header, 1, (size_t)header_len, fp) != (size_t)header_len) die_errno("read header", s->path); header[header_len] = '\0'; @@ -691,6 +722,15 @@ static float *dequant_fp8_weight(const st_value *w, const st_value *scale, int64 const int64_t scale_rows = out_dim / block_out; const int64_t scale_cols = in_dim / block_in; if (scale->shape[0] != scale_rows || scale->shape[1] != scale_cols) die("FP8 scale shape mismatch"); + /* shape and data_offsets are independent header fields; cross-check that the + * on-disk buffers (sized from data_offsets by db_read) are actually large + * enough for the shape-driven indexing below. Without this, a weight that + * declares a large shape but a tiny data_offsets range makes the loops read + * past the end of w->data / scale->data (heap-buffer-overflow read). One + * byte per element for F8_E4M3 weights and F8_E8M0 scales. */ + if (w->nbytes < (size_t)out_dim * (size_t)in_dim || + scale->nbytes < (size_t)scale_rows * (size_t)scale_cols) + die("FP8 tensor data smaller than its declared shape"); float *out = xmalloc((size_t)out_dim * (size_t)in_dim * sizeof(float)); for (int64_t ob = 0; ob < scale_rows; ob++) { for (int64_t ib = 0; ib < scale_cols; ib++) { @@ -721,6 +761,14 @@ static float *dequant_fp4_weight(const st_value *w, const st_value *scale, int64 if (in_dim % 32) die("FP4 in_dim is not divisible by 32"); const int64_t n_blocks = in_dim / 32; if (scale->shape[0] != out_dim || scale->shape[1] != n_blocks) die("FP4 scale shape mismatch"); + /* As in dequant_fp8_weight: cross-check the on-disk buffer sizes (from + * data_offsets) against the shape-driven indexing so a small data range + * under a large declared shape cannot drive an out-of-bounds read. The I8 + * weight packs two 4-bit values per byte -> out_dim * packed_in bytes; the + * F8_E8M0 scale is one byte per block. */ + if (w->nbytes < (size_t)out_dim * (size_t)packed_in || + scale->nbytes < (size_t)out_dim * (size_t)n_blocks) + die("FP4 tensor data smaller than its declared shape"); float *out = xmalloc((size_t)out_dim * (size_t)in_dim * sizeof(float)); for (int64_t r = 0; r < out_dim; r++) { for (int64_t b = 0; b < n_blocks; b++) { @@ -1359,7 +1407,7 @@ static size_t gguf_scalar_size(uint32_t type) { } static char *read_gguf_string_fp(FILE *fp) { - uint64_t n = read_u64_le_fp(fp, "GGUF string length"); + uint64_t n = read_checked_len_fp(fp, "GGUF string length"); char *s = xmalloc((size_t)n + 1); if (n && fread(s, 1, (size_t)n, fp) != (size_t)n) die("short GGUF string read"); s[n] = '\0'; diff --git a/tasks/lessons.md b/tasks/lessons.md new file mode 100644 index 000000000..24292cf88 --- /dev/null +++ b/tasks/lessons.md @@ -0,0 +1,7 @@ +# Lessons + +- When client threads publish server statistics, copy every reported value from worker-owned session state into mutex-protected server state; never read mutable `ds4_session` fields directly outside the single worker. +- When running supplemental AddressSanitizer checks on macOS, disable unsupported leak detection and time-box the run so an unexpectedly slow instrumented test cannot compete with the live Metal server. +- When a lifecycle claims an output adapter boundary, route prefill, stream-open, delta, flush, and terminal writes through that seam; terminal-only adaptation leaves irreversible failures outside the transaction. +- When reporting session disposition after a failed mutator, query explicit checkpoint validity; a nonzero token position does not prove the backend graph is reusable. +- When testing an ordered lifecycle, size the event log for the complete success path and activate asynchronous refresh behavior through a real producer, not by seeding its internal flag. diff --git a/tasks/todo.md b/tasks/todo.md new file mode 100644 index 000000000..908bb88c9 --- /dev/null +++ b/tasks/todo.md @@ -0,0 +1,129 @@ +# Candidate 01 — Session-State Transaction + +## Scope + +- Implement exactly-once terminalization for admitted `ds4-server` requests. +- Keep live session/frontier mutation on the single worker. +- Publish immutable statistics snapshots; `/stats` must not inspect `ds4_session`. +- Preserve current wire ordering, continuation behavior, checkpoint compatibility, and the running local Metal process. +- Add deterministic scripted failure coverage and a concise ADR. +- Exclude protocol-adapter, continuation-policy, and KVC-format refactors. + +## Plan + +- [x] Compare three deep-module interfaces and record the approved design and implementation plan. +- [x] Add a worker-published immutable `/stats` snapshot test-first. +- [x] Add typed execution phases, reasons, dispositions, and one idempotent terminalizer test-first. +- [x] Add private production and scripted adapters with deterministic failure precedence tests. +- [x] Migrate restore, sync, decode, output, commit/rollback, tracing, statistics, and cleanup through the controlled lifecycle. +- [x] Add the domain glossary entry and ADR. +- [x] Route prefill/open/delta output and nonterminal trace/statistics observations through the private adapters. +- [x] Correct causal-failure, checkpoint-disposition, wire, and stats-publication edge cases found by guard review. +- [x] Add deterministic coverage for operational adapter failures, shutdown/output precedence, checkpoint disposition, and idle stats refresh. +- [x] Run safe verification, guard reviews, inspect the diff, and commit only scoped files. + +## Acceptance criteria + +- Every admitted request produces exactly one typed terminal outcome. +- Terminalization and cleanup are idempotent and run through one path. +- The primary failure survives rollback, trace, statistics, output-finalization, or cleanup failures. +- Streamed bytes are recorded as irreversible and are never described as rolled back. +- `/stats` reads one immutable snapshot and never calls a live-session accessor. +- Scripted tests cover restore, sync, decode, cancellation, output, commit, rollback, tracing, and cleanup failures. +- Existing server tests and the normal build pass without stopping the currently running server. + +## Review + +- Replaced the worker's request monolith with one shared, forward-only + transaction driver and private production/scripted session, output, trace, + and statistics adapters. All admitted jobs publish one typed outcome through + an idempotent terminalizer. +- Routed prefill keepalives, stream open/update/flush/finalization, trace + begin/event/piece/finalization, request counters, progress snapshots, + settlement, cleanup, and checkpoint accounting through the controlled + lifecycle. Rollback no longer publishes a newly parsed continuation frontier. +- `/stats` now copies only a worker-published immutable snapshot. Worker refresh + coalescing prioritizes admitted jobs, and terminal publication occurs after + trace and cleanup so `busy=false` is truthful. +- Added explicit session-validity inspection, sticky shutdown/output failure + precedence, broken-wire no-retry behavior, checkpoint secondary failures, + and actual-validity rollback disposition. +- Verification passed: + - warning-free `make -B ds4-server ds4_test`; + - `./ds4_test --server`; + - `./ds4-eval --self-test-extractors`; + - `git diff --check`; + - independent spec, concurrency, test/documentation, and clean-code audits. +- Gracefully stopped PID 81030 after it persisted 101,224 live tokens to the + disk cache, then restarted the exact requested command as PID 31807. Metal + mapped about 95.1 GiB, allocated about 8.6 GiB for the 524,288-token context, + reopened the 32 GiB cache, and listened on `127.0.0.1:8000`. +- Live health, model metadata, and immutable stats checks passed. A one-token + chat smoke request completed in 2.7 seconds; the final snapshot reported + `busy=false`, one request, nine live tokens, and no rejection/cancellation. + Its trace closed with completed/length, committed session, complete wire, and + no secondary failure. +- Supplemental macOS AddressSanitizer was not a passing gate: LeakSanitizer is + unsupported, and the leak-disabled instrumented server suite was time-boxed + and terminated when it remained unexpectedly CPU-heavy. CUDA, distributed, + and SSD-streaming model modes were not exercised; the live Apple M5 Max Metal + path and disk checkpoint cache were exercised. + +--- + +# Prior: ds4 Server Architecture Review — 2026-07-10 + +## Scope + +- Review `ds4-server` for architectural deepening opportunities. +- Preserve its role as a local DeepSeek V4 Flash Metal server on the Apple M5 Max with 128 GiB unified memory. +- Keep source code unchanged; write the visual report to the OS temp directory. +- Preserve the user's existing untracked files. + +## Plan + +- [x] Launch the requested server command and verify port 8000 is listening. +- [x] Monitor live server logs while the user exercises it during this review. +- [x] Read project guidance, server documentation, current implementation, tests, and recent server-enhancement history. +- [x] Identify candidates that pass the deletion test and validate each with file-level evidence. +- [x] Generate, validate, and open a self-contained HTML report with before/after diagrams. + +## Acceptance criteria + +- The requested server remains running on `127.0.0.1:8000` with tracing enabled. +- Every candidate names involved files, dependency category, architectural friction, deepening, locality, leverage, and test impact. +- No candidate re-proposes work already implemented on `server-enhancements`. +- The report ends with one top recommendation and proposes no concrete interfaces. + +## Out of scope observations + +- `ds4_server.c:11617-11663` lets a client thread read the worker-owned session position while the worker mutates it; the report treats this as architectural evidence, but this review does not change source code. +- `README.md:1039-1052` trails the current KVC header and extension flags in `ds4_kvstore.h:15-18,36-57`; documentation repair is separate from this architecture review. + +## Review + +- Started the exact requested command and verified the Metal-backed DeepSeek V4 Flash server on `127.0.0.1:8000`. +- Monitored the live tool loop through roughly 132K tokens of session depth. Requests completed with normal `stop` or `tool_calls` finishes; no queue drops, cancellations, socket failures, model failures, malformed DSML, or corrupt-cache warnings appeared. +- Normal disk-budget pressure evicted zero-hit checkpoints and successfully wrote cold/continued replacements. +- Produced and opened `/var/folders/fs/brn3wr_x4ns2km1cq1ph9zb80000gn/T/architecture-review-20260710-200425.html` with four deletion-test-backed candidates. +- Top recommendation: make request execution one terminal transaction while preserving the single local Metal worker. +- Verified the report in headless Chrome, including Tailwind and Mermaid rendering, and ran `./ds4_test --server` successfully. +- No production or test source was changed. Repo changes are limited to the task tracker and lesson required by the operating manual. + +# Task: Post-review robustness fixes for the session transaction (2026-07-10) + +## Plan + +- [x] Two-axis review (standards + spec) of 5a91c33..a2815e5 → verify: findings cite file:line evidence. +- [x] Fix rollback retaining stale protocol live bindings → verify: new unit test fails before, passes after. +- [x] Consume the `kv_cache_store_current("shutdown")` result → verify: warning logged on failure path. +- [x] Compile `test_txn_event` only under `DS4_SERVER_TEST` → verify: warning-free production build. +- [x] Downgrade duplicate-terminal-publish `die()` to a loud log → verify: `./ds4_test --server` still passes. +- [x] Align spec text with the queued-disconnect encoding (client gone, restore phase) → verify: doc reads true against `production_restore`. + +## Review + +- Declined review item "wire mislabeled BROKEN on zero-byte failure": the spec's monotonic wire ledger deliberately treats any failed write attempt as may-have-emitted (spec lines 170-171, 195-196), scripted tests pin that contract, and the cited stream-failed early return is unreachable from `production_output_finish` because the wire is already BROKEN there. +- Kept the worker-ownership `die()` calls: they guard cross-thread session mutation, which is memory-unsafe to continue past. +- Deferred (out of scope): collapsing the adapter vtable layer to direct calls, deduplicating the two trace vsnprintf wrappers and the two failure latches, and whether docs/tasks files belong in the upstream PR. +- Verified: warning-free `make ds4-server ds4_test`; `./ds4_test --server` OK including new `test_production_settle_rollback_clears_live_bindings`.