engine: time-split chat generation (build vs prefill) to locate pre-gen latency

Direct Kilocode requests showed ~40s before the first token even though prefill
was a cache hit (14551 prefix-match, 1 token to eval) — so the delay is before
decode. Added timing in vulkan generate_chat_stream: logs "[timing] chat build
(template+tokenize)" around create_chat_completion (eager chat-template render +
tokenize) and "[timing] chat lock+prefill+first-token" around the first streamed
token. One request now reveals whether the 40s is the gemma chat-template Jinja
render (huge template + many tool schemas, done in Python) or lock/prefill.
Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011DDv7BchtZQWsnPG6Jm49m

codai/admin/templates/chat.html

@@ -3997,6 +3997,7 @@ function addMsg(role, text, imgSrc) {
     </div>`;
   wrap.appendChild(d);
   wrap.scrollTop = wrap.scrollHeight;
+  return d;
 }
 
 function attachImg(input) {

codai/backends/vulkan.py

@@ -2172,6 +2172,9 @@ class VulkanBackend(ModelBackend):
         # Build the completion up front so a template error (e.g. Gemma's "System
         # role not supported") is caught here and retried with the system message
         # folded into the first user turn — before any chunk is streamed.
+        # [timing] split build (chat-template render + tokenize, done eagerly by
+        # create_chat_completion) from lock+prefill+first-token, to locate latency.
+        _t_build0 = time.monotonic()
         try:
             _completion = self.model.create_chat_completion(**kwargs)
         except Exception as e:
@@ -2179,11 +2182,19 @@ class VulkanBackend(ModelBackend):
                 raise
             kwargs['messages'] = self._fold_system_into_user(messages)
             _completion = self.model.create_chat_completion(**kwargs)
+        print(f"[timing] chat build (template+tokenize): "
+              f"{time.monotonic() - _t_build0:.2f}s", flush=True)
 
         prompt_tokens = 0
         completion_tokens = 0
+        _t_first = time.monotonic()
+        _first_token = True
         try:
             async for chunk in _aiter_blocking(_completion, lock=self._gen_lock):
+                if _first_token:
+                    print(f"[timing] chat lock+prefill+first-token: "
+                          f"{time.monotonic() - _t_first:.2f}s", flush=True)
+                    _first_token = False
                 delta = chunk['choices'][0].get('delta', {})
                 text = delta.get('content') or ''
                 if text: