Skip to content

/v1/responses with tools fails with "System message must be at the beginning" Jinja exception for Ornith-1.0-35B (and likely other reasoning models) #2674

Open
Open
/v1/responses with tools fails with "System message must be at the beginning" Jinja exception for Ornith-1.0-35B (and likely other reasoning models)#2674
Labels
area::apiHTTP REST API surface and route handlersbugSomething isn't workingengine::llamacppllama.cpp backend (LlamaCppServer); GPU/CPU LLM inference (Vulkan, ROCm, Metal)

Description

@tmyymmt
tmyymmt
opened on Jul 12, 2026

Platform

Windows

Lemonade Version

10.9.0

GPU / APU Model

AMD RYZEN AI MAX+395 w/Radeon 8060S

Component

llama.cpp

Bug Description

Environment

  • Lemonade Server (Windows), model: Ornith-1.0-35B-GGUF-Q5_K_M (deepreinforce-ai/Ornith-1.0-35B-GGUF, Q5_K_M)
  • Client: OpenAI Codex CLI v0.144.1, wire_api = "responses", base_url = http://localhost:13305/v1
  • Backend: llama.cpp (Chat format: peg-native)

Summary

Plain (no-tools) requests to /v1/responses work fine, including streaming and non-streaming.
As soon as the request includes tool definitions (as sent by Codex CLI, which includes internal
tool types like namespace and web_search alongside the shell/function tools), the server
logs:

