From c9fbfd9f71fc32f2e9171d467e70adfc3949ebb1 Mon Sep 17 00:00:00 2001 From: Andrew B <1974197+andrewb-nz@users.noreply.github.com> Date: Sat, 15 Aug 2026 16:12:22 +1200 Subject: [PATCH] fix(chat): make the assistant response timeout configurable (#2910) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * fix(chat): make the assistant response timeout configurable (#2893) Self-hosted users running a local model report the chat failing with "assistant not available" after 90 seconds even though the model generates a reply and tokens are billed. Three timeouts are involved and only one was configurable: - OPENAI_REQUEST_TIMEOUT (60s) — already settable, not the blocker. - The browser watchdog in chat_controller.js (90s) — hardcoded, and this is what actually fires. - Chat::UNDELIVERED_RESPONSE_TIMEOUT (60s) — a constant, so raising the client value alone would not have helped. The watchdog cannot be avoided by streaming here: custom OpenAI-compatible providers route through generic_chat_response, which forces synchronous calls, so nothing renders until the whole generation finishes. Time-to-last-token has to beat the deadline. Adds AI_RESPONSE_TIMEOUT (ENV > Setting > 90s default, floored at 30s), exposed on the Self-Hosting settings page and passed to the Stimulus controller at all three mount points — show, index and the sidebar in the application layout, each of which declares data-controller="chat" independently. The server floor is derived from the same value but kept 10s below it. report_timeout answers 200 whether or not it acted and the client only retries on a non-ok response, so a floor at or above the client value would let clock skew strand a pending bubble permanently. Also guards AssistantMessage#append_text!. The watchdog runs in the web process while the job holds its own copy of the message, so a job finishing after the bubble was destroyed or demoted would silently resurrect it alongside the error the user was already shown. * fix(chat): let the watchdog retry when report_timeout declines `report_timeout` answered 200 whether or not `handle_undelivered_response!` acted. The Stimulus watchdog only stops retrying a URL once it sees a 2xx, so a declined report was treated as final. That stranded the bubble whenever the client's clock ran more than SERVER_TIMEOUT_GRACE ahead of the server's: the watchdog posts at its own timeout, the server sees a message younger than its floor and no-ops, and nothing ever retries. The bubble spins forever with no error and no Retry. Answering 409 instead lets the next 5s tick try again, so any amount of skew costs retries rather than a stuck chat. The grace window stays as an optimisation to keep those retries rare, not as the correctness mechanism. * docs(chat): correct the AI_RESPONSE_TIMEOUT ordering guidance The docs, locale string and examples all said to keep OPENAI_REQUEST_TIMEOUT at or above AI_RESPONSE_TIMEOUT. That is backwards. The two limits span different things. OPENAI_REQUEST_TIMEOUT bounds each HTTP call to the model on its own; AI_RESPONSE_TIMEOUT covers the whole turn and its clock starts when the message is queued, so it also absorbs Sidekiq queue time and, for a tool-using turn, two model calls plus the tool run between them. Keeping the chat timeout the larger of the two means a slow model surfaces the specific HTTP timeout error rather than a generic "no response", and the job stops instead of running on after the chat has given up. The shipped 60/90 defaults already had this ordering; only the guidance was wrong. compose.example.ai.yml gets 300/660 so the Ollama example can actually complete a tool-using turn. * fix(chat): claim the pending bubble atomically before appending append_text! read the row's status and then saved, leaving a window in which the watchdog could demote the row to `failed` between the two. The late content would then land on a bubble the user had already been told failed, flipping it back to `complete`. Replaces the read with a conditional UPDATE that only succeeds while the row is still pending, so the check and the state change cannot be separated. Uses a conditional UPDATE rather than with_lock because append_text! is called once per chunk on the streaming path; a row lock and transaction per chunk would be far more expensive. The claim only runs on the first append, since later ones are no longer pending. * test(chat): isolate AI_RESPONSE_TIMEOUT from the environment Chat.response_timeout reads ENV ahead of Setting, so stubbing only the Setting left the assertions at the mercy of the environment they run in. With AI_RESPONSE_TIMEOUT=45 exported, five of these tests failed — the default, floor and grace assertions were all silently measuring the env value. Adds a with_setting_timeout helper that stubs the Setting and clears the variable together, and switches the controller tests to stub Chat.undelivered_response_timeout directly, since what they care about is the resolved floor rather than how it was configured. Both files now pass with or without AI_RESPONSE_TIMEOUT set. * docs(chat): size AI_RESPONSE_TIMEOUT for chained tool calls The guidance assumed a tool-using turn costs two model calls. #2767 landed after this branch was opened and made tool calls iterative: `Assistant::Responder` now loops until `iteration > max_tool_call_iterations`, so a turn runs to 1 + ASSISTANT_MAX_TOOL_CALL_ITERATIONS calls — six by default — with tool execution in between. At the default 60s per-call timeout that is up to 360s of model time against a 90s watchdog. Streaming does not rescue this either. `emit(:output_text)` only fires for a response that carries text, and tool-call-only rounds carry none, so the bubble stays on "Thinking…" through every round regardless of provider. Documents ASSISTANT_MAX_TOOL_CALL_ITERATIONS as the cheaper lever: dropping it to 2 halves the worst case instead of demanding a half-hour timeout, at the cost of failing long tool chains earlier with a clear limit error. compose.example.ai.yml now shows that combination rather than a timeout sized for six calls it never had. * docs(chat): state the whole-turn timeout as a sum, not a maximum The guidance said to keep AI_RESPONSE_TIMEOUT "above" or "the larger of" OPENAI_REQUEST_TIMEOUT. That understates it: the watchdog covers the entire turn, so the bound is (1 + ASSISTANT_MAX_TOOL_CALL_ITERATIONS) * OPENAI_REQUEST_TIMEOUT + tool execution + queue wait Merely exceeding the per-call limit can still leave the chat reporting failure while the worker keeps going. One phrasing was outright wrong: "keep AI_RESPONSE_TIMEOUT the largest of the three" compared a duration against ASSISTANT_MAX_TOOL_CALL_ITERATIONS, which is a count, not seconds. Resizes the examples against the formula — compose.example.ai.yml 1000 -> 1200 and the Ollama doc example 600 -> 720, both now showing the arithmetic — and states plainly that the 90s default is sized for typical cloud latency rather than the worst-case bound, with the formula being what matters once per-call latency approaches the timeout. * docs(chat): list the AI settings fields and tag the formula fence The Settings UI walkthrough listed three of the eight fields on the AI Provider form. JSON Mode, the three Token Budget fields and the new Chat Response Timeout were all missing, so the timeout was only discoverable from the troubleshooting section. Rewrites the list to follow the form's own grouping and uses the labels the form actually renders. Also tags the whole-turn formula fence as `text` (markdownlint MD040). * fix(compose): forward ASSISTANT_MAX_TOOL_CALL_ITERATIONS in standard compose This file enumerates container environment explicitly — there is no env_file — so a variable absent from the x-rails-env anchor never reaches web or worker. The tool-call cap was only named in a comment here, while the docs added in 3360dbf5 tell operators to lower it to keep a turn inside AI_RESPONSE_TIMEOUT. Following that advice on this compose file silently changed nothing: the app kept the default of 5 while the timeout was sized for 3 calls, which lands back on the "no response" error this branch exists to fix. Left with an empty default so the app's own default governs, matching OPENAI_MODEL and LLM_CONTEXT_WINDOW above. compose.example.ai.yml already forwarded it. --- .env.example | 23 +++++++ .env.local.example | 2 + app/controllers/messages_controller.rb | 12 +++- .../settings/hostings_controller.rb | 11 ++-- app/javascript/controllers/chat_controller.js | 4 +- app/models/assistant_message.rb | 31 +++++++++- app/models/chat.rb | 47 +++++++++++++-- app/models/setting.rb | 7 +++ app/views/chats/index.html.erb | 2 +- app/views/chats/show.html.erb | 2 +- app/views/layouts/application.html.erb | 2 +- .../hostings/_openai_settings.html.erb | 14 +++++ compose.example.ai.yml | 18 ++++++ compose.example.yml | 9 +++ config/locales/views/settings/hostings/en.yml | 4 ++ docs/hosting/ai.md | 60 +++++++++++++++++-- test/controllers/messages_controller_test.rb | 33 ++++++++++ test/models/assistant_message_test.rb | 43 +++++++++++++ test/models/chat_test.rb | 58 ++++++++++++++++++ 19 files changed, 361 insertions(+), 21 deletions(-) diff --git a/.env.example b/.env.example index b3cd1cb2c..41f98ffc5 100644 --- a/.env.example +++ b/.env.example @@ -35,6 +35,29 @@ OPENAI_URI_BASE= # LLM_SYSTEM_PROMPT_RESERVE=256 # LLM_MAX_ITEMS_PER_CALL=25 +# Optional: how long the chat waits for an assistant response before showing a +# "no response" error. Raise for slow local models — OpenAI-compatible providers +# are not streamed, so nothing renders until the whole reply is generated. +# +# This clock starts when the message is queued and covers the whole turn, so it +# is a SUM, not a maximum. The worst case is: +# +# (1 + ASSISTANT_MAX_TOOL_CALL_ITERATIONS) * OPENAI_REQUEST_TIMEOUT +# + tool execution + queue wait +# +# At the defaults that bound is 6 * 60 = 360s plus overhead. The 90s default is +# sized for typical latency rather than that bound — cloud models answer in +# seconds, so a turn rarely approaches it. Size against the formula once your +# per-call latency is genuinely near OPENAI_REQUEST_TIMEOUT, which is the case +# for local models. Set too low, you get a generic "no response" instead of the +# specific timeout error, and the job keeps burning tokens after the chat gave up. +# Minimum 30; also settable on the Self-Hosting settings page. +# AI_RESPONSE_TIMEOUT=90 +# +# Lowering the tool-call cap is often the better lever on slow hardware: it cuts +# the first term of that sum instead of requiring a very long timeout. +# ASSISTANT_MAX_TOOL_CALL_ITERATIONS=5 + # Optional: OpenAI-compatible capability flags # OPENAI_REQUEST_TIMEOUT=60 # HTTP timeout in seconds; raise for slow local models # OPENAI_SUPPORTS_PDF_PROCESSING=true # Set to false for endpoints without vision support diff --git a/.env.local.example b/.env.local.example index 383fb71ac..8e74d6672 100644 --- a/.env.local.example +++ b/.env.local.example @@ -46,6 +46,8 @@ OPENAI_MODEL = # OpenAI-compatible capability flags (custom/self-hosted providers) # OPENAI_REQUEST_TIMEOUT = 60 # HTTP timeout in seconds; raise for slow local models +# AI_RESPONSE_TIMEOUT = 90 # Whole-turn budget: (1 + iterations) * OPENAI_REQUEST_TIMEOUT + tool time + queue wait +# ASSISTANT_MAX_TOOL_CALL_ITERATIONS = 5 # Chained tool calls per turn; a turn costs up to (1 + this) model calls # OPENAI_SUPPORTS_PDF_PROCESSING = true # Set to false for endpoints without vision support # OPENAI_SUPPORTS_RESPONSES_ENDPOINT = # true to force Responses API on custom providers # LLM_JSON_MODE = # auto | strict | json_object | none diff --git a/app/controllers/messages_controller.rb b/app/controllers/messages_controller.rb index 252d6645c..0e414a5cb 100644 --- a/app/controllers/messages_controller.rb +++ b/app/controllers/messages_controller.rb @@ -24,8 +24,16 @@ class MessagesController < ApplicationController # current user's chat. def report_timeout message = @chat.messages.find(params[:id]) - @chat.handle_undelivered_response!(message) - head :ok + + if @chat.handle_undelivered_response!(message) + head :ok + else + # Declined — the message has not waited past the server's own floor yet, + # which usually means the client's clock runs ahead of ours and it reported + # early. This must not be a 2xx: the watchdog only stops retrying a URL once + # it sees one, so answering OK here would strand the bubble spinning forever. + head :conflict + end rescue ActiveRecord::RecordNotFound head :not_found end diff --git a/app/controllers/settings/hostings_controller.rb b/app/controllers/settings/hostings_controller.rb index f988aca36..a32f9a17e 100644 --- a/app/controllers/settings/hostings_controller.rb +++ b/app/controllers/settings/hostings_controller.rb @@ -1,13 +1,14 @@ class Settings::HostingsController < ApplicationController layout "settings" - # Minimum accepted value for each configurable LLM budget field. Mirrors the + # Minimum accepted value for each configurable numeric LLM field. Mirrors the # `min:` attribute on the form inputs in `_openai_settings.html.erb` so the # controller rejects what the browser-side validator would reject. - LLM_BUDGET_MINIMUMS = { + LLM_NUMERIC_MINIMUMS = { llm_context_window: 256, llm_max_response_tokens: 64, - llm_max_items_per_call: 1 + llm_max_items_per_call: 1, + ai_response_timeout: Chat::MIN_RESPONSE_TIMEOUT.to_i }.freeze guard_feature unless: -> { self_hosted? } @@ -211,7 +212,7 @@ class Settings::HostingsController < ApplicationController end end - LLM_BUDGET_MINIMUMS.each do |key, minimum| + LLM_NUMERIC_MINIMUMS.each do |key, minimum| next unless hosting_params.key?(key) raw = hosting_params[key].to_s.strip if raw.blank? @@ -271,7 +272,7 @@ class Settings::HostingsController < ApplicationController private def hosting_params return ActionController::Parameters.new unless params.key?(:setting) - params.require(:setting).permit(:onboarding_state, :require_email_confirmation, :invite_only_default_family_id, :brand_fetch_client_id, :brand_fetch_high_res_logos, :twelve_data_api_key, :tiingo_api_key, :eodhd_api_key, :alpha_vantage_api_key, :tinkoff_invest_api_key, :rentcast_api_key, :realie_api_key, :openai_access_token, :openai_uri_base, :openai_model, :openai_json_mode, :anthropic_access_token, :anthropic_base_url, :anthropic_model, :llm_provider, :llm_context_window, :llm_max_response_tokens, :llm_max_items_per_call, :exchange_rate_provider, :securities_provider, :syncs_include_pending, :auto_sync_enabled, :auto_sync_time, :external_assistant_url, :external_assistant_token, :external_assistant_agent_id, securities_providers: []) + params.require(:setting).permit(:onboarding_state, :require_email_confirmation, :invite_only_default_family_id, :brand_fetch_client_id, :brand_fetch_high_res_logos, :twelve_data_api_key, :tiingo_api_key, :eodhd_api_key, :alpha_vantage_api_key, :tinkoff_invest_api_key, :rentcast_api_key, :realie_api_key, :openai_access_token, :openai_uri_base, :openai_model, :openai_json_mode, :anthropic_access_token, :anthropic_base_url, :anthropic_model, :llm_provider, :llm_context_window, :llm_max_response_tokens, :llm_max_items_per_call, :ai_response_timeout, :exchange_rate_provider, :securities_provider, :syncs_include_pending, :auto_sync_enabled, :auto_sync_time, :external_assistant_url, :external_assistant_token, :external_assistant_agent_id, securities_providers: []) end def update_assistant_type diff --git a/app/javascript/controllers/chat_controller.js b/app/javascript/controllers/chat_controller.js index dfb750238..ca61305af 100644 --- a/app/javascript/controllers/chat_controller.js +++ b/app/javascript/controllers/chat_controller.js @@ -5,7 +5,9 @@ export default class extends Controller { static values = { // How long a pending "Thinking…" bubble may wait before we assume the // background worker never delivered a response. Generous so slow models or - // tool calls don't trip it. + // tool calls don't trip it. Set from the server (`Chat.response_timeout_ms`) + // so self-hosters running local models can raise it; this default only + // applies if the value is missing from the markup. responseTimeout: { type: Number, default: 90000 }, // How often to re-check pending bubbles. pollInterval: { type: Number, default: 5000 }, diff --git a/app/models/assistant_message.rb b/app/models/assistant_message.rb index a40304d2c..de172ede3 100644 --- a/app/models/assistant_message.rb +++ b/app/models/assistant_message.rb @@ -5,9 +5,38 @@ class AssistantMessage < Message "assistant" end + # Appends streamed (or, for non-streaming providers, whole) response text. + # + # Returns false without saving if the bubble is no longer awaiting a response. + # The watchdog runs in the *web* process and may have destroyed or failed this + # message while the job was still waiting on a slow model; the job holds its + # own in-memory copy and would otherwise silently resurrect a bubble the user + # has already been told failed. Re-checked once, on the first append — later + # appends stay in-memory cheap. def append_text!(text) + return false if destroyed? || frozen? + return false if pending? && !claim! + self.content += text - self.status = :complete if pending? save! end + + private + + # Flips pending -> complete with a conditional UPDATE, so the check and the + # state change cannot be separated by the watchdog's write. Returns false if + # the row is already gone or `failed`, meaning this turn lost the race and + # must not write. A plain read-then-save would leave a window in which the + # watchdog demotes the row between the two, and the late content would land + # on a bubble the user was already told had failed. + # + # Only reached on the first append (later ones are no longer `pending`), so + # a streaming response pays for this once, not once per chunk. + def claim! + return true unless persisted? + + claimed = self.class.where(id: id, status: :pending).update_all(status: "complete").positive? + self.status = :complete if claimed + claimed + end end diff --git a/app/models/chat.rb b/app/models/chat.rb index 6b76f4c95..4a4a1379f 100644 --- a/app/models/chat.rb +++ b/app/models/chat.rb @@ -132,10 +132,47 @@ class Chat < ApplicationRecord assistant.respond_to(message, assistant_message: assistant_message) end - # Minimum age before the server will treat a still-pending response as - # undelivered. The browser watchdog waits longer (default 90s) before it even - # asks, but the client clock is untrusted, so the server enforces its own floor. - UNDELIVERED_RESPONSE_TIMEOUT = 60.seconds + # How long a pending "Thinking…" bubble may wait before the browser watchdog + # reports it as undelivered. Configurable because a local model on slow + # hardware can legitimately take minutes to produce its first token, and the + # custom OpenAI-compatible provider path is non-streaming — so nothing renders + # until the whole generation finishes. + DEFAULT_RESPONSE_TIMEOUT = 90.seconds + + # Floor on the configured value. Below this the watchdog would fire during + # normal cloud-model latency and kill healthy responses. + MIN_RESPONSE_TIMEOUT = 30.seconds + + # How far *below* the client timeout the server's own floor sits, so a client + # whose clock runs modestly ahead is not refused on its first report. This is + # only an optimisation to keep retries rare: correctness for arbitrary skew + # comes from `MessagesController#report_timeout` answering non-OK when it + # declines, which leaves the watchdog free to try again on its next tick. + SERVER_TIMEOUT_GRACE = 10.seconds + + class << self + # Client-side watchdog timeout. Precedence: ENV > Setting > default, with + # non-positive values treated as unset (a 0-second timeout is never meant). + def response_timeout + configured = ENV["AI_RESPONSE_TIMEOUT"].to_s.strip.to_i + configured = Setting.ai_response_timeout.to_i unless configured.positive? + return DEFAULT_RESPONSE_TIMEOUT unless configured.positive? + + [ configured.seconds, MIN_RESPONSE_TIMEOUT ].max + end + + # Same value in milliseconds, for the Stimulus `responseTimeout` value. + def response_timeout_ms + response_timeout.to_i * 1000 + end + + # Minimum age before the server will treat a still-pending response as + # undelivered. The client clock is untrusted, so the server enforces its own + # floor — kept just under the client's so a genuine report is never refused. + def undelivered_response_timeout + response_timeout - SERVER_TIMEOUT_GRACE + end + end # Handles the case where an assistant response was never delivered — the # background worker never ran `AssistantResponseJob` (or it died before it @@ -152,7 +189,7 @@ class Chat < ApplicationRecord resolved = assistant_message.with_lock do next false unless assistant_message.pending? - next false if assistant_message.created_at > UNDELIVERED_RESPONSE_TIMEOUT.ago + next false if assistant_message.created_at > self.class.undelivered_response_timeout.ago if assistant_message.content.blank? assistant_message.destroy! diff --git a/app/models/setting.rb b/app/models/setting.rb index dde71b960..deed1d5a6 100644 --- a/app/models/setting.rb +++ b/app/models/setting.rb @@ -22,6 +22,13 @@ class Setting < RailsSettings::Base field :llm_context_window, type: :integer, default: ENV["LLM_CONTEXT_WINDOW"]&.to_i field :llm_max_response_tokens, type: :integer, default: ENV["LLM_MAX_RESPONSE_TOKENS"]&.to_i field :llm_max_items_per_call, type: :integer, default: ENV["LLM_MAX_ITEMS_PER_CALL"]&.to_i + + # How long the chat UI waits for an assistant response before treating it as + # undelivered. Self-hosted users running local models on slow hardware need + # this well above the 90s default — a local model that takes minutes to + # generate would otherwise always trip the watchdog. Read via + # `Chat.response_timeout`, which applies ENV > Setting > default precedence. + field :ai_response_timeout, type: :integer, default: ENV["AI_RESPONSE_TIMEOUT"]&.to_i field :external_assistant_url, type: :string field :external_assistant_token, type: :string field :external_assistant_agent_id, type: :string diff --git a/app/views/chats/index.html.erb b/app/views/chats/index.html.erb index 8afa67c57..139e616cc 100644 --- a/app/views/chats/index.html.erb +++ b/app/views/chats/index.html.erb @@ -1,4 +1,4 @@ -
+
<%= turbo_frame_tag chat_frame do %>
<% if show_demo_warning? %> diff --git a/app/views/chats/show.html.erb b/app/views/chats/show.html.erb index 743f7169b..3a41fce4b 100644 --- a/app/views/chats/show.html.erb +++ b/app/views/chats/show.html.erb @@ -1,4 +1,4 @@ -
+
<%= turbo_frame_tag chat_frame do %> <%= turbo_stream_from @chat %> diff --git a/app/views/layouts/application.html.erb b/app/views/layouts/application.html.erb index 4a9dd4ef1..e6e279a6b 100644 --- a/app/views/layouts/application.html.erb +++ b/app/views/layouts/application.html.erb @@ -211,7 +211,7 @@ end %> inert: !Current.user.show_ai_sidebar?, data: { app_layout_target: "rightSidebar", sidebar_resize_target: "rightSidebar" } do %> <%= render "layouts/shared/sidebar_resize_handle", side: "right" %> - <%= tag.div id: "chat-container", class: "relative h-full px-4 overflow-y-auto", data: { controller: "chat hotkey", turbo_permanent: true } do %> + <%= tag.div id: "chat-container", class: "relative h-full px-4 overflow-y-auto", data: { controller: "chat hotkey", chat_response_timeout_value: Chat.response_timeout_ms, turbo_permanent: true } do %>
<%= turbo_frame_tag chat_frame, src: chat_view_path(@chat), loading: "lazy", class: "h-full" do %>
diff --git a/app/views/settings/hostings/_openai_settings.html.erb b/app/views/settings/hostings/_openai_settings.html.erb index a1920e38b..7fbdc78dc 100644 --- a/app/views/settings/hostings/_openai_settings.html.erb +++ b/app/views/settings/hostings/_openai_settings.html.erb @@ -95,5 +95,19 @@ data: { "auto-submit-form-target": "auto" } %>

<%= t(".max_items_per_call_help") %>

+ +
+

<%= t(".ai_response_timeout_heading") %>

+

<%= t(".ai_response_timeout_description") %>

+ + <%= form.number_field :ai_response_timeout, + label: t(".ai_response_timeout_label"), + placeholder: Chat::DEFAULT_RESPONSE_TIMEOUT.to_i.to_s, + value: Setting.ai_response_timeout, + min: Chat::MIN_RESPONSE_TIMEOUT.to_i, + disabled: ENV["AI_RESPONSE_TIMEOUT"].present?, + data: { "auto-submit-form-target": "auto" } %> +

<%= t(".ai_response_timeout_help") %>

+
<% end %>
diff --git a/compose.example.ai.yml b/compose.example.ai.yml index c09fe1b39..5f35ce539 100644 --- a/compose.example.ai.yml +++ b/compose.example.ai.yml @@ -93,6 +93,24 @@ x-rails-env: &rails_env OPENAI_ACCESS_TOKEN: token-can-be-any-value-for-ollama OPENAI_MODEL: llama3.1:8b # Note: Use tool-enabled model OPENAI_URI_BASE: http://ollama:11434/v1 + # Local models are not streamed, so the chat shows nothing until the whole reply + # is generated, and tool-call rounds display nothing at all. OPENAI_REQUEST_TIMEOUT + # bounds each call to the model on its own; AI_RESPONSE_TIMEOUT covers the whole + # turn, so it has to be sized as a sum rather than simply set higher: + # + # (1 + ASSISTANT_MAX_TOOL_CALL_ITERATIONS) * OPENAI_REQUEST_TIMEOUT + # + tool execution + queue wait + # + # Here that is (1 + 2) * 300 = 900s of model time, plus 300s of headroom for tool + # execution and queue wait, giving 1200. + # + # The cap is lowered to 2 rather than left at 5 so the bound is three model calls + # instead of six — at 300s each, leaving it at 5 would need a timeout beyond half + # an hour. The trade is that longer tool chains fail earlier, with an explicit + # tool-call limit error rather than a timeout. + OPENAI_REQUEST_TIMEOUT: ${OPENAI_REQUEST_TIMEOUT:-300} + ASSISTANT_MAX_TOOL_CALL_ITERATIONS: ${ASSISTANT_MAX_TOOL_CALL_ITERATIONS:-2} + AI_RESPONSE_TIMEOUT: ${AI_RESPONSE_TIMEOUT:-1200} # Vector store — pgvector keeps all data local (requires pgvector/pgvector Docker image for db) VECTOR_STORE_PROVIDER: pgvector EMBEDDING_MODEL: nomic-embed-text diff --git a/compose.example.yml b/compose.example.yml index b93219624..e2ebabac5 100644 --- a/compose.example.yml +++ b/compose.example.yml @@ -62,6 +62,15 @@ x-rails-env: &rails_env OPENAI_URI_BASE: ${OPENAI_URI_BASE:-} LLM_CONTEXT_WINDOW: ${LLM_CONTEXT_WINDOW:-} OPENAI_REQUEST_TIMEOUT: ${OPENAI_REQUEST_TIMEOUT:-60} + # Seconds the chat waits for an assistant response before showing a "no response" + # error. This covers the whole turn, so its worst case is a sum: + # (1 + ASSISTANT_MAX_TOOL_CALL_ITERATIONS) * OPENAI_REQUEST_TIMEOUT + # + tool execution + queue wait + # 90 is sized for typical cloud latency, not that bound — raise it (or lower the + # tool-call cap) once per-call latency approaches OPENAI_REQUEST_TIMEOUT, which + # is what happens with a local model. See compose.example.ai.yml. + AI_RESPONSE_TIMEOUT: ${AI_RESPONSE_TIMEOUT:-90} + ASSISTANT_MAX_TOOL_CALL_ITERATIONS: ${ASSISTANT_MAX_TOOL_CALL_ITERATIONS:-} services: web: diff --git a/config/locales/views/settings/hostings/en.yml b/config/locales/views/settings/hostings/en.yml index 9c6539ad9..1b2068598 100644 --- a/config/locales/views/settings/hostings/en.yml +++ b/config/locales/views/settings/hostings/en.yml @@ -141,6 +141,10 @@ en: max_response_tokens_help: "Tokens reserved for the model's reply. Default: 512. Lower to free up room for longer history." max_items_per_call_label: Max Items Per Batch (Optional) max_items_per_call_help: "Upper bound for auto-categorize / merchant detection batches. Default: 25. Larger batches are auto-sliced to fit the context window." + ai_response_timeout_heading: Chat Response Timeout + ai_response_timeout_description: How long the chat waits for the assistant before showing a "no response" error. Raise this if you run a local model on slow hardware — responses from OpenAI-compatible providers are not streamed, and tool-call rounds display nothing, so the chat can sit on "Thinking…" for the whole turn. + ai_response_timeout_label: Response Timeout in Seconds (Optional) + ai_response_timeout_help: "Default: 90. This covers the whole turn, so size it as a sum: (1 + ASSISTANT_MAX_TOOL_CALL_ITERATIONS) × OPENAI_REQUEST_TIMEOUT, plus tool execution and queue time. Lowering ASSISTANT_MAX_TOOL_CALL_ITERATIONS reduces how large this needs to be, and is often the better lever on slow hardware." title: OpenAI yahoo_finance_settings: title: Yahoo Finance diff --git a/docs/hosting/ai.md b/docs/hosting/ai.md index 8225510c4..9b844bd53 100644 --- a/docs/hosting/ai.md +++ b/docs/hosting/ai.md @@ -223,6 +223,19 @@ LLM_CONTEXT_WINDOW=8192 # Slow local models often need a longer HTTP timeout once the prompt budget issue is fixed. OPENAI_REQUEST_TIMEOUT=180 +# Chained tool calls per turn. Each iteration is another call to the model, so +# lowering this is the cheapest way to keep a turn inside the timeout below. +ASSISTANT_MAX_TOOL_CALL_ITERATIONS=2 + +# Whole-turn budget before the chat gives up and shows a "no response" error. +# Responses from custom providers are not streamed and tool-call rounds display +# nothing, so this covers every call the turn makes, not just the first token. +# Size it as a sum: +# (1 + ASSISTANT_MAX_TOOL_CALL_ITERATIONS) * OPENAI_REQUEST_TIMEOUT +# + tool execution + queue wait +# Here (1 + 2) * 180 = 540s of model time, plus headroom, so 720. +AI_RESPONSE_TIMEOUT=720 + # Optional: enable debug logging in the AI chat AI_DEBUG_MODE=true ``` @@ -233,6 +246,7 @@ AI_DEBUG_MODE=true - If you don't set a model, chats will fail with a validation error - Auto-categorization uses a conservative default `LLM_CONTEXT_WINDOW=2048`, so large category lists or schemas can exhaust the prompt budget before any transactions are sent - If requests start timing out after raising `LLM_CONTEXT_WINDOW`, increase `OPENAI_REQUEST_TIMEOUT` too; these are separate limits +- Responses from custom providers are **not streamed** — the chat shows "Thinking…" until the entire reply is generated, and a turn that chains tool calls stays there through every round, since tool-call responses have no text to display. If the chat errors while your model is clearly still working, raise `AI_RESPONSE_TIMEOUT` or lower `ASSISTANT_MAX_TOOL_CALL_ITERATIONS`; `OPENAI_REQUEST_TIMEOUT` alone will not help. `AI_RESPONSE_TIMEOUT` has to cover the whole turn, so size it as `(1 + ASSISTANT_MAX_TOOL_CALL_ITERATIONS) × OPENAI_REQUEST_TIMEOUT` plus tool execution and queue wait — a sum, not simply a larger number than the per-call limit ### Docker Compose Example @@ -318,10 +332,13 @@ For self-hosted deployments, you can configure AI settings through the web inter 1. Go to **Settings** → **Self-Hosting** 2. Scroll to the **AI Provider** section -3. Configure: - - **OpenAI Access Token** - Your API key - - **OpenAI URI Base** - Custom endpoint (leave blank for OpenAI) - - **OpenAI Model** - Model name (required for custom endpoints) +3. Configure the provider: + - **Access Token** - Your API key + - **API Base URL** - Custom endpoint (leave blank for OpenAI) + - **Model** - Model name (required for custom endpoints) + - **JSON Mode** - Structured-output format; `Auto` suits most models +4. Optionally tune **Token Budget** — Context Window, Max Response Tokens and Max Items Per Batch. The defaults are conservative so small-context local models work out of the box; raise them for cloud or large-context models. +5. Optionally set **Chat Response Timeout** — how long the chat waits for a whole turn before showing a "no response" error (default 90s). Raise it for slow local models; see [Chat Errors While the Model Is Still Generating](#chat-errors-while-the-model-is-still-generating). **Note:** Environment variables take precedence over UI settings. When an env var is set, the corresponding UI field is disabled. @@ -1094,6 +1111,41 @@ Then restart both `web` and `worker` so the new env var is loaded. If you are us - Check for thermal throttling - If you see `Net::ReadTimeout` after fixing the context budget, raise `OPENAI_REQUEST_TIMEOUT` (for example `180`) +### Chat Errors While the Model Is Still Generating + +**Symptom:** The chat shows "Thinking…" for a while, then an error saying the assistant is not available — but the model does produce a reply and LLM Usage shows tokens were generated. + +**Cause:** Three settings interact here, measured over different spans: + +- `OPENAI_REQUEST_TIMEOUT` (default `60`) — applies to **each HTTP call** to the model, on its own. +- `ASSISTANT_MAX_TOOL_CALL_ITERATIONS` (default `5`) — how many chained tool calls one turn may make. A turn costs up to `1 + this` model calls. +- `AI_RESPONSE_TIMEOUT` (default `90`) — covers the **whole turn**, and its clock starts when the message is queued, so Sidekiq queue time counts against it. + +Responses from custom OpenAI-compatible providers are **not streamed**, so nothing appears in the chat until the entire reply is generated. Worse, the assistant only shows text once a response actually contains some — a tool-call-only response produces nothing to display — so a turn that chains several tool calls sits on "Thinking…" through all of them. At the defaults the worst case is six sequential model calls plus five tool executions. + +**Fix:** size `AI_RESPONSE_TIMEOUT` as a **sum**, not simply as a number larger than the per-call limit: + +```text +AI_RESPONSE_TIMEOUT ≥ (1 + ASSISTANT_MAX_TOOL_CALL_ITERATIONS) × OPENAI_REQUEST_TIMEOUT + + tool execution + queue wait +``` + +You have two levers, and the cheaper one is usually the tool-call cap, because it divides the first term. With `ASSISTANT_MAX_TOOL_CALL_ITERATIONS=2` a turn costs at most three model calls instead of six, halving the timeout you need. The trade-off is that genuinely long tool chains fail earlier, with a clear "exceeded the tool-call limit" error rather than a timeout. + +```bash +OPENAI_REQUEST_TIMEOUT=300 +ASSISTANT_MAX_TOOL_CALL_ITERATIONS=2 +AI_RESPONSE_TIMEOUT=1200 # (1 + 2) × 300 = 900, plus 300 headroom +``` + +Keeping the full five iterations at 300s per call would instead need `6 × 300 = 1800` plus headroom — which is why lowering the cap is usually the better trade. + +If `AI_RESPONSE_TIMEOUT` ends up below what the turn actually takes, you get a generic "no response" instead of the specific timeout error, and the job keeps running and burning tokens after the chat has given up. + +`AI_RESPONSE_TIMEOUT` can also be set at **Settings → Self-Hosting → OpenAI → Chat Response Timeout**, which takes effect without a restart. The environment variable wins if both are set. The minimum accepted value is `30`. + +Restart `web` and `worker` after changing the environment variables, and make sure your Docker Compose file forwards them into the containers. + ### No Provider Available **Symptom:** "Provider not found" or similar error diff --git a/test/controllers/messages_controller_test.rb b/test/controllers/messages_controller_test.rb index 6fdc425a4..db09caa30 100644 --- a/test/controllers/messages_controller_test.rb +++ b/test/controllers/messages_controller_test.rb @@ -42,6 +42,39 @@ class MessagesControllerTest < ActionDispatch::IntegrationTest assert @chat.reload.error.present? end + # A client clock running ahead of the server's reports before the server floor + # has elapsed. The response must not be 2xx: the watchdog stops retrying a URL + # once it sees one, so an OK here would leave the bubble spinning forever. + test "report_timeout declines retryably when the message is still too young" do + Chat.stubs(:undelivered_response_timeout).returns(10.minutes) + + pending = @chat.messages.create!(type: "AssistantMessage", content: "", ai_model: "gpt-4.1", status: :pending, created_at: 5.minutes.ago) + + post report_timeout_chat_message_url(@chat, pending) + + assert_response :conflict + assert pending.reload.pending? + assert_nil @chat.reload.error + end + + # The same bubble must resolve once it genuinely ages past the floor, so an + # early report costs a retry rather than stranding the message. + test "report_timeout succeeds on a later retry once the message is old enough" do + BackgroundJobHealth.stubs(:snapshot).returns({}) + BackgroundJobHealth.stubs(:summary).returns("") + + pending = @chat.messages.create!(type: "AssistantMessage", content: "", ai_model: "gpt-4.1", status: :pending, created_at: 5.minutes.ago) + + Chat.stubs(:undelivered_response_timeout).returns(10.minutes) + post report_timeout_chat_message_url(@chat, pending) + assert_response :conflict + + Chat.stubs(:undelivered_response_timeout).returns(1.minute) + post report_timeout_chat_message_url(@chat, pending) + assert_response :ok + assert_not Message.exists?(pending.id) + end + test "report_timeout cannot touch another user's chat" do other_chat = users(:family_member).chats.first pending = other_chat.messages.create!(type: "AssistantMessage", content: "", ai_model: "gpt-4.1", status: :pending) diff --git a/test/models/assistant_message_test.rb b/test/models/assistant_message_test.rb index 167fed4ee..ed9be8c8a 100644 --- a/test/models/assistant_message_test.rb +++ b/test/models/assistant_message_test.rb @@ -17,6 +17,49 @@ class AssistantMessageTest < ActiveSupport::TestCase assert_equal "assistant_message_#{message.id}", streams.last["target"] end + test "append_text! streams into a pending bubble" do + message = AssistantMessage.create!(chat: @chat, content: "", ai_model: "gpt-4.1", status: :pending) + + assert message.append_text!("Hello") + assert_equal "Hello", message.reload.content + assert message.complete? + end + + # The watchdog runs in the web process; a slow job holds its own copy of the + # message and must not resurrect a bubble the user was already told failed. + test "append_text! refuses to resurrect a bubble the watchdog already cleared" do + message = AssistantMessage.create!(chat: @chat, content: "", ai_model: "gpt-4.1", status: :pending) + job_copy = AssistantMessage.find(message.id) + + message.destroy! + + assert_not job_copy.append_text!("late response") + assert_not Message.exists?(job_copy.id) + end + + test "append_text! refuses to resurrect a bubble the watchdog demoted to failed" do + message = AssistantMessage.create!(chat: @chat, content: "", ai_model: "gpt-4.1", status: :pending) + job_copy = AssistantMessage.find(message.id) + + message.update_columns(status: "failed") + + assert_not job_copy.append_text!("late response") + assert_equal "failed", message.reload.status + assert_equal "", message.content + end + + # Only the first append claims the row, so a streaming response does not pay + # for the conditional UPDATE on every chunk. + test "append_text! claims the pending row once, then appends in place" do + message = AssistantMessage.create!(chat: @chat, content: "", ai_model: "gpt-4.1", status: :pending) + + assert message.append_text!("Hello") + assert message.append_text!(" world") + + assert_equal "Hello world", message.reload.content + assert message.complete? + end + test "broadcasts remove after destroy so a failed turn's bubble is cleared" do message = AssistantMessage.create!(chat: @chat, content: "Hello from assistant", ai_model: "gpt-4.1") message.destroy! diff --git a/test/models/chat_test.rb b/test/models/chat_test.rb index 7466ba82b..b7433b8fc 100644 --- a/test/models/chat_test.rb +++ b/test/models/chat_test.rb @@ -199,4 +199,62 @@ class ChatTest < ActiveSupport::TestCase assert_not chat.handle_undelivered_response!(complete) end end + + # `Chat.response_timeout` reads ENV ahead of Setting, so every assertion about + # the Setting, the default or the floor has to clear AI_RESPONSE_TIMEOUT first — + # otherwise an environment that happens to define it silently decides the result. + def with_setting_timeout(value) + Setting.stubs(:ai_response_timeout).returns(value) + with_env_overrides("AI_RESPONSE_TIMEOUT" => nil) { yield } + end + + test "response_timeout falls back to the default when unconfigured" do + with_setting_timeout(nil) do + assert_equal Chat::DEFAULT_RESPONSE_TIMEOUT, Chat.response_timeout + end + end + + test "response_timeout prefers ENV over Setting" do + with_setting_timeout(120) do + assert_equal 120.seconds, Chat.response_timeout + end + + Setting.stubs(:ai_response_timeout).returns(120) + with_env_overrides("AI_RESPONSE_TIMEOUT" => "300") do + assert_equal 300.seconds, Chat.response_timeout + end + end + + test "response_timeout ignores non-positive values and enforces a floor" do + with_setting_timeout(0) do + assert_equal Chat::DEFAULT_RESPONSE_TIMEOUT, Chat.response_timeout + end + + with_setting_timeout(5) do + assert_equal Chat::MIN_RESPONSE_TIMEOUT, Chat.response_timeout + end + end + + # An early report is refused by the server, and `report_timeout` answers 409 so + # the watchdog retries. The grace window keeps those retries rare for a client + # whose clock is modestly ahead. + test "undelivered_response_timeout stays below the client timeout" do + with_setting_timeout(300) do + assert_equal 290.seconds, Chat.undelivered_response_timeout + assert Chat.undelivered_response_timeout < Chat.response_timeout + end + end + + test "handle_undelivered_response! respects a raised timeout" do + chat = chats(:two) + pending = chat.messages.create!(type: "AssistantMessage", content: "", ai_model: "gpt-4.1", status: :pending, created_at: 5.minutes.ago) + + with_setting_timeout(600) do + assert_no_difference [ "DebugLogEntry.count", "Message.count" ] do + assert_not chat.handle_undelivered_response!(pending) + end + end + + assert pending.reload.pending? + end end