srv server_chat_: unsupported Responses tool type 'namespace' skipped
srv server_chat_: unsupported Responses tool type 'web_search' skipped
got exception: {"error":{"code":400,"message":"Unable to generate parser for this template.
Automatic parser generation failed:
------------
While executing CallExpression at line 85, column 32 in source:
...first %}
            {{- raise_exception('System message must be at the beginnin...
                                           ^
Error: Jinja Exception: System message must be at the beginning.","type":"invalid_request_error"}}

The client (Codex CLI) only observes this as a mid-stream disconnect ("stream disconnected before
completion: stream closed before response.completed") and retries 5 times before giving up, since
the 400 happens after HTTP 200 + text/event-stream headers are already sent.

Steps to Reproduce

  1. Start Lemonade Server with Ornith-1.0-35B-GGUF-Q5_K_M loaded.
  2. Send a /v1/responses request with stream: true and a tools array that includes an
    unsupported tool type (e.g. namespace) plus a normal function tool, similar to what Codex CLI
    sends for a real agent turn (instructions + prior conversation items + tool defs).
  3. Observe: POST /v1/responses - Streaming followed by the two unsupported Responses tool type ... skipped warnings, then a 400 Jinja exception logged server-side, while the client only
    sees an unexpected stream close.

A minimal curl example that reproduces successfully (no tools, no system-first constraint issue):

curl -s -N http://localhost:13305/v1/responses -X POST -H "Content-Type: application/json" -d '{
  "model":"Ornith-1.0-35B-GGUF-Q5_K_M",
  "input":"What is 2+2?",
  "stream":true
}'
# => completes normally with response.completed

A single function-tool call (no namespace/web_search) also completes normally via curl.
The failure appears specific to the exact message/tool shape that Codex CLI constructs for a full
agent turn (multiple tool defs including unsupported types, and instructions/context ordering that
the Ornith chat template's Jinja guard rejects).

Expected vs Actual Behavior

  • Either: unsupported Responses tool types should be dropped before building the prompt in a way
    that keeps the resulting chat-completions payload valid against the model's chat template (i.e.
    don't leave a message ordering that violates "system message must be at the beginning").
  • Or: the 400 error should be surfaced to the client as a proper non-200 response before
    text/event-stream headers are sent, so clients don't spin retrying against a stream that will
    never complete.

Log Output

2026-07-12 14:26:12.061 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:26:12.061 [Info] (Server) POST /api/v1/responses - Non-streaming
2026-07-12 14:26:12.088 [Info] (Process) 2453.50.926.343 I srv    operator(): Chat format: peg-native
2026-07-12 14:26:12.088 [Info] (Process) 2453.50.926.506 I slot get_availabl: id  2 | task -1 | selected slot by LRU, t_last = 130813258089
2026-07-12 14:26:12.088 [Info] (Process) 2453.50.926.509 I srv  get_availabl: updating prompt cache
2026-07-12 14:26:12.088 [Info] (Process) 2453.50.926.519 I srv          load:  - looking for better prompt, base f_keep = -1.000, sim = 0.000
2026-07-12 14:26:12.088 [Info] (Process) 2453.50.926.527 I srv        update:  - cache state: 1 prompts, 5200.656 MiB (limits: 8192.000 MiB, 262144 tokens, 307681 est)
2026-07-12 14:26:12.088 [Info] (Process) 2453.50.926.529 I srv        update:    - prompt 0000021A5A1BABD0:  195330 tokens, checkpoints: 21,  5200.656 MiB
2026-07-12 14:26:12.088 [Info] (Process) 2453.50.926.530 I srv  get_availabl: prompt cache update took 0.02 ms
2026-07-12 14:26:12.088 [Info] (Process) 2453.50.926.967 I slot launch_slot_: id  2 | task 94848 | processing task, is_child = 0
2026-07-12 14:26:12.089 [Info] (Process) 2453.50.926.971 I slot process_sing: id  0 | task -1 | saving idle slot to prompt cache
2026-07-12 14:26:12.089 [Info] (Process) 2453.50.927.708 W srv   prompt_save:  - saving prompt with length 1536, total state size = 92.843 MiB (draft: 0.000 MiB)
2026-07-12 14:26:13.202 [Info] (Process) 2453.52.040.024 I srv        update:  - cache state: 2 prompts, 5356.312 MiB (limits: 8192.000 MiB, 262144 tokens, 301088 est)
2026-07-12 14:26:13.202 [Info] (Process) 2453.52.040.035 I srv        update:    - prompt 0000021A5A1BABD0:  195330 tokens, checkpoints: 21,  5200.656 MiB
2026-07-12 14:26:13.202 [Info] (Process) 2453.52.040.036 I srv        update:    - prompt 0000021BF3BC2F90:    1536 tokens, checkpoints:  1,   155.656 MiB
2026-07-12 14:26:13.202 [Info] (Process) 2453.52.040.037 I slot prompt_clear: id  0 | task -1 | clearing prompt with 1536 tokens
2026-07-12 14:26:13.202 [Info] (Process) 2453.52.040.587 I slot process_sing: id  1 | task -1 | saving idle slot to prompt cache
2026-07-12 14:26:13.203 [Info] (Process) 2453.52.041.148 W srv   prompt_save:  - saving prompt with length 10870, total state size = 275.325 MiB (draft: 0.000 MiB)
2026-07-12 14:26:15.627 [Info] (Process) 2453.54.465.151 I srv        update:  - cache state: 3 prompts, 5882.890 MiB (limits: 8192.000 MiB, 262144 tokens, 289275 est)
2026-07-12 14:26:15.627 [Info] (Process) 2453.54.465.157 I srv        update:    - prompt 0000021A5A1BABD0:  195330 tokens, checkpoints: 21,  5200.656 MiB
2026-07-12 14:26:15.627 [Info] (Process) 2453.54.465.158 I srv        update:    - prompt 0000021BF3BC2F90:    1536 tokens, checkpoints:  1,   155.656 MiB
2026-07-12 14:26:15.627 [Info] (Process) 2453.54.465.159 I srv        update:    - prompt 0000021BF3BC2B10:   10870 tokens, checkpoints:  4,   526.578 MiB
2026-07-12 14:26:15.627 [Info] (Process) 2453.54.465.160 I slot prompt_clear: id  1 | task -1 | clearing prompt with 10870 tokens
2026-07-12 14:26:15.628 [Info] (Process) 2453.54.466.896 I slot process_sing: id  3 | task -1 | saving idle slot to prompt cache
2026-07-12 14:26:15.628 [Info] (Process) 2453.54.466.901 I slot prompt_clear: id  3 | task -1 | clearing prompt with 0 tokens
2026-07-12 14:26:15.629 [Info] (Process) 2453.54.467.100 W slot update_slots: id  2 | task 94848 | erased invalidated context checkpoint (pos_min = 538, pos_max = 538, n_tokens = 539, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:26:16.206 [Info] (Process) 2453.55.044.447 I slot create_check: id  2 | task 94848 | created context checkpoint 1 of 32 (pos_min = 12, pos_max = 12, n_tokens = 13, size = 62.813 MiB)
2026-07-12 14:26:18.260 [Info] (Process) 2453.57.098.460 I slot print_timing: id  2 | task 94848 | prompt eval time =     604.53 ms /    17 tokens (   35.56 ms per token,    28.12 tokens per second)
2026-07-12 14:26:18.260 [Info] (Process) 2453.57.098.467 I slot print_timing: id  2 | task 94848 |        eval time =    2026.82 ms /   139 tokens (   14.58 ms per token,    68.58 tokens per second)
2026-07-12 14:26:18.260 [Info] (Process) 2453.57.098.468 I slot print_timing: id  2 | task 94848 |       total time =    2631.36 ms /   156 tokens
2026-07-12 14:26:18.260 [Info] (Process) 2453.57.098.469 I slot print_timing: id  2 | task 94848 |    graphs reused =      92468
2026-07-12 14:26:18.261 [Info] (Process) 2453.57.098.495 I slot      release: id  2 | task 94848 | stop processing: n_tokens = 155, truncated = 0
2026-07-12 14:26:18.272 [Info] (Server) 200 OK
2026-07-12 14:27:19.915 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:27:19.915 [Info] (Server) POST /api/v1/responses - Streaming
2026-07-12 14:27:19.918 [Info] (Process) 2454.58.756.677 W srv  server_chat_: unsupported Responses tool type 'namespace' skipped
2026-07-12 14:27:19.918 [Info] (Process) 2454.58.756.710 W srv  server_chat_: unsupported Responses tool type 'web_search' skipped
2026-07-12 14:27:19.937 [Error] (Process) 2454.58.775.240 W srv    operator(): got exception: {"error":{"code":400,"message":"Unable to generate parser for this template. Automatic parser generation failed: \n------------\nWhile executing CallExpression at line 85, column 32 in source:\n...first %}↵            {{- raise_exception('System message must be at the beginnin...\n                                           ^\nError: Jinja Exception: System message must be at the beginning.","type":"invalid_request_error"}}
2026-07-12 14:27:20.163 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:27:20.163 [Info] (Server) POST /api/v1/responses - Streaming
2026-07-12 14:27:20.165 [Info] (Process) 2454.59.003.139 W srv  server_chat_: unsupported Responses tool type 'namespace' skipped
2026-07-12 14:27:20.165 [Info] (Process) 2454.59.003.163 W srv  server_chat_: unsupported Responses tool type 'web_search' skipped
2026-07-12 14:27:20.180 [Error] (Process) 2454.59.017.992 W srv    operator(): got exception: {"error":{"code":400,"message":"Unable to generate parser for this template. Automatic parser generation failed: \n------------\nWhile executing CallExpression at line 85, column 32 in source:\n...first %}↵            {{- raise_exception('System message must be at the beginnin...\n                                           ^\nError: Jinja Exception: System message must be at the beginning.","type":"invalid_request_error"}}
2026-07-12 14:27:20.598 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:27:20.598 [Info] (Server) POST /api/v1/responses - Streaming
2026-07-12 14:27:20.600 [Info] (Process) 2454.59.438.665 W srv  server_chat_: unsupported Responses tool type 'namespace' skipped
2026-07-12 14:27:20.600 [Info] (Process) 2454.59.438.690 W srv  server_chat_: unsupported Responses tool type 'web_search' skipped
2026-07-12 14:27:20.616 [Error] (Process) 2454.59.454.862 W srv    operator(): got exception: {"error":{"code":400,"message":"Unable to generate parser for this template. Automatic parser generation failed: \n------------\nWhile executing CallExpression at line 85, column 32 in source:\n...first %}↵            {{- raise_exception('System message must be at the beginnin...\n                                           ^\nError: Jinja Exception: System message must be at the beginning.","type":"invalid_request_error"}}
2026-07-12 14:27:21.306 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:27:21.306 [Info] (Server) POST /api/v1/responses - Streaming
2026-07-12 14:27:21.308 [Info] (Process) 2455.00.146.571 W srv  server_chat_: unsupported Responses tool type 'namespace' skipped
2026-07-12 14:27:21.308 [Info] (Process) 2455.00.146.596 W srv  server_chat_: unsupported Responses tool type 'web_search' skipped
2026-07-12 14:27:21.321 [Error] (Process) 2455.00.159.574 W srv    operator(): got exception: {"error":{"code":400,"message":"Unable to generate parser for this template. Automatic parser generation failed: \n------------\nWhile executing CallExpression at line 85, column 32 in source:\n...first %}↵            {{- raise_exception('System message must be at the beginnin...\n                                           ^\nError: Jinja Exception: System message must be at the beginning.","type":"invalid_request_error"}}
2026-07-12 14:27:22.890 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:27:22.891 [Info] (Server) POST /api/v1/responses - Streaming
2026-07-12 14:27:22.893 [Info] (Process) 2455.01.731.058 W srv  server_chat_: unsupported Responses tool type 'namespace' skipped
2026-07-12 14:27:22.893 [Info] (Process) 2455.01.731.083 W srv  server_chat_: unsupported Responses tool type 'web_search' skipped
2026-07-12 14:27:22.906 [Error] (Process) 2455.01.744.019 W srv    operator(): got exception: {"error":{"code":400,"message":"Unable to generate parser for this template. Automatic parser generation failed: \n------------\nWhile executing CallExpression at line 85, column 32 in source:\n...first %}↵            {{- raise_exception('System message must be at the beginnin...\n                                           ^\nError: Jinja Exception: System message must be at the beginning.","type":"invalid_request_error"}}
2026-07-12 14:27:25.864 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:27:25.865 [Info] (Server) POST /api/v1/responses - Streaming
2026-07-12 14:27:25.866 [Info] (Process) 2455.04.704.920 W srv  server_chat_: unsupported Responses tool type 'namespace' skipped
2026-07-12 14:27:25.867 [Info] (Process) 2455.04.704.945 W srv  server_chat_: unsupported Responses tool type 'web_search' skipped
2026-07-12 14:27:25.880 [Error] (Process) 2455.04.718.522 W srv    operator(): got exception: {"error":{"code":400,"message":"Unable to generate parser for this template. Automatic parser generation failed: \n------------\nWhile executing CallExpression at line 85, column 32 in source:\n...first %}↵            {{- raise_exception('System message must be at the beginnin...\n                                           ^\nError: Jinja Exception: System message must be at the beginning.","type":"invalid_request_error"}}
2026-07-12 14:27:40.605 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:27:40.606 [Info] (Server) POST /api/v1/responses - Streaming
2026-07-12 14:27:40.620 [Info] (Process) 2455.19.458.648 I srv    operator(): Chat format: peg-native
2026-07-12 14:27:40.620 [Info] (Process) 2455.19.458.787 I slot get_availabl: id  2 | task -1 | selected slot by LCP similarity, sim_best = 1.000 (> 0.100 thold), f_keep = 0.110
2026-07-12 14:27:40.620 [Info] (Process) 2455.19.458.790 I srv  get_availabl: updating prompt cache
2026-07-12 14:27:40.620 [Info] (Process) 2455.19.458.965 W srv   prompt_save:  - saving prompt with length 155, total state size = 65.844 MiB (draft: 0.000 MiB)
2026-07-12 14:27:41.140 [Info] (Process) 2455.19.978.368 I srv          load:  - looking for better prompt, base f_keep = 0.110, sim = 1.000
2026-07-12 14:27:41.140 [Info] (Process) 2455.19.978.382 I srv        update:  - cache state: 4 prompts, 6011.547 MiB (limits: 8192.000 MiB, 262144 tokens, 283295 est)
2026-07-12 14:27:41.140 [Info] (Process) 2455.19.978.385 I srv        update:    - prompt 0000021A5A1BABD0:  195330 tokens, checkpoints: 21,  5200.656 MiB
2026-07-12 14:27:41.140 [Info] (Process) 2455.19.978.386 I srv        update:    - prompt 0000021BF3BC2F90:    1536 tokens, checkpoints:  1,   155.656 MiB
2026-07-12 14:27:41.140 [Info] (Process) 2455.19.978.387 I srv        update:    - prompt 0000021BF3BC2B10:   10870 tokens, checkpoints:  4,   526.578 MiB
2026-07-12 14:27:41.140 [Info] (Process) 2455.19.978.388 I srv        update:    - prompt 0000021BF3BC28D0:     155 tokens, checkpoints:  1,   128.657 MiB
2026-07-12 14:27:41.141 [Info] (Process) 2455.19.978.392 I srv  get_availabl: prompt cache update took 519.60 ms
2026-07-12 14:27:41.141 [Info] (Process) 2455.19.978.595 I slot launch_slot_: id  2 | task 94989 | processing task, is_child = 0
2026-07-12 14:27:41.141 [Info] (Process) 2455.19.978.598 I slot process_sing: id  0 | task -1 | saving idle slot to prompt cache
2026-07-12 14:27:41.141 [Info] (Process) 2455.19.978.599 I slot prompt_clear: id  0 | task -1 | clearing prompt with 0 tokens
2026-07-12 14:27:41.141 [Info] (Process) 2455.19.978.721 I slot process_sing: id  1 | task -1 | saving idle slot to prompt cache
2026-07-12 14:27:41.141 [Info] (Process) 2455.19.978.724 I slot prompt_clear: id  1 | task -1 | clearing prompt with 0 tokens
2026-07-12 14:27:41.141 [Info] (Process) 2455.19.978.834 I slot process_sing: id  3 | task -1 | saving idle slot to prompt cache
2026-07-12 14:27:41.141 [Info] (Process) 2455.19.978.836 I slot prompt_clear: id  3 | task -1 | clearing prompt with 0 tokens
2026-07-12 14:27:41.141 [Info] (Process) 2455.19.978.960 I slot update_slots: id  2 | task 94989 | Checking checkpoint with [12, 12] against 16...
2026-07-12 14:27:41.143 [Info] (Process) 2455.19.981.171 W slot update_slots: id  2 | task 94989 | restored context checkpoint (pos_min = 12, pos_max = 12, n_tokens = 13, n_past = 13, size = 62.813 MiB)
2026-07-12 14:27:41.456 [Info] (Process) 2455.20.294.337 W srv          stop: cancel task, id_task = 94989
2026-07-12 14:27:41.471 [Info] (Process) 2455.20.309.470 I slot      release: id  2 | task 94989 | stop processing: n_tokens = 37, truncated = 0
2026-07-12 14:27:49.492 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:27:49.492 [Info] (Server) POST /api/v1/responses - Streaming
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.115 I srv    operator(): Chat format: peg-native
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.252 I slot get_availabl: id  2 | task -1 | selected slot by LCP similarity, sim_best = 1.000 (> 0.100 thold), f_keep = 0.459
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.255 I srv  get_availabl: updating prompt cache
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.377 W srv   prompt_save:  - saving prompt with length 37, total state size = 63.537 MiB (draft: 0.000 MiB)
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.381 I srv         alloc:  - prompt is already in the cache, skipping
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.383 I srv          load:  - looking for better prompt, base f_keep = 0.459, sim = 1.000
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.389 I srv        update:  - cache state: 4 prompts, 6011.547 MiB (limits: 8192.000 MiB, 262144 tokens, 283295 est)
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.391 I srv        update:    - prompt 0000021A5A1BABD0:  195330 tokens, checkpoints: 21,  5200.656 MiB
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.392 I srv        update:    - prompt 0000021BF3BC2F90:    1536 tokens, checkpoints:  1,   155.656 MiB
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.393 I srv        update:    - prompt 0000021BF3BC2B10:   10870 tokens, checkpoints:  4,   526.578 MiB
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.394 I srv        update:    - prompt 0000021BF3BC28D0:     155 tokens, checkpoints:  1,   128.657 MiB
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.395 I srv  get_availabl: prompt cache update took 0.14 ms
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.600 I slot launch_slot_: id  2 | task 95012 | processing task, is_child = 0
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.603 I slot process_sing: id  0 | task -1 | saving idle slot to prompt cache
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.604 I slot prompt_clear: id  0 | task -1 | clearing prompt with 0 tokens
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.718 I slot process_sing: id  1 | task -1 | saving idle slot to prompt cache
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.720 I slot prompt_clear: id  1 | task -1 | clearing prompt with 0 tokens
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.836 I slot process_sing: id  3 | task -1 | saving idle slot to prompt cache
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.838 I slot prompt_clear: id  3 | task -1 | clearing prompt with 0 tokens
2026-07-12 14:27:49.507 [Info] (Process) 2455.28.345.957 I slot update_slots: id  2 | task 95012 | Checking checkpoint with [12, 12] against 16...
2026-07-12 14:27:49.510 [Info] (Process) 2455.28.348.111 W slot update_slots: id  2 | task 95012 | restored context checkpoint (pos_min = 12, pos_max = 12, n_tokens = 13, n_past = 13, size = 62.813 MiB)
2026-07-12 14:27:51.514 [Info] (Process) 2455.30.352.574 I slot print_timing: id  2 | task 95012 | prompt eval time =      29.56 ms /     4 tokens (    7.39 ms per token,   135.31 tokens per second)
2026-07-12 14:27:51.514 [Info] (Process) 2455.30.352.581 I slot print_timing: id  2 | task 95012 |        eval time =    1977.04 ms /   135 tokens (   14.64 ms per token,    68.28 tokens per second)
2026-07-12 14:27:51.514 [Info] (Process) 2455.30.352.581 I slot print_timing: id  2 | task 95012 |       total time =    2006.60 ms /   139 tokens
2026-07-12 14:27:51.514 [Info] (Process) 2455.30.352.582 I slot print_timing: id  2 | task 95012 |    graphs reused =      92620
2026-07-12 14:27:51.514 [Info] (Process) 2455.30.352.599 I slot      release: id  2 | task 95012 | stop processing: n_tokens = 151, truncated = 0
2026-07-12 14:27:51.516 [Warn] (StreamingProxy) WARNING: Backend did not send [DONE] marker, adding it
2026-07-12 14:27:51.516 [Info] (Server) Streaming completed - 200 OK
2026-07-12 14:28:04.336 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:28:04.336 [Info] (Server) POST /api/v1/responses - Streaming
2026-07-12 14:28:04.367 [Info] (Process) 2455.43.205.365 I srv    operator(): Chat format: peg-native
2026-07-12 14:28:04.367 [Info] (Process) 2455.43.205.890 I slot get_availabl: id  3 | task -1 | selected slot by LRU, t_last = 130954660654
2026-07-12 14:28:04.368 [Info] (Process) 2455.43.205.894 I srv  get_availabl: updating prompt cache
2026-07-12 14:28:04.368 [Info] (Process) 2455.43.205.901 I srv          load:  - looking for better prompt, base f_keep = -1.000, sim = 0.000
2026-07-12 14:28:04.368 [Info] (Process) 2455.43.205.910 I srv        update:  - cache state: 4 prompts, 6011.547 MiB (limits: 8192.000 MiB, 262144 tokens, 283295 est)
2026-07-12 14:28:04.368 [Info] (Process) 2455.43.205.911 I srv        update:    - prompt 0000021A5A1BABD0:  195330 tokens, checkpoints: 21,  5200.656 MiB
2026-07-12 14:28:04.368 [Info] (Process) 2455.43.205.913 I srv        update:    - prompt 0000021BF3BC2F90:    1536 tokens, checkpoints:  1,   155.656 MiB
2026-07-12 14:28:04.368 [Info] (Process) 2455.43.205.913 I srv        update:    - prompt 0000021BF3BC2B10:   10870 tokens, checkpoints:  4,   526.578 MiB
2026-07-12 14:28:04.368 [Info] (Process) 2455.43.205.914 I srv        update:    - prompt 0000021BF3BC28D0:     155 tokens, checkpoints:  1,   128.657 MiB
2026-07-12 14:28:04.368 [Info] (Process) 2455.43.205.915 I srv  get_availabl: prompt cache update took 0.02 ms
2026-07-12 14:28:04.368 [Info] (Process) 2455.43.206.011 I reasoning-budget: activated, budget=2147483647 tokens
2026-07-12 14:28:04.368 [Info] (Process) 2455.43.206.372 I slot launch_slot_: id  3 | task 95148 | processing task, is_child = 0
2026-07-12 14:28:04.368 [Info] (Process) 2455.43.206.375 I slot process_sing: id  0 | task -1 | saving idle slot to prompt cache
2026-07-12 14:28:04.368 [Info] (Process) 2455.43.206.376 I slot prompt_clear: id  0 | task -1 | clearing prompt with 0 tokens
2026-07-12 14:28:04.368 [Info] (Process) 2455.43.206.509 I slot process_sing: id  1 | task -1 | saving idle slot to prompt cache
2026-07-12 14:28:04.368 [Info] (Process) 2455.43.206.515 I slot prompt_clear: id  1 | task -1 | clearing prompt with 0 tokens
2026-07-12 14:28:04.368 [Info] (Process) 2455.43.206.638 I slot process_sing: id  2 | task -1 | saving idle slot to prompt cache
2026-07-12 14:28:04.368 [Info] (Process) 2455.43.206.760 W srv   prompt_save:  - saving prompt with length 151, total state size = 65.766 MiB (draft: 0.000 MiB)
2026-07-12 14:28:04.877 [Info] (Process) 2455.43.715.067 I srv        update:  - cache state: 5 prompts, 6140.126 MiB (limits: 8192.000 MiB, 262144 tokens, 277564 est)
2026-07-12 14:28:04.877 [Info] (Process) 2455.43.715.074 I srv        update:    - prompt 0000021A5A1BABD0:  195330 tokens, checkpoints: 21,  5200.656 MiB
2026-07-12 14:28:04.877 [Info] (Process) 2455.43.715.075 I srv        update:    - prompt 0000021BF3BC2F90:    1536 tokens, checkpoints:  1,   155.656 MiB
2026-07-12 14:28:04.877 [Info] (Process) 2455.43.715.076 I srv        update:    - prompt 0000021BF3BC2B10:   10870 tokens, checkpoints:  4,   526.578 MiB
2026-07-12 14:28:04.877 [Info] (Process) 2455.43.715.077 I srv        update:    - prompt 0000021BF3BC28D0:     155 tokens, checkpoints:  1,   128.657 MiB
2026-07-12 14:28:04.877 [Info] (Process) 2455.43.715.078 I srv        update:    - prompt 0000021BF3BC2BA0:     151 tokens, checkpoints:  1,   128.579 MiB
2026-07-12 14:28:04.877 [Info] (Process) 2455.43.715.079 I slot prompt_clear: id  2 | task -1 | clearing prompt with 151 tokens
2026-07-12 14:28:04.877 [Info] (Process) 2455.43.715.241 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 8000, pos_max = 8000, n_tokens = 8001, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.879 [Info] (Process) 2455.43.717.255 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 10756, pos_max = 10756, n_tokens = 10757, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.881 [Info] (Process) 2455.43.719.326 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 11268, pos_max = 11268, n_tokens = 11269, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.883 [Info] (Process) 2455.43.721.518 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 11536, pos_max = 11536, n_tokens = 11537, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.885 [Info] (Process) 2455.43.723.520 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 11884, pos_max = 11884, n_tokens = 11885, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.887 [Info] (Process) 2455.43.725.711 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 12163, pos_max = 12163, n_tokens = 12164, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.889 [Info] (Process) 2455.43.727.888 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 12484, pos_max = 12484, n_tokens = 12485, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.891 [Info] (Process) 2455.43.729.943 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 12804, pos_max = 12804, n_tokens = 12805, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.893 [Info] (Process) 2455.43.731.960 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 13124, pos_max = 13124, n_tokens = 13125, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.895 [Info] (Process) 2455.43.733.944 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 13444, pos_max = 13444, n_tokens = 13445, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.897 [Info] (Process) 2455.43.735.991 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 13764, pos_max = 13764, n_tokens = 13765, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.900 [Info] (Process) 2455.43.737.998 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 14084, pos_max = 14084, n_tokens = 14085, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.902 [Info] (Process) 2455.43.740.023 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 14404, pos_max = 14404, n_tokens = 14405, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.903 [Info] (Process) 2455.43.741.904 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 14724, pos_max = 14724, n_tokens = 14725, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.905 [Info] (Process) 2455.43.743.812 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 15044, pos_max = 15044, n_tokens = 15045, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.907 [Info] (Process) 2455.43.745.691 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 15364, pos_max = 15364, n_tokens = 15365, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.909 [Info] (Process) 2455.43.747.611 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 15684, pos_max = 15684, n_tokens = 15685, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.911 [Info] (Process) 2455.43.749.611 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 16004, pos_max = 16004, n_tokens = 16005, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.913 [Info] (Process) 2455.43.751.515 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 16324, pos_max = 16324, n_tokens = 16325, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.915 [Info] (Process) 2455.43.753.403 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 16644, pos_max = 16644, n_tokens = 16645, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.917 [Info] (Process) 2455.43.755.323 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 16964, pos_max = 16964, n_tokens = 16965, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.919 [Info] (Process) 2455.43.757.289 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 17284, pos_max = 17284, n_tokens = 17285, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.921 [Info] (Process) 2455.43.759.413 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 17604, pos_max = 17604, n_tokens = 17605, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.923 [Info] (Process) 2455.43.761.444 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 17924, pos_max = 17924, n_tokens = 17925, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.925 [Info] (Process) 2455.43.763.470 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 18244, pos_max = 18244, n_tokens = 18245, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.927 [Info] (Process) 2455.43.765.437 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 18564, pos_max = 18564, n_tokens = 18565, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.929 [Info] (Process) 2455.43.767.270 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 18884, pos_max = 18884, n_tokens = 18885, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.931 [Info] (Process) 2455.43.769.114 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 19204, pos_max = 19204, n_tokens = 19205, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.932 [Info] (Process) 2455.43.770.975 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 19524, pos_max = 19524, n_tokens = 19525, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.934 [Info] (Process) 2455.43.772.827 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 19844, pos_max = 19844, n_tokens = 19845, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.936 [Info] (Process) 2455.43.774.711 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 20164, pos_max = 20164, n_tokens = 20165, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:04.938 [Info] (Process) 2455.43.776.618 W slot update_slots: id  3 | task 95148 | erased invalidated context checkpoint (pos_min = 20484, pos_max = 20484, n_tokens = 20485, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:28:05.752 [Info] (Process) 2455.44.590.062 I slot create_check: id  3 | task 95148 | created context checkpoint 1 of 32 (pos_min = 254, pos_max = 254, n_tokens = 255, size = 62.813 MiB)
2026-07-12 14:28:07.679 [Info] (Process) 2455.46.517.039 I reasoning-budget: deactivated (natural end)
2026-07-12 14:28:08.105 [Info] (Process) 2455.46.942.980 I slot print_timing: id  3 | task 95148 | prompt eval time =     984.10 ms /   276 tokens (    3.57 ms per token,   280.46 tokens per second)
2026-07-12 14:28:08.105 [Info] (Process) 2455.46.942.985 I slot print_timing: id  3 | task 95148 |        eval time =    2243.62 ms /   154 tokens (   14.57 ms per token,    68.64 tokens per second)
2026-07-12 14:28:08.105 [Info] (Process) 2455.46.942.988 I slot print_timing: id  3 | task 95148 |       total time =    3227.72 ms /   430 tokens
2026-07-12 14:28:08.105 [Info] (Process) 2455.46.942.990 I slot print_timing: id  3 | task 95148 |    graphs reused =      92772
2026-07-12 14:28:08.105 [Info] (Process) 2455.46.943.087 I slot      release: id  3 | task 95148 | stop processing: n_tokens = 429, truncated = 0
2026-07-12 14:28:08.106 [Warn] (StreamingProxy) WARNING: Backend did not send [DONE] marker, adding it
2026-07-12 14:28:08.106 [Info] (Server) Streaming completed - 200 OK
2026-07-12 14:28:30.156 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:28:30.156 [Info] (Server) POST /api/v1/responses - Streaming
2026-07-12 14:28:30.158 [Info] (Process) 2456.08.996.496 W srv  server_chat_: unsupported Responses tool type 'namespace' skipped
2026-07-12 14:28:30.158 [Info] (Process) 2456.08.996.520 W srv  server_chat_: unsupported Responses tool type 'web_search' skipped
2026-07-12 14:28:30.173 [Error] (Process) 2456.09.011.796 W srv    operator(): got exception: {"error":{"code":400,"message":"Unable to generate parser for this template. Automatic parser generation failed: \n------------\nWhile executing CallExpression at line 85, column 32 in source:\n...first %}↵            {{- raise_exception('System message must be at the beginnin...\n                                           ^\nError: Jinja Exception: System message must be at the beginning.","type":"invalid_request_error"}}
2026-07-12 14:28:30.386 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:28:30.386 [Info] (Server) POST /api/v1/responses - Streaming
2026-07-12 14:28:30.389 [Info] (Process) 2456.09.227.476 W srv  server_chat_: unsupported Responses tool type 'namespace' skipped
2026-07-12 14:28:30.389 [Info] (Process) 2456.09.227.508 W srv  server_chat_: unsupported Responses tool type 'web_search' skipped
2026-07-12 14:28:30.402 [Error] (Process) 2456.09.240.002 W srv    operator(): got exception: {"error":{"code":400,"message":"Unable to generate parser for this template. Automatic parser generation failed: \n------------\nWhile executing CallExpression at line 85, column 32 in source:\n...first %}↵            {{- raise_exception('System message must be at the beginnin...\n                                           ^\nError: Jinja Exception: System message must be at the beginning.","type":"invalid_request_error"}}
2026-07-12 14:28:30.802 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:28:30.802 [Info] (Server) POST /api/v1/responses - Streaming
2026-07-12 14:28:30.804 [Info] (Process) 2456.09.642.270 W srv  server_chat_: unsupported Responses tool type 'namespace' skipped
2026-07-12 14:28:30.804 [Info] (Process) 2456.09.642.293 W srv  server_chat_: unsupported Responses tool type 'web_search' skipped
2026-07-12 14:28:30.817 [Error] (Process) 2456.09.655.301 W srv    operator(): got exception: {"error":{"code":400,"message":"Unable to generate parser for this template. Automatic parser generation failed: \n------------\nWhile executing CallExpression at line 85, column 32 in source:\n...first %}↵            {{- raise_exception('System message must be at the beginnin...\n                                           ^\nError: Jinja Exception: System message must be at the beginning.","type":"invalid_request_error"}}
2026-07-12 14:28:31.558 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:28:31.558 [Info] (Server) POST /api/v1/responses - Streaming
2026-07-12 14:28:31.577 [Info] (Process) 2456.10.415.133 W srv  server_chat_: unsupported Responses tool type 'namespace' skipped
2026-07-12 14:28:31.577 [Info] (Process) 2456.10.415.160 W srv  server_chat_: unsupported Responses tool type 'web_search' skipped
2026-07-12 14:28:31.590 [Error] (Process) 2456.10.428.325 W srv    operator(): got exception: {"error":{"code":400,"message":"Unable to generate parser for this template. Automatic parser generation failed: \n------------\nWhile executing CallExpression at line 85, column 32 in source:\n...first %}↵            {{- raise_exception('System message must be at the beginnin...\n                                           ^\nError: Jinja Exception: System message must be at the beginning.","type":"invalid_request_error"}}
2026-07-12 14:28:33.146 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:28:33.147 [Info] (Server) POST /api/v1/responses - Streaming
2026-07-12 14:28:33.148 [Info] (Process) 2456.11.986.946 W srv  server_chat_: unsupported Responses tool type 'namespace' skipped
2026-07-12 14:28:33.149 [Info] (Process) 2456.11.986.970 W srv  server_chat_: unsupported Responses tool type 'web_search' skipped
2026-07-12 14:28:33.162 [Error] (Process) 2456.12.000.445 W srv    operator(): got exception: {"error":{"code":400,"message":"Unable to generate parser for this template. Automatic parser generation failed: \n------------\nWhile executing CallExpression at line 85, column 32 in source:\n...first %}↵            {{- raise_exception('System message must be at the beginnin...\n                                           ^\nError: Jinja Exception: System message must be at the beginning.","type":"invalid_request_error"}}
2026-07-12 14:28:36.219 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:28:36.219 [Info] (Server) POST /api/v1/responses - Streaming
2026-07-12 14:28:36.221 [Info] (Process) 2456.15.059.603 W srv  server_chat_: unsupported Responses tool type 'namespace' skipped
2026-07-12 14:28:36.221 [Info] (Process) 2456.15.059.625 W srv  server_chat_: unsupported Responses tool type 'web_search' skipped
2026-07-12 14:28:36.235 [Error] (Process) 2456.15.073.126 W srv    operator(): got exception: {"error":{"code":400,"message":"Unable to generate parser for this template. Automatic parser generation failed: \n------------\nWhile executing CallExpression at line 85, column 32 in source:\n...first %}↵            {{- raise_exception('System message must be at the beginnin...\n                                           ^\nError: Jinja Exception: System message must be at the beginning.","type":"invalid_request_error"}}
2026-07-12 14:29:10.179 [Info] (Server) Model already loaded: Ornith-1.0-35B-GGUF-Q5_K_M
2026-07-12 14:29:10.179 [Info] (Server) POST /api/v1/responses - Streaming
2026-07-12 14:29:10.198 [Info] (Process) 2456.49.036.839 I srv    operator(): Chat format: peg-native
2026-07-12 14:29:10.199 [Info] (Process) 2456.49.037.715 I slot get_availabl: id  1 | task -1 | selected slot by LRU, t_last = 131192602515
2026-07-12 14:29:10.199 [Info] (Process) 2456.49.037.719 I srv  get_availabl: updating prompt cache
2026-07-12 14:29:10.199 [Info] (Process) 2456.49.037.727 I srv          load:  - looking for better prompt, base f_keep = -1.000, sim = 0.000
2026-07-12 14:29:10.199 [Info] (Process) 2456.49.037.738 I srv        update:  - cache state: 5 prompts, 6140.126 MiB (limits: 8192.000 MiB, 262144 tokens, 277564 est)
2026-07-12 14:29:10.199 [Info] (Process) 2456.49.037.740 I srv        update:    - prompt 0000021A5A1BABD0:  195330 tokens, checkpoints: 21,  5200.656 MiB
2026-07-12 14:29:10.199 [Info] (Process) 2456.49.037.742 I srv        update:    - prompt 0000021BF3BC2F90:    1536 tokens, checkpoints:  1,   155.656 MiB
2026-07-12 14:29:10.200 [Info] (Process) 2456.49.037.743 I srv        update:    - prompt 0000021BF3BC2B10:   10870 tokens, checkpoints:  4,   526.578 MiB
2026-07-12 14:29:10.200 [Info] (Process) 2456.49.037.744 I srv        update:    - prompt 0000021BF3BC28D0:     155 tokens, checkpoints:  1,   128.657 MiB
2026-07-12 14:29:10.200 [Info] (Process) 2456.49.037.745 I srv        update:    - prompt 0000021BF3BC2BA0:     151 tokens, checkpoints:  1,   128.579 MiB
2026-07-12 14:29:10.200 [Info] (Process) 2456.49.037.747 I srv  get_availabl: prompt cache update took 0.03 ms
2026-07-12 14:29:10.200 [Info] (Process) 2456.49.038.028 I reasoning-budget: activated, budget=2147483647 tokens
2026-07-12 14:29:10.200 [Info] (Process) 2456.49.038.494 I slot launch_slot_: id  1 | task 95305 | processing task, is_child = 0
2026-07-12 14:29:10.200 [Info] (Process) 2456.49.038.498 I slot process_sing: id  0 | task -1 | saving idle slot to prompt cache
2026-07-12 14:29:10.200 [Info] (Process) 2456.49.038.500 I slot prompt_clear: id  0 | task -1 | clearing prompt with 0 tokens
2026-07-12 14:29:10.200 [Info] (Process) 2456.49.038.984 I slot process_sing: id  2 | task -1 | saving idle slot to prompt cache
2026-07-12 14:29:10.201 [Info] (Process) 2456.49.038.987 I slot prompt_clear: id  2 | task -1 | clearing prompt with 0 tokens
2026-07-12 14:29:10.201 [Info] (Process) 2456.49.039.100 I slot process_sing: id  3 | task -1 | saving idle slot to prompt cache
2026-07-12 14:29:10.201 [Info] (Process) 2456.49.039.236 W srv   prompt_save:  - saving prompt with length 429, total state size = 71.201 MiB (draft: 0.000 MiB)
2026-07-12 14:29:10.747 [Info] (Process) 2456.49.584.203 I srv        update:  - cache state: 6 prompts, 6274.139 MiB (limits: 8192.000 MiB, 262144 tokens, 272195 est)
2026-07-12 14:29:10.747 [Info] (Process) 2456.49.584.212 I srv        update:    - prompt 0000021A5A1BABD0:  195330 tokens, checkpoints: 21,  5200.656 MiB
2026-07-12 14:29:10.747 [Info] (Process) 2456.49.584.213 I srv        update:    - prompt 0000021BF3BC2F90:    1536 tokens, checkpoints:  1,   155.656 MiB
2026-07-12 14:29:10.747 [Info] (Process) 2456.49.584.214 I srv        update:    - prompt 0000021BF3BC2B10:   10870 tokens, checkpoints:  4,   526.578 MiB
2026-07-12 14:29:10.747 [Info] (Process) 2456.49.584.216 I srv        update:    - prompt 0000021BF3BC28D0:     155 tokens, checkpoints:  1,   128.657 MiB
2026-07-12 14:29:10.747 [Info] (Process) 2456.49.584.217 I srv        update:    - prompt 0000021BF3BC2BA0:     151 tokens, checkpoints:  1,   128.579 MiB
2026-07-12 14:29:10.747 [Info] (Process) 2456.49.584.218 I srv        update:    - prompt 0000021BF400C240:     429 tokens, checkpoints:  1,   134.014 MiB
2026-07-12 14:29:10.747 [Info] (Process) 2456.49.584.219 I slot prompt_clear: id  3 | task -1 | clearing prompt with 429 tokens
2026-07-12 14:29:10.747 [Info] (Process) 2456.49.584.506 W slot update_slots: id  1 | task 95305 | erased invalidated context checkpoint (pos_min = 8002, pos_max = 8002, n_tokens = 8003, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:29:10.749 [Info] (Process) 2456.49.587.335 W slot update_slots: id  1 | task 95305 | erased invalidated context checkpoint (pos_min = 9493, pos_max = 9493, n_tokens = 9494, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:29:10.751 [Info] (Process) 2456.49.589.469 W slot update_slots: id  1 | task 95305 | erased invalidated context checkpoint (pos_min = 10005, pos_max = 10005, n_tokens = 10006, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:29:10.753 [Info] (Process) 2456.49.591.457 W slot update_slots: id  1 | task 95305 | erased invalidated context checkpoint (pos_min = 10471, pos_max = 10471, n_tokens = 10472, n_swa = 0, pos_next = 0, size = 62.813 MiB)
2026-07-12 14:29:11.726 [Info] (Process) 2456.50.564.703 I slot create_check: id  1 | task 95305 | created context checkpoint 1 of 32 (pos_min = 421, pos_max = 421, n_tokens = 422, size = 62.813 MiB)
2026-07-12 14:29:12.600 [Info] (Process) 2456.51.438.703 I reasoning-budget: deactivated (natural end)
2026-07-12 14:29:12.733 [Info] (Process) 2456.51.571.803 I slot print_timing: id  1 | task 95305 | prompt eval time =    1082.69 ms /   439 tokens (    2.47 ms per token,   405.47 tokens per second)
2026-07-12 14:29:12.734 [Info] (Process) 2456.51.571.818 I slot print_timing: id  1 | task 95305 |        eval time =     904.59 ms /    62 tokens (   14.59 ms per token,    68.54 tokens per second)
2026-07-12 14:29:12.734 [Info] (Process) 2456.51.571.825 I slot print_timing: id  1 | task 95305 |       total time =    1987.28 ms /   501 tokens
2026-07-12 14:29:12.734 [Info] (Process) 2456.51.571.838 I slot print_timing: id  1 | task 95305 |    graphs reused =      92832
2026-07-12 14:29:12.734 [Info] (Process) 2456.51.572.064 I slot      release: id  1 | task 95305 | stop processing: n_tokens = 500, truncated = 0
2026-07-12 14:29:12.734 [Warn] (StreamingProxy) WARNING: Backend did not send [DONE] marker, adding it
2026-07-12 14:29:12.734 [Info] (Server) Streaming completed - 200 OK

Additional Context

  • This may not be Ornith-specific; other models with strict chat templates (e.g. some Qwen3.x
    variants) reportedly show similar agent-loop failures with tool-calling clients, while working
    fine in simpler Chat Completions based clients (e.g. opencode).
  • Happy to provide the full Codex CLI debug log (RUST_LOG=debug) and the exact request payload
    if helpful.

Metadata

Metadata

Assignees

No one assigned

    Labels

    area::apiHTTP REST API surface and route handlersbugSomething isn't workingengine::llamacppllama.cpp backend (LlamaCppServer); GPU/CPU LLM inference (Vulkan, ROCm, Metal)

    Type

    No type

    Fields

    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